sozu_lib/protocol/mux/h1.rs
1//! H1 mux connection wrapper.
2//!
3//! Hosts the single active H1 stream (`stream: GlobalStreamId`) and wires
4//! Kawa-owned H1 parsing + serialization into the shared mux `Context` so the
5//! same routing / shutdown / readiness machinery applies across H1 and H2
6//! connections. Long-form lifecycle: `lib/src/protocol/mux/LIFECYCLE.md`.
7
8use std::{
9 cell::Cell,
10 io::IoSlice,
11 time::{Duration, Instant},
12};
13
14use rusty_ulid::Ulid;
15use sozu_command::{logging::ansi_palette, ready::Ready};
16
17pub(super) use super::shared::{LINGER_MAX_BYTES, Linger};
18use crate::metrics::names;
19use crate::{
20 L7ListenerHandler, ListenerHandler, Readiness,
21 protocol::mux::{
22 BackendStatus, Context, DebugEvent, Endpoint, GlobalStreamId, MuxResult, Position,
23 StreamState, forcefully_terminate_answer, memoized_rtt,
24 parser::H2Error,
25 remove_backend_stream, set_default_answer,
26 shared::{
27 EndStreamAction, LingerRead, drain_discard, drain_tls_close_notify, end_stream_decision,
28 },
29 update_readiness_after_read, update_readiness_after_write,
30 },
31 socket::{SocketHandler, SocketResult},
32};
33
34/// Prefix applied to every [`ConnectionH1`] log line. Matches the RUSTLS
35/// log-context convention (`MUX-H1\tSession(...)\t >>>`). When the logger is
36/// in colored mode the label is bold bright-white (uniform across every
37/// protocol) and the session detail is rendered in light grey.
38///
39/// Fields included in the session block (chosen to surface the most common
40/// H1 troubleshooting axes — keep-alive churn, stream pinning, buffer-pressure
41/// stall and graceful TLS shutdown):
42/// - `peer` — peer address via [`SocketHandler::peer_addr`](crate::socket::SocketHandler::peer_addr),
43/// snapshotted once into `ConnectionH1::peer_address` at construction rather
44/// than looked up live on each expansion. It therefore survives the peer's
45/// RST (which is when these lines are read); on a PROXY-protocol frontend it
46/// names the advertised client rather than the load balancer, matching the
47/// `HTTPS`/`HTTP` line for the same request id; and on a backend connection
48/// it names the cluster-configured address even while the async `connect()`
49/// is still in flight and `getpeername(2)` would refuse
50/// - `position` — `Server` / `Client(...)` orientation
51/// - `stream` — currently active [`GlobalStreamId`] (or `none`)
52/// - `requests` — request count served on this connection (keep-alive)
53/// - `parked` — set when the kawa buffer is full and `READABLE` is suspended
54/// - `close_notify` — TLS `close_notify` send state
55/// - `readiness` — connection-level mio readiness snapshot
56macro_rules! log_context {
57 ($self:expr) => {{
58 let (open, reset, grey, gray, white) = ansi_palette();
59 format!(
60 "[{ulid} - - -]\t{open}MUX-H1{reset}\t{grey}Session{reset}({gray}peer{reset}={white}{peer:?}{reset}, {gray}position{reset}={white}{position:?}{reset}, {gray}stream{reset}={white}{stream:?}{reset}, {gray}requests{reset}={white}{requests}{reset}, {gray}parked{reset}={white}{parked}{reset}, {gray}close_notify{reset}={white}{close_notify}{reset}, {gray}readiness{reset}={white}{readiness}{reset})\t >>>",
61 open = open,
62 reset = reset,
63 grey = grey,
64 gray = gray,
65 white = white,
66 ulid = $self.session_ulid,
67 peer = $self.peer_address,
68 position = $self.position,
69 stream = $self.stream,
70 requests = $self.requests,
71 parked = $self.parked_on_buffer_pressure,
72 close_notify = $self.close_notify_sent,
73 readiness = $self.readiness,
74 )
75 }};
76}
77
78/// Per-stream variant of [`log_context!`] used when a `HttpContext` is in
79/// scope. Fills the `request_id` slot of the bracket so the log line can be
80/// grepped by the specific request that triggered it.
81#[allow(unused_macros)]
82macro_rules! log_context_stream {
83 ($self:expr, $http_context:expr) => {{
84 let (open, reset, grey, gray, white) = ansi_palette();
85 format!(
86 "[{ulid} {req} {cluster} {backend}]\t{open}MUX-H1{reset}\t{grey}Session{reset}({gray}peer{reset}={white}{peer:?}{reset}, {gray}position{reset}={white}{position:?}{reset}, {gray}stream{reset}={white}{stream:?}{reset}, {gray}requests{reset}={white}{requests}{reset}, {gray}parked{reset}={white}{parked}{reset}, {gray}close_notify{reset}={white}{close_notify}{reset}, {gray}readiness{reset}={white}{readiness}{reset})\t >>>",
87 open = open,
88 reset = reset,
89 grey = grey,
90 gray = gray,
91 white = white,
92 ulid = $self.session_ulid,
93 req = $http_context.id,
94 cluster = $http_context.cluster_id.as_deref().unwrap_or("-"),
95 backend = $http_context.backend_id.as_deref().unwrap_or("-"),
96 peer = $self.peer_address,
97 position = $self.position,
98 stream = $self.stream,
99 requests = $self.requests,
100 parked = $self.parked_on_buffer_pressure,
101 close_notify = $self.close_notify_sent,
102 readiness = $self.readiness,
103 )
104 }};
105}
106
107/// Module-level prefix for logs without a [`ConnectionH1`] in scope. Honours
108/// the colored flag.
109macro_rules! log_module_context {
110 () => {{
111 let (open, reset, _, _, _) = ansi_palette();
112 format!("{open}MUX-H1{reset}\t >>>", open = open, reset = reset)
113 }};
114}
115
116/// HTTP/1.1 connection handler within the mux layer.
117///
118/// Manages a single HTTP/1.1 connection (either frontend or backend),
119/// handling request/response forwarding through kawa buffers. Supports
120/// keep-alive, chunked transfer encoding, close-delimited responses,
121/// and upgrade (e.g., WebSocket).
122pub struct ConnectionH1<Front: SocketHandler> {
123 pub position: Position,
124 pub readiness: Readiness,
125 pub requests: usize,
126 pub socket: Front,
127 /// Peer address of this connection, captured once at construction from
128 /// [`SocketHandler::peer_addr`](crate::socket::SocketHandler::peer_addr)
129 /// and never re-read.
130 ///
131 /// This is the `peer=` slot every `log_context!` line carries, and the one
132 /// its per-stream twin `log_context_stream!` fills. Both used to build it
133 /// from `socket.socket_ref().peer_addr().ok()` — a live `getpeername(2)`
134 /// that reached past the trait method added to stop exactly that.
135 ///
136 /// Both production handlers *prefer* a cached address and fall back to a
137 /// live lookup when they hold none: `SessionTcpStream` and `FrontRustls`
138 /// each answer `self.configured_peer.or_else(|| self.stream.peer_addr().ok())`
139 /// (`socket.rs`). **That fallback arm is reachable** — the direct routes
140 /// seed `configured_peer` from a best-effort `peer_addr().ok()` at accept,
141 /// an `Option` precisely because that lookup can fail — it is pinned by its
142 /// own tests, and nothing here licenses deleting it.
143 ///
144 /// The snapshot is at least as good on every path, which is the actual
145 /// argument. It is taken while the connection is established, so wherever
146 /// the fallback would have answered it answers here too; it then survives
147 /// the peer's reset, where a later live lookup returns `ENOTCONN` and
148 /// renders `peer=None` on exactly the error lines an operator reads during
149 /// an incident. The divergence is one-directional — `Some` where `None`
150 /// used to appear, never a different address.
151 ///
152 /// This is `ConnectionH2::peer_address`' shape, so an operator grepping a
153 /// single session ULID reads the same `peer=` on the `MUX-H1` and `MUX-H2`
154 /// lines of one connection.
155 pub(super) peer_address: Option<std::net::SocketAddr>,
156 /// Active stream index, or `None` when the connection has no assigned stream
157 /// (initial client state before `start_stream`, or after `end_stream` detaches).
158 pub stream: Option<GlobalStreamId>,
159 /// Configured idle timeout for this connection. The core never arms a
160 /// wheel entry itself: it publishes the next instant it wants to be called
161 /// back at through `ConnectionH1::poll_timeout`, and the embedder — the
162 /// `Mux` adapter — owns the `TimeoutContainer` that reflects it onto the
163 /// real timer. See `LIFECYCLE.md` §7.7.
164 pub timeout_duration: Duration,
165 /// Next instant this connection wants `timeout()` called at, or `None`
166 /// when it wants no timer at all.
167 pub(super) timeout_deadline: Option<Instant>,
168 /// Set when `readable` exits early because the kawa buffer was full.
169 /// Edge-triggered epoll will not re-fire READABLE for data already in the
170 /// kernel socket buffer, so the cross-readiness mechanism must re-arm it
171 /// via `try_resume_reading` once the peer drains the buffer.
172 pub parked_on_buffer_pressure: bool,
173 /// A write to the client failed (reset, broken pipe or another socket
174 /// error): nothing more can be flushed to it, so the connection reports
175 /// no pending write and the session closes instead of waiting to flush.
176 pub write_failed: bool,
177 /// True once we've asked rustls to emit TLS close_notify for this frontend.
178 pub close_notify_sent: bool,
179 /// Connection/session ULID propagated from the parent [`super::Mux`]. Used to
180 /// stamp the session slot of the `[session req cluster backend]` log
181 /// prefix emitted by the local `log_context!` macro.
182 pub session_ulid: Ulid,
183 /// True once this backend connection has served a stream that it picked
184 /// up out of the H1 keep-alive pool, rather than on the fresh dial that
185 /// created it.
186 ///
187 /// This is pingora's `client_reused` bit — the provenance the protocol
188 /// layer cannot see but the retry decision needs.
189 ///
190 /// It does NOT prove what the peer did. An EOF with no response is
191 /// indistinguishable at this layer from a stale pool socket, from an
192 /// origin that half-closed after processing the request but before
193 /// answering, and from one that crashed mid-request: `readable` treats
194 /// every `size == 0` alike, and an empty back buffer proves only that no
195 /// response byte arrived. What this bit does is bound the window in
196 /// which sozu is willing to re-issue: a connection that came out of the
197 /// pool has been idle long enough for its peer to have closed it
198 /// unobserved, a freshly dialled one has not. What makes re-issuing
199 /// permissible at all is the idempotence gate (RFC 9110 §9.2.2) in
200 /// `Stream::can_replay_on_fresh_upstream`; this bit only narrows when
201 /// that permission is exercised, so only a reused connection arms
202 /// request capture (sozu-proxy/sozu#1442). Always false on a
203 /// `Position::Server` connection.
204 pub reused_from_pool: bool,
205 /// `writable`'s vectored-write scratch, kept for the connection's
206 /// lifetime so a write pass reuses its capacity instead of allocating
207 /// and growing a fresh vector (sozu-proxy/sozu#1580).
208 ///
209 /// Empty outside one `h2_transmit::gather` / `h2_transmit::confirm`
210 /// bracket inside `writable`: only the capacity survives a pass, never a
211 /// descriptor. `pub(super)` rather than private (as in `H2Shell`) only
212 /// because `ConnectionH1` has no constructor in this module: both are
213 /// struct literals in `connection.rs`. Nothing else in `mux` touches it.
214 pub(super) io_slices: Vec<IoSlice<'static>>,
215 /// This connection's one `getsockopt(TCP_INFO)` sample, `None` until its
216 /// first access log asks for it. Read through `Connection::rtt` and
217 /// [`Self::rtt`], both of which go through
218 /// [`memoized_rtt`](super::memoized_rtt); never reset, so a keep-alive
219 /// connection pays one read, not one per request. `pub(super)` for the
220 /// same reason as `io_slices`: the struct literals live in
221 /// `connection.rs`.
222 pub(super) rtt: Cell<Option<Option<Duration>>>,
223 /// How long a lingering close may drain the rest of a request: the
224 /// listener's `request_timeout`, which a frontend connection is built
225 /// with. Unused on a backend connection.
226 pub(super) linger_timeout: Duration,
227 /// Lingering-close state of a frontend connection. See [`Linger`].
228 pub(super) linger: Linger,
229}
230
231impl<Front: SocketHandler> std::fmt::Debug for ConnectionH1<Front> {
232 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
233 f.debug_struct("ConnectionH1")
234 .field("position", &self.position)
235 .field("readiness", &self.readiness)
236 .field("peer_address", &self.peer_address)
237 .field("stream", &self.stream)
238 .field("reused_from_pool", &self.reused_from_pool)
239 .finish()
240 }
241}
242
243impl<Front: SocketHandler> ConnectionH1<Front> {
244 /// Smoothed RTT of this connection's socket, sampled at the first access
245 /// log that asks for it and reused for the connection's whole life.
246 fn rtt(&self) -> Option<Duration> {
247 memoized_rtt(&self.rtt, self.socket.socket_ref())
248 }
249
250 /// The next instant this connection wants its embedder to call `timeout()`
251 /// at, or `None` for "no timer". The adapter reflects this onto the real
252 /// wheel; nothing here touches `crate::timer`.
253 pub(super) fn poll_timeout(&self) -> Option<Instant> {
254 self.timeout_deadline
255 }
256
257 /// Push the deadline one full [`Self::timeout_duration`] out from `now`.
258 /// Replaces the old `TimeoutContainer::reset()` at the same call sites.
259 ///
260 /// A no-op while lingering: the linger deadline bounds the whole drain,
261 /// and every caller — `readable`, `writable`, `Mux::timeout_inner`'s
262 /// re-arm after a write pass that may itself have started the linger —
263 /// must leave it in place.
264 pub(super) fn arm_timeout(&mut self, now: Instant) {
265 if self.is_lingering() {
266 return;
267 }
268 self.timeout_deadline = now.checked_add(self.timeout_duration);
269 }
270
271 /// Ask for no timer at all. Replaces `TimeoutContainer::cancel()`.
272 pub(super) fn clear_timeout(&mut self) {
273 self.timeout_deadline = None;
274 }
275
276 /// Adopt a new configured duration and re-arm from `now`.
277 ///
278 /// Mirrors `TimeoutContainer::set_duration`, which likewise cancelled and
279 /// re-armed rather than keeping the old deadline. It re-arms
280 /// unconditionally: the old method re-armed whenever the container had ever
281 /// held a token, which every live connection has.
282 pub(super) fn set_timeout_duration(&mut self, duration: Duration, now: Instant) {
283 self.timeout_duration = duration;
284 self.arm_timeout(now);
285 }
286
287 fn defer_close_for_tls_flush(&mut self, reason: &'static str) -> MuxResult {
288 if self.initiate_close_notify() {
289 trace!(
290 "{} H1 writable delaying close after {}: stream={:?}, close_notify_sent={}, wants_write={}, readiness={:?}",
291 log_context!(self),
292 reason,
293 self.stream,
294 self.close_notify_sent,
295 self.socket.socket_wants_write(),
296 self.readiness
297 );
298 MuxResult::Continue
299 } else if let Linger::Pending { deadline } = self.linger {
300 self.start_linger(deadline, reason)
301 } else {
302 MuxResult::CloseSession
303 }
304 }
305
306 /// Whether the connection is draining the rest of a request after its
307 /// response (see [`Linger`]).
308 pub(super) fn is_lingering(&self) -> bool {
309 matches!(self.linger, Linger::Draining { .. })
310 }
311
312 /// Shut the write side down after a fully flushed response, then read
313 /// what the client still sends until [`Self::drain_linger`] closes.
314 fn start_linger(&mut self, deadline: Instant, reason: &'static str) -> MuxResult {
315 debug_assert!(
316 self.position.is_server() && !self.socket.socket_wants_write(),
317 "a linger starts on a frontend with nothing left to flush"
318 );
319 // The FIN follows the response; the client reads it all, then EOF.
320 if let Err(e) = super::shutdown_write(self.socket.socket_ref(), false) {
321 debug!(
322 "{} H1 closing without lingering after {}: shutdown failed: {:?}",
323 log_context!(self),
324 reason,
325 e
326 );
327 return MuxResult::CloseSession;
328 }
329 debug!(
330 "{} H1 lingering after {}: draining the rest of the request",
331 log_context!(self),
332 reason
333 );
334 self.linger = Linger::Draining {
335 deadline,
336 remaining: LINGER_MAX_BYTES,
337 };
338 // Fixed, never re-armed: the deadline bounds the whole drain.
339 self.timeout_deadline = Some(deadline);
340 self.readiness.interest = Ready::READABLE | Ready::HUP | Ready::ERROR;
341 self.readiness.event.remove(Ready::WRITABLE);
342 // Edge-triggered epoll will not report bytes already queued.
343 self.readiness.event.insert(Ready::READABLE);
344 MuxResult::Continue
345 }
346
347 /// Read and drop what the client still sends while lingering. Closes on
348 /// the client's EOF, a socket error, the byte budget, or the deadline;
349 /// otherwise waits for the next READABLE.
350 fn drain_linger(&mut self, now: Instant) -> MuxResult {
351 let Linger::Draining {
352 deadline,
353 mut remaining,
354 } = self.linger
355 else {
356 unreachable!("drain_linger runs only while draining");
357 };
358 if now >= deadline {
359 debug!(
360 "{} H1 lingering close: deadline reached",
361 log_context!(self)
362 );
363 return MuxResult::CloseSession;
364 }
365 let position = &self.position;
366 let result = match drain_discard(self.socket.socket_ref(), &mut remaining, |size| {
367 // Bytes the client sent: counted like any frontend read.
368 crate::protocol::mux::h2::record_metric(position.bytes_in_event(size));
369 }) {
370 LingerRead::Wait => {
371 self.readiness.event.remove(Ready::READABLE);
372 MuxResult::Continue
373 }
374 LingerRead::Close => {
375 debug!(
376 "{} H1 lingering close: EOF, error or {} bytes left of the budget",
377 log_context!(self),
378 remaining
379 );
380 MuxResult::CloseSession
381 }
382 };
383 self.linger = Linger::Draining {
384 deadline,
385 remaining,
386 };
387 result
388 }
389
390 /// Drop the trailer block of a Content-Length-framed message before it
391 /// is written to this H1 peer, and return whether one was dropped.
392 ///
393 /// HTTP/1.1 carries a trailer section only with chunked coding (RFC 9112
394 /// §7.1) and a length-framed message ends with its last body byte
395 /// (§6.3), while `pkawa::handle_trailer` queues an H2 trailer block for
396 /// every peer, so an H2 peer still receives it. A trailer block is the
397 /// run of `Header` blocks before a closing `Flags { end_header,
398 /// end_stream }` that does not follow the `StatusLine` or `Cookies` of a
399 /// header section. Its fields are removed and its closing flags lose
400 /// `end_header`, so kawa's H1 serializer writes nothing after the body
401 /// (RFC 9110 §6.5.1 lets a recipient discard trailers). An H2 trailer
402 /// block is queued whole, and kawa's H1 serializer drains every queued
403 /// block in one `prepare`, so the block is never split across passes.
404 fn drop_length_framed_trailers(kawa: &mut super::GenericHttpStream) -> bool {
405 if !matches!(kawa.body_size, kawa::BodySize::Length(_)) {
406 return false;
407 }
408 let Some(kawa::Block::Flags(kawa::Flags {
409 end_header: true,
410 end_stream: true,
411 ..
412 })) = kawa.blocks.back()
413 else {
414 return false;
415 };
416 let closing = kawa.blocks.len() - 1;
417 let first_field = kawa
418 .blocks
419 .range(..closing)
420 .rposition(|block| !matches!(block, kawa::Block::Header(_)))
421 .map_or(0, |before| before + 1);
422 if first_field > 0
423 && matches!(
424 kawa.blocks[first_field - 1],
425 kawa::Block::StatusLine | kawa::Block::Cookies
426 )
427 {
428 return false;
429 }
430 kawa.blocks.drain(first_field..closing);
431 if let Some(kawa::Block::Flags(flags)) = kawa.blocks.back_mut() {
432 flags.end_header = false;
433 }
434 warn!(
435 "{} trailers of a Content-Length-framed message dropped towards an H1 peer \
436 (RFC 9112 §7.1); omit Content-Length to have them forwarded",
437 log_module_context!()
438 );
439 incr!(names::h2::TRAILERS_DROPPED_CONTENT_LENGTH);
440 true
441 }
442
443 /// Whether the response on this stream has no body by definition: a
444 /// response to HEAD (RFC 9110 §9.3.2) or a 204 or 304 (RFC 9110 §15.3.5,
445 /// §15.4.5). Its H1 message ends with the header section whatever its
446 /// framing fields say (RFC 9112 §6.3 rule 1).
447 fn response_has_no_body(context: &crate::protocol::kawa_h1::editor::HttpContext) -> bool {
448 context.method == Some(crate::protocol::kawa_h1::parser::Method::Head)
449 || matches!(context.status, Some(204 | 304))
450 }
451
452 /// Strip the end-of-body framing and the trailer block of a response
453 /// that has no body by definition (`response_has_no_body`) before it is
454 /// written to this H1 client, and return whether a trailer block was
455 /// dropped.
456 ///
457 /// An H1 client reads such a response as ending with its header section
458 /// (RFC 9112 §6.3 rule 1), so it carries neither a last chunk nor a
459 /// trailer section, and any byte written after the head is read as the
460 /// start of the next response on a keep-alive connection. The end of an
461 /// H2 backend stream, an empty DATA frame or a trailer HEADERS frame,
462 /// queues `Flags` that kawa's H1 serializer writes as `0\r\n` under
463 /// chunked framing, and as the trailer fields and an empty line;
464 /// `pkawa::handle_header` gives such a response no chunked framing, and
465 /// leaves it open until that end. Every block after the header section
466 /// is cleared here: its trailer fields are removed (RFC 9110
467 /// §6.5.1 lets a recipient discard trailers) and its `Flags` lose
468 /// `end_body`, `end_chunk` and `end_header`, so for a stream ended by a
469 /// trailer HEADERS frame or an empty DATA frame nothing is written after
470 /// the head. DATA carrying a payload on such a response never reaches
471 /// this queue: `ConnectionH2::handle_data_frame` resets the backend
472 /// stream of a 204 or a 304 and discards the payload of a response to
473 /// HEAD first (RFC 9110 §6.4.1). The header section is the last queued `StatusLine` (an
474 /// informational head queued before it is left whole) up to its first
475 /// closing `Flags { end_header }`; when it is no longer queued, kawa's
476 /// H1 serializer already wrote it whole, since it drains every queued
477 /// block in one `prepare`. `drop_length_framed_trailers` runs first and
478 /// keeps counting a `Content-Length`-framed trailer block.
479 fn drop_bodiless_response_framing(kawa: &mut super::GenericHttpStream) -> bool {
480 let after_head = match kawa
481 .blocks
482 .iter()
483 .rposition(|block| matches!(block, kawa::Block::StatusLine))
484 {
485 Some(status_line) => match kawa.blocks.range(status_line..).position(|block| {
486 matches!(
487 block,
488 kawa::Block::Flags(kawa::Flags {
489 end_header: true,
490 ..
491 })
492 )
493 }) {
494 Some(closing) => status_line + closing + 1,
495 // The header section is not complete yet.
496 None => return false,
497 },
498 None => 0,
499 };
500 let mut dropped_trailers = false;
501 let mut index = after_head;
502 while index < kawa.blocks.len() {
503 match &mut kawa.blocks[index] {
504 kawa::Block::Header(_) => {
505 kawa.blocks.remove(index);
506 continue;
507 }
508 kawa::Block::Flags(flags) => {
509 dropped_trailers |= flags.end_header && flags.end_stream;
510 flags.end_body = false;
511 flags.end_chunk = false;
512 flags.end_header = false;
513 }
514 _ => {}
515 }
516 index += 1;
517 }
518 if dropped_trailers {
519 warn!(
520 "{} trailers of a response without a body dropped towards an H1 client \
521 (RFC 9112 §6.3)",
522 log_module_context!()
523 );
524 incr!(names::h2::TRAILERS_DROPPED_NO_BODY);
525 }
526 dropped_trailers
527 }
528
529 /// End a response body at the backend's EOF.
530 ///
531 /// Only a body with neither `Content-Length` nor chunked coding
532 /// (`BodySize::Empty`) is delimited by the close (RFC 9112 §6.3 rule 8):
533 /// it is terminated by pushing END_STREAM flags.
534 ///
535 /// A `Content-Length` body still expecting bytes, or a chunked body the
536 /// backend closed before its terminating `0\r\n\r\n` (RFC 9112 §7.1), is
537 /// truncated: RFC 9112 §6.3 rule 5 makes it incomplete. It is demoted to
538 /// `ParsingPhase::Error`, so the H2 converter emits
539 /// RST_STREAM(InternalError) and the H1 frontend closes the connection,
540 /// rather than a silent end of message over a truncated body.
541 fn terminate_close_delimited(kawa: &mut super::GenericHttpStream, stream_id: GlobalStreamId) {
542 // Pre: we only synthesize an end-of-body for a response still in its
543 // body phase. A kawa already Terminated/Error must not be re-terminated
544 // (it would double-push an END_STREAM flag onto the converter).
545 debug_assert!(
546 !kawa.is_terminated(),
547 "terminate_close_delimited must not run on an already-terminated kawa"
548 );
549 debug_assert!(
550 kawa.is_main_phase(),
551 "terminate_close_delimited must only end a response in its body phase"
552 );
553 if kawa.body_size != kawa::BodySize::Empty {
554 // kawa moves a `Content-Length` body to Terminated once its last
555 // byte is parsed, so a `Length` body still in its body phase is
556 // missing bytes: `expects` counts them.
557 debug_assert!(
558 !matches!(kawa.body_size, kawa::BodySize::Length(_)) || kawa.expects > 0,
559 "a Content-Length body still in its body phase must be missing bytes"
560 );
561 warn!(
562 "{} H1 backend EOF before the end of a {:?} response on stream {}: emitting RST_STREAM",
563 log_module_context!(),
564 kawa.body_size,
565 stream_id
566 );
567 incr!(names::h1::BACKEND_EOF_BEFORE_MESSAGE_COMPLETE);
568 kawa.parsing_phase
569 .error(kawa::ParsingErrorKind::Processing {
570 message: "INTERNAL_ERROR",
571 });
572 // Post: a truncated body is demoted to Error so the converter
573 // emits RST_STREAM, never a silent END_STREAM.
574 debug_assert!(
575 kawa.is_error(),
576 "truncated response must end in the Error phase"
577 );
578 return;
579 }
580 debug!(
581 "{} H1 close-delimited EOF on stream {}: terminating body",
582 log_module_context!(),
583 stream_id
584 );
585 kawa.push_block(kawa::Block::Flags(kawa::Flags {
586 end_body: true,
587 end_chunk: false,
588 end_header: false,
589 end_stream: true,
590 }));
591 kawa.parsing_phase = kawa::ParsingPhase::Terminated;
592 // Post: a close-delimited body is now Terminated so the converter
593 // emits DATA with END_STREAM on the last frame.
594 debug_assert!(
595 kawa.is_terminated(),
596 "close-delimited body must end in the Terminated phase"
597 );
598 }
599
600 pub fn readable<E, L>(&mut self, context: &mut Context<L>, mut endpoint: E) -> MuxResult
601 where
602 E: Endpoint,
603 L: ListenerHandler + L7ListenerHandler,
604 {
605 trace!(
606 "{} ======= MUX H1 READABLE {:?}",
607 log_context!(self),
608 self.position
609 );
610 if self.is_lingering() {
611 // Before `arm_timeout`: the linger deadline is never pushed out.
612 return self.drain_linger(context.now);
613 }
614 let Some(stream_id) = self.stream else {
615 error!(
616 "{} readable() called on H1 connection with no active stream",
617 log_context!(self)
618 );
619 return MuxResult::Continue;
620 };
621 self.arm_timeout(context.now);
622 let stream = &mut context.streams[stream_id];
623 // The answer registry this request captured when it arrived, not the
624 // one a reload may have installed since.
625 let answers_rc = stream.answers.clone();
626 if stream.metrics.start.is_none() {
627 stream.metrics.mark_request_start();
628 }
629 // Read before `split` borrows the stream: the relink guard below
630 // needs it while `parts` is alive.
631 let answered = stream.state == StreamState::Unlinked;
632 let parts = stream.split(&self.position);
633 let kawa = parts.rbuffer;
634
635 // If the buffer has no space, don't attempt a read — socket_read with
636 // an empty buffer returns (0, Continue) which is indistinguishable from
637 // a real EOF. Remove READABLE from the event so the inner loop doesn't
638 // spin; `try_resume_reading` will re-arm it once the peer drains the
639 // buffer (edge-triggered epoll won't re-fire for data already in the
640 // kernel socket buffer).
641 if kawa.storage.available_space() == 0 {
642 self.readiness.event.remove(Ready::READABLE);
643 self.parked_on_buffer_pressure = true;
644 // Pair the park flag with the cleared READABLE event: only
645 // `try_resume_reading` may re-arm it once the peer drains space.
646 debug_assert!(
647 self.parked_on_buffer_pressure && !self.readiness.event.is_readable(),
648 "parking on buffer pressure must clear the READABLE event"
649 );
650 return MuxResult::Continue;
651 }
652
653 self.parked_on_buffer_pressure = false;
654 // Pre: we never ask the socket to read into a full buffer (that path
655 // returned above) — `socket_read` requires a non-empty target slice.
656 let space_before = kawa.storage.available_space();
657 debug_assert!(
658 space_before > 0,
659 "socket_read must target a buffer with free space"
660 );
661 let (size, status) = self.socket.socket_read(kawa.storage.space());
662 // A read cannot deliver more bytes than the buffer had room for.
663 // `debug_assert!` only — `size` is socket-derived, never trusted to
664 // panic, but a violation here is a SocketHandler contract bug.
665 debug_assert!(
666 size <= space_before,
667 "socket_read returned more bytes than the buffer could hold"
668 );
669 context.debug.push(DebugEvent::StreamEvent(0, size));
670 if size > 0 && self.position.is_client() {
671 // The upstream answered, so this attempt is past the replay
672 // boundary (`Stream::can_replay_on_fresh_upstream`) whatever the
673 // bytes turn out to parse as. Drop the captured request now
674 // instead of carrying it to the end of the response.
675 *parts.retry_buffer = None;
676 }
677 kawa.storage.fill(size);
678 debug_assert_eq!(
679 kawa.storage.available_space(),
680 space_before - size,
681 "fill must consume exactly `size` bytes of free space"
682 );
683 crate::protocol::mux::h2::record_metric(self.position.bytes_in_event(size));
684 self.position.count_bytes_in(parts.metrics, size);
685 // A backend read that met the EOF records it as HUP, with or without
686 // bytes (sozu-proxy/sozu#1603). `Closed` from a backend socket means
687 // `read(2)` returned 0 or the connection was reset: the fact
688 // `Ready::from(&mio::event::Event)` (`command/src/ready.rs`) reports
689 // as HUP from `is_read_closed()`, and whose edge the kernel has
690 // already queued. With HUP recorded, the dead-backend check of
691 // `Mux::ready_inner` closes this connection on the pass's next inner
692 // iteration, after the bytes read here were parsed below. Since
693 // sozu-proxy/sozu#1606 a read stops on a short read, so the last bytes
694 // and the EOF no longer come back from one `recv`: the EOF is read by
695 // a later `readable`, in the same pass when the edge already carried
696 // HUP, one `epoll_wait` round later when the FIN landed after that
697 // `epoll_wait` returned (HAProxy's trade, `src/raw_sock.c`).
698 //
699 // Backends only. A frontend `Closed` can also be a TLS
700 // `close_notify` on a connection whose TCP stream is still open
701 // (`FrontRustls::socket_read`), which the kernel does not report as
702 // read-closed, and a frontend HUP closes the whole session at the
703 // top of the next pass (`Mux::ready_inner`).
704 if status == SocketResult::Closed && self.position.is_client() {
705 self.readiness.event.insert(Ready::HUP);
706 }
707 // A backend buffer can hold bytes no socket event will announce: a
708 // backend that writes an interim 1xx and what follows it (another
709 // 1xx, the final response) at once leaves the rest unparsed when the
710 // interim is forwarded and cleared (`kawa::Kawa::clear` keeps the
711 // storage). The writable arms that clear it re-arm this read with
712 // `Readiness::signal_pending_read`, and those bytes are parsed here
713 // even though the socket has nothing new. A frontend buffer is left
714 // alone: its leftover bytes are pipelined requests, which wait for
715 // the response in flight.
716 let buffered_response =
717 self.position.is_client() && !kawa.storage.unparsed_data().is_empty();
718 if update_readiness_after_read(size, status, &mut self.readiness) && !buffered_response {
719 // size=0: the socket returned EOF (Closed) or WouldBlock.
720 // For a close-delimited backend response (no Content-Length, no
721 // chunked), a graceful EOF IS the end-of-body signal. Terminate
722 // the kawa so the H2 converter emits DATA with END_STREAM.
723 // SocketResult::Error (ECONNRESET etc.) is NOT treated as a valid
724 // close-delimiter — transport errors should produce 502, not a
725 // truncated response.
726 if status == SocketResult::Closed
727 && self.position.is_client()
728 && kawa.is_main_phase()
729 && !kawa.is_terminated()
730 && !parts.context.keep_alive_backend
731 {
732 Self::terminate_close_delimited(kawa, stream_id);
733 self.timeout_deadline = None;
734 self.readiness.interest.remove(Ready::READABLE);
735 if let StreamState::Linked(token) = stream.state {
736 // Signal pending write alongside the WRITABLE interest flip:
737 // edge-triggered epoll won't re-fire for bytes we just queued
738 // onto the peer — the synthetic event is the only wake path.
739 let peer = endpoint.readiness_mut(token);
740 peer.arm_writable();
741 }
742 }
743 return MuxResult::Continue;
744 }
745
746 let was_main_phase = kawa.is_main_phase();
747 let blocks_before_parse = kawa.blocks.len();
748 kawa::h1::parse(kawa, parts.context);
749 // kawa has no trailer callback: drop spoofed forwarding fields and
750 // the fields RFC 9110 §6.5.1 keeps out of trailers from a chunked
751 // request's trailer section here, and reject one with too many fields
752 // (sozu-proxy/sozu#1689, sozu-proxy/sozu#1701). A trailer section over
753 // the limit marks `kawa` in error, which the branch below answers. A
754 // backend response is a `Kind::Response` and is left untouched.
755 parts
756 .context
757 .filter_request_trailers(kawa, blocks_before_parse);
758 if kawa.is_error() {
759 match self.position {
760 Position::Client(..) => {
761 incr!(names::http::BACKEND_PARSE_ERRORS);
762 let StreamState::Linked(token) = stream.state else {
763 error!(
764 "{} client stream in error is not in Linked state",
765 log_context!(self)
766 );
767 return MuxResult::CloseSession;
768 };
769 let global_stream_id = stream_id;
770 self.end_stream(global_stream_id, context);
771 endpoint.end_stream(token, global_stream_id, context);
772 }
773 Position::Server if stream.back.consumed => {
774 // The response already started on the wire — a backend
775 // may answer early and stream its body while the client
776 // is still uploading. A 400 now would land inside that
777 // body as a second, complete response, which the client
778 // reads as part of the first. The response is cut
779 // instead: nothing more is written, and the connection
780 // closes for writing, so the client sees a truncated
781 // message (RFC 9112 §8), never a spliced one.
782 incr!(names::http::FRONTEND_PARSE_ERRORS);
783 warn!(
784 "{} H1 request rejected after its response started: closing",
785 log_context!(self)
786 );
787 // The backend holds part of the rejected request: end its
788 // stream so an H1 connection closes, never pooled even
789 // when its response is complete (sozu-proxy/sozu#1716).
790 // The client connection closes below whatever this flag
791 // says, so clearing it only reaches the backend.
792 if let StreamState::Linked(token) = stream.state {
793 stream.context.keep_alive_backend = false;
794 endpoint.end_stream(token, stream_id, context);
795 }
796 let stream = &mut context.streams[stream_id];
797 forcefully_terminate_answer(
798 stream,
799 &mut self.readiness,
800 H2Error::InternalError,
801 );
802 debug_assert!(
803 stream.back.is_error() && stream.back.out.is_empty(),
804 "a response already started is cut, not replaced"
805 );
806 return self.defer_close_for_tls_flush("request-error-mid-response");
807 }
808 Position::Server => {
809 incr!(names::http::FRONTEND_PARSE_ERRORS);
810 // A request rejected after its stream was linked, such
811 // as a trailer section over `h2_max_header_fields` read
812 // after the head and body were forwarded, left part of
813 // itself on the backend. End the backend stream before
814 // the answer replaces the response, so the connection
815 // closes and leaves the reverse index, instead of
816 // holding a cut request attached to this stream slot
817 // (sozu-proxy/sozu#1716). The response is cleared first
818 // because a complete one would return an H1 connection
819 // to the keep-alive pool; the 400 replaces it anyway. An
820 // H2 backend only resets this stream. The client
821 // connection closes once the answer is flushed: the
822 // request was never received whole (sozu-proxy/sozu#1721).
823 if let StreamState::Linked(token) = stream.state {
824 stream.back.clear();
825 endpoint.end_stream(token, stream_id, context);
826 }
827 let stream = &mut context.streams[stream_id];
828 let answers = answers_rc.borrow();
829 set_default_answer(stream, &mut self.readiness, 400, &answers);
830 }
831 }
832 return MuxResult::Continue;
833 }
834 // Capture borrow-sensitive values after parsing but before the 1xx block
835 // accesses stream.state (which ends the split borrow from `parts`).
836 let is_keep_alive_backend = parts.context.keep_alive_backend;
837 let is_body_phase_after_parse = kawa.is_main_phase();
838
839 // 1xx informational responses (every 1xx, RFC 9110 §15.2): the H1
840 // parser treats them as complete (Terminated + end_stream=true), but for
841 // H2 frontends they must be forwarded WITHOUT END_STREAM so the real
842 // response can follow on the same stream. Also keep READABLE interest
843 // so the backend can send the final response.
844 let is_1xx_backend = if self.position.is_client() {
845 if let kawa::StatusLine::Response { code, .. } = &kawa.detached.status_line {
846 if (100..200).contains(code) {
847 debug!(
848 "{} H1 backend: received {} informational response",
849 log_context!(self),
850 code
851 );
852 for block in &mut kawa.blocks {
853 if let kawa::Block::Flags(flags) = block {
854 flags.end_stream = false;
855 flags.end_body = false;
856 }
857 }
858 true
859 } else {
860 false
861 }
862 } else {
863 false
864 }
865 } else {
866 false
867 };
868 if kawa.is_terminated() && !is_1xx_backend {
869 self.timeout_deadline = None;
870 self.readiness.interest.remove(Ready::READABLE);
871 }
872 if kawa.is_main_phase() {
873 if !was_main_phase && self.position.is_client() {
874 // The backend's response headers have just finished parsing:
875 // the client twin of the `is_server()` branch below, on the
876 // same header -> body edge. This is the whole of
877 // `backend_header_time`'s H1 arming — nginx's
878 // `$upstream_header_time` (sozu-proxy/sozu#426).
879 //
880 // Unconditional, including on a 1xx: every interim response
881 // (100-Continue, 102-199) clears the back buffer in
882 // `ConnectionH1::writable`, so the FINAL response re-enters
883 // this edge and overwrites, which is the response
884 // `SessionMetrics::backend_stop` also anchors on. A 101 has no
885 // successor and correctly keeps its own instant.
886 parts.metrics.backend_headers_received();
887 }
888 // A request already answered is never linked. `Mux::timeout_inner`
889 // (`lib/src/protocol/mux/mod.rs`) answers 408 on an `Idle` stream
890 // whose head was incomplete and leaves it `Unlinked`; the rest of
891 // that head may still arrive, and is drained by the linger after
892 // the answer (`ConnectionH1::start_linger`), never forwarded.
893 if !was_main_phase && self.position.is_server() && !answered {
894 if parts.context.method.is_none()
895 || parts.context.authority.is_none()
896 || parts.context.path.is_none()
897 {
898 if let kawa::StatusLine::Request {
899 version: kawa::Version::V10,
900 ..
901 } = kawa.detached.status_line
902 {
903 error!(
904 "{} Unexpected malformed request: HTTP/1.0 from {:?} with {:?} {:?} {:?}",
905 log_context!(self),
906 parts.context.session_address,
907 parts.context.method,
908 parts.context.authority,
909 parts.context.path
910 );
911 } else {
912 error!("{} Unexpected malformed request", log_context!(self));
913 kawa::debug_kawa(kawa);
914 }
915 let answers = answers_rc.borrow();
916 set_default_answer(stream, &mut self.readiness, 400, &answers);
917 return MuxResult::Continue;
918 }
919 // First-seen request on this (server) connection: the keep-alive
920 // request counter advances by exactly one and the matching
921 // `http.active_requests` gauge `+1` is paired with flipping
922 // `request_counted` true (the `generate_access_log` `-1` is
923 // gated on that flag, so they must stay balanced).
924 let requests_before = self.requests;
925 let links_before = context.pending_links.len();
926 self.requests += 1;
927 debug_assert_eq!(
928 self.requests,
929 requests_before + 1,
930 "server keep-alive request counter must advance by exactly one"
931 );
932 trace!("{} REQUESTS: {}", log_context!(self), self.requests);
933 incr!(names::http::REQUESTS);
934 gauge_add!(names::http::ACTIVE_REQUESTS, 1);
935 parts.metrics.service_start();
936 // Set request_counted after the last use of `parts` to satisfy the borrow checker
937 stream.request_counted = true;
938 stream.state = StreamState::Link;
939 // An H1 frontend has one request in flight, so its session
940 // never queues more than one link: size the queue for exactly
941 // that on first use instead of four (#1610).
942 if context.pending_links.capacity() == 0 {
943 context.pending_links.reserve_exact(1);
944 }
945 context.pending_links.push_back(stream_id);
946 // Post: the stream is queued for backend linking exactly once
947 // and is now in the Link state the ready loop expects.
948 debug_assert!(
949 stream.request_counted,
950 "request_counted must be set when the active-requests gauge is incremented"
951 );
952 debug_assert_eq!(
953 stream.state,
954 StreamState::Link,
955 "a first-seen request must transition the stream to Link"
956 );
957 debug_assert_eq!(
958 context.pending_links.len(),
959 links_before + 1,
960 "a first-seen request must enqueue exactly one pending link"
961 );
962 }
963 if let StreamState::Linked(token) = stream.state {
964 // Signal pending write alongside the WRITABLE interest flip: the
965 // bytes we just parsed live in sozu's buffers, not the kernel,
966 // so edge-triggered epoll won't re-fire on its own.
967 let peer = endpoint.readiness_mut(token);
968 peer.arm_writable();
969 }
970 };
971 // 1xx informational: kawa sets `detached.status_line` as soon as the
972 // status line parses and only then moves to `ParsingPhase::Headers`,
973 // so a read that stops inside the 1xx headers leaves
974 // `is_main_phase()` false while `is_1xx_backend` is already true. On
975 // that pass only this arm wakes the frontend, early, before the 1xx is
976 // complete; the pass that completes the headers re-arms it through the
977 // `Linked` arm above either way. When the whole 1xx arrives in one
978 // read it parses to `Terminated`, which kawa counts as a main phase, so
979 // the `Linked` arm above has already fired and this call is redundant
980 // (`arm_writable` is idempotent).
981 if is_1xx_backend && let StreamState::Linked(token) = stream.state {
982 let peer = endpoint.readiness_mut(token);
983 peer.arm_writable();
984 }
985
986 // Close-delimited response: socket_read returned (size > 0, Closed) —
987 // the last data chunk arrived together with the EOF in a single read.
988 // After parsing the data above, terminate the kawa now so the H2
989 // converter emits END_STREAM on the last DATA frame.
990 if status == SocketResult::Closed
991 && self.position.is_client()
992 && is_body_phase_after_parse
993 && !is_keep_alive_backend
994 && !context.streams[stream_id].back.is_terminated()
995 {
996 let kawa = &mut context.streams[stream_id].back;
997 Self::terminate_close_delimited(kawa, stream_id);
998 self.timeout_deadline = None;
999 self.readiness.interest.remove(Ready::READABLE);
1000 }
1001
1002 MuxResult::Continue
1003 }
1004
1005 pub fn writable<E, L>(&mut self, context: &mut Context<L>, mut endpoint: E) -> MuxResult
1006 where
1007 E: Endpoint,
1008 L: ListenerHandler + L7ListenerHandler,
1009 {
1010 trace!(
1011 "{} ======= MUX H1 WRITABLE {:?}",
1012 log_context!(self),
1013 self.position
1014 );
1015 if self.is_lingering() {
1016 // The write side is shut down: nothing is left to write, and the
1017 // linger deadline is never pushed out.
1018 self.readiness.interest.remove(Ready::WRITABLE);
1019 self.readiness.event.remove(Ready::WRITABLE);
1020 return MuxResult::Continue;
1021 }
1022 let Some(stream_id) = self.stream else {
1023 if self.socket.socket_wants_write() {
1024 let (size, status) = self.socket.socket_write_vectored(&[]);
1025 let _ = update_readiness_after_write(size, status, &mut self.readiness);
1026 if let Some(result) = self.client_write_failed(status) {
1027 return result;
1028 }
1029 // Only after `Continue`: see the same check below.
1030 if self.socket.socket_wants_write() && status == SocketResult::Continue {
1031 self.readiness.signal_pending_write();
1032 }
1033 }
1034 return MuxResult::Continue;
1035 };
1036 // One clock read for the whole pass: the two later re-arms below
1037 // (100-Continue, keep-alive recycle) run while `context` is mutably
1038 // reborrowed for the stream, so they cannot reach `context.now`.
1039 let now = context.now;
1040 self.arm_timeout(now);
1041 let stream = &mut context.streams[stream_id];
1042 let parts = stream.split(&self.position);
1043 let kawa = parts.wbuffer;
1044 // Apply per-frontend response-side header edits stashed by the
1045 // routing layer at request time. Only the Server-position pass
1046 // touches the response back-kawa; the Client-position pass
1047 // (writing the request to the backend) has already had its
1048 // edits applied in `Router::route_from_request`.
1049 //
1050 // Drained via `mem::take` so the injection runs exactly once
1051 // per response. H1 keep-alive can re-enter this writable path
1052 // for the same stream when the backend response spans more
1053 // than one TCP read; without the take, the second pass would
1054 // re-insert the same headers (typically as duplicate STS lines
1055 // on the wire — RFC 6797 §6.1 expects a single header). On H2
1056 // the same multi-prepare-cycle pattern surfaces as a
1057 // `H2BlockConverter::finalize` "out buffer not empty" leak.
1058 if matches!(self.position, Position::Server) && !parts.context.headers_response.is_empty() {
1059 let edits = std::mem::take(&mut parts.context.headers_response);
1060 super::shared::apply_response_header_edits(kawa, &edits);
1061 }
1062 Self::drop_length_framed_trailers(kawa);
1063 if matches!(self.position, Position::Server) && Self::response_has_no_body(parts.context) {
1064 Self::drop_bodiless_response_framing(kawa);
1065 }
1066 kawa.prepare(&mut kawa::h1::BlockConverter);
1067 // SAFETY: the descriptors `gather` pushes borrow memory `kawa` owns:
1068 // a `Store::Slice` or `Detached` points into `kawa.storage`, while an
1069 // `Alloc`, `Static` or `Shared` store points at bytes held by the
1070 // block in `kawa.out` itself. So nothing may mutate `kawa`, neither
1071 // `storage` nor `out`, while they are live: no `push_out`, no
1072 // `storage.fill`, no `consume` and no `clear` between this call and
1073 // the `h2_transmit::confirm` below, which clears `self.io_slices`
1074 // before its own `Kawa::consume`. In between, the pass only writes
1075 // the descriptors to the socket, which reborrows them for the call
1076 // and cannot retain them, copies them into the replay capture, which
1077 // mutates `retry_buffer` and never `kawa`, and pushes a debug event
1078 // onto `context.debug`. Its one `return` in that window is taken only
1079 // when the vector is empty, so no descriptor outlives the pass.
1080 let queued = unsafe { super::h2_transmit::gather(kawa, &mut self.io_slices) };
1081 // A response in the Error phase ends here too: the backend truncated
1082 // it or it was forcefully terminated, so once what was queued before
1083 // the failure is flushed the connection closes (see below).
1084 let can_finalize_server_close = matches!(self.position, Position::Server)
1085 && (kawa.is_terminated() || kawa.is_error())
1086 && kawa.is_completed();
1087 if self.io_slices.is_empty()
1088 && !self.socket.socket_wants_write()
1089 && !can_finalize_server_close
1090 {
1091 self.readiness.interest.remove(Ready::WRITABLE);
1092 return MuxResult::Continue;
1093 }
1094 let tls_only_flush = self.io_slices.is_empty();
1095 // `queued` is the total the gathered slices offer the socket; a
1096 // vectored write can never report more consumed than we handed it.
1097 let (size, status) = self.socket.socket_write_vectored(&self.io_slices);
1098 debug_assert!(
1099 size <= queued,
1100 "socket_write_vectored reported more bytes written than were queued"
1101 );
1102 // Capture the bytes the socket accepted BEFORE `kawa::Kawa::consume`
1103 // drops them from the front buffer and shifts the storage: past that
1104 // point sozu no longer holds the request, so a stale pooled upstream
1105 // could not be retried without this copy. Every proxy that retries a
1106 // request already written upstream pays the same copy — HAProxy
1107 // ("requires to allocate a buffer and copy the whole request into
1108 // it, so it has memory and performance impacts"), pingora
1109 // (`enable_retry_buffering`, a fixed 64 KiB `FixedBuffer`).
1110 //
1111 // It is charged ONLY to a connection that came out of the keep-alive
1112 // pool: `reused_from_pool` is set by `start_stream` on the
1113 // KeepAlive -> Connected transition and nowhere else, so a freshly
1114 // dialled upstream and every `Position::Server` write cost nothing.
1115 // That is pingora's `RetryType::ReusedOnly` boundary, argued in
1116 // `Stream::can_replay_on_fresh_upstream` (sozu-proxy/sozu#1442).
1117 //
1118 // Overflowing one front buffer truncates the capture to `None` and
1119 // the request stops being replayable, rather than the buffer
1120 // growing: HAProxy, same reason — "Requests not fitting in a single
1121 // buffer will never be retried".
1122 //
1123 // The bytes are appended straight onto the capture, with the budget
1124 // decided first: `size` is already known, `kawa` was moved out of
1125 // `parts` above so `parts.retry_buffer` is independently borrowable,
1126 // and the slices still alias `kawa.storage` until `consume` below.
1127 // Staging them through a temporary `Vec` first would cost one extra
1128 // allocation, one extra copy and one free on every write of every
1129 // pooled connection.
1130 let retry_budget = kawa.storage.capacity();
1131 if self.reused_from_pool {
1132 match parts.retry_buffer.as_mut() {
1133 // The capture has to stay a byte-exact prefix of what the
1134 // socket accepted, so a write that would carry it past one
1135 // front buffer drops it whole rather than truncating it.
1136 Some(buffer) if size <= retry_budget.saturating_sub(buffer.len()) => {
1137 buffer.reserve(size);
1138 let mut remaining = size;
1139 for slice in &self.io_slices {
1140 if remaining == 0 {
1141 break;
1142 }
1143 let take = remaining.min(slice.len());
1144 buffer.extend_from_slice(&slice[..take]);
1145 remaining -= take;
1146 }
1147 debug_assert_eq!(
1148 remaining, 0,
1149 "the replay capture must mirror every byte the socket accepted"
1150 );
1151 }
1152 _ => *parts.retry_buffer = None,
1153 }
1154 }
1155 context.debug.push(DebugEvent::StreamEvent(1, size));
1156 super::h2_transmit::confirm(kawa, &mut self.io_slices, size);
1157 crate::protocol::mux::h2::record_metric(self.position.bytes_out_event(size));
1158 self.position.count_bytes_out(parts.metrics, size);
1159 if self.position.is_server() {
1160 context.client_bytes_out = context.client_bytes_out.wrapping_add(size);
1161 }
1162 let should_yield = update_readiness_after_write(size, status, &mut self.readiness);
1163 if let Some(result) = self.client_write_failed(status) {
1164 return result;
1165 }
1166 if self.socket.socket_wants_write() {
1167 // Only a write that answered `Continue` queues a synthetic
1168 // event. A socket that answered `WouldBlock` is full: the kernel
1169 // raises the next WRITABLE edge once the peer reads. Re-raising
1170 // it here while rustls still held the records the kernel refused
1171 // made `Mux::ready_inner` call this write again on every inner
1172 // iteration, each answering `WouldBlock`, until
1173 // `MAX_LOOP_ITERATIONS` counted `http.infinite_loop.error`
1174 // (sozu-proxy/sozu#1780). An `Error` or `Closed` write has nothing
1175 // to retry either: on the frontend `client_write_failed` closed the
1176 // session above; on a backend the hang-up that follows closes it.
1177 if status == SocketResult::Continue {
1178 self.readiness.signal_pending_write();
1179 // Pair the queued-write signal with the socket's own report: we
1180 // only synthesize a WRITABLE event when the socket still has bytes
1181 // buffered (edge-triggered epoll won't re-fire on its own).
1182 debug_assert!(
1183 self.readiness.event.is_writable(),
1184 "signal_pending_write must leave a WRITABLE event queued"
1185 );
1186 } else {
1187 debug_assert!(
1188 !self.readiness.event.is_writable(),
1189 "a write that did not answer Continue must leave WRITABLE to the next edge"
1190 );
1191 }
1192 return MuxResult::Continue;
1193 }
1194 if !tls_only_flush && should_yield {
1195 return MuxResult::Continue;
1196 }
1197
1198 if matches!(self.position, Position::Server) && kawa.is_error() && kawa.is_completed() {
1199 // The response failed after part of it may have left: a body the
1200 // backend truncated (`ConnectionH1::terminate_close_delimited`) or
1201 // a response `forcefully_terminate_answer` ended. H1 has no
1202 // RST_STREAM, and neither a default answer nor the next pipelined
1203 // response may follow those bytes on this connection, so close
1204 // it: the client sees a close before the end of the message, which
1205 // RFC 9112 §6.3 rule 5 makes the incomplete-message signal. Never
1206 // kept alive; `Mux::close` logs the stream as an error.
1207 debug_assert!(
1208 !kawa.is_terminated(),
1209 "an errored response must not also be terminated"
1210 );
1211 debug!(
1212 "{} H1 closing the frontend after an incomplete response on stream {}",
1213 log_context!(self),
1214 stream_id
1215 );
1216 return self.defer_close_for_tls_flush("incomplete-response");
1217 }
1218 if kawa.is_terminated() && kawa.is_completed() {
1219 match self.position {
1220 Position::Client(..) => self.readiness.interest.insert(Ready::READABLE),
1221 Position::Server => {
1222 if stream.context.closing {
1223 return self.defer_close_for_tls_flush("closing-context");
1224 }
1225 let kawa = &mut stream.back;
1226 match kawa.detached.status_line {
1227 kawa::StatusLine::Response { code: 101, .. } => {
1228 debug!("{} ============== HANDLE UPGRADE!", log_context!(self));
1229 stream.metrics.backend_stop();
1230 let client_rtt = self.rtt();
1231 let server_rtt =
1232 stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1233 for event in stream
1234 .generate_access_log(
1235 false,
1236 Some("H1::Upgrade"),
1237 context.listener.clone(),
1238 client_rtt,
1239 server_rtt,
1240 )
1241 .into_iter()
1242 .flatten()
1243 {
1244 crate::protocol::mux::h2::record_metric(event);
1245 }
1246 return MuxResult::Upgrade;
1247 }
1248 kawa::StatusLine::Response { code: 100, .. } => {
1249 debug!("{} ============== HANDLE CONTINUE!", log_context!(self));
1250 // After a 100 Continue, we expect the client to continue
1251 // with its request body. Do NOT call generate_access_log
1252 // here — the final response will emit the access log.
1253 // Calling it here would double-decrement http.active_requests.
1254 self.timeout_deadline = now.checked_add(self.timeout_duration);
1255 self.readiness.interest.insert(Ready::READABLE);
1256 kawa.clear();
1257 stream.metrics.backend_stop();
1258 if let StreamState::Linked(token) = stream.state {
1259 // The final response may already sit in the
1260 // backend buffer, read with the 100: no
1261 // socket event will announce it, so the read
1262 // is re-armed, not only its interest.
1263 let backend = endpoint.readiness_mut(token);
1264 backend.interest.insert(Ready::READABLE);
1265 backend.signal_pending_read();
1266 }
1267 return MuxResult::Continue;
1268 }
1269 // Every other 1xx (102 Processing, 103 Early Hints and
1270 // the unassigned 104-199) is interim too: RFC 9110
1271 // §15.2 has a client accept any number of them before
1272 // the final response, so the stream stays linked and
1273 // the backend stays out of the keep-alive pool until
1274 // that final response has been written.
1275 kawa::StatusLine::Response { code, .. } if (102..200).contains(&code) => {
1276 debug!(
1277 "{} ============== HANDLE INTERIM {}!",
1278 log_context!(self),
1279 code
1280 );
1281 // Do NOT call generate_access_log for an interim response.
1282 // The final response will emit the access log.
1283 // Calling it here would double-decrement http.active_requests.
1284 if let StreamState::Linked(token) = stream.state {
1285 // after an interim response, we expect the backend to send its final
1286 // response, which may already sit in the backend buffer, read with
1287 // the interim: no socket event will announce it, so the read is
1288 // re-armed, not only its interest.
1289 let backend = endpoint.readiness_mut(token);
1290 backend.interest.insert(Ready::READABLE);
1291 backend.signal_pending_read();
1292 kawa.clear();
1293 stream.metrics.backend_stop();
1294 return MuxResult::Continue;
1295 } else {
1296 stream.metrics.backend_stop();
1297 let client_rtt = self.rtt();
1298 let server_rtt =
1299 stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1300 for event in stream
1301 .generate_access_log(
1302 false,
1303 Some("H1::Interim"),
1304 context.listener.clone(),
1305 client_rtt,
1306 server_rtt,
1307 )
1308 .into_iter()
1309 .flatten()
1310 {
1311 crate::protocol::mux::h2::record_metric(event);
1312 }
1313 return self.defer_close_for_tls_flush("interim");
1314 }
1315 }
1316 _ => {}
1317 }
1318 incr!(names::http::E2E_HTTP11);
1319 stream.metrics.backend_stop();
1320 let client_rtt = self.rtt();
1321 let server_rtt = stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1322 for event in stream
1323 .generate_access_log(
1324 false,
1325 Some("H1::Complete"),
1326 context.listener.clone(),
1327 client_rtt,
1328 server_rtt,
1329 )
1330 .into_iter()
1331 .flatten()
1332 {
1333 crate::protocol::mux::h2::record_metric(event);
1334 }
1335 stream.metrics.reset();
1336 let old_state = std::mem::replace(&mut stream.state, StreamState::Unlinked);
1337 if let StreamState::Linked(token) = old_state {
1338 remove_backend_stream(&mut context.backend_streams, token, stream_id);
1339 }
1340 // The connection outlives the response only when neither
1341 // side asked to close it. `keep_alive_backend` is false
1342 // once the backend's response carried `Connection: close`,
1343 // or was a non-persistent HTTP/1.0 one that sozu forwards
1344 // as HTTP/1.1 with `Connection: close` added
1345 // (`HttpContext::on_response_headers`,
1346 // `lib/src/protocol/kawa_h1/editor.rs`): sozu forwards that
1347 // header, so RFC 9112 §9.6 requires it to close after this
1348 // response and to process no further request on it. It
1349 // is also the only way a close-delimited body ends here:
1350 // `ConnectionH1::terminate_close_delimited` runs only for
1351 // such a backend, and that body ends, for the client too,
1352 // only with the close (§6.3 rule 8). Keeping the
1353 // connection left the client waiting for more body until
1354 // the frontend timeout, and appended the next pipelined
1355 // response to the body (sozu-proxy/sozu#1642).
1356 //
1357 // The request must have been received whole as well: a
1358 // backend, or a default answer, may answer early (a 413 or
1359 // a 401 on an upload) while the client is still sending
1360 // the body. RFC 9112 §9.3 lets a connection carry another
1361 // message only once the previous one is complete, and the
1362 // rest of that body belongs to the answered request.
1363 // Resetting the parser here would read it as a new
1364 // request (sozu-proxy/sozu#1721), so the connection closes
1365 // instead. Whether the request was also fully written to
1366 // the backend decides only whether that backend may be
1367 // pooled: `ConnectionH1::end_stream` checks it, and a
1368 // default answer leaves a request it never forwarded.
1369 //
1370 // Pre: the decision is taken once, when the whole response
1371 // has left, never while part of it is still queued.
1372 debug_assert!(
1373 stream.back.is_terminated() && stream.back.is_completed(),
1374 "the keep-alive decision must follow a completely written response"
1375 );
1376 let request_complete = stream.front.is_terminated();
1377 let keep_alive = request_complete
1378 && stream.context.keep_alive_frontend
1379 && stream.context.keep_alive_backend;
1380 if keep_alive {
1381 self.timeout_deadline = now.checked_add(self.timeout_duration);
1382 if let StreamState::Linked(token) = old_state {
1383 endpoint.end_stream(token, stream_id, context);
1384 }
1385 self.readiness.interest.insert(Ready::READABLE);
1386 // The next request on this connection is a new
1387 // request: it gets its own id, minted from the same
1388 // per-session source as an H2 stream's.
1389 let request_id = context.next_request_id();
1390 let stream = &mut context.streams[stream_id];
1391 stream.context.reset(request_id);
1392 stream.back.clear();
1393 stream.back.storage.clear();
1394 stream.front.clear();
1395 // do not stream.front.storage.clear() because of H1 pipelining
1396 // The next request has not been encoded for any
1397 // backend yet (sozu-proxy/sozu#1632).
1398 stream.front_bound_to_backend = false;
1399 stream.attempts = 0;
1400 stream.tried_backends.clear();
1401 // The next request is a new H2 stream on an H2
1402 // backend connection, which reads these to refuse a
1403 // frame on a closed stream (RFC 9113 §5.1) and to
1404 // check `content-length` (§8.1.1): clear them as
1405 // `Context::create_stream` does for a recycled slot,
1406 // or the backend's response HEADERS is refused as
1407 // arriving after END_STREAM (sozu-proxy/sozu#1781).
1408 stream.front_received_end_of_stream = false;
1409 stream.back_received_end_of_stream = false;
1410 stream.front_data_received = 0;
1411 stream.back_data_received = 0;
1412 // The next pipelined request gets its own replay
1413 // decision: `start_stream` re-arms capture only if it
1414 // again picks a connection out of the keep-alive pool.
1415 stream.forget_upstream_replay();
1416 // Transition back to Idle so buffered pipelined requests
1417 // trigger a phase transition on the next readable() call.
1418 stream.state = StreamState::Idle;
1419 // Post: the keep-alive reset leaves a clean, closed slot
1420 // ready for the next pipelined request. `request_counted`
1421 // was already cleared by `generate_access_log` above, so
1422 // the slot carries no pending active-requests charge.
1423 debug_assert_eq!(
1424 stream.state,
1425 StreamState::Idle,
1426 "keep-alive reset must return the stream to Idle"
1427 );
1428 debug_assert_eq!(stream.attempts, 0, "keep-alive reset must zero attempts");
1429 debug_assert!(
1430 !stream.request_counted,
1431 "keep-alive reset must leave no counted request (active-requests leak)"
1432 );
1433 debug_assert!(
1434 stream.back.storage.is_empty(),
1435 "keep-alive reset must drain the response storage"
1436 );
1437 // HTTP/1.1 pipelining: if there's still data in the frontend
1438 // storage (pipelined requests already read from the socket),
1439 // parse it now. We can't rely on a new READABLE event because
1440 // the socket buffer may be empty — all requests were already
1441 // read into kawa storage in the first socket_read.
1442 if !stream.front.storage.is_empty() {
1443 let blocks_before_parse = stream.front.blocks.len();
1444 kawa::h1::parse(&mut stream.front, &mut stream.context);
1445 stream
1446 .context
1447 .filter_request_trailers(&mut stream.front, blocks_before_parse);
1448 let is_error = stream.front.is_error();
1449 let is_main = stream.front.is_main_phase();
1450 let malformed = is_main
1451 && (stream.context.method.is_none()
1452 || stream.context.authority.is_none()
1453 || stream.context.path.is_none());
1454 if is_error || malformed {
1455 let answers_rc = stream.answers.clone();
1456 let answers = answers_rc.borrow();
1457 set_default_answer(stream, &mut self.readiness, 400, &answers);
1458 } else if is_main {
1459 self.requests += 1;
1460 incr!(names::http::REQUESTS);
1461 gauge_add!(names::http::ACTIVE_REQUESTS, 1);
1462 stream.metrics.service_start();
1463 stream.request_counted = true;
1464 stream.state = StreamState::Link;
1465 context.pending_links.push_back(stream_id);
1466 }
1467 // else: incomplete parse, wait for more data via READABLE
1468 }
1469 } else {
1470 // Pair: at least one side asked for the close, or
1471 // the request was not received whole. A
1472 // pipelined request already buffered is dropped with
1473 // the connection, never answered on it; the client
1474 // retries it on a new connection (RFC 9112 §9.3.2).
1475 debug_assert!(
1476 !request_complete
1477 || !stream.context.keep_alive_frontend
1478 || !stream.context.keep_alive_backend,
1479 "the frontend closes only when one side asked to or the request is incomplete"
1480 );
1481 // A TLS close is deferred until `close_notify` is
1482 // flushed, and `writable` runs again: mark the stream
1483 // closing so that pass takes the `closing-context`
1484 // exit above, instead of completing the response a
1485 // second time (a second access log and counters) and
1486 // re-taking the keep-alive decision after
1487 // `close_notify`.
1488 stream.context.closing = true;
1489 // No byte of the request arrived (a 408 to a silent
1490 // client): nothing is in flight, the close cannot
1491 // reset anything away, so it does not linger.
1492 let request_started =
1493 !matches!(stream.front.parsing_phase, kawa::ParsingPhase::StatusLine)
1494 || !stream.front.storage.is_empty();
1495 if !request_complete && request_started {
1496 // The client may still be sending the request:
1497 // drain it once the response is flushed, so the
1498 // close does not reset the response away (RFC
1499 // 9112 §9.6). The backend is done with either way.
1500 self.linger = Linger::Pending {
1501 deadline: now + self.linger_timeout,
1502 };
1503 if let StreamState::Linked(token) = old_state {
1504 endpoint.end_stream(token, stream_id, context);
1505 }
1506 }
1507 let stream = &mut context.streams[stream_id];
1508 if stream.context.keep_alive_frontend && stream.context.keep_alive_backend {
1509 // Both sides wanted to keep it: only the
1510 // incomplete request closes it.
1511 debug_assert!(
1512 !request_complete,
1513 "with both sides keeping alive, only an incomplete request closes"
1514 );
1515 debug!(
1516 "{} H1 closing the frontend after a response that completed before its request on stream {}",
1517 log_context!(self),
1518 stream_id
1519 );
1520 incr!(names::http::CLOSE_REQUEST_INCOMPLETE);
1521 return self.defer_close_for_tls_flush("request-incomplete");
1522 }
1523 if !stream.context.keep_alive_backend {
1524 debug!(
1525 "{} H1 closing the frontend after a response carrying the backend's Connection: close on stream {}",
1526 log_context!(self),
1527 stream_id
1528 );
1529 }
1530 return self.defer_close_for_tls_flush("response-complete");
1531 }
1532 }
1533 }
1534 }
1535 MuxResult::Continue
1536 }
1537
1538 pub fn force_disconnect(&mut self) -> MuxResult {
1539 match &mut self.position {
1540 Position::Client(_, _, status) => {
1541 *status = BackendStatus::Disconnecting;
1542 self.readiness.event = Ready::HUP;
1543 debug!(
1544 "{} H1 force_disconnect client: stream={:?}, wants_write={}, readiness={:?}",
1545 log_context!(self),
1546 self.stream,
1547 self.socket.socket_wants_write(),
1548 self.readiness
1549 );
1550 MuxResult::Continue
1551 }
1552 Position::Server => {
1553 if self.socket.socket_wants_write() {
1554 debug!(
1555 "{} H1 force_disconnect delaying close: stream={:?}, wants_write=true, readiness={:?}",
1556 log_context!(self),
1557 self.stream,
1558 self.readiness
1559 );
1560 self.readiness.interest = Ready::WRITABLE | Ready::HUP | Ready::ERROR;
1561 self.readiness.signal_pending_write();
1562 MuxResult::Continue
1563 } else {
1564 debug!(
1565 "{} H1 force_disconnect closing session: stream={:?}, wants_write=false, readiness={:?}",
1566 log_context!(self),
1567 self.stream,
1568 self.readiness
1569 );
1570 MuxResult::CloseSession
1571 }
1572 }
1573 }
1574 }
1575
1576 pub fn has_pending_write(&self) -> bool {
1577 !self.write_failed && self.socket.socket_wants_write()
1578 }
1579
1580 /// A write to the client failed: the client is gone, or its socket can
1581 /// never be flushed. Close at once; `Self::has_pending_write` stops
1582 /// reporting output, so no delayed close waits for a flush that cannot
1583 /// happen.
1584 fn client_write_failed(&mut self, status: SocketResult) -> Option<MuxResult> {
1585 if self.position.is_server() && matches!(status, SocketResult::Error | SocketResult::Closed)
1586 {
1587 debug!(
1588 "{} H1 closing the frontend after a failed write: {:?}",
1589 log_context!(self),
1590 status
1591 );
1592 self.write_failed = true;
1593 Some(MuxResult::CloseSession)
1594 } else {
1595 None
1596 }
1597 }
1598
1599 pub fn initiate_close_notify(&mut self) -> bool {
1600 if !self.position.is_server() {
1601 return false;
1602 }
1603 // Past the guard we are always server-side; close_notify is a
1604 // frontend-only TLS concern.
1605 debug_assert!(
1606 self.position.is_server(),
1607 "initiate_close_notify past the guard must be server-side"
1608 );
1609 if !self.close_notify_sent {
1610 trace!("{} H1 initiating CLOSE_NOTIFY", log_context!(self));
1611 self.socket.socket_close();
1612 self.close_notify_sent = true;
1613 }
1614 // `close_notify` is monotone: once requested it stays sent for the
1615 // connection's lifetime (a second send would corrupt the TLS stream).
1616 debug_assert!(
1617 self.close_notify_sent,
1618 "close_notify_sent must be set once initiate_close_notify has run"
1619 );
1620 if self.socket.socket_wants_write() {
1621 self.readiness.arm_writable();
1622 // arm_writable pairs interest + event so the deferred TLS flush is
1623 // actually scheduled under edge-triggered epoll.
1624 debug_assert!(
1625 self.readiness.interest.is_writable() && self.readiness.event.is_writable(),
1626 "arm_writable must set both WRITABLE interest and event"
1627 );
1628 true
1629 } else {
1630 false
1631 }
1632 }
1633
1634 pub fn close<E, L>(&mut self, context: &mut Context<L>, mut endpoint: E)
1635 where
1636 E: Endpoint,
1637 L: ListenerHandler + L7ListenerHandler,
1638 {
1639 match self.position {
1640 Position::Client(_, _, BackendStatus::KeepAlive)
1641 | Position::Client(_, _, BackendStatus::Disconnecting) => {
1642 trace!("{} close detached client ConnectionH1", log_context!(self));
1643 return;
1644 }
1645 Position::Client(_, _, BackendStatus::Connecting(_))
1646 | Position::Client(_, _, BackendStatus::Connected) => {
1647 debug!(
1648 "{} BACKEND CLOSING FOR: {:?} {:?}",
1649 log_context!(self),
1650 self.position,
1651 self.stream
1652 );
1653 }
1654 Position::Server => {
1655 let tls_pending_before = self.socket.socket_wants_write();
1656 let (tls_pending_after, drain_rounds) =
1657 drain_tls_close_notify(&mut self.socket, &mut self.close_notify_sent);
1658 if tls_pending_after {
1659 error!(
1660 "{} H1 TLS buffer NOT fully drained on close: pending_before={}, pending_after={}, drain_rounds={}, stream={:?}, close_notify_sent={}, readiness={:?}",
1661 log_context!(self),
1662 tls_pending_before,
1663 tls_pending_after,
1664 drain_rounds,
1665 self.stream,
1666 self.close_notify_sent,
1667 self.readiness
1668 );
1669 }
1670 return;
1671 }
1672 }
1673 let Some(stream_id) = self.stream else {
1674 trace!(
1675 "{} closing detached H1 client with no active stream",
1676 log_context!(self)
1677 );
1678 return;
1679 };
1680 // reconnection is handled by the server
1681 let StreamState::Linked(token) = context.streams[stream_id].state else {
1682 trace!(
1683 "{} closing detached H1 client in state {:?} on stream {}",
1684 log_context!(self),
1685 context.streams[stream_id].state,
1686 stream_id
1687 );
1688 return;
1689 };
1690 endpoint.end_stream(token, stream_id, context)
1691 }
1692
1693 pub fn end_stream<L>(&mut self, stream: GlobalStreamId, context: &mut Context<L>)
1694 where
1695 L: ListenerHandler + L7ListenerHandler,
1696 {
1697 if self.stream != Some(stream) {
1698 error!(
1699 "{} end_stream called with stream {} but expected {:?}",
1700 log_context!(self),
1701 stream,
1702 self.stream
1703 );
1704 return;
1705 }
1706 // Reached only on the matched-stream path: the connection's active
1707 // stream is exactly the one being ended.
1708 debug_assert_eq!(
1709 self.stream,
1710 Some(stream),
1711 "end_stream past the guard must target the active stream"
1712 );
1713 context.unlink_stream(stream);
1714 // Post: whatever backend token this stream was Linked to no longer
1715 // lists it in the reverse index. `unlink_stream` is idempotent — it
1716 // evicts only while the stream is still `Linked` — so a subsequent
1717 // end/close cannot double-remove it. It is NOT the module's only
1718 // eviction point: `remove_backend_stream` has direct callers here and
1719 // in `h2.rs`. Extra eviction is harmless; what this post-condition
1720 // claims is that THIS path evicted.
1721 // (The `state` field is still `Linked` here; the arms below retire it.)
1722 #[cfg(debug_assertions)]
1723 if let StreamState::Linked(token) = context.streams[stream].state {
1724 debug_assert!(
1725 context
1726 .backend_streams
1727 .get(&token)
1728 .is_none_or(|ids| !ids.contains(&stream)),
1729 "unlink_stream must evict the stream from the backend reverse index"
1730 );
1731 }
1732 let stream_id = stream;
1733 let stream = &mut context.streams[stream_id];
1734 let answers_rc = stream.answers.clone();
1735 let stream_context = &mut stream.context;
1736 trace!(
1737 "{} end H1 stream {:?}: {:#?}",
1738 log_context!(self),
1739 self.stream,
1740 stream_context
1741 );
1742 match &mut self.position {
1743 Position::Client(_, _, BackendStatus::Connecting(_)) => {
1744 self.stream = None;
1745 if stream.state != StreamState::Recycle {
1746 stream.state = StreamState::Unlinked;
1747 }
1748 // Post: the client connection detaches from its stream and the
1749 // slot is retired (Unlinked) unless already marked for reuse —
1750 // never left dangling in an open/Linked state.
1751 debug_assert!(
1752 self.stream.is_none(),
1753 "client end_stream must detach the stream"
1754 );
1755 debug_assert!(
1756 !matches!(stream.state, StreamState::Linked(_)),
1757 "detached stream must not remain Linked"
1758 );
1759 self.readiness.interest.remove(Ready::ALL);
1760 self.force_disconnect();
1761 }
1762 Position::Client(_, _, status @ BackendStatus::Connected) => {
1763 self.stream = None;
1764 if stream.state != StreamState::Recycle {
1765 stream.state = StreamState::Unlinked;
1766 }
1767 debug_assert!(
1768 self.stream.is_none(),
1769 "client end_stream must detach the stream"
1770 );
1771 debug_assert!(
1772 !matches!(stream.state, StreamState::Linked(_)),
1773 "detached stream must not remain Linked"
1774 );
1775 self.readiness.interest.remove(Ready::ALL);
1776 // keep alive should probably be used only if the http context is fully reset
1777 // in case end_stream occurs due to an error the connection state is probably
1778 // unrecoverable and should be terminated
1779 // Both messages must be complete: a backend that answered
1780 // before the whole request was written to it still expects
1781 // the rest of the body, and would read the next request
1782 // pooled onto it as that body (RFC 9112 §9.3,
1783 // sozu-proxy/sozu#1721).
1784 if stream_context.keep_alive_backend
1785 && stream.back.is_terminated()
1786 && stream.front.is_terminated()
1787 && stream.front.is_completed()
1788 {
1789 *status = BackendStatus::KeepAlive;
1790 } else {
1791 self.force_disconnect();
1792 }
1793 }
1794 Position::Client(_, _, BackendStatus::KeepAlive)
1795 | Position::Client(_, _, BackendStatus::Disconnecting) => {
1796 error!(
1797 "{} end_stream called on KeepAlive or Disconnecting H1 client",
1798 log_context!(self)
1799 );
1800 }
1801 Position::Server => match end_stream_decision(stream) {
1802 EndStreamAction::ForwardTerminated => {
1803 debug!("{} CLOSING H1 TERMINATED STREAM", log_context!(self));
1804 stream.state = StreamState::Unlinked;
1805 self.readiness.interest.insert(Ready::WRITABLE);
1806 // End-of-stream was already queued into kawa by the parser;
1807 // no fresh WRITABLE event will arrive from the kernel.
1808 self.readiness.signal_pending_write();
1809 }
1810 EndStreamAction::CloseDelimited => {
1811 debug!("{} CLOSE DELIMITED", log_context!(self));
1812 stream.state = StreamState::Unlinked;
1813 self.readiness.arm_writable();
1814 }
1815 EndStreamAction::ForwardUnterminated => {
1816 debug!("{} CLOSING H1 UNTERMINATED STREAM", log_context!(self));
1817 forcefully_terminate_answer(
1818 stream,
1819 &mut self.readiness,
1820 H2Error::InternalError,
1821 );
1822 }
1823 EndStreamAction::SendDefault(status) => {
1824 let answers = answers_rc.borrow();
1825 set_default_answer(stream, &mut self.readiness, status, &answers);
1826 }
1827 EndStreamAction::Reconnect => {
1828 debug!("{} H1 RECONNECT", log_context!(self));
1829 stream.state = StreamState::Link;
1830 context.pending_links.push_back(stream_id);
1831 }
1832 EndStreamAction::ReplayOnFreshBackend => match stream.queue_upstream_replay() {
1833 Some(len) => {
1834 debug!(
1835 "{} H1 REPLAY {} request bytes on a fresh backend",
1836 log_context!(self),
1837 len
1838 );
1839 incr!(
1840 names::backend::RETRY_STALE_UPSTREAM,
1841 stream.context.cluster_id.as_deref(),
1842 stream.context.backend_id.as_deref(),
1843 stream.context.cluster_metrics_incarnation()
1844 );
1845 stream.state = StreamState::Link;
1846 context.pending_links.push_back(stream_id);
1847 // `Router::plan_connect` still gates on `stream.attempts`
1848 // against `max_connection_attempts`, so a cluster whose backends
1849 // are all stale cannot loop: the budget runs out and
1850 // the caller answers 503.
1851 }
1852 None => {
1853 // Unreachable while `end_stream_decision` only picks
1854 // this action behind `can_replay_on_fresh_upstream`,
1855 // which requires the buffer. Degrade to the answer
1856 // the old code sent rather than stranding the stream.
1857 error!(
1858 "{} replay selected with no captured request",
1859 log_context!(self)
1860 );
1861 let answers = answers_rc.borrow();
1862 set_default_answer(stream, &mut self.readiness, 502, &answers);
1863 }
1864 },
1865 },
1866 }
1867 }
1868
1869 pub fn start_stream<L>(&mut self, stream: GlobalStreamId, context: &mut Context<L>) -> bool
1870 where
1871 L: ListenerHandler + L7ListenerHandler,
1872 {
1873 trace!(
1874 "{} start H1 stream {} {:?}",
1875 log_context!(self),
1876 stream,
1877 self.readiness
1878 );
1879 self.readiness.interest.insert(Ready::ALL);
1880 self.stream = Some(stream);
1881 debug_assert_eq!(
1882 self.stream,
1883 Some(stream),
1884 "start_stream must pin the connection's active stream"
1885 );
1886 match &mut self.position {
1887 Position::Client(_, _, status @ BackendStatus::KeepAlive) => {
1888 *status = BackendStatus::Connected;
1889 // This stream is being written onto a socket that has been
1890 // idle in the pool, so the peer may already have closed it
1891 // without sozu noticing. Record the provenance and arm
1892 // request capture so the write path below can keep the bytes
1893 // needed to replay elsewhere (sozu-proxy/sozu#1442).
1894 self.reused_from_pool = true;
1895 context.streams[stream].arm_upstream_replay();
1896 // A keep-alive client transitions to Connected when it picks up
1897 // a new stream; it must not stay parked in KeepAlive.
1898 debug_assert!(
1899 matches!(
1900 self.position,
1901 Position::Client(_, _, BackendStatus::Connected)
1902 ),
1903 "a reused keep-alive client must become Connected on start_stream"
1904 );
1905 }
1906 Position::Client(_, _, BackendStatus::Disconnecting) => {
1907 error!(
1908 "{} start_stream called on Disconnecting H1 client",
1909 log_context!(self)
1910 );
1911 return false;
1912 }
1913 Position::Client(_, _, _) => {}
1914 Position::Server => {
1915 error!(
1916 "{} start_stream must not be called on H1 server connection",
1917 log_context!(self)
1918 );
1919 return false;
1920 }
1921 }
1922 true
1923 }
1924}
1925
1926#[cfg(test)]
1927mod tests {
1928 use std::{cell::Cell, cell::RefCell, io::Write, rc::Rc};
1929
1930 use super::*;
1931 use crate::{
1932 Protocol as TransportKind,
1933 pool::Pool,
1934 protocol::{
1935 kawa_h1::editor::HttpContext,
1936 mux::{
1937 BackendId, BackendSlot, Connection,
1938 connection::{EndpointClient, EndpointServer},
1939 router::Router,
1940 tcp_info_reads,
1941 test_support::{connected_socket, test_context},
1942 },
1943 },
1944 socket::SessionTcpStream,
1945 };
1946
1947 // ── The `peer=` slot of the MUX-H1 log prefix ───────────────────────
1948 //
1949 // These pin that the slot is the address the connection snapshotted at
1950 // construction, not a live `getpeername(2)` taken per expansion. The
1951 // difference is invisible while a connection is healthy and is the whole
1952 // story once it is not: `getpeername(2)` answers ENOTCONN after the peer
1953 // resets, and it reports the transport peer — the load balancer — on a
1954 // PROXY-protocol frontend.
1955
1956 /// Address the handler caches. Deliberately non-loopback so it cannot
1957 /// collide with whatever ephemeral port a live lookup would report.
1958 const CACHED_PEER: &str = "10.0.0.42:12345";
1959
1960 fn cached_peer() -> std::net::SocketAddr {
1961 CACHED_PEER
1962 .parse()
1963 .expect("the cached peer literal must parse")
1964 }
1965
1966 /// A live, established loopback connection plus the address
1967 /// `getpeername(2)` reports for it. The listener is returned so the
1968 /// connection stays up for the whole test: these tests assert the snapshot
1969 /// wins even while the live lookup is perfectly healthy, so a half-dead
1970 /// socket would weaken them rather than strengthen them.
1971 fn connected_loopback_stream() -> (
1972 std::net::TcpListener,
1973 mio::net::TcpStream,
1974 std::net::SocketAddr,
1975 ) {
1976 let listener = std::net::TcpListener::bind("127.0.0.1:0")
1977 .expect("test listener must bind to a loopback port");
1978 let live_peer = listener
1979 .local_addr()
1980 .expect("test listener must report its local address");
1981 let stream =
1982 std::net::TcpStream::connect(live_peer).expect("loopback connect must complete");
1983 stream
1984 .set_nonblocking(true)
1985 .expect("mio requires a nonblocking stream");
1986 (listener, mio::net::TcpStream::from_std(stream), live_peer)
1987 }
1988
1989 /// A socket that was never connected, and therefore one whose
1990 /// `getpeername(2)` fails with `ENOTCONN` *deterministically*.
1991 ///
1992 /// This is the one reliable way to stage a failing live lookup. The
1993 /// obvious alternative — connect to a closed port and wait for the RST —
1994 /// is a race: whether the kernel has collected the RST yet, and so whether
1995 /// `getpeername(2)` has started refusing, is not something a test may
1996 /// assert on. An unconnected socket is in the refusing state from birth,
1997 /// which is the state a reset peer leaves behind and the state these
1998 /// tests are about.
1999 fn unconnected_stream() -> mio::net::TcpStream {
2000 let socket = socket2::Socket::new(
2001 socket2::Domain::IPV4,
2002 socket2::Type::STREAM,
2003 Some(socket2::Protocol::TCP),
2004 )
2005 .expect("a test socket must be creatable");
2006 socket
2007 .set_nonblocking(true)
2008 .expect("mio requires a nonblocking stream");
2009 mio::net::TcpStream::from_std(std::net::TcpStream::from(socket))
2010 }
2011
2012 /// An opaque backend id for a `Position::Client` connection. The slot is
2013 /// never resolved by anything under test — `log_context!` renders
2014 /// `position` and nothing looks the backend up — so a standalone id is
2015 /// enough and spares these tests a whole `Mux` and backend registry.
2016 fn test_backend_id(address: std::net::SocketAddr) -> BackendId {
2017 BackendId {
2018 slot: BackendSlot(0),
2019 backend_id: Rc::from("test-backend"),
2020 address,
2021 metric_incarnation: Default::default(),
2022 }
2023 }
2024
2025 /// Unwrap the H1 arm of a freshly built connection.
2026 fn h1_of<Front: SocketHandler>(connection: Connection<Front>) -> ConnectionH1<Front> {
2027 match connection {
2028 Connection::H1(connection) => connection,
2029 Connection::H2(_) => unreachable!("new_h1_* builds an H1 connection"),
2030 }
2031 }
2032
2033 /// Symptom 1 — `getpeername(2)` answers `ENOTCONN` once the peer has
2034 /// reset, so the pre-fix macro rendered `peer=None` on exactly the
2035 /// `error!` lines an operator reads during an incident. The address was
2036 /// least available precisely when it mattered most.
2037 ///
2038 /// Staged with a never-connected socket rather than a reset one, because
2039 /// only the former refuses deterministically — see [`unconnected_stream`].
2040 /// A peer reset is one way to reach that state; what this pins is the
2041 /// rendering once the socket is in it, which is the part the macro owns.
2042 ///
2043 /// To SEE THIS RED: in `log_context!`, put
2044 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2045 /// `peer = $self.peer_address,`. The slot collapses to `peer=None`.
2046 #[test]
2047 fn log_context_renders_the_peer_when_the_live_lookup_fails() {
2048 let stream = unconnected_stream();
2049 let cached = cached_peer();
2050
2051 // Premise: the live lookup really is refusing, so the assertion below
2052 // cannot pass for the wrong reason.
2053 assert_eq!(
2054 stream.peer_addr().ok(),
2055 None,
2056 "an unconnected socket must refuse getpeername(2)"
2057 );
2058
2059 let session_ulid = Ulid::generate();
2060 let connection = h1_of(Connection::new_h1_server(
2061 session_ulid,
2062 SessionTcpStream::new(stream, session_ulid, Some(cached)),
2063 Duration::from_secs(30),
2064 ));
2065
2066 let rendered = log_context!(connection);
2067
2068 assert!(
2069 rendered.contains(&format!("peer=Some({cached})")),
2070 "the MUX-H1 peer= slot must survive a failed live lookup: {rendered}"
2071 );
2072 assert!(
2073 !rendered.contains("peer=None"),
2074 "the MUX-H1 peer= slot must not collapse to None while a snapshot \
2075 exists: {rendered}"
2076 );
2077 }
2078
2079 /// Symptom 2 — a backend connection is built from a nonblocking
2080 /// `connect()` that has not completed, so `getpeername(2)` refuses for the
2081 /// whole window in which an ECONNREFUSED line is emitted. The dial path
2082 /// caches the cluster-configured backend address into
2083 /// `SessionTcpStream::configured_peer` for exactly that reason, and the H1
2084 /// macro has to consult it rather than the raw stream.
2085 ///
2086 /// This is the `Position::Client` constructor, which `ConnectionH2` has no
2087 /// counterpart for: `ConnectionH1` serves backend connections too.
2088 ///
2089 /// To SEE THIS RED: in `log_context!`, put
2090 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2091 /// `peer = $self.peer_address,`. The backend id the operator needs is
2092 /// replaced by `peer=None`.
2093 #[test]
2094 fn log_context_renders_the_backend_peer_while_the_connect_is_in_flight() {
2095 let stream = unconnected_stream();
2096 let backend_address = cached_peer();
2097
2098 // Premise: this is the state a dial in flight really leaves the socket
2099 // in — the live lookup refuses.
2100 assert_eq!(
2101 stream.peer_addr().ok(),
2102 None,
2103 "a connect() still in flight must refuse getpeername(2)"
2104 );
2105
2106 let session_ulid = Ulid::generate();
2107 let connection = h1_of(Connection::new_h1_client(
2108 session_ulid,
2109 SessionTcpStream::new(stream, session_ulid, Some(backend_address)),
2110 "test-cluster".into(),
2111 test_backend_id(backend_address),
2112 Duration::from_secs(30),
2113 ));
2114
2115 let rendered = log_context!(connection);
2116
2117 assert!(
2118 rendered.contains(&format!("peer=Some({backend_address})")),
2119 "a backend MUX-H1 line must name the configured backend: {rendered}"
2120 );
2121 assert!(
2122 !rendered.contains("peer=None"),
2123 "a backend MUX-H1 line must not collapse to None while the dial is \
2124 in flight: {rendered}"
2125 );
2126 }
2127
2128 /// Symptom 3 — on a PROXY-protocol frontend the cached address is the
2129 /// advertised client while the socket's own peer is the load balancer.
2130 /// `upgrade_expect` adopts the advertised source into the handler's
2131 /// `configured_peer`, and the pre-fix macro read straight past it: for one
2132 /// request id the `HTTP` line named the client and the `MUX-H1` line named
2133 /// the load balancer.
2134 ///
2135 /// The live lookup is deliberately HEALTHY here and disagrees with the
2136 /// cache, which is what separates this from
2137 /// [`log_context_renders_the_peer_when_the_live_lookup_fails`] — a single
2138 /// test cannot be red for both reasons.
2139 ///
2140 /// This stages the cleartext expect-proxy route, whose handler really is a
2141 /// `SessionTcpStream`. The TLS route composes the same macro with
2142 /// `FrontRustls::peer_addr`, whose own PROXY seeding is pinned in
2143 /// `https.rs` by `front_rustls_peer_snapshot_is_the_session_peer_not_the_accepted_socket`.
2144 ///
2145 /// To SEE THIS RED: in `log_context!`, put
2146 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2147 /// `peer = $self.peer_address,`. The rendered line then carries the
2148 /// loopback address the socket is really connected to — the load balancer
2149 /// — so the first assertion fails on the missing advertised client.
2150 #[test]
2151 fn log_context_renders_the_proxy_advertised_peer_not_the_load_balancer() {
2152 let (_listener, stream, live_peer) = connected_loopback_stream();
2153 let advertised = cached_peer();
2154
2155 // Premise: the live lookup is healthy and disagrees with the cache, so
2156 // the assertions below cannot pass for the wrong reason.
2157 assert_eq!(
2158 stream.peer_addr().ok(),
2159 Some(live_peer),
2160 "the test socket must be genuinely connected, so a live lookup succeeds"
2161 );
2162 assert_ne!(
2163 advertised, live_peer,
2164 "the advertised and transport addresses must differ for this test to discriminate"
2165 );
2166
2167 let session_ulid = Ulid::generate();
2168 let connection = h1_of(Connection::new_h1_server(
2169 session_ulid,
2170 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2171 Duration::from_secs(30),
2172 ));
2173
2174 let rendered = log_context!(connection);
2175
2176 assert!(
2177 rendered.contains(&format!("peer=Some({advertised})")),
2178 "MUX-H1 must render the PROXY-advertised client: {rendered}"
2179 );
2180 assert!(
2181 !rendered.contains(&live_peer.to_string()),
2182 "MUX-H1 must not fall back to the transport peer, which is the load \
2183 balancer on a PROXY frontend: {rendered}"
2184 );
2185 }
2186
2187 /// The per-stream twin fills the same slot from the same snapshot.
2188 ///
2189 /// `log_context_stream!` has no production expansion in this file today
2190 /// and carries `#[allow(unused_macros)]`, so nothing else type-checks its
2191 /// body at all. That is the reason to pin it rather than a reason to skip
2192 /// it: leaving twin macros on different sources is how they drift apart,
2193 /// and the divergence would be worse than either being wrong alone — the
2194 /// same session would render two different peers depending on whether a
2195 /// stream happened to be in scope at the callsite.
2196 ///
2197 /// To SEE THIS RED: in `log_context_stream!`, put
2198 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2199 /// `peer = $self.peer_address,`. The per-stream envelope then carries the
2200 /// loopback address while the connection envelope carries the cache.
2201 #[test]
2202 fn log_context_stream_renders_the_snapshot_not_a_live_lookup() {
2203 let (_listener, stream, live_peer) = connected_loopback_stream();
2204 let advertised = cached_peer();
2205
2206 assert_eq!(
2207 stream.peer_addr().ok(),
2208 Some(live_peer),
2209 "the test socket must be genuinely connected, so a live lookup succeeds"
2210 );
2211
2212 let session_ulid = Ulid::generate();
2213 let connection = h1_of(Connection::new_h1_server(
2214 session_ulid,
2215 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2216 Duration::from_secs(30),
2217 ));
2218 let http_context = test_http_context(session_ulid);
2219
2220 let rendered = log_context_stream!(connection, http_context);
2221
2222 assert!(
2223 rendered.contains(&format!("peer=Some({advertised})")),
2224 "the per-stream MUX-H1 envelope must render the snapshot: {rendered}"
2225 );
2226 assert!(
2227 !rendered.contains(&live_peer.to_string()),
2228 "the per-stream MUX-H1 envelope must not fall back to the live \
2229 getpeername(2) answer: {rendered}"
2230 );
2231 }
2232
2233 /// A [`SocketHandler`] that counts how often it is asked for the peer
2234 /// address, delegating every other method to a real loopback stream.
2235 ///
2236 /// The tests above pin WHICH address the log prefix renders. None of them
2237 /// can see how many times the connection reaches into the socket to get
2238 /// it, because both production handlers answer from a cache and so give
2239 /// the same answer however often they are asked. This handler makes the
2240 /// count observable.
2241 struct PeerAddrCountingSocket {
2242 stream: mio::net::TcpStream,
2243 peer: std::net::SocketAddr,
2244 calls: Rc<Cell<usize>>,
2245 }
2246
2247 impl SocketHandler for PeerAddrCountingSocket {
2248 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
2249 self.stream.socket_read(buf)
2250 }
2251
2252 fn socket_write(&mut self, buf: &[u8]) -> (usize, SocketResult) {
2253 self.stream.socket_write(buf)
2254 }
2255
2256 fn socket_write_vectored(&mut self, bufs: &[IoSlice]) -> (usize, SocketResult) {
2257 self.stream.socket_write_vectored(bufs)
2258 }
2259
2260 fn socket_ref(&self) -> &mio::net::TcpStream {
2261 &self.stream
2262 }
2263
2264 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
2265 &mut self.stream
2266 }
2267
2268 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
2269 self.calls.set(self.calls.get() + 1);
2270 Some(self.peer)
2271 }
2272
2273 fn protocol(&self) -> crate::socket::TransportProtocol {
2274 crate::socket::TransportProtocol::Tcp
2275 }
2276
2277 fn read_error(&self) {}
2278
2279 fn write_error(&self) {}
2280 }
2281
2282 /// The `peer=` slot is read from the socket exactly ONCE per connection —
2283 /// at construction — however many log lines the connection renders.
2284 ///
2285 /// This is the property that makes `peer_address` worth having, and it is
2286 /// the only one that separates the snapshot from simply calling the trait
2287 /// method in the macro. It is not about which address appears (the tests
2288 /// above own that): for a handler that already caches, reading the cache
2289 /// and reading a snapshot taken from that cache agree by construction, so
2290 /// substituting `peer = $self.socket.peer_addr(),` leaves every one of
2291 /// them green. What the snapshot changed is WHICH object a log line reads,
2292 /// and only a call count can observe that.
2293 ///
2294 /// TO SEE THIS RED: in `log_context!`, put
2295 /// `peer = $self.socket.peer_addr(),` — the call-the-trait-method shape —
2296 /// in place of `peer = $self.peer_address,`. The count then rises by one
2297 /// per rendered line and the final assertion fails with
2298 /// `the peer address must be read once, at construction, not once per log line:
2299 /// left: 4, right: 1`.
2300 #[test]
2301 fn log_context_reads_the_peer_address_once_per_connection() {
2302 let (_listener, stream, _live_peer) = connected_loopback_stream();
2303 let calls = Rc::new(Cell::new(0usize));
2304 let peer = cached_peer();
2305 let socket = PeerAddrCountingSocket {
2306 stream,
2307 peer,
2308 calls: Rc::clone(&calls),
2309 };
2310
2311 let connection = h1_of(Connection::new_h1_server(
2312 Ulid::generate(),
2313 socket,
2314 Duration::from_secs(30),
2315 ));
2316
2317 assert_eq!(
2318 calls.get(),
2319 1,
2320 "construction takes exactly one peer_addr() snapshot"
2321 );
2322
2323 // Premise: the rendered lines really do carry the address, so a zero
2324 // count below would mean the slot went missing rather than that it
2325 // became free.
2326 for _ in 0..3 {
2327 let rendered = log_context!(connection);
2328 assert!(
2329 rendered.contains(&format!("peer=Some({peer})")),
2330 "each rendered line must still carry the peer: {rendered}"
2331 );
2332 }
2333
2334 assert_eq!(
2335 calls.get(),
2336 1,
2337 "the peer address must be read once, at construction, not once per log line"
2338 );
2339 }
2340
2341 /// The three fields `log_context_stream!` reads out of an `HttpContext`,
2342 /// with every other field at an inert default. Built directly rather than
2343 /// through a `Stream`, because the macro touches no buffer and a real
2344 /// stream would drag a whole `Pool` in behind it.
2345 fn test_http_context(session_ulid: Ulid) -> HttpContext {
2346 HttpContext {
2347 keep_alive_backend: true,
2348 keep_alive_frontend: true,
2349 sticky_session_found: None,
2350 method: None,
2351 authority: None,
2352 path: None,
2353 status: None,
2354 reason: None,
2355 user_agent: None,
2356 x_request_id: None,
2357 xff_chain: None,
2358 #[cfg(feature = "opentelemetry")]
2359 otel: None,
2360 closing: false,
2361 session_id: session_ulid,
2362 id: Ulid::generate(),
2363 backend_id: None,
2364 cluster_id: None,
2365 cluster_metrics_incarnation: Default::default(),
2366 affinity_key: None,
2367 protocol: TransportKind::HTTP,
2368 public_address: "127.0.0.1:0"
2369 .parse()
2370 .expect("the public address literal must parse"),
2371 session_address: None,
2372 sticky_name: String::new(),
2373 sticky_session: None,
2374 backend_address: None,
2375 tls_server_name: None,
2376 tls_cert_names: None,
2377 strict_sni_binding: false,
2378 elide_x_real_ip: false,
2379 send_x_real_ip: false,
2380 forwarded_headers: sozu_command_lib::proto::command::ForwardedHeaders::Both,
2381 max_trailer_fields: 128,
2382 trailer_fields: 0,
2383 tls_version: None,
2384 tls_cipher: None,
2385 tls_alpn: None,
2386 sozu_id_header: String::from("Sozu-Id"),
2387 redirect_location: None,
2388 www_authenticate: None,
2389 original_authority: None,
2390 headers_response: Vec::new(),
2391 retry_after_seconds: None,
2392 frontend_redirect_template: None,
2393 redirect_status: None,
2394 tags: None,
2395 forwarding_hop: None,
2396 access_log_message: None,
2397 backends_unavailable: false,
2398 }
2399 }
2400
2401 /// `ConnectionH1`'s `Debug` renders the peer address the connection
2402 /// snapshotted at construction, not the transport address the kernel knows.
2403 ///
2404 /// This is the twin of `ConnectionH2`'s `Debug`, which already renders
2405 /// `peer_address` and names no socket at all. `ConnectionH1` was the last
2406 /// `Debug` in this module handing `mio::net::TcpStream`'s own `Debug` a
2407 /// `socket` field through `SocketHandler::socket_ref` — a local address, a
2408 /// peer address and a file descriptor — and so the last one whose rendered
2409 /// line could disagree with the `peer=` slot every `log_context!` line of
2410 /// the same connection already carries.
2411 ///
2412 /// Staged like
2413 /// [`log_context_renders_the_proxy_advertised_peer_not_the_load_balancer`]:
2414 /// a genuinely connected loopback socket whose live lookup is healthy and
2415 /// disagrees with the address its handler declares, which is the
2416 /// PROXY-protocol frontend's shape. This pins the VALUE rendered rather
2417 /// than a count — the two addresses differ, so only one of them can appear.
2418 ///
2419 /// To SEE THIS RED: in `impl Debug for ConnectionH1`, put
2420 /// `.field("socket", &self.socket.socket_ref())` back in place of
2421 /// `.field("peer_address", &self.peer_address)`. The rendered struct then
2422 /// carries the loopback address the socket is really connected to — the
2423 /// load balancer — so the first assertion fails on the missing advertised
2424 /// client and the second on the transport address being present.
2425 #[test]
2426 fn debug_renders_the_proxy_advertised_peer_not_the_transport_socket() {
2427 let (_listener, stream, live_peer) = connected_loopback_stream();
2428 let advertised = cached_peer();
2429
2430 // Premise: the live lookup is healthy and disagrees with the declared
2431 // address, so the assertions below cannot pass for the wrong reason.
2432 assert_eq!(
2433 stream.peer_addr().ok(),
2434 Some(live_peer),
2435 "the test socket must be genuinely connected, so a live lookup succeeds"
2436 );
2437 assert_ne!(
2438 advertised, live_peer,
2439 "the declared and transport addresses must differ for this test to discriminate"
2440 );
2441
2442 let session_ulid = Ulid::generate();
2443 let connection = h1_of(Connection::new_h1_server(
2444 session_ulid,
2445 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2446 Duration::from_secs(30),
2447 ));
2448
2449 let rendered = format!("{connection:?}");
2450
2451 assert!(
2452 rendered.contains(&format!("Some({advertised})")),
2453 "the ConnectionH1 Debug must render the declared peer: {rendered}"
2454 );
2455 assert!(
2456 !rendered.contains(&live_peer.to_string()),
2457 "the ConnectionH1 Debug must not render the transport address, which \
2458 is the load balancer on a PROXY frontend: {rendered}"
2459 );
2460 }
2461
2462 // ── `backend_header_time`, the H1 half (sozu-proxy/sozu#426) ─────────
2463 //
2464 // DO NOT READ THESE TESTS AS COVERING H2. They drive
2465 // `ConnectionH1::readable` only. The H2 twin lives in
2466 // `ConnectionH2::handle_headers_frame` (`lib/src/protocol/mux/h2.rs`) and
2467 // is pinned by its own test there.
2468
2469 /// A `Position::Client` H1 backend connection whose stream is linked to a
2470 /// frontend, staged at the exact moment a real dial completes: the
2471 /// connection is `Connected`, `backend_connected` is armed, and not one
2472 /// response byte has arrived.
2473 ///
2474 /// Both loopback peers are returned and must be held for the whole test —
2475 /// dropping either tears the connection down and turns the next
2476 /// `readable()` into a forced disconnect instead of a parse.
2477 /// Held together rather than returned as a tuple, the way
2478 /// `LedgerFixture` (`lib/src/protocol/mux/h2.rs`) is: the buffer pool and
2479 /// both loopback peers are lifetime ballast with no business in a test
2480 /// body, and a six-element tuple is `clippy::type_complexity`.
2481 struct BackendReadFixture {
2482 context: Context<crate::protocol::mux::test_support::TestListener>,
2483 frontend: Connection<mio::net::TcpStream>,
2484 client: ConnectionH1<mio::net::TcpStream>,
2485 backend_peer: std::net::TcpStream,
2486 _frontend_peer: std::net::TcpStream,
2487 _pool: Rc<RefCell<Pool>>,
2488 }
2489
2490 fn linked_backend_connection() -> BackendReadFixture {
2491 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2492 let mut context = test_context(&pool);
2493 context
2494 .create_stream(Ulid::generate(), 1 << 16)
2495 .expect("the test pool must hand out stream buffers");
2496
2497 let (front_socket, front_peer) = connected_socket();
2498 let frontend =
2499 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2500
2501 let (back_socket, back_peer) = connected_socket();
2502 let session_ulid = Ulid::generate();
2503 let mut client = h1_of(Connection::new_h1_client(
2504 session_ulid,
2505 back_socket,
2506 "test-cluster".into(),
2507 test_backend_id(cached_peer()),
2508 Duration::from_secs(60),
2509 ));
2510 // `new_h1_client` opens in `Connecting`; move it the way a completed
2511 // dial does, so the read path runs its `Connected` accounting.
2512 if let Position::Client(_, _, status) = &mut client.position {
2513 *status = BackendStatus::Connected;
2514 }
2515 client.stream = Some(0);
2516
2517 let stream = &mut context.streams[0];
2518 stream.state = StreamState::Linked(mio::Token(1));
2519 stream.metrics.backend_id = Some("test-backend".into());
2520 stream.metrics.backend_start();
2521 stream.metrics.backend_connected();
2522
2523 BackendReadFixture {
2524 context,
2525 frontend,
2526 client,
2527 backend_peer: back_peer,
2528 _frontend_peer: front_peer,
2529 _pool: pool,
2530 }
2531 }
2532
2533 /// Hand `bytes` to the backend peer and drive `ConnectionH1::readable`
2534 /// until `done` holds, bounded.
2535 ///
2536 /// The loop is not a retry papering over a flaky assertion: a loopback
2537 /// write is a syscall away, not instantaneous, so a single `readable()`
2538 /// may legitimately see `WouldBlock` and read nothing. The bound is what
2539 /// keeps a genuine failure a failure instead of a hang.
2540 fn feed_backend<F>(
2541 peer: &mut std::net::TcpStream,
2542 client: &mut ConnectionH1<mio::net::TcpStream>,
2543 context: &mut Context<crate::protocol::mux::test_support::TestListener>,
2544 frontend: &mut Connection<mio::net::TcpStream>,
2545 bytes: &[u8],
2546 done: F,
2547 ) where
2548 F: Fn(&Context<crate::protocol::mux::test_support::TestListener>) -> bool,
2549 {
2550 peer.write_all(bytes)
2551 .expect("the loopback peer must accept the staged response bytes");
2552 for _ in 0..64 {
2553 client.readiness.event.insert(Ready::READABLE);
2554 client.readable(context, EndpointServer(frontend));
2555 if done(context) {
2556 return;
2557 }
2558 }
2559 panic!("the backend read path never reached the staged state");
2560 }
2561
2562 /// The whole point of the metric, pinned as an ordering: the H1 backend
2563 /// time-to-first-header-byte instant is taken when the response HEADERS
2564 /// finish parsing, which is strictly before the response ENDS.
2565 ///
2566 /// Two phases, and the split is what makes this discriminating. After the
2567 /// headers alone (`Content-Length: 2`, body withheld) the header instant
2568 /// must already exist while `backend_stop` — the response-end marker every
2569 /// one of `ConnectionH1::writable`'s five sites owns — must still be
2570 /// absent. An instant placed at any of those sites cannot satisfy that.
2571 /// After the body, the instant must be UNCHANGED: the transition fires on
2572 /// the header -> body edge, not on every read.
2573 ///
2574 /// The ordering assertion is then `header_time <= response_time` on
2575 /// `Duration`s, not on the millisecond values the histogram stores: at
2576 /// millisecond resolution a fast test rounds both to 0 and the relation
2577 /// would hold however wrong the placement is.
2578 ///
2579 /// `backend_stop` is marked by the test rather than driven through
2580 /// `ConnectionH1::writable` because that pass calls
2581 /// `SessionMetrics::reset` immediately after its access log, which wipes
2582 /// every instant before a test could read one.
2583 ///
2584 /// To SEE THIS RED: move `parts.metrics.backend_headers_received();` out
2585 /// of the `!was_main_phase && self.position.is_client()` branch of
2586 /// `ConnectionH1::readable` and put it immediately after the
2587 /// `stream.metrics.backend_stop();` that precedes `Some("H1::Complete")`
2588 /// in `ConnectionH1::writable`. Phase one then reports no header time at
2589 /// all.
2590 #[test]
2591 fn the_h1_backend_header_instant_lands_on_the_headers_not_the_response_end() {
2592 let mut fixture = linked_backend_connection();
2593 let BackendReadFixture {
2594 context,
2595 frontend,
2596 client,
2597 backend_peer,
2598 ..
2599 } = &mut fixture;
2600
2601 // Premise: nothing has been received, so neither instant can be stale.
2602 assert_eq!(context.streams[0].metrics.backend_header_time(), None);
2603 assert_eq!(context.streams[0].metrics.backend_stop, None);
2604
2605 feed_backend(
2606 backend_peer,
2607 client,
2608 context,
2609 frontend,
2610 b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\n",
2611 |context| context.streams[0].back.is_main_phase(),
2612 );
2613
2614 let after_headers = context.streams[0]
2615 .metrics
2616 .backend_headers_received
2617 .expect("the response headers must arm the backend header instant");
2618 assert!(
2619 !context.streams[0].back.is_terminated(),
2620 "premise: the response is not over — its 2-byte body is still \
2621 outstanding, so this phase cannot be observing the response end"
2622 );
2623 assert_eq!(
2624 context.streams[0].metrics.backend_stop, None,
2625 "the response-end marker must still be absent while only the \
2626 headers have arrived"
2627 );
2628
2629 feed_backend(backend_peer, client, context, frontend, b"ok", |context| {
2630 context.streams[0].back.is_terminated()
2631 });
2632
2633 assert_eq!(
2634 context.streams[0].metrics.backend_headers_received,
2635 Some(after_headers),
2636 "the instant is taken on the header -> body edge, so the body \
2637 reads must not move it"
2638 );
2639
2640 // What the `Some("H1::Complete")` arm of `ConnectionH1::writable` does
2641 // once the whole response has been forwarded.
2642 context.streams[0].metrics.backend_stop();
2643
2644 let metrics = &context.streams[0].metrics;
2645 let header_time = metrics
2646 .backend_header_time()
2647 .expect("a completed H1 response must report a backend header time");
2648 let response_time = metrics
2649 .backend_response_time()
2650 .expect("a completed H1 response must report a backend response time");
2651 assert!(
2652 header_time <= response_time,
2653 "the first response-header byte arrives before the last response \
2654 byte: header_time {header_time:?} must not exceed response_time \
2655 {response_time:?}"
2656 );
2657 }
2658
2659 // ── The access log of a request the parse rejected (sozu-proxy/sozu#1085) ──
2660 //
2661 // DO NOT READ THESE TESTS AS COVERING H2. They drive a `Position::Server`
2662 // `ConnectionH1` only. An H2 request whose field block `handle_header`
2663 // (`lib/src/protocol/mux/pkawa.rs`) refuses takes another path,
2664 // `record_rejected_request` in the same file, and is covered by the
2665 // `h2` tests beside `rejected_request_line`
2666 // (`lib/src/protocol/mux/stream.rs`).
2667
2668 /// Drive `request` through a real `Position::Server` `ConnectionH1`, the
2669 /// way a client socket does: `readable` until the parse is rejected, then
2670 /// `writable` until the 400 is written and its access log emitted.
2671 /// Returns every log line the run produced.
2672 ///
2673 /// Driving both halves, rather than calling `Stream::generate_access_log`
2674 /// on a staged stream, is what makes these tests say which site emits the
2675 /// line and that the request bytes are still in the front buffer when it
2676 /// does.
2677 ///
2678 /// The loops are bounded for the reason `feed_backend` gives: a loopback
2679 /// write is a syscall away, not instantaneous.
2680 fn access_log_of_a_rejected_h1_request(request: &'static [u8]) -> String {
2681 crate::capture_test_logs(move || {
2682 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2683 let mut context = test_context(&pool);
2684 context
2685 .create_stream(Ulid::generate(), 1 << 16)
2686 .expect("the test pool must hand out stream buffers");
2687 let (front_socket, mut front_peer) = connected_socket();
2688 let mut server = h1_of(Connection::new_h1_server(
2689 Ulid::generate(),
2690 front_socket,
2691 Duration::from_secs(60),
2692 ));
2693 server.stream = Some(0);
2694 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2695
2696 front_peer
2697 .write_all(request)
2698 .expect("the loopback peer must accept the staged request bytes");
2699 for _ in 0..64 {
2700 server.readiness.event.insert(Ready::READABLE);
2701 server.readable(&mut context, EndpointClient(&mut router));
2702 if context.streams[0].front.is_error() {
2703 break;
2704 }
2705 }
2706 assert!(
2707 context.streams[0].front.is_error(),
2708 "premise: the staged request must be rejected by the parse"
2709 );
2710 assert_eq!(
2711 context.streams[0].context.method, None,
2712 "premise: the rejection happened before `HttpContext` captured \
2713 the request line, which is the whole defect"
2714 );
2715
2716 // `ConnectionH1::writable` resets the stream metrics right after
2717 // it emits the access log, so a cleared start instant is the
2718 // observable "the line went out".
2719 for _ in 0..64 {
2720 server.readiness.event.insert(Ready::WRITABLE);
2721 server.writable(&mut context, EndpointClient(&mut router));
2722 if context.streams[0].metrics.start.is_none() {
2723 break;
2724 }
2725 }
2726 })
2727 }
2728
2729 /// A request that fails to parse after its response started on the wire
2730 /// (a backend answering early and streaming its body while the client
2731 /// still uploads a chunked body, then a malformed chunk) must cut that
2732 /// response, never splice a complete `HTTP/1.1 400` into its body, which
2733 /// the client would read as part of the first response.
2734 ///
2735 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the
2736 /// `Position::Server if stream.back.consumed` arm. The 400 is then
2737 /// written: `no 400 may follow a response already on the wire`.
2738 #[test]
2739 fn a_request_error_after_the_response_started_cuts_it_instead_of_splicing_a_400() {
2740 use std::io::Read;
2741
2742 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2743 let mut context = test_context(&pool);
2744 context
2745 .create_stream(Ulid::generate(), 1 << 16)
2746 .expect("the test pool must hand out stream buffers");
2747 let (front_socket, mut front_peer) = connected_socket();
2748 front_peer
2749 .set_nonblocking(true)
2750 .expect("the loopback peer must switch to non-blocking");
2751 let mut server = h1_of(Connection::new_h1_server(
2752 Ulid::generate(),
2753 front_socket,
2754 Duration::from_secs(60),
2755 ));
2756 server.stream = Some(0);
2757 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2758 // The early response already put bytes on the client's wire.
2759 context.streams[0].back.consumed = true;
2760
2761 front_peer
2762 .write_all(
2763 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\nZZ\r\n",
2764 )
2765 .expect("the loopback peer must accept the staged request bytes");
2766 let mut result = MuxResult::Continue;
2767 for _ in 0..64 {
2768 server.readiness.event.insert(Ready::READABLE);
2769 result = server.readable(&mut context, EndpointClient(&mut router));
2770 if context.streams[0].front.is_error() {
2771 break;
2772 }
2773 }
2774 assert!(
2775 context.streams[0].front.is_error(),
2776 "premise: the malformed chunk must be rejected by the parse"
2777 );
2778
2779 let mut received = Vec::new();
2780 for _ in 0..16 {
2781 server.readiness.event.insert(Ready::WRITABLE);
2782 if server.readiness.filter_interest().is_writable() {
2783 server.writable(&mut context, EndpointClient(&mut router));
2784 }
2785 let mut buf = [0u8; 4096];
2786 if let Ok(n) = front_peer.read(&mut buf) {
2787 received.extend_from_slice(&buf[..n]);
2788 }
2789 }
2790 assert!(
2791 !received.windows(12).any(|w| w == b"HTTP/1.1 400"),
2792 "no 400 may follow a response already on the wire, got {:?}",
2793 String::from_utf8_lossy(&received)
2794 );
2795 assert_ne!(
2796 context.streams[0].context.status,
2797 Some(400),
2798 "the started response must not be replaced by a 400"
2799 );
2800 assert!(
2801 context.streams[0].back.is_error() && matches!(result, MuxResult::CloseSession),
2802 "the response is cut and the session closes, got {:?} / {:?}",
2803 context.streams[0].back.parsing_phase,
2804 result
2805 );
2806 }
2807
2808 /// A request that fails to parse after its stream was linked, and after
2809 /// the backend's complete response already started on the wire, cuts that
2810 /// response and also ends the backend stream (sozu-proxy/sozu#1716). The
2811 /// backend connection holds part of the rejected request, so it must leave
2812 /// the `backend_streams` reverse index and be disconnected. It must not stay
2813 /// attached to the stream slot, and must not go back to the keep-alive pool,
2814 /// although its response is complete.
2815 ///
2816 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the block of the
2817 /// `Position::Server if stream.back.consumed` arm that clears
2818 /// `keep_alive_backend` and calls `endpoint.end_stream`. The reverse index
2819 /// then still lists the stream: `the rejected stream must leave the
2820 /// backend reverse index`. Keeping `end_stream` but not the flag instead
2821 /// pools the connection: `a backend holding part of a rejected request
2822 /// must be disconnected, not pooled`.
2823 #[test]
2824 fn a_request_error_after_a_linked_response_started_ends_the_backend_stream() {
2825 const BACKEND: mio::Token = mio::Token(1);
2826
2827 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2828 let mut context = test_context(&pool);
2829 context
2830 .create_stream(Ulid::generate(), 1 << 16)
2831 .expect("the test pool must hand out stream buffers");
2832 let (front_socket, mut front_peer) = connected_socket();
2833 let mut frontend =
2834 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2835 if let Connection::H1(server) = &mut frontend {
2836 server.stream = Some(0);
2837 }
2838 let (back_socket, mut back_peer) = connected_socket();
2839 let backend_ulid = Ulid::generate();
2840 let mut client = h1_of(Connection::new_h1_client(
2841 backend_ulid,
2842 SessionTcpStream::new(back_socket, backend_ulid, None),
2843 "test-cluster".into(),
2844 test_backend_id(cached_peer()),
2845 Duration::from_secs(60),
2846 ));
2847 if let Position::Client(_, _, status) = &mut client.position {
2848 *status = BackendStatus::KeepAlive;
2849 }
2850 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2851
2852 // The request head and a first chunk: the stream is routed.
2853 front_peer
2854 .write_all(
2855 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHello\r\n",
2856 )
2857 .expect("the loopback peer must accept the staged request head");
2858 for _ in 0..64 {
2859 frontend.readiness_mut().event.insert(Ready::READABLE);
2860 frontend.readable(&mut context, EndpointClient(&mut router));
2861 if context.streams[0].state == StreamState::Link {
2862 break;
2863 }
2864 }
2865 assert_eq!(
2866 context.streams[0].state,
2867 StreamState::Link,
2868 "premise: the request head must be parsed and queued for linking"
2869 );
2870
2871 // What the router does with a pooled backend connection.
2872 assert!(
2873 client.start_stream(0, &mut context),
2874 "premise: the pooled backend must accept the stream"
2875 );
2876 context.link_stream(0, BACKEND);
2877 router.backends.insert(BACKEND, Connection::H1(client));
2878
2879 // The backend answers early and completely, and that response has
2880 // started on the client's wire.
2881 back_peer
2882 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
2883 .expect("the loopback backend peer must accept the response");
2884 for _ in 0..64 {
2885 let Some(backend) = router.backends.get_mut(&BACKEND) else {
2886 unreachable!("the backend was inserted")
2887 };
2888 backend.readiness_mut().event.insert(Ready::READABLE);
2889 backend.readable(&mut context, EndpointServer(&mut frontend));
2890 if context.streams[0].back.is_terminated() {
2891 break;
2892 }
2893 }
2894 assert!(
2895 context.streams[0].back.is_terminated(),
2896 "premise: the backend response must be read whole"
2897 );
2898 context.streams[0].back.consumed = true;
2899
2900 // A malformed chunk-size line rejects the request.
2901 front_peer
2902 .write_all(b"ZZ\r\n")
2903 .expect("the loopback peer must accept the malformed chunk");
2904 let mut result = MuxResult::Continue;
2905 for _ in 0..64 {
2906 frontend.readiness_mut().event.insert(Ready::READABLE);
2907 result = frontend.readable(&mut context, EndpointClient(&mut router));
2908 if context.streams[0].front.is_error() {
2909 break;
2910 }
2911 }
2912 assert!(
2913 context.streams[0].front.is_error(),
2914 "premise: the malformed chunk must be rejected by the parse"
2915 );
2916 assert!(
2917 matches!(result, MuxResult::CloseSession),
2918 "the started response is cut and the session closes, got {result:?}"
2919 );
2920
2921 assert!(
2922 context
2923 .backend_streams
2924 .get(&BACKEND)
2925 .is_none_or(|ids| !ids.contains(&0)),
2926 "the rejected stream must leave the backend reverse index"
2927 );
2928 let Some(Connection::H1(client)) = router.backends.get(&BACKEND) else {
2929 unreachable!("the backend was inserted as H1")
2930 };
2931 assert_eq!(
2932 client.stream, None,
2933 "the backend connection must no longer carry the rejected stream"
2934 );
2935 assert!(
2936 matches!(
2937 client.position,
2938 Position::Client(_, _, BackendStatus::Disconnecting)
2939 ),
2940 "a backend holding part of a rejected request must be disconnected, not pooled"
2941 );
2942 }
2943
2944 /// A request that fails to parse after its stream was linked, before any
2945 /// byte of the response reached the client, is answered 400 and also ends
2946 /// the backend stream (sozu-proxy/sozu#1716). The backend connection holds
2947 /// part of the rejected request, so it must leave the `backend_streams`
2948 /// reverse index and be disconnected, not stay attached to the stream slot
2949 /// nor go back to the keep-alive pool, although its response is complete.
2950 ///
2951 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the block of the
2952 /// `Position::Server` arm (the one that answers 400) that clears the
2953 /// response and calls `endpoint.end_stream`. The reverse index then still
2954 /// lists the stream: `the rejected stream must leave the backend reverse
2955 /// index`.
2956 #[test]
2957 fn a_request_error_answered_400_after_linking_ends_the_backend_stream() {
2958 const BACKEND: mio::Token = mio::Token(1);
2959
2960 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2961 let mut context = test_context(&pool);
2962 context
2963 .create_stream(Ulid::generate(), 1 << 16)
2964 .expect("the test pool must hand out stream buffers");
2965 let (front_socket, mut front_peer) = connected_socket();
2966 let mut frontend =
2967 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2968 if let Connection::H1(server) = &mut frontend {
2969 server.stream = Some(0);
2970 }
2971 let (back_socket, mut back_peer) = connected_socket();
2972 let backend_ulid = Ulid::generate();
2973 let mut client = h1_of(Connection::new_h1_client(
2974 backend_ulid,
2975 SessionTcpStream::new(back_socket, backend_ulid, None),
2976 "test-cluster".into(),
2977 test_backend_id(cached_peer()),
2978 Duration::from_secs(60),
2979 ));
2980 if let Position::Client(_, _, status) = &mut client.position {
2981 *status = BackendStatus::KeepAlive;
2982 }
2983 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2984
2985 // The request head and a first chunk: the stream is routed.
2986 front_peer
2987 .write_all(
2988 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHello\r\n",
2989 )
2990 .expect("the loopback peer must accept the staged request head");
2991 for _ in 0..64 {
2992 frontend.readiness_mut().event.insert(Ready::READABLE);
2993 frontend.readable(&mut context, EndpointClient(&mut router));
2994 if context.streams[0].state == StreamState::Link {
2995 break;
2996 }
2997 }
2998 assert_eq!(
2999 context.streams[0].state,
3000 StreamState::Link,
3001 "premise: the request head must be parsed and queued for linking"
3002 );
3003
3004 // What the router does with a pooled backend connection.
3005 assert!(
3006 client.start_stream(0, &mut context),
3007 "premise: the pooled backend must accept the stream"
3008 );
3009 context.link_stream(0, BACKEND);
3010 router.backends.insert(BACKEND, Connection::H1(client));
3011
3012 // The backend answers early and completely, but no byte of that
3013 // response has reached the client yet.
3014 back_peer
3015 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
3016 .expect("the loopback backend peer must accept the response");
3017 for _ in 0..64 {
3018 let Some(backend) = router.backends.get_mut(&BACKEND) else {
3019 unreachable!("the backend was inserted")
3020 };
3021 backend.readiness_mut().event.insert(Ready::READABLE);
3022 backend.readable(&mut context, EndpointServer(&mut frontend));
3023 if context.streams[0].back.is_terminated() {
3024 break;
3025 }
3026 }
3027 assert!(
3028 context.streams[0].back.is_terminated(),
3029 "premise: the backend response must be read whole"
3030 );
3031 assert!(
3032 !context.streams[0].back.consumed,
3033 "premise: the response must not have started on the client's wire"
3034 );
3035
3036 // A malformed chunk-size line rejects the request.
3037 front_peer
3038 .write_all(b"ZZ\r\n")
3039 .expect("the loopback peer must accept the malformed chunk");
3040 let mut result = MuxResult::Continue;
3041 for _ in 0..64 {
3042 frontend.readiness_mut().event.insert(Ready::READABLE);
3043 result = frontend.readable(&mut context, EndpointClient(&mut router));
3044 if context.streams[0].front.is_error() {
3045 break;
3046 }
3047 }
3048 assert!(
3049 context.streams[0].front.is_error(),
3050 "premise: the malformed chunk must be rejected by the parse"
3051 );
3052 assert!(
3053 matches!(result, MuxResult::Continue),
3054 "the request is answered 400 on the client connection, got {result:?}"
3055 );
3056
3057 assert!(
3058 context
3059 .backend_streams
3060 .get(&BACKEND)
3061 .is_none_or(|ids| !ids.contains(&0)),
3062 "the rejected stream must leave the backend reverse index"
3063 );
3064 let Some(Connection::H1(client)) = router.backends.get(&BACKEND) else {
3065 unreachable!("the backend was inserted as H1")
3066 };
3067 assert_eq!(
3068 client.stream, None,
3069 "the backend connection must no longer carry the rejected stream"
3070 );
3071 assert!(
3072 matches!(
3073 client.position,
3074 Position::Client(_, _, BackendStatus::Disconnecting)
3075 ),
3076 "a backend holding part of a rejected request must be disconnected, not pooled"
3077 );
3078 }
3079
3080 /// The access log of an H1 request carries the frontend round-trip time,
3081 /// the connection's one sample, taken here because this is its first
3082 /// line, and no backend one when the request never reached a backend.
3083 ///
3084 /// TO SEE THIS RED: in `ConnectionH1::writable`, at the `H1::Complete`
3085 /// access log that writes the rejected request's 400, replace the
3086 /// `self.rtt()` of `client_rtt` with `None`. The
3087 /// line then carries `-` in that cell and the first assertion fails.
3088 #[test]
3089 fn the_h1_access_log_carries_the_frontend_rtt() {
3090 let output =
3091 access_log_of_a_rejected_h1_request(b"GET /rtt HTTP/1.1\r\nBad Header: x\r\n\r\n");
3092 let line = output
3093 .lines()
3094 .find(|line| line.contains("GET /rtt 400"))
3095 .unwrap_or_else(|| panic!("the 400 must be logged, got: {output}"));
3096 let cells: Vec<&str> = line
3097 .split_whitespace()
3098 .find_map(|token| {
3099 let cells: Vec<&str> = token.split('/').collect();
3100 (cells.len() == 5).then_some(cells)
3101 })
3102 .unwrap_or_else(|| panic!("the line must carry the five durations: {line}"));
3103 assert_ne!(
3104 cells[3], "-",
3105 "the H1 access log must carry the frontend client_rtt, got: {line}"
3106 );
3107 assert_eq!(
3108 cells[4], "-",
3109 "a request that never reached a backend has no server_rtt, got: {line}"
3110 );
3111 }
3112
3113 /// Twenty keep-alive requests on one frontend connection, each answered
3114 /// through the same backend connection taken back out of the keep-alive
3115 /// pool, cost one `getsockopt(TCP_INFO)` per side — not one per request
3116 /// and side — and every one of the twenty access lines still carries both
3117 /// RTTs, the same value on each line.
3118 ///
3119 /// Driven through the real `H1::Complete` site of
3120 /// `ConnectionH1::writable` and the real `EndpointClient::peer_rtt`, with
3121 /// the backend recycled by `ConnectionH1::end_stream` and
3122 /// `ConnectionH1::start_stream` exactly as a `Mux` does between two
3123 /// requests. The request side is staged rather than parsed: what is under
3124 /// test is the log emission, not routing.
3125 ///
3126 /// TO SEE THIS RED: in `memoized_rtt` (`lib/src/protocol/mux/mod.rs`),
3127 /// delete the early return on `memo.get()`. Every request then reads both
3128 /// sockets again and the count assertion fails with `left: 40`,
3129 /// `right: 2`.
3130 #[test]
3131 fn keep_alive_requests_read_tcp_info_once_per_connection() {
3132 const REQUESTS: usize = 20;
3133 const BACKEND: mio::Token = mio::Token(1);
3134 let (reads_sender, reads_receiver) = std::sync::mpsc::channel();
3135
3136 let output = crate::capture_test_logs(move || {
3137 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3138 let mut context = test_context(&pool);
3139 context
3140 .create_stream(Ulid::generate(), 1 << 16)
3141 .expect("the test pool must hand out stream buffers");
3142 let (front_socket, mut front_peer) = connected_socket();
3143 front_peer
3144 .set_nonblocking(true)
3145 .expect("the frontend peer is drained without blocking");
3146 let mut frontend =
3147 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
3148 let (back_socket, mut back_peer) = connected_socket();
3149 let backend_ulid = Ulid::generate();
3150 let mut client = h1_of(Connection::new_h1_client(
3151 backend_ulid,
3152 SessionTcpStream::new(back_socket, backend_ulid, None),
3153 "test-cluster".into(),
3154 test_backend_id(cached_peer()),
3155 Duration::from_secs(60),
3156 ));
3157 // The first request finds the connection freshly dialled; every
3158 // later one takes it back out of the pool through `start_stream`.
3159 if let Position::Client(_, _, status) = &mut client.position {
3160 *status = BackendStatus::KeepAlive;
3161 }
3162 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3163 router.backends.insert(BACKEND, Connection::H1(client));
3164
3165 let before = tcp_info_reads();
3166 let mut drained = [0u8; 4096];
3167 for request in 0..REQUESTS {
3168 let Some(Connection::H1(client)) = router.backends.get_mut(&BACKEND) else {
3169 unreachable!("the backend was inserted as H1")
3170 };
3171 assert!(
3172 client.start_stream(0, &mut context),
3173 "premise: the pooled backend must accept request {request}"
3174 );
3175 let stream = &mut context.streams[0];
3176 stream.state = StreamState::Linked(BACKEND);
3177 stream.context.keep_alive_frontend = true;
3178 // The staged request is complete and fully written: only then
3179 // may either connection outlive it (sozu-proxy/sozu#1721).
3180 stream.front.parsing_phase = kawa::ParsingPhase::Terminated;
3181 stream.metrics.service_start();
3182 stream.metrics.backend_id = Some("test-backend".into());
3183 stream.metrics.backend_start();
3184 stream.metrics.backend_connected();
3185
3186 back_peer
3187 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
3188 .expect("the loopback backend peer must accept the response");
3189 for _ in 0..64 {
3190 client.readiness.event.insert(Ready::READABLE);
3191 client.readable(&mut context, EndpointServer(&mut frontend));
3192 if context.streams[0].back.is_terminated() {
3193 break;
3194 }
3195 }
3196 assert!(
3197 context.streams[0].back.is_terminated(),
3198 "premise: response {request} must be read whole"
3199 );
3200
3201 for _ in 0..64 {
3202 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3203 frontend.writable(&mut context, EndpointClient(&mut router));
3204 if context.streams[0].metrics.start.is_none() {
3205 break;
3206 }
3207 }
3208 assert_eq!(
3209 context.streams[0].state,
3210 StreamState::Idle,
3211 "premise: request {request} must complete through the \
3212 keep-alive branch of `H1::Complete`"
3213 );
3214 while let Ok(read) = std::io::Read::read(&mut front_peer, &mut drained) {
3215 if read == 0 {
3216 break;
3217 }
3218 }
3219 }
3220 reads_sender
3221 .send(tcp_info_reads() - before)
3222 .expect("the test thread must report its TCP_INFO reads");
3223 });
3224
3225 let lines: Vec<&str> = output
3226 .lines()
3227 .filter(|line| line.contains("H1::Complete"))
3228 .collect();
3229 assert_eq!(
3230 lines.len(),
3231 REQUESTS,
3232 "every request must be logged, got: {output}"
3233 );
3234 let mut rtts = Vec::with_capacity(REQUESTS);
3235 for line in &lines {
3236 let cells: Vec<&str> = line
3237 .split_whitespace()
3238 .find_map(|token| {
3239 let cells: Vec<&str> = token.split('/').collect();
3240 (cells.len() == 5).then_some(cells)
3241 })
3242 .unwrap_or_else(|| panic!("the line must carry the five durations: {line}"));
3243 assert_ne!(cells[3], "-", "every line must carry client_rtt: {line}");
3244 assert_ne!(cells[4], "-", "every line must carry server_rtt: {line}");
3245 rtts.push((cells[3], cells[4]));
3246 }
3247 assert_eq!(
3248 reads_receiver
3249 .recv()
3250 .expect("the test thread must report its TCP_INFO reads"),
3251 2,
3252 "{REQUESTS} keep-alive requests must read TCP_INFO once for the \
3253 frontend and once for the backend"
3254 );
3255 assert!(
3256 rtts.windows(2).all(|pair| pair[0] == pair[1]),
3257 "every request of one connection reports that connection's one \
3258 sample, got: {rtts:?}"
3259 );
3260 }
3261
3262 /// A backend connection that answered before the whole request was
3263 /// written to it still expects the rest of the body: `end_stream` must not
3264 /// pool it, or the next request would be read as that body
3265 /// (sozu-proxy/sozu#1721). The same connection, once the request is
3266 /// complete too, is pooled: that half pins the guard is not a blanket
3267 /// refusal.
3268 ///
3269 /// A request received whole but not yet fully written upstream is just
3270 /// as incomplete for that backend.
3271 ///
3272 /// TO SEE THIS RED: in `ConnectionH1::end_stream`, drop the two
3273 /// `stream.front` conditions from the `BackendStatus::Connected` arm. The
3274 /// incomplete request then leaves the connection `KeepAlive`.
3275 #[test]
3276 fn a_backend_that_answered_before_the_whole_request_is_not_pooled() {
3277 const BACKEND: mio::Token = mio::Token(1);
3278 // (request phase, request bytes still unwritten, pooled?)
3279 for (request_phase, unwritten, expect_pooled) in [
3280 (kawa::ParsingPhase::Body, false, false),
3281 (kawa::ParsingPhase::Chunks { first: false }, false, false),
3282 (kawa::ParsingPhase::Terminated, true, false),
3283 (kawa::ParsingPhase::Terminated, false, true),
3284 ] {
3285 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3286 let mut context = test_context(&pool);
3287 context
3288 .create_stream(Ulid::generate(), 1 << 16)
3289 .expect("the test pool must hand out stream buffers");
3290 let (back_socket, _back_peer) = connected_socket();
3291 let backend_ulid = Ulid::generate();
3292 let mut client = h1_of(Connection::new_h1_client(
3293 backend_ulid,
3294 SessionTcpStream::new(back_socket, backend_ulid, None),
3295 "test-cluster".into(),
3296 test_backend_id(cached_peer()),
3297 Duration::from_secs(60),
3298 ));
3299 if let Position::Client(_, _, status) = &mut client.position {
3300 *status = BackendStatus::Connected;
3301 }
3302 client.stream = Some(0);
3303 let stream = &mut context.streams[0];
3304 stream.state = StreamState::Linked(BACKEND);
3305 stream.context.keep_alive_backend = true;
3306 // The response is complete; the request is as staged.
3307 stream.back.parsing_phase = kawa::ParsingPhase::Terminated;
3308 stream.front.parsing_phase = request_phase;
3309 if unwritten {
3310 // Received whole, but its end was never written upstream.
3311 stream
3312 .front
3313 .blocks
3314 .push_back(kawa::Block::Flags(kawa::Flags {
3315 end_body: true,
3316 end_chunk: false,
3317 end_header: false,
3318 end_stream: true,
3319 }));
3320 }
3321
3322 client.end_stream(0, &mut context);
3323
3324 let pooled = matches!(
3325 client.position,
3326 Position::Client(_, _, BackendStatus::KeepAlive)
3327 );
3328 assert_eq!(
3329 pooled,
3330 expect_pooled,
3331 "a request in {request_phase:?} (unwritten bytes: {unwritten}) must {}pool the backend connection",
3332 if expect_pooled { "" } else { "not " }
3333 );
3334 }
3335 }
3336
3337 /// A frontend socket whose `close_notify` is left pending by the close and
3338 /// flushed by the next write, as a TLS socket whose peer had not drained
3339 /// it yet: the close is deferred, and `writable` runs again on the same
3340 /// connection once the flush went through.
3341 #[derive(Debug)]
3342 struct PendingCloseNotifySocket {
3343 stream: mio::net::TcpStream,
3344 closing: bool,
3345 }
3346
3347 impl SocketHandler for PendingCloseNotifySocket {
3348 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
3349 self.stream.socket_read(buf)
3350 }
3351
3352 fn socket_write(&mut self, buf: &[u8]) -> (usize, SocketResult) {
3353 self.stream.socket_write(buf)
3354 }
3355
3356 fn socket_write_vectored(&mut self, bufs: &[IoSlice]) -> (usize, SocketResult) {
3357 // The pending `close_notify` leaves with this write.
3358 self.closing = false;
3359 self.stream.socket_write_vectored(bufs)
3360 }
3361
3362 fn socket_wants_write(&self) -> bool {
3363 self.closing
3364 }
3365
3366 fn socket_close(&mut self) {
3367 self.closing = true;
3368 }
3369
3370 fn socket_ref(&self) -> &mio::net::TcpStream {
3371 &self.stream
3372 }
3373
3374 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
3375 &mut self.stream
3376 }
3377
3378 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
3379 self.stream.peer_addr().ok()
3380 }
3381
3382 fn protocol(&self) -> crate::socket::TransportProtocol {
3383 crate::socket::TransportProtocol::Tcp
3384 }
3385
3386 fn read_error(&self) {}
3387
3388 fn write_error(&self) {}
3389 }
3390
3391 /// A frontend socket that still reports buffered TLS records and answers
3392 /// every write with `status`, as a TLS socket whose peer stopped reading
3393 /// (`WouldBlock`) or whose write met a socket error (`Error`).
3394 #[derive(Debug)]
3395 struct StuckTlsSocket {
3396 stream: mio::net::TcpStream,
3397 status: SocketResult,
3398 }
3399
3400 impl SocketHandler for StuckTlsSocket {
3401 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
3402 self.stream.socket_read(buf)
3403 }
3404
3405 fn socket_write(&mut self, _buf: &[u8]) -> (usize, SocketResult) {
3406 (0, self.status)
3407 }
3408
3409 fn socket_write_vectored(&mut self, _bufs: &[IoSlice]) -> (usize, SocketResult) {
3410 (0, self.status)
3411 }
3412
3413 fn socket_wants_write(&self) -> bool {
3414 true
3415 }
3416
3417 fn socket_ref(&self) -> &mio::net::TcpStream {
3418 &self.stream
3419 }
3420
3421 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
3422 &mut self.stream
3423 }
3424
3425 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
3426 self.stream.peer_addr().ok()
3427 }
3428
3429 fn protocol(&self) -> crate::socket::TransportProtocol {
3430 crate::socket::TransportProtocol::Tls1_3
3431 }
3432
3433 fn read_error(&self) {}
3434
3435 fn write_error(&self) {}
3436 }
3437
3438 /// A TLS flush that did not answer `Continue` leaves WRITABLE to the next
3439 /// kernel edge, even while the socket still reports records: re-raising
3440 /// it would make `Mux::ready_inner` retry the same refused or failed
3441 /// write on every inner iteration until `MAX_LOOP_ITERATIONS`
3442 /// (sozu-proxy/sozu#1780).
3443 ///
3444 /// Both flushes are covered: the one with no stream, and the TLS-only
3445 /// flush of a stream with nothing left to write.
3446 ///
3447 /// On this server-side connection an `Error` flush instead closes the
3448 /// session through `ConnectionH1::client_write_failed`, before that check
3449 /// (sozu-proxy/sozu#1779): it stops reporting pending output, and leaves
3450 /// WRITABLE unraised too.
3451 ///
3452 /// TO SEE THIS RED: in either flush of `ConnectionH1::writable`, drop the
3453 /// `status == SocketResult::Continue` condition. The `WouldBlock` case
3454 /// then re-raises WRITABLE.
3455 #[test]
3456 fn a_tls_flush_that_did_not_continue_leaves_writable_to_the_kernel() {
3457 for (status, with_stream) in [
3458 (SocketResult::WouldBlock, false),
3459 (SocketResult::Error, false),
3460 (SocketResult::WouldBlock, true),
3461 (SocketResult::Error, true),
3462 ] {
3463 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 4, 16384)));
3464 let mut context = test_context(&pool);
3465 if with_stream {
3466 context
3467 .create_stream(Ulid::generate(), 1 << 16)
3468 .expect("the test pool must hand out stream buffers");
3469 }
3470 let (socket, _peer) = connected_socket();
3471 let mut frontend = Connection::new_h1_server(
3472 Ulid::generate(),
3473 StuckTlsSocket {
3474 stream: socket,
3475 status,
3476 },
3477 Duration::from_secs(60),
3478 );
3479 if let Connection::H1(server) = &mut frontend {
3480 server.stream = with_stream.then_some(0);
3481 }
3482 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3483 frontend.readiness_mut().interest.insert(Ready::WRITABLE);
3484 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3485
3486 let result = frontend.writable(&mut context, EndpointClient(&mut router));
3487
3488 if status == SocketResult::Error {
3489 assert!(
3490 matches!(result, MuxResult::CloseSession),
3491 "a failed flush (stream: {with_stream}) must close the session"
3492 );
3493 assert!(
3494 !frontend.has_pending_write(),
3495 "a failed flush (stream: {with_stream}) must stop reporting output"
3496 );
3497 } else {
3498 assert!(matches!(result, MuxResult::Continue));
3499 assert!(
3500 frontend.has_pending_write(),
3501 "premise: the socket must still report records"
3502 );
3503 }
3504 assert!(
3505 !frontend.readiness().event.is_writable(),
3506 "a flush that answered {status:?} (stream: {with_stream}) must not re-raise \
3507 WRITABLE, got {:?}",
3508 frontend.readiness()
3509 );
3510 }
3511 }
3512
3513 /// Once `writable` decided to close after a response, a deferred TLS
3514 /// close must not run the completion again: the next pass would log the
3515 /// request a second time, count it twice, and re-take the keep-alive
3516 /// decision after `close_notify` — keeping the connection if the body
3517 /// finished in between (sozu-proxy/sozu#1721).
3518 ///
3519 /// Once `close_notify` is flushed, the request still incomplete, the
3520 /// connection starts its lingering close (RFC 9112 §9.6) and closes the
3521 /// session once the client closes.
3522 ///
3523 /// TO SEE THIS RED: in `ConnectionH1::writable`, delete the
3524 /// `stream.context.closing = true;` of the close path. The second pass
3525 /// then logs a second `H1::Complete` line and resets the stream to
3526 /// `Idle` instead of closing the session.
3527 #[test]
3528 fn a_deferred_tls_close_completes_the_response_once() {
3529 const BACKEND: mio::Token = mio::Token(1);
3530 let (states_sender, states_receiver) = std::sync::mpsc::channel();
3531
3532 let output = crate::capture_test_logs(move || {
3533 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3534 let mut context = test_context(&pool);
3535 context
3536 .create_stream(Ulid::generate(), 1 << 16)
3537 .expect("the test pool must hand out stream buffers");
3538 let (front_socket, mut front_peer) = connected_socket();
3539 front_peer
3540 .set_nonblocking(true)
3541 .expect("the frontend peer is drained without blocking");
3542 let mut frontend = Connection::new_h1_server(
3543 Ulid::generate(),
3544 PendingCloseNotifySocket {
3545 stream: front_socket,
3546 closing: false,
3547 },
3548 Duration::from_secs(60),
3549 );
3550 if let Connection::H1(server) = &mut frontend {
3551 server.stream = Some(0);
3552 }
3553 let (back_socket, mut back_peer) = connected_socket();
3554 let backend_ulid = Ulid::generate();
3555 let mut client = h1_of(Connection::new_h1_client(
3556 backend_ulid,
3557 SessionTcpStream::new(back_socket, backend_ulid, None),
3558 "test-cluster".into(),
3559 test_backend_id(cached_peer()),
3560 Duration::from_secs(60),
3561 ));
3562 if let Position::Client(_, _, status) = &mut client.position {
3563 *status = BackendStatus::KeepAlive;
3564 }
3565 assert!(
3566 client.start_stream(0, &mut context),
3567 "premise: the backend must accept the request"
3568 );
3569 let stream = &mut context.streams[0];
3570 stream.state = StreamState::Linked(BACKEND);
3571 stream.context.keep_alive_frontend = true;
3572 // An upload still in its body: the response completes first.
3573 stream.front.parsing_phase = kawa::ParsingPhase::Body;
3574 stream.metrics.service_start();
3575 stream.metrics.backend_id = Some("test-backend".into());
3576 stream.metrics.backend_start();
3577 stream.metrics.backend_connected();
3578
3579 back_peer
3580 .write_all(b"HTTP/1.1 413 Content Too Large\r\nContent-Length: 0\r\n\r\n")
3581 .expect("the loopback backend peer must accept the response");
3582 for _ in 0..64 {
3583 client.readiness.event.insert(Ready::READABLE);
3584 client.readable(&mut context, EndpointServer(&mut frontend));
3585 if context.streams[0].back.is_terminated() {
3586 break;
3587 }
3588 }
3589 assert!(
3590 context.streams[0].back.is_terminated(),
3591 "premise: the early response must be read whole"
3592 );
3593 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3594 router.backends.insert(BACKEND, Connection::H1(client));
3595
3596 let mut states = Vec::new();
3597 for pass in 0..2 {
3598 if pass == 1 {
3599 // The body finishes after the close began.
3600 context.streams[0].front.parsing_phase = kawa::ParsingPhase::Terminated;
3601 }
3602 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3603 let result = frontend.writable(&mut context, EndpointClient(&mut router));
3604 states.push((result, context.streams[0].state));
3605 if pass == 0 {
3606 assert_eq!(
3607 context.streams[0].state,
3608 StreamState::Unlinked,
3609 "premise: the first pass completes the response and closes"
3610 );
3611 }
3612 }
3613 let Connection::H1(server) = &mut frontend else {
3614 unreachable!("the frontend is H1");
3615 };
3616 let lingering = server.is_lingering();
3617 let peer_eof = read_to_eof(&mut front_peer).is_some();
3618 // The client closes: the drain meets its EOF and the session closes.
3619 drop(front_peer);
3620 let mut after_client_close = MuxResult::Continue;
3621 for _ in 0..1000 {
3622 server.readiness.event.insert(Ready::READABLE);
3623 after_client_close = server.readable(&mut context, EndpointClient(&mut router));
3624 if matches!(after_client_close, MuxResult::CloseSession) {
3625 break;
3626 }
3627 std::thread::sleep(Duration::from_millis(1));
3628 }
3629 states_sender
3630 .send((states, lingering, peer_eof, after_client_close))
3631 .expect("the test thread must report its states");
3632 });
3633
3634 let (states, lingering, peer_eof, after_client_close) = states_receiver
3635 .recv()
3636 .expect("the test thread must report its states");
3637 let completions = output
3638 .lines()
3639 .filter(|line| line.contains("H1::Complete"))
3640 .count();
3641 assert_eq!(
3642 completions, 1,
3643 "the response must be completed and logged once, got: {output}"
3644 );
3645 for (pass, (_, state)) in states.iter().enumerate() {
3646 assert_ne!(
3647 *state,
3648 StreamState::Idle,
3649 "pass {pass}: no keep-alive reset after the close began"
3650 );
3651 }
3652 assert!(
3653 matches!(states[0].0, MuxResult::Continue),
3654 "the first pass defers the close behind the pending close_notify"
3655 );
3656 assert!(
3657 matches!(states[1].0, MuxResult::Continue) && lingering,
3658 "once close_notify is flushed the connection lingers, got {:?}",
3659 states[1].0
3660 );
3661 assert!(
3662 peer_eof,
3663 "the lingering close sends the FIN after the response"
3664 );
3665 assert!(
3666 matches!(after_client_close, MuxResult::CloseSession),
3667 "the session closes once the client closed, got {after_client_close:?}"
3668 );
3669 }
3670
3671 /// Read `peer` until its EOF, retrying a nonblocking read for up to about
3672 /// one second. `None` when no EOF arrived in that time.
3673 fn read_to_eof(peer: &mut std::net::TcpStream) -> Option<Vec<u8>> {
3674 let mut received = Vec::new();
3675 let mut buf = [0u8; 4096];
3676 for _ in 0..1000 {
3677 match std::io::Read::read(peer, &mut buf) {
3678 Ok(0) => return Some(received),
3679 Ok(size) => received.extend_from_slice(&buf[..size]),
3680 Err(e) if e.kind() == std::io::ErrorKind::WouldBlock => {
3681 std::thread::sleep(Duration::from_millis(1));
3682 }
3683 Err(_) => return None,
3684 }
3685 }
3686 None
3687 }
3688
3689 /// A frontend connection lingering over a live loopback socket, and the
3690 /// client end of that socket.
3691 fn lingering_frontend(
3692 deadline: Instant,
3693 ) -> (ConnectionH1<SessionTcpStream>, std::net::TcpStream) {
3694 let (front_socket, front_peer) = connected_socket();
3695 let ulid = Ulid::generate();
3696 let mut server = h1_of(Connection::new_h1_server(
3697 ulid,
3698 SessionTcpStream::new(front_socket, ulid, None),
3699 Duration::from_secs(10),
3700 ));
3701 server.linger = Linger::Pending { deadline };
3702 assert!(
3703 matches!(
3704 server.defer_close_for_tls_flush("test"),
3705 MuxResult::Continue
3706 ),
3707 "a pending linger starts instead of closing"
3708 );
3709 (server, front_peer)
3710 }
3711
3712 /// Drive `readable` until it closes the session or reads everything
3713 /// queued. Returns the last result.
3714 fn drain_passes<L: ListenerHandler + L7ListenerHandler>(
3715 server: &mut ConnectionH1<SessionTcpStream>,
3716 context: &mut Context<L>,
3717 router: &mut Router,
3718 ) -> MuxResult {
3719 let mut result = MuxResult::Continue;
3720 for _ in 0..100 {
3721 server.readiness.event.insert(Ready::READABLE);
3722 result = server.readable(context, EndpointClient(router));
3723 if matches!(result, MuxResult::CloseSession) {
3724 break;
3725 }
3726 std::thread::sleep(Duration::from_millis(1));
3727 }
3728 result
3729 }
3730
3731 /// RFC 9112 §9.6 lingering close: the write side is shut down first, the
3732 /// rest of the request is read and dropped without pushing the deadline
3733 /// out, and the drain ends on the client's EOF.
3734 ///
3735 /// TO SEE THIS RED: in `ConnectionH1::readable`, move the
3736 /// `if self.is_lingering()` early return after `self.arm_timeout(...)`:
3737 /// the deadline moves with each read.
3738 #[test]
3739 fn a_lingering_close_half_closes_then_drains_to_the_client_eof() {
3740 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3741 let mut context = test_context(&pool);
3742 context
3743 .create_stream(Ulid::generate(), 1 << 16)
3744 .expect("the test pool must hand out stream buffers");
3745 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3746 let deadline = Instant::now() + Duration::from_secs(10);
3747 let (mut server, mut front_peer) = lingering_frontend(deadline);
3748
3749 assert!(server.is_lingering(), "the connection drains");
3750 assert_eq!(
3751 server.poll_timeout(),
3752 Some(deadline),
3753 "the drain is bounded"
3754 );
3755 assert!(
3756 !server.readiness.interest.is_writable(),
3757 "nothing is written while lingering"
3758 );
3759 assert_eq!(
3760 read_to_eof(&mut front_peer),
3761 Some(Vec::new()),
3762 "the client sees the FIN while it may still send"
3763 );
3764
3765 // The client keeps sending: sozu drops it, and the deadline stays.
3766 front_peer
3767 .write_all(&vec![b'y'; 100 * 1024])
3768 .expect("the client may still send after the FIN");
3769 context.now = Instant::now();
3770 let result = drain_passes(&mut server, &mut context, &mut router);
3771 assert!(
3772 matches!(result, MuxResult::Continue),
3773 "the drain waits for more, got {result:?}"
3774 );
3775 match server.linger {
3776 Linger::Draining { remaining, .. } => assert_eq!(
3777 remaining,
3778 LINGER_MAX_BYTES - 100 * 1024,
3779 "every byte sent is drained and counted"
3780 ),
3781 other => panic!("the connection must still drain, got {other:?}"),
3782 }
3783 assert_eq!(
3784 server.poll_timeout(),
3785 Some(deadline),
3786 "a drained read never pushes the deadline out"
3787 );
3788
3789 drop(front_peer);
3790 let result = drain_passes(&mut server, &mut context, &mut router);
3791 assert!(
3792 matches!(result, MuxResult::CloseSession),
3793 "the client's EOF ends the drain, got {result:?}"
3794 );
3795 }
3796
3797 /// The drain is bounded in bytes and in time: past either bound the
3798 /// session closes although the client is still sending.
3799 ///
3800 /// TO SEE THIS RED: in `ConnectionH1::drain_linger`, read `buf.len()`
3801 /// bytes instead of `remaining.min(buf.len())` (the budget case reads
3802 /// past its budget), or delete the `now >= deadline` check (the deadline
3803 /// case keeps draining).
3804 #[test]
3805 fn a_lingering_close_stops_at_its_byte_budget_and_its_deadline() {
3806 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3807 let mut context = test_context(&pool);
3808 context
3809 .create_stream(Ulid::generate(), 1 << 16)
3810 .expect("the test pool must hand out stream buffers");
3811 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3812
3813 // Byte budget: the client sends more than is left of it.
3814 let deadline = Instant::now() + Duration::from_secs(10);
3815 let (mut server, mut front_peer) = lingering_frontend(deadline);
3816 server.linger = Linger::Draining {
3817 deadline,
3818 remaining: 1024,
3819 };
3820 front_peer
3821 .write_all(&[b'y'; 4096])
3822 .expect("the client may still send after the FIN");
3823 context.now = Instant::now();
3824 let result = drain_passes(&mut server, &mut context, &mut router);
3825 assert!(
3826 matches!(result, MuxResult::CloseSession),
3827 "past its byte budget the drain closes, got {result:?}"
3828 );
3829 assert_eq!(
3830 server.linger,
3831 Linger::Draining {
3832 deadline,
3833 remaining: 0
3834 },
3835 "the drain read exactly its budget"
3836 );
3837
3838 // Deadline: the client still sends when it passes.
3839 let (mut server, mut front_peer) = lingering_frontend(deadline);
3840 front_peer
3841 .write_all(&[b'y'; 4096])
3842 .expect("the client may still send after the FIN");
3843 context.now = deadline;
3844 server.readiness.event.insert(Ready::READABLE);
3845 let result = server.readable(&mut context, EndpointClient(&mut router));
3846 assert!(
3847 matches!(result, MuxResult::CloseSession),
3848 "past its deadline the drain closes, got {result:?}"
3849 );
3850 }
3851
3852 /// A header the parser refuses, after a well-formed request line: the
3853 /// access log must still name the method and the path.
3854 ///
3855 /// The authority is asserted ABSENT, on purpose. This request carries a
3856 /// `Host` line before the bad one, so a `Host` block exists here — but a
3857 /// client that puts the bad line first gets no `Host` block at all, so
3858 /// reading it would log an unvalidated value whenever the client chose
3859 /// to. Only an authority the request line itself carries is logged.
3860 ///
3861 /// To SEE THIS RED: in `Stream::generate_access_log`
3862 /// (`lib/src/protocol/mux/stream.rs`), replace the
3863 /// `rejected_request_line(&self.front)` call with
3864 /// `None::<RejectedRequestLine<'_>>`. The line then renders
3865 /// `- - - 400`.
3866 #[test]
3867 fn a_header_parse_error_keeps_the_method_and_path_in_the_access_log() {
3868 let output = access_log_of_a_rejected_h1_request(
3869 b"GET /diag?x=1 HTTP/1.1\r\nHost: example.com\r\nBad Header: x\r\n\r\n",
3870 );
3871
3872 assert!(
3873 output.contains("GET /diag?x=1 400"),
3874 "the access log of a request rejected on a header must carry its \
3875 method and path, got: {output}"
3876 );
3877 assert!(
3878 output.contains("- GET /diag?x=1 400"),
3879 "the authority of an origin-form request rejected on a header must \
3880 not be read from a `Host` line, got: {output}"
3881 );
3882 assert!(
3883 output.contains("H1::Complete"),
3884 "the 400 of a parse error is logged by `ConnectionH1::writable` once \
3885 the answer is written, not at session close, got: {output}"
3886 );
3887 }
3888
3889 /// Sōzu's own CL.TE guard in `HttpContext::on_request_headers`
3890 /// (`lib/src/protocol/kawa_h1/editor.rs`) rejects a request kawa parsed
3891 /// cleanly, and returns before the request line is captured. Here kawa's
3892 /// `process_headers` already resolved the authority and the path, so all
3893 /// three fields are logged.
3894 ///
3895 /// `identity` then `chunked` is the pair that reaches that guard: kawa
3896 /// combines it to a chunked-final coding and accepts it, and the guard
3897 /// refuses to forward two TE lines. A lone `Transfer-Encoding: gzip`
3898 /// would not — kawa refuses it itself, before resolving the authority.
3899 ///
3900 /// To SEE THIS RED: the same substitution as
3901 /// `a_header_parse_error_keeps_the_method_and_path_in_the_access_log`.
3902 #[test]
3903 fn a_cl_te_rejection_keeps_the_whole_request_line_in_the_access_log() {
3904 let output = access_log_of_a_rejected_h1_request(
3905 b"POST /upload HTTP/1.1\r\nHost: example.com\r\n\
3906 Transfer-Encoding: identity\r\nTransfer-Encoding: chunked\r\n\r\n",
3907 );
3908
3909 assert!(
3910 output.contains("example.com POST /upload 400"),
3911 "the access log of a request rejected by the CL.TE guard must carry \
3912 its authority, method and path, got: {output}"
3913 );
3914 }
3915
3916 /// The one authority a header rejection may log: the one the request
3917 /// line itself carries. An absolute-form target names it, so it is
3918 /// logged, split from the path the way kawa splits it.
3919 ///
3920 /// To SEE THIS RED: the same substitution as
3921 /// `a_header_parse_error_keeps_the_method_and_path_in_the_access_log`.
3922 #[test]
3923 fn a_header_parse_error_logs_the_authority_an_absolute_form_carries() {
3924 let output = access_log_of_a_rejected_h1_request(
3925 b"GET http://example.com:8080/abs HTTP/1.1\r\nBad Header: x\r\n\r\n",
3926 );
3927
3928 assert!(
3929 output.contains("example.com:8080 GET /abs 400"),
3930 "the access log of an absolute-form request rejected on a header \
3931 must carry the authority of its request-target, got: {output}"
3932 );
3933 }
3934
3935 // ── A warm H1 write pass allocates nothing ───────────────────────────
3936 //
3937 // DO NOT READ THESE TESTS AS COVERING H2. `H2Shell::write_streams`
3938 // (`lib/src/protocol/mux/h2.rs`) is a separate write path with its own
3939 // allocation test.
3940
3941 /// `Store` blocks each measured pass queues. A fresh `Vec<IoSlice>`
3942 /// reserves four descriptors on its first push, so a pass over more than
3943 /// four blocks also exercises the growth a per-pass vector would pay.
3944 /// One H1 header block is already dozens of them: the `BlockConverter`
3945 /// emits every name, separator, value and CRLF as its own `Store`.
3946 const WARM_PASS_BLOCKS: usize = 16;
3947
3948 /// Queue [`WARM_PASS_BLOCKS`] blocks on `kawa`, drive two write passes
3949 /// through `write`, and return the heap allocations each one made.
3950 ///
3951 /// The first pass is the cold one of a fresh connection and may grow
3952 /// whatever the connection keeps; the second queues the same blocks again
3953 /// and is the warm measurement.
3954 /// Both go to a live loopback peer, so the write is a real `writev(2)`.
3955 /// The blocks are `Store::Static`, so queueing them touches no storage
3956 /// and the kawa never terminates: the pass stops after the write, before
3957 /// the completion arm and its access log, which is not the hot path.
3958 fn allocations_of_two_write_passes(
3959 context: &mut Context<crate::protocol::mux::test_support::TestListener>,
3960 outgoing: fn(
3961 &mut crate::protocol::mux::Stream,
3962 ) -> &mut crate::protocol::mux::GenericHttpStream,
3963 mut write: impl FnMut(&mut Context<crate::protocol::mux::test_support::TestListener>),
3964 ) -> [usize; 2] {
3965 let mut measured = [0; 2];
3966 for (pass, slot) in measured.iter_mut().enumerate() {
3967 let kawa = outgoing(&mut context.streams[0]);
3968 for _ in 0..WARM_PASS_BLOCKS {
3969 kawa.out
3970 .push_back(kawa::OutBlock::Store(kawa::Store::Static(
3971 b"x-warm: pass\r\n",
3972 )));
3973 }
3974 let before = crate::test_allocations::allocations();
3975 write(context);
3976 let allocations = crate::test_allocations::allocations() - before;
3977 assert!(
3978 outgoing(&mut context.streams[0]).out.is_empty(),
3979 "premise: write pass {pass} must drain every queued block, or \
3980 the measured pass would start from a different state"
3981 );
3982 *slot = allocations;
3983 }
3984 measured
3985 }
3986
3987 /// The frontend side: a `Position::Server` pass writing the response.
3988 ///
3989 /// TO SEE THIS RED: in `ConnectionH1::writable`, declare
3990 /// `let mut io_slices: Vec<IoSlice<'static>> = Vec::new();` above the
3991 /// `gather` call and hand that local to `gather`, the emptiness checks,
3992 /// the write, the replay capture and `confirm` in place of
3993 /// `self.io_slices`. Measured with 16 blocks: `left: 3, right: 0` under
3994 /// both `cargo test` and `cargo test --release` — one allocation and two
3995 /// `realloc`s per pass, as the per-pass vector grows 4 → 8 → 16.
3996 #[test]
3997 fn a_warm_h1_response_write_pass_allocates_nothing() {
3998 let mut fixture = linked_backend_connection();
3999 let BackendReadFixture {
4000 context, frontend, ..
4001 } = &mut fixture;
4002 let Connection::H1(server) = frontend else {
4003 unreachable!("new_h1_server builds an H1 connection");
4004 };
4005 server.stream = Some(0);
4006 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4007
4008 let [_, warm] = allocations_of_two_write_passes(
4009 context,
4010 |stream| &mut stream.back,
4011 |context| {
4012 server.readiness.event.insert(Ready::WRITABLE);
4013 server.writable(context, EndpointClient(&mut router));
4014 },
4015 );
4016
4017 assert_eq!(warm, 0, "a warm H1 response write pass must not allocate");
4018 }
4019
4020 /// The backend side: a `Position::Client` pass writing the request.
4021 ///
4022 /// The fixture's connection was dialled fresh, not taken from the
4023 /// keep-alive pool, so the replay capture stays off: its `reserve` is the
4024 /// one allocation a pooled upstream is documented to pay, and it is not
4025 /// what this pins.
4026 ///
4027 /// TO SEE THIS RED: the same substitution as
4028 /// `a_warm_h1_response_write_pass_allocates_nothing`.
4029 #[test]
4030 fn a_warm_h1_request_write_pass_allocates_nothing() {
4031 let mut fixture = linked_backend_connection();
4032 let BackendReadFixture {
4033 context,
4034 frontend,
4035 client,
4036 ..
4037 } = &mut fixture;
4038 assert!(
4039 !client.reused_from_pool,
4040 "premise: a freshly dialled upstream does not capture for replay"
4041 );
4042
4043 let [_, warm] = allocations_of_two_write_passes(
4044 context,
4045 |stream| &mut stream.front,
4046 |context| {
4047 client.readiness.event.insert(Ready::WRITABLE);
4048 client.writable(context, EndpointServer(frontend));
4049 },
4050 );
4051
4052 assert_eq!(warm, 0, "a warm H1 request write pass must not allocate");
4053 }
4054
4055 /// #1610: an H1 frontend sizes its session's link queue for the one
4056 /// request it has in flight, not the four a first `push_back` reserves.
4057 ///
4058 /// Measured against a control whose queue already holds room for one
4059 /// link, so the difference is the queue's own allocation and nothing else
4060 /// the parse allocates.
4061 ///
4062 /// TO SEE THIS RED: drop the `reserve_exact(1)` before the
4063 /// `context.pending_links.push_back(stream_id)` that queues a parsed
4064 /// request in `ConnectionH1::readable`. The queue then allocates four
4065 /// slots.
4066 #[test]
4067 fn a_parsed_h1_request_queues_its_link_in_a_queue_sized_for_one() {
4068 use crate::test_allocations::bytes;
4069
4070 let parse = |presized: bool| {
4071 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
4072 let mut context = test_context(&pool);
4073 context
4074 .create_stream(Ulid::generate(), 1 << 16)
4075 .expect("the test pool must hand out stream buffers");
4076 if presized {
4077 context.pending_links.reserve_exact(1);
4078 }
4079 let (front_socket, mut front_peer) = connected_socket();
4080 let mut server = h1_of(Connection::new_h1_server(
4081 Ulid::generate(),
4082 front_socket,
4083 Duration::from_secs(60),
4084 ));
4085 server.stream = Some(0);
4086 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4087 front_peer
4088 .write_all(b"GET / HTTP/1.1\r\nHost: example.com\r\n\r\n")
4089 .expect("the loopback peer must accept the staged request bytes");
4090
4091 let before = bytes();
4092 for _ in 0..64 {
4093 server.readiness.event.insert(Ready::READABLE);
4094 server.readable(&mut context, EndpointClient(&mut router));
4095 if !context.pending_links.is_empty() {
4096 break;
4097 }
4098 }
4099 let parsed = bytes() - before;
4100 assert_eq!(
4101 context.pending_links,
4102 [0],
4103 "premise: the parsed request must be queued for linking"
4104 );
4105 parsed
4106 };
4107
4108 // The thread's first parse also initialises state that outlives the
4109 // session; run one before measuring.
4110 let _ = parse(true);
4111 assert_eq!(
4112 parse(false) - parse(true),
4113 std::mem::size_of::<GlobalStreamId>(),
4114 "an H1 frontend must queue its link in a queue sized for one"
4115 );
4116 }
4117
4118 /// #1610: the first write pass of a fresh connection sizes its descriptor
4119 /// vector in ONE allocation, on both sides.
4120 ///
4121 /// Measured against a control that is the same pass on a connection whose
4122 /// `io_slices` already holds [`WARM_PASS_BLOCKS`] descriptors, so the
4123 /// difference is the vector's own cost and nothing else the first pass
4124 /// sets up (which differs between debug and release builds).
4125 ///
4126 /// TO SEE THIS RED: drop the `io_slices.reserve(kawa.out.len())` in
4127 /// `h2_transmit::gather`. The fresh vector then doubles 4 → 8 → 16 over the
4128 /// [`WARM_PASS_BLOCKS`] blocks: three allocations per side.
4129 #[test]
4130 fn a_cold_h1_write_pass_sizes_its_descriptor_vector_once() {
4131 let response = |presized: bool| {
4132 let mut fixture = linked_backend_connection();
4133 let BackendReadFixture {
4134 context, frontend, ..
4135 } = &mut fixture;
4136 let Connection::H1(server) = frontend else {
4137 unreachable!("new_h1_server builds an H1 connection");
4138 };
4139 if presized {
4140 server.io_slices.reserve(WARM_PASS_BLOCKS);
4141 }
4142 server.stream = Some(0);
4143 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4144 allocations_of_two_write_passes(
4145 context,
4146 |stream| &mut stream.back,
4147 |context| {
4148 server.readiness.event.insert(Ready::WRITABLE);
4149 server.writable(context, EndpointClient(&mut router));
4150 },
4151 )[0]
4152 };
4153 let request = |presized: bool| {
4154 let mut fixture = linked_backend_connection();
4155 let BackendReadFixture {
4156 context,
4157 frontend,
4158 client,
4159 ..
4160 } = &mut fixture;
4161 if presized {
4162 client.io_slices.reserve(WARM_PASS_BLOCKS);
4163 }
4164 allocations_of_two_write_passes(
4165 context,
4166 |stream| &mut stream.front,
4167 |context| {
4168 client.readiness.event.insert(Ready::WRITABLE);
4169 client.writable(context, EndpointServer(frontend));
4170 },
4171 )[0]
4172 };
4173
4174 // The thread's first pass also initialises state that outlives the
4175 // connection; run one of each before measuring.
4176 let _ = (response(true), request(true));
4177 assert_eq!(
4178 response(false) - response(true),
4179 1,
4180 "a fresh H1 frontend must size its descriptor vector in one allocation"
4181 );
4182 assert_eq!(
4183 request(false) - request(true),
4184 1,
4185 "a fresh H1 backend must size its descriptor vector in one allocation"
4186 );
4187 }
4188
4189 /// What kawa's H1 serializer writes for a `kind` message framed by
4190 /// `Content-Length: 5`, holding `hello`, after `pkawa::handle_trailer`
4191 /// queued an H2 trailer block of `fields` and the H1 write path ran
4192 /// `drop_length_framed_trailers`, which returns whether it dropped one.
4193 fn h1_bytes_of_a_length_framed_message(
4194 kind: kawa::Kind,
4195 fields: &[(&[u8], &[u8])],
4196 ) -> (bool, String) {
4197 let mut pool = Pool::with_capacity(1, 1, 4096);
4198 let checkout = pool
4199 .checkout()
4200 .expect("the test pool must hand out a buffer");
4201 let mut kawa: super::super::GenericHttpStream =
4202 kawa::Kawa::new(kind, kawa::Buffer::new(checkout));
4203 kawa.body_size = kawa::BodySize::Length(5);
4204 // One DATA frame, as `handle_data` queues it for a length-framed
4205 // message.
4206 kawa.push_block(kawa::Block::Chunk(kawa::Chunk {
4207 data: kawa::Store::Static(b"hello"),
4208 }));
4209 let mut encoder = super::super::hpack::Encoder::new();
4210 let mut encoded = Vec::new();
4211 for &(name, value) in fields {
4212 encoder.encode_header_into((name, value), &mut encoded);
4213 }
4214 let result = super::super::pkawa::handle_trailer(
4215 &mut kawa,
4216 &encoded,
4217 true,
4218 &mut super::super::hpack::Decoder::new(),
4219 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4220 u32::MAX,
4221 false,
4222 &mut Vec::new(),
4223 );
4224 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4225
4226 let dropped = ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa);
4227 kawa.prepare(&mut kawa::h1::BlockConverter);
4228 let buffer = kawa.storage.buffer();
4229 let bytes: Vec<u8> = kawa
4230 .out
4231 .iter()
4232 .flat_map(|block| match block {
4233 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4234 kawa::OutBlock::Delimiter => Vec::new(),
4235 })
4236 .collect();
4237 (dropped, String::from_utf8_lossy(&bytes).into_owned())
4238 }
4239
4240 /// An H2 trailer block on a Content-Length-framed message adds nothing
4241 /// after the body on HTTP/1.1, which carries trailers only with chunked
4242 /// coding (RFC 9112 §6.3, §7.1): the fields and the empty line are
4243 /// dropped, for a request towards an H1 backend and for a response
4244 /// towards an H1 client, with one trailer field or none.
4245 ///
4246 /// TO SEE THIS RED: make `drop_length_framed_trailers` return `false`
4247 /// before touching the block queue.
4248 #[test]
4249 fn a_length_framed_message_writes_no_trailer_to_an_h1_peer() {
4250 let with_field: &[(&[u8], &[u8])] = &[(b"grpc-status", b"0")];
4251 for kind in [kawa::Kind::Request, kawa::Kind::Response] {
4252 for fields in [with_field, &[]] {
4253 assert_eq!(
4254 h1_bytes_of_a_length_framed_message(kind, fields),
4255 (true, "hello".to_owned()),
4256 "{kind:?} with {} trailer field(s)",
4257 fields.len()
4258 );
4259 }
4260 }
4261 }
4262
4263 /// What `ConnectionH1::writable` writes to an H1 client for a response
4264 /// from an H2 backend whose header section `head` arrived without
4265 /// END_STREAM, ended by a trailer HEADERS block of `trailer` fields when
4266 /// `trailer` is `Some`, or by an empty DATA frame with END_STREAM
4267 /// otherwise. `body_size`, when `Some`, overrides the framing
4268 /// `pkawa::handle_header` resolved. Returns the resolved framing and the
4269 /// bytes, written in one pass like a backend that sent the whole
4270 /// response before the client side became writable.
4271 fn h1_bytes_of_a_bodiless_response(
4272 head: &[(&[u8], &[u8])],
4273 body_size: Option<kawa::BodySize>,
4274 trailer: Option<&[(&[u8], &[u8])]>,
4275 ) -> (kawa::BodySize, String) {
4276 struct NoCallbacks;
4277 impl kawa::h1::ParserCallbacks<crate::pool::Checkout> for NoCallbacks {
4278 fn on_headers(&mut self, _kawa: &mut super::super::GenericHttpStream) {}
4279 }
4280 let mut pool = Pool::with_capacity(1, 1, 4096);
4281 let checkout = pool
4282 .checkout()
4283 .expect("the test pool must hand out a buffer");
4284 let mut kawa: super::super::GenericHttpStream =
4285 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4286 let mut decoder = super::super::hpack::Decoder::new();
4287 let mut encoder = super::super::hpack::Encoder::new();
4288 let mut encoded = Vec::new();
4289 for &(name, value) in head {
4290 encoder.encode_header_into((name, value), &mut encoded);
4291 }
4292 let (_, result) = super::super::pkawa::handle_header(
4293 &mut decoder,
4294 &mut crate::protocol::mux::h2_scheduler::Prioriser::default(),
4295 1,
4296 &mut kawa,
4297 &encoded,
4298 false,
4299 &mut NoCallbacks,
4300 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4301 u32::MAX,
4302 false,
4303 );
4304 assert!(result.is_ok(), "handle_header failed: {:?}", result.err());
4305 if let Some(body_size) = body_size {
4306 kawa.body_size = body_size;
4307 }
4308 match trailer {
4309 Some(fields) => {
4310 let mut encoded = Vec::new();
4311 for &(name, value) in fields {
4312 encoder.encode_header_into((name, value), &mut encoded);
4313 }
4314 let result = super::super::pkawa::handle_trailer(
4315 &mut kawa,
4316 &encoded,
4317 true,
4318 &mut decoder,
4319 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4320 u32::MAX,
4321 false,
4322 &mut Vec::new(),
4323 );
4324 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4325 }
4326 // The blocks `handle_data_frame` queues for an empty DATA frame
4327 // with END_STREAM.
4328 None => {
4329 kawa.push_block(kawa::Block::Chunk(kawa::Chunk {
4330 data: kawa::Store::Static(b""),
4331 }));
4332 let end_chunk = kawa.is_streaming();
4333 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4334 end_body: true,
4335 end_chunk,
4336 end_header: false,
4337 end_stream: true,
4338 }));
4339 }
4340 }
4341 let body_size = kawa.body_size;
4342
4343 ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa);
4344 ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa);
4345 kawa.prepare(&mut kawa::h1::BlockConverter);
4346 let buffer = kawa.storage.buffer();
4347 let bytes: Vec<u8> = kawa
4348 .out
4349 .iter()
4350 .flat_map(|block| match block {
4351 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4352 kawa::OutBlock::Delimiter => Vec::new(),
4353 })
4354 .collect();
4355 (body_size, String::from_utf8_lossy(&bytes).into_owned())
4356 }
4357
4358 /// A response to HEAD, a 204 or a 304 ends with its header section on
4359 /// HTTP/1.1 (RFC 9112 §6.3 rule 1): whatever its framing, nothing
4360 /// follows the head towards an H1 client, neither a last chunk nor a
4361 /// trailer section (RFC 9110 §6.5.1), so the next response on a
4362 /// keep-alive connection starts right after it. Covers chunked framing,
4363 /// `Content-Length` framing and `BodySize::Empty`, each ended by a
4364 /// trailer block with one field or none, or by an empty DATA frame. A
4365 /// `:status 200` stands for the response to a HEAD: with no callbacks,
4366 /// `pkawa::handle_header` does not know the method and frames it chunked,
4367 /// with `Transfer-Encoding`, while it gives a 204 or a 304 no framing and
4368 /// removes a 204's `content-length` (RFC 9110 §8.6).
4369 ///
4370 /// TO SEE THIS RED: make `drop_bodiless_response_framing` return `false`
4371 /// before touching the block queue.
4372 #[test]
4373 fn a_bodiless_response_writes_nothing_after_its_head_to_an_h1_client() {
4374 let with_field: &[(&[u8], &[u8])] = &[(b"grpc-status", b"0")];
4375 for status in [&b"204"[..], b"304", b"200"] {
4376 let status_line = String::from_utf8_lossy(status);
4377 let (unframed_size, unframed) = if status == b"200" {
4378 (kawa::BodySize::Chunked, "Transfer-Encoding: chunked\r\n")
4379 } else {
4380 (kawa::BodySize::Empty, "")
4381 };
4382 let length_framed = |length: usize, field: &'static str| {
4383 if status == b"204" {
4384 (kawa::BodySize::Empty, "")
4385 } else {
4386 (kawa::BodySize::Length(length), field)
4387 }
4388 };
4389 let (zero_size, zero) = length_framed(0, "content-length: 0\r\n");
4390 let (five_size, five) = length_framed(5, "content-length: 5\r\n");
4391 for (content_length, body_size, expected_size, framing) in [
4392 (None, None, unframed_size, unframed),
4393 (
4394 None,
4395 Some(kawa::BodySize::Chunked),
4396 kawa::BodySize::Chunked,
4397 unframed,
4398 ),
4399 (Some(&b"0"[..]), None, zero_size, zero),
4400 (Some(b"5"), None, five_size, five),
4401 (
4402 None,
4403 Some(kawa::BodySize::Empty),
4404 kawa::BodySize::Empty,
4405 unframed,
4406 ),
4407 ] {
4408 let mut head: Vec<(&[u8], &[u8])> = vec![(b":status", status)];
4409 if let Some(length) = content_length {
4410 head.push((b"content-length", length));
4411 }
4412 let expected = format!("HTTP/1.1 {status_line} FromH2\r\n{framing}\r\n");
4413 for trailer in [Some(with_field), Some(&[][..]), None] {
4414 assert_eq!(
4415 h1_bytes_of_a_bodiless_response(&head, body_size, trailer),
4416 (expected_size, expected.clone()),
4417 "{status_line} {expected_size:?} ended by {trailer:?}"
4418 );
4419 }
4420 }
4421 }
4422 }
4423
4424 /// The trailer block of a bodiless response queued alone, its header
4425 /// section written in an earlier pass, is dropped whole and counted;
4426 /// a queue with no trailer block reports none.
4427 #[test]
4428 fn a_bodiless_response_trailer_block_queued_after_its_head_is_dropped() {
4429 let mut pool = Pool::with_capacity(1, 1, 4096);
4430 let checkout = pool
4431 .checkout()
4432 .expect("the test pool must hand out a buffer");
4433 let mut kawa: super::super::GenericHttpStream =
4434 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4435 kawa.body_size = kawa::BodySize::Chunked;
4436 let mut encoded = Vec::new();
4437 super::super::hpack::Encoder::new()
4438 .encode_header_into((b"grpc-status", b"0"), &mut encoded);
4439 let result = super::super::pkawa::handle_trailer(
4440 &mut kawa,
4441 &encoded,
4442 true,
4443 &mut super::super::hpack::Decoder::new(),
4444 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4445 u32::MAX,
4446 false,
4447 &mut Vec::new(),
4448 );
4449 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4450 assert!(ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa));
4451 assert!(
4452 !kawa
4453 .blocks
4454 .iter()
4455 .any(|block| matches!(block, kawa::Block::Header(_))),
4456 "the trailer fields are removed"
4457 );
4458 kawa.prepare(&mut kawa::h1::BlockConverter);
4459 assert!(kawa.out.is_empty(), "nothing is written after the head");
4460 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa));
4461 }
4462
4463 /// What kawa's H1 serializer writes to an H1 client for the header
4464 /// section `head` of an H2 backend response that arrived without
4465 /// END_STREAM, to a `method` request, and whether the response was then
4466 /// complete (`ParsingPhase::Terminated`).
4467 fn h1_head_of_an_h2_response(
4468 method: crate::protocol::kawa_h1::parser::Method,
4469 head: &[(&[u8], &[u8])],
4470 ) -> (String, bool) {
4471 let mut pool = Pool::with_capacity(1, 1, 4096);
4472 let checkout = pool
4473 .checkout()
4474 .expect("the test pool must hand out a buffer");
4475 let mut kawa: super::super::GenericHttpStream =
4476 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4477 let mut context = test_http_context(Ulid::generate());
4478 context.method = Some(method);
4479 let mut encoded = Vec::new();
4480 let mut encoder = super::super::hpack::Encoder::new();
4481 for &(name, value) in head {
4482 encoder.encode_header_into((name, value), &mut encoded);
4483 }
4484 let (_, result) = super::super::pkawa::handle_header(
4485 &mut super::super::hpack::Decoder::new(),
4486 &mut crate::protocol::mux::h2_scheduler::Prioriser::default(),
4487 1,
4488 &mut kawa,
4489 &encoded,
4490 false,
4491 &mut context,
4492 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4493 u32::MAX,
4494 false,
4495 );
4496 assert!(result.is_ok(), "handle_header failed: {:?}", result.err());
4497 let terminated = kawa.is_terminated();
4498 kawa.prepare(&mut kawa::h1::BlockConverter);
4499 let buffer = kawa.storage.buffer();
4500 let bytes: Vec<u8> = kawa
4501 .out
4502 .iter()
4503 .flat_map(|block| match block {
4504 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4505 kawa::OutBlock::Delimiter => Vec::new(),
4506 })
4507 .collect();
4508 (String::from_utf8_lossy(&bytes).into_owned(), terminated)
4509 }
4510
4511 /// An H2 response whose header section arrives without END_STREAM gains
4512 /// no `Transfer-Encoding` towards an H1 client when it has no content by
4513 /// definition (RFC 9110 §6.4.1): a 1xx or a 204 (RFC 9112 §6.1 MUST NOT),
4514 /// a 304 or a response to HEAD. A 1xx or a 204 also loses the
4515 /// `content-length` the backend sent, which a server MUST NOT send in
4516 /// them (RFC 9110 §8.6), while a 304 or a response to HEAD keeps it. A
4517 /// 1xx is complete at its head (`ParsingPhase::Terminated`), the final
4518 /// response following on the same stream; any other response waits for
4519 /// the END_STREAM of its stream (RFC 9113 §8.1). A `200` to GET still
4520 /// gains chunked framing.
4521 ///
4522 /// TO SEE THIS RED: drop the `no_content` guard of the chunked upgrade in
4523 /// `pkawa::handle_header`, or its removal of a 1xx or 204
4524 /// `content-length`.
4525 #[test]
4526 fn a_bodiless_h2_response_gains_no_transfer_encoding_towards_an_h1_client() {
4527 use crate::protocol::kawa_h1::parser::Method;
4528 /// The header fields of a response, `:status` first.
4529 type Head = &'static [(&'static [u8], &'static [u8])];
4530 let cases: [(Method, Head, &str, bool); 10] = [
4531 (
4532 Method::Get,
4533 &[(b":status", b"204")],
4534 "HTTP/1.1 204 FromH2\r\n",
4535 false,
4536 ),
4537 (
4538 Method::Get,
4539 &[(b":status", b"204"), (b"content-length", b"0")],
4540 "HTTP/1.1 204 FromH2\r\n",
4541 false,
4542 ),
4543 (
4544 Method::Get,
4545 &[(b":status", b"304")],
4546 "HTTP/1.1 304 FromH2\r\n",
4547 false,
4548 ),
4549 (
4550 Method::Get,
4551 &[(b":status", b"304"), (b"content-length", b"5")],
4552 "HTTP/1.1 304 FromH2\r\ncontent-length: 5\r\n",
4553 false,
4554 ),
4555 (
4556 Method::Get,
4557 &[(b":status", b"103"), (b"link", b"</a.css>")],
4558 "HTTP/1.1 103 FromH2\r\nlink: </a.css>\r\n",
4559 true,
4560 ),
4561 (
4562 Method::Get,
4563 &[
4564 (b":status", b"103"),
4565 (b"content-length", b"5"),
4566 (b"link", b"</a.css>"),
4567 ],
4568 "HTTP/1.1 103 FromH2\r\nlink: </a.css>\r\n",
4569 true,
4570 ),
4571 (
4572 Method::Head,
4573 &[(b":status", b"200")],
4574 "HTTP/1.1 200 FromH2\r\n",
4575 false,
4576 ),
4577 (
4578 Method::Head,
4579 &[(b":status", b"200"), (b"content-length", b"5")],
4580 "HTTP/1.1 200 FromH2\r\ncontent-length: 5\r\n",
4581 false,
4582 ),
4583 (
4584 Method::Head,
4585 &[(b":status", b"200"), (b"content-length", b"0")],
4586 "HTTP/1.1 200 FromH2\r\ncontent-length: 0\r\n",
4587 false,
4588 ),
4589 (
4590 Method::Get,
4591 &[(b":status", b"200")],
4592 "HTTP/1.1 200 FromH2\r\nTransfer-Encoding: chunked\r\n",
4593 false,
4594 ),
4595 ];
4596 for (method, head, status_and_fields, terminated) in cases {
4597 let (bytes, complete) = h1_head_of_an_h2_response(method.clone(), head);
4598 let bytes = bytes
4599 .split("\r\n")
4600 .filter(|line| !line.starts_with("Sozu-Id: "))
4601 .collect::<Vec<_>>()
4602 .join("\r\n");
4603 assert_eq!(
4604 (bytes, complete),
4605 (format!("{status_and_fields}\r\n"), terminated),
4606 "{method:?} {head:?}"
4607 );
4608 }
4609 }
4610
4611 /// Which responses `response_has_no_body` treats as bodiless.
4612 #[test]
4613 fn a_response_has_no_body_for_head_204_and_304_only() {
4614 use crate::protocol::kawa_h1::parser::Method;
4615 let cases = [
4616 (Some(Method::Head), Some(200), true),
4617 (Some(Method::Get), Some(204), true),
4618 (Some(Method::Get), Some(304), true),
4619 (Some(Method::Get), Some(200), false),
4620 (Some(Method::Post), Some(205), false),
4621 (None, None, false),
4622 ];
4623 for (method, status, expected) in cases {
4624 let mut context = test_http_context(Ulid::generate());
4625 context.method = method.clone();
4626 context.status = status;
4627 assert_eq!(
4628 ConnectionH1::<mio::net::TcpStream>::response_has_no_body(&context),
4629 expected,
4630 "{method:?} {status:?}"
4631 );
4632 }
4633 }
4634
4635 /// The header section of a length-framed message closed with
4636 /// `end_stream` (a message with no body) is not a trailer block: it is
4637 /// written whole.
4638 #[test]
4639 fn a_length_framed_header_section_is_not_taken_for_trailers() {
4640 let mut pool = Pool::with_capacity(1, 1, 4096);
4641 let checkout = pool
4642 .checkout()
4643 .expect("the test pool must hand out a buffer");
4644 let mut kawa: super::super::GenericHttpStream =
4645 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4646 kawa.body_size = kawa::BodySize::Length(0);
4647 kawa.push_block(kawa::Block::StatusLine);
4648 kawa.push_block(kawa::Block::Header(kawa::Pair {
4649 key: kawa::Store::Static(b"Content-Length"),
4650 val: kawa::Store::Static(b"0"),
4651 }));
4652 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4653 end_body: false,
4654 end_chunk: false,
4655 end_header: true,
4656 end_stream: true,
4657 }));
4658 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4659 assert_eq!(kawa.blocks.len(), 3, "the header section stays whole");
4660 }
4661
4662 /// A `Cookies` block belongs to a header section: a length-framed
4663 /// request whose header section ends with its cookies and closes with
4664 /// `end_stream` is not a trailer block, and is written whole.
4665 ///
4666 /// TO SEE THIS RED: drop the `kawa::Block::Cookies` arm from the
4667 /// header-section guard of `drop_length_framed_trailers`.
4668 #[test]
4669 fn a_length_framed_header_section_ending_with_cookies_is_not_taken_for_trailers() {
4670 let mut pool = Pool::with_capacity(1, 1, 4096);
4671 let checkout = pool
4672 .checkout()
4673 .expect("the test pool must hand out a buffer");
4674 let mut kawa: super::super::GenericHttpStream =
4675 kawa::Kawa::new(kawa::Kind::Request, kawa::Buffer::new(checkout));
4676 kawa.body_size = kawa::BodySize::Length(0);
4677 kawa.push_block(kawa::Block::StatusLine);
4678 kawa.push_block(kawa::Block::Header(kawa::Pair {
4679 key: kawa::Store::Static(b"Content-Length"),
4680 val: kawa::Store::Static(b"0"),
4681 }));
4682 kawa.push_block(kawa::Block::Cookies);
4683 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4684 end_body: false,
4685 end_chunk: false,
4686 end_header: true,
4687 end_stream: true,
4688 }));
4689 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4690 assert_eq!(kawa.blocks.len(), 4, "the header section stays whole");
4691 assert!(
4692 matches!(
4693 kawa.blocks.back(),
4694 Some(kawa::Block::Flags(kawa::Flags {
4695 end_header: true,
4696 ..
4697 }))
4698 ),
4699 "the header section keeps its closing empty line"
4700 );
4701 }
4702
4703 /// A response to HEAD declares the length of the body it does not carry
4704 /// (RFC 9110 §9.3.2): its header section alone ends the message with
4705 /// `end_stream`, under a non-zero `Content-Length`. It is not a trailer
4706 /// block, and is written whole.
4707 ///
4708 /// TO SEE THIS RED: drop the `kawa::Block::StatusLine` arm from the
4709 /// header-section guard of `drop_length_framed_trailers`.
4710 #[test]
4711 fn a_header_only_head_response_is_not_taken_for_trailers() {
4712 let mut pool = Pool::with_capacity(1, 1, 4096);
4713 let checkout = pool
4714 .checkout()
4715 .expect("the test pool must hand out a buffer");
4716 let mut kawa: super::super::GenericHttpStream =
4717 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4718 kawa.body_size = kawa::BodySize::Length(5);
4719 kawa.push_block(kawa::Block::StatusLine);
4720 kawa.push_block(kawa::Block::Header(kawa::Pair {
4721 key: kawa::Store::Static(b"Content-Length"),
4722 val: kawa::Store::Static(b"5"),
4723 }));
4724 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4725 end_body: false,
4726 end_chunk: false,
4727 end_header: true,
4728 end_stream: true,
4729 }));
4730 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4731 assert_eq!(kawa.blocks.len(), 3, "the header section stays whole");
4732 assert!(
4733 matches!(
4734 kawa.blocks.back(),
4735 Some(kawa::Block::Flags(kawa::Flags {
4736 end_header: true,
4737 ..
4738 }))
4739 ),
4740 "the header section keeps its closing empty line"
4741 );
4742 }
4743
4744 /// `ConnectionH1::terminate_close_delimited` at a backend EOF: only a body
4745 /// with neither `Content-Length` nor chunked coding is delimited by the
4746 /// close (RFC 9112 §6.3 rule 8). A `Content-Length` body still missing
4747 /// bytes (rule 5) and a chunked body without its terminating zero chunk
4748 /// (§7.1) are truncated and end in the Error phase, which the H2
4749 /// converter turns into RST_STREAM and the H1 frontend into a close.
4750 ///
4751 /// Red on `d5161919`: the `Content-Length` case ended `Terminated`
4752 /// (sozu-proxy/sozu#1633).
4753 #[test]
4754 fn only_a_close_delimited_body_ends_cleanly_at_the_backend_eof() {
4755 let cases: [(&[u8], bool); 3] = [
4756 (b"HTTP/1.1 200 OK\r\nContent-Length: 10\r\n\r\nabcd", true),
4757 (
4758 b"HTTP/1.1 200 OK\r\nTransfer-Encoding: chunked\r\n\r\n4\r\nabcd\r\n",
4759 true,
4760 ),
4761 (b"HTTP/1.1 200 OK\r\n\r\nabcd", false),
4762 ];
4763 for (bytes, truncated) in cases {
4764 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
4765 let mut context = test_context(&pool);
4766 let id = context
4767 .create_stream(Ulid::generate(), 1 << 16)
4768 .expect("the test pool must hand out stream buffers");
4769 let kawa = &mut context.streams[id].back;
4770 kawa.storage.space()[..bytes.len()].copy_from_slice(bytes);
4771 kawa.storage.fill(bytes.len());
4772 kawa::h1::parse(kawa, &mut kawa::h1::NoCallbacks);
4773 assert!(
4774 kawa.is_main_phase() && !kawa.is_terminated(),
4775 "premise: {:?} is in its body phase",
4776 kawa.body_size
4777 );
4778 ConnectionH1::<mio::net::TcpStream>::terminate_close_delimited(kawa, id);
4779 if truncated {
4780 assert!(
4781 kawa.is_error(),
4782 "a truncated {:?} body must end in Error, got {:?}",
4783 kawa.body_size,
4784 kawa.parsing_phase
4785 );
4786 } else {
4787 assert!(
4788 kawa.is_terminated(),
4789 "a close-delimited body ends cleanly, got {:?}",
4790 kawa.parsing_phase
4791 );
4792 }
4793 }
4794 }
4795}