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 context.stream_bytes_out = context.stream_bytes_out.wrapping_add(size);
1163 let should_yield = update_readiness_after_write(size, status, &mut self.readiness);
1164 if let Some(result) = self.client_write_failed(status) {
1165 return result;
1166 }
1167 if self.socket.socket_wants_write() {
1168 // Only a write that answered `Continue` queues a synthetic
1169 // event. A socket that answered `WouldBlock` is full: the kernel
1170 // raises the next WRITABLE edge once the peer reads. Re-raising
1171 // it here while rustls still held the records the kernel refused
1172 // made `Mux::ready_inner` call this write again on every inner
1173 // iteration, each answering `WouldBlock`, until
1174 // `MAX_LOOP_ITERATIONS` counted `http.infinite_loop.error`
1175 // (sozu-proxy/sozu#1780). An `Error` or `Closed` write has nothing
1176 // to retry either: on the frontend `client_write_failed` closed the
1177 // session above; on a backend the hang-up that follows closes it.
1178 if status == SocketResult::Continue {
1179 self.readiness.signal_pending_write();
1180 // Pair the queued-write signal with the socket's own report: we
1181 // only synthesize a WRITABLE event when the socket still has bytes
1182 // buffered (edge-triggered epoll won't re-fire on its own).
1183 debug_assert!(
1184 self.readiness.event.is_writable(),
1185 "signal_pending_write must leave a WRITABLE event queued"
1186 );
1187 } else {
1188 debug_assert!(
1189 !self.readiness.event.is_writable(),
1190 "a write that did not answer Continue must leave WRITABLE to the next edge"
1191 );
1192 }
1193 return MuxResult::Continue;
1194 }
1195 if !tls_only_flush && should_yield {
1196 return MuxResult::Continue;
1197 }
1198
1199 if matches!(self.position, Position::Server) && kawa.is_error() && kawa.is_completed() {
1200 // The response failed after part of it may have left: a body the
1201 // backend truncated (`ConnectionH1::terminate_close_delimited`) or
1202 // a response `forcefully_terminate_answer` ended. H1 has no
1203 // RST_STREAM, and neither a default answer nor the next pipelined
1204 // response may follow those bytes on this connection, so close
1205 // it: the client sees a close before the end of the message, which
1206 // RFC 9112 §6.3 rule 5 makes the incomplete-message signal. Never
1207 // kept alive; `Mux::close` logs the stream as an error.
1208 debug_assert!(
1209 !kawa.is_terminated(),
1210 "an errored response must not also be terminated"
1211 );
1212 debug!(
1213 "{} H1 closing the frontend after an incomplete response on stream {}",
1214 log_context!(self),
1215 stream_id
1216 );
1217 return self.defer_close_for_tls_flush("incomplete-response");
1218 }
1219 if kawa.is_terminated() && kawa.is_completed() {
1220 match self.position {
1221 Position::Client(..) => self.readiness.interest.insert(Ready::READABLE),
1222 Position::Server => {
1223 if stream.context.closing {
1224 return self.defer_close_for_tls_flush("closing-context");
1225 }
1226 let kawa = &mut stream.back;
1227 match kawa.detached.status_line {
1228 kawa::StatusLine::Response { code: 101, .. } => {
1229 debug!("{} ============== HANDLE UPGRADE!", log_context!(self));
1230 stream.metrics.backend_stop();
1231 let client_rtt = self.rtt();
1232 let server_rtt =
1233 stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1234 for event in stream
1235 .generate_access_log(
1236 false,
1237 Some("H1::Upgrade"),
1238 context.listener.clone(),
1239 client_rtt,
1240 server_rtt,
1241 )
1242 .into_iter()
1243 .flatten()
1244 {
1245 crate::protocol::mux::h2::record_metric(event);
1246 }
1247 return MuxResult::Upgrade;
1248 }
1249 kawa::StatusLine::Response { code: 100, .. } => {
1250 debug!("{} ============== HANDLE CONTINUE!", log_context!(self));
1251 // After a 100 Continue, we expect the client to continue
1252 // with its request body. Do NOT call generate_access_log
1253 // here — the final response will emit the access log.
1254 // Calling it here would double-decrement http.active_requests.
1255 self.timeout_deadline = now.checked_add(self.timeout_duration);
1256 self.readiness.interest.insert(Ready::READABLE);
1257 kawa.clear();
1258 stream.metrics.backend_stop();
1259 if let StreamState::Linked(token) = stream.state {
1260 // The final response may already sit in the
1261 // backend buffer, read with the 100: no
1262 // socket event will announce it, so the read
1263 // is re-armed, not only its interest.
1264 let backend = endpoint.readiness_mut(token);
1265 backend.interest.insert(Ready::READABLE);
1266 backend.signal_pending_read();
1267 }
1268 return MuxResult::Continue;
1269 }
1270 // Every other 1xx (102 Processing, 103 Early Hints and
1271 // the unassigned 104-199) is interim too: RFC 9110
1272 // §15.2 has a client accept any number of them before
1273 // the final response, so the stream stays linked and
1274 // the backend stays out of the keep-alive pool until
1275 // that final response has been written.
1276 kawa::StatusLine::Response { code, .. } if (102..200).contains(&code) => {
1277 debug!(
1278 "{} ============== HANDLE INTERIM {}!",
1279 log_context!(self),
1280 code
1281 );
1282 // Do NOT call generate_access_log for an interim response.
1283 // The final response will emit the access log.
1284 // Calling it here would double-decrement http.active_requests.
1285 if let StreamState::Linked(token) = stream.state {
1286 // after an interim response, we expect the backend to send its final
1287 // response, which may already sit in the backend buffer, read with
1288 // the interim: no socket event will announce it, so the read is
1289 // re-armed, not only its interest.
1290 let backend = endpoint.readiness_mut(token);
1291 backend.interest.insert(Ready::READABLE);
1292 backend.signal_pending_read();
1293 kawa.clear();
1294 stream.metrics.backend_stop();
1295 return MuxResult::Continue;
1296 } else {
1297 stream.metrics.backend_stop();
1298 let client_rtt = self.rtt();
1299 let server_rtt =
1300 stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1301 for event in stream
1302 .generate_access_log(
1303 false,
1304 Some("H1::Interim"),
1305 context.listener.clone(),
1306 client_rtt,
1307 server_rtt,
1308 )
1309 .into_iter()
1310 .flatten()
1311 {
1312 crate::protocol::mux::h2::record_metric(event);
1313 }
1314 return self.defer_close_for_tls_flush("interim");
1315 }
1316 }
1317 _ => {}
1318 }
1319 incr!(names::http::E2E_HTTP11);
1320 stream.metrics.backend_stop();
1321 let client_rtt = self.rtt();
1322 let server_rtt = stream.linked_token().and_then(|t| endpoint.peer_rtt(t));
1323 for event in stream
1324 .generate_access_log(
1325 false,
1326 Some("H1::Complete"),
1327 context.listener.clone(),
1328 client_rtt,
1329 server_rtt,
1330 )
1331 .into_iter()
1332 .flatten()
1333 {
1334 crate::protocol::mux::h2::record_metric(event);
1335 }
1336 stream.metrics.reset();
1337 let old_state = std::mem::replace(&mut stream.state, StreamState::Unlinked);
1338 if let StreamState::Linked(token) = old_state {
1339 remove_backend_stream(&mut context.backend_streams, token, stream_id);
1340 }
1341 // The connection outlives the response only when neither
1342 // side asked to close it. `keep_alive_backend` is false
1343 // once the backend's response carried `Connection: close`,
1344 // or was a non-persistent HTTP/1.0 one that sozu forwards
1345 // as HTTP/1.1 with `Connection: close` added
1346 // (`HttpContext::on_response_headers`,
1347 // `lib/src/protocol/kawa_h1/editor.rs`): sozu forwards that
1348 // header, so RFC 9112 §9.6 requires it to close after this
1349 // response and to process no further request on it. It
1350 // is also the only way a close-delimited body ends here:
1351 // `ConnectionH1::terminate_close_delimited` runs only for
1352 // such a backend, and that body ends, for the client too,
1353 // only with the close (§6.3 rule 8). Keeping the
1354 // connection left the client waiting for more body until
1355 // the frontend timeout, and appended the next pipelined
1356 // response to the body (sozu-proxy/sozu#1642).
1357 //
1358 // The request must have been received whole as well: a
1359 // backend, or a default answer, may answer early (a 413 or
1360 // a 401 on an upload) while the client is still sending
1361 // the body. RFC 9112 §9.3 lets a connection carry another
1362 // message only once the previous one is complete, and the
1363 // rest of that body belongs to the answered request.
1364 // Resetting the parser here would read it as a new
1365 // request (sozu-proxy/sozu#1721), so the connection closes
1366 // instead. Whether the request was also fully written to
1367 // the backend decides only whether that backend may be
1368 // pooled: `ConnectionH1::end_stream` checks it, and a
1369 // default answer leaves a request it never forwarded.
1370 //
1371 // Pre: the decision is taken once, when the whole response
1372 // has left, never while part of it is still queued.
1373 debug_assert!(
1374 stream.back.is_terminated() && stream.back.is_completed(),
1375 "the keep-alive decision must follow a completely written response"
1376 );
1377 let request_complete = stream.front.is_terminated();
1378 let keep_alive = request_complete
1379 && stream.context.keep_alive_frontend
1380 && stream.context.keep_alive_backend;
1381 if keep_alive {
1382 self.timeout_deadline = now.checked_add(self.timeout_duration);
1383 if let StreamState::Linked(token) = old_state {
1384 endpoint.end_stream(token, stream_id, context);
1385 }
1386 self.readiness.interest.insert(Ready::READABLE);
1387 // The next request on this connection is a new
1388 // request: it gets its own id, minted from the same
1389 // per-session source as an H2 stream's.
1390 let request_id = context.next_request_id();
1391 let stream = &mut context.streams[stream_id];
1392 stream.context.reset(request_id);
1393 stream.back.clear();
1394 stream.back.storage.clear();
1395 stream.front.clear();
1396 // do not stream.front.storage.clear() because of H1 pipelining
1397 // The next request has not been encoded for any
1398 // backend yet (sozu-proxy/sozu#1632).
1399 stream.front_bound_to_backend = false;
1400 stream.attempts = 0;
1401 stream.tried_backends.clear();
1402 // The next request is a new H2 stream on an H2
1403 // backend connection, which reads these to refuse a
1404 // frame on a closed stream (RFC 9113 §5.1) and to
1405 // check `content-length` (§8.1.1): clear them as
1406 // `Context::create_stream` does for a recycled slot,
1407 // or the backend's response HEADERS is refused as
1408 // arriving after END_STREAM (sozu-proxy/sozu#1781).
1409 stream.front_received_end_of_stream = false;
1410 stream.back_received_end_of_stream = false;
1411 stream.front_data_received = 0;
1412 stream.back_data_received = 0;
1413 // The next pipelined request gets its own replay
1414 // decision: `start_stream` re-arms capture only if it
1415 // again picks a connection out of the keep-alive pool.
1416 stream.forget_upstream_replay();
1417 // Transition back to Idle so buffered pipelined requests
1418 // trigger a phase transition on the next readable() call.
1419 stream.state = StreamState::Idle;
1420 // Post: the keep-alive reset leaves a clean, closed slot
1421 // ready for the next pipelined request. `request_counted`
1422 // was already cleared by `generate_access_log` above, so
1423 // the slot carries no pending active-requests charge.
1424 debug_assert_eq!(
1425 stream.state,
1426 StreamState::Idle,
1427 "keep-alive reset must return the stream to Idle"
1428 );
1429 debug_assert_eq!(stream.attempts, 0, "keep-alive reset must zero attempts");
1430 debug_assert!(
1431 !stream.request_counted,
1432 "keep-alive reset must leave no counted request (active-requests leak)"
1433 );
1434 debug_assert!(
1435 stream.back.storage.is_empty(),
1436 "keep-alive reset must drain the response storage"
1437 );
1438 // HTTP/1.1 pipelining: if there's still data in the frontend
1439 // storage (pipelined requests already read from the socket),
1440 // parse it now. We can't rely on a new READABLE event because
1441 // the socket buffer may be empty — all requests were already
1442 // read into kawa storage in the first socket_read.
1443 if !stream.front.storage.is_empty() {
1444 let blocks_before_parse = stream.front.blocks.len();
1445 kawa::h1::parse(&mut stream.front, &mut stream.context);
1446 stream
1447 .context
1448 .filter_request_trailers(&mut stream.front, blocks_before_parse);
1449 let is_error = stream.front.is_error();
1450 let is_main = stream.front.is_main_phase();
1451 let malformed = is_main
1452 && (stream.context.method.is_none()
1453 || stream.context.authority.is_none()
1454 || stream.context.path.is_none());
1455 if is_error || malformed {
1456 let answers_rc = stream.answers.clone();
1457 let answers = answers_rc.borrow();
1458 set_default_answer(stream, &mut self.readiness, 400, &answers);
1459 } else if is_main {
1460 self.requests += 1;
1461 incr!(names::http::REQUESTS);
1462 gauge_add!(names::http::ACTIVE_REQUESTS, 1);
1463 stream.metrics.service_start();
1464 stream.request_counted = true;
1465 stream.state = StreamState::Link;
1466 context.pending_links.push_back(stream_id);
1467 }
1468 // else: incomplete parse, wait for more data via READABLE
1469 }
1470 } else {
1471 // Pair: at least one side asked for the close, or
1472 // the request was not received whole. A
1473 // pipelined request already buffered is dropped with
1474 // the connection, never answered on it; the client
1475 // retries it on a new connection (RFC 9112 §9.3.2).
1476 debug_assert!(
1477 !request_complete
1478 || !stream.context.keep_alive_frontend
1479 || !stream.context.keep_alive_backend,
1480 "the frontend closes only when one side asked to or the request is incomplete"
1481 );
1482 // A TLS close is deferred until `close_notify` is
1483 // flushed, and `writable` runs again: mark the stream
1484 // closing so that pass takes the `closing-context`
1485 // exit above, instead of completing the response a
1486 // second time (a second access log and counters) and
1487 // re-taking the keep-alive decision after
1488 // `close_notify`.
1489 stream.context.closing = true;
1490 // No byte of the request arrived (a 408 to a silent
1491 // client): nothing is in flight, the close cannot
1492 // reset anything away, so it does not linger.
1493 let request_started =
1494 !matches!(stream.front.parsing_phase, kawa::ParsingPhase::StatusLine)
1495 || !stream.front.storage.is_empty();
1496 if !request_complete && request_started {
1497 // The client may still be sending the request:
1498 // drain it once the response is flushed, so the
1499 // close does not reset the response away (RFC
1500 // 9112 §9.6). The backend is done with either way.
1501 self.linger = Linger::Pending {
1502 deadline: now + self.linger_timeout,
1503 };
1504 if let StreamState::Linked(token) = old_state {
1505 endpoint.end_stream(token, stream_id, context);
1506 }
1507 }
1508 let stream = &mut context.streams[stream_id];
1509 if stream.context.keep_alive_frontend && stream.context.keep_alive_backend {
1510 // Both sides wanted to keep it: only the
1511 // incomplete request closes it.
1512 debug_assert!(
1513 !request_complete,
1514 "with both sides keeping alive, only an incomplete request closes"
1515 );
1516 debug!(
1517 "{} H1 closing the frontend after a response that completed before its request on stream {}",
1518 log_context!(self),
1519 stream_id
1520 );
1521 incr!(names::http::CLOSE_REQUEST_INCOMPLETE);
1522 return self.defer_close_for_tls_flush("request-incomplete");
1523 }
1524 if !stream.context.keep_alive_backend {
1525 debug!(
1526 "{} H1 closing the frontend after a response carrying the backend's Connection: close on stream {}",
1527 log_context!(self),
1528 stream_id
1529 );
1530 }
1531 return self.defer_close_for_tls_flush("response-complete");
1532 }
1533 }
1534 }
1535 }
1536 MuxResult::Continue
1537 }
1538
1539 pub fn force_disconnect(&mut self) -> MuxResult {
1540 match &mut self.position {
1541 Position::Client(_, _, status) => {
1542 *status = BackendStatus::Disconnecting;
1543 self.readiness.event = Ready::HUP;
1544 debug!(
1545 "{} H1 force_disconnect client: stream={:?}, wants_write={}, readiness={:?}",
1546 log_context!(self),
1547 self.stream,
1548 self.socket.socket_wants_write(),
1549 self.readiness
1550 );
1551 MuxResult::Continue
1552 }
1553 Position::Server => {
1554 if self.socket.socket_wants_write() {
1555 debug!(
1556 "{} H1 force_disconnect delaying close: stream={:?}, wants_write=true, readiness={:?}",
1557 log_context!(self),
1558 self.stream,
1559 self.readiness
1560 );
1561 self.readiness.interest = Ready::WRITABLE | Ready::HUP | Ready::ERROR;
1562 self.readiness.signal_pending_write();
1563 MuxResult::Continue
1564 } else {
1565 debug!(
1566 "{} H1 force_disconnect closing session: stream={:?}, wants_write=false, readiness={:?}",
1567 log_context!(self),
1568 self.stream,
1569 self.readiness
1570 );
1571 MuxResult::CloseSession
1572 }
1573 }
1574 }
1575 }
1576
1577 pub fn has_pending_write(&self) -> bool {
1578 !self.write_failed && self.socket.socket_wants_write()
1579 }
1580
1581 /// A write to the client failed: the client is gone, or its socket can
1582 /// never be flushed. Close at once; `Self::has_pending_write` stops
1583 /// reporting output, so no delayed close waits for a flush that cannot
1584 /// happen.
1585 fn client_write_failed(&mut self, status: SocketResult) -> Option<MuxResult> {
1586 if self.position.is_server() && matches!(status, SocketResult::Error | SocketResult::Closed)
1587 {
1588 debug!(
1589 "{} H1 closing the frontend after a failed write: {:?}",
1590 log_context!(self),
1591 status
1592 );
1593 self.write_failed = true;
1594 Some(MuxResult::CloseSession)
1595 } else {
1596 None
1597 }
1598 }
1599
1600 pub fn initiate_close_notify(&mut self) -> bool {
1601 if !self.position.is_server() {
1602 return false;
1603 }
1604 // Past the guard we are always server-side; close_notify is a
1605 // frontend-only TLS concern.
1606 debug_assert!(
1607 self.position.is_server(),
1608 "initiate_close_notify past the guard must be server-side"
1609 );
1610 if !self.close_notify_sent {
1611 trace!("{} H1 initiating CLOSE_NOTIFY", log_context!(self));
1612 self.socket.socket_close();
1613 self.close_notify_sent = true;
1614 }
1615 // `close_notify` is monotone: once requested it stays sent for the
1616 // connection's lifetime (a second send would corrupt the TLS stream).
1617 debug_assert!(
1618 self.close_notify_sent,
1619 "close_notify_sent must be set once initiate_close_notify has run"
1620 );
1621 if self.socket.socket_wants_write() {
1622 self.readiness.arm_writable();
1623 // arm_writable pairs interest + event so the deferred TLS flush is
1624 // actually scheduled under edge-triggered epoll.
1625 debug_assert!(
1626 self.readiness.interest.is_writable() && self.readiness.event.is_writable(),
1627 "arm_writable must set both WRITABLE interest and event"
1628 );
1629 true
1630 } else {
1631 false
1632 }
1633 }
1634
1635 pub fn close<E, L>(&mut self, context: &mut Context<L>, mut endpoint: E)
1636 where
1637 E: Endpoint,
1638 L: ListenerHandler + L7ListenerHandler,
1639 {
1640 match self.position {
1641 Position::Client(_, _, BackendStatus::KeepAlive)
1642 | Position::Client(_, _, BackendStatus::Disconnecting) => {
1643 trace!("{} close detached client ConnectionH1", log_context!(self));
1644 return;
1645 }
1646 Position::Client(_, _, BackendStatus::Connecting(_))
1647 | Position::Client(_, _, BackendStatus::Connected) => {
1648 debug!(
1649 "{} BACKEND CLOSING FOR: {:?} {:?}",
1650 log_context!(self),
1651 self.position,
1652 self.stream
1653 );
1654 }
1655 Position::Server => {
1656 let tls_pending_before = self.socket.socket_wants_write();
1657 let (tls_pending_after, drain_rounds) =
1658 drain_tls_close_notify(&mut self.socket, &mut self.close_notify_sent);
1659 if tls_pending_after {
1660 error!(
1661 "{} H1 TLS buffer NOT fully drained on close: pending_before={}, pending_after={}, drain_rounds={}, stream={:?}, close_notify_sent={}, readiness={:?}",
1662 log_context!(self),
1663 tls_pending_before,
1664 tls_pending_after,
1665 drain_rounds,
1666 self.stream,
1667 self.close_notify_sent,
1668 self.readiness
1669 );
1670 }
1671 return;
1672 }
1673 }
1674 let Some(stream_id) = self.stream else {
1675 trace!(
1676 "{} closing detached H1 client with no active stream",
1677 log_context!(self)
1678 );
1679 return;
1680 };
1681 // reconnection is handled by the server
1682 let StreamState::Linked(token) = context.streams[stream_id].state else {
1683 trace!(
1684 "{} closing detached H1 client in state {:?} on stream {}",
1685 log_context!(self),
1686 context.streams[stream_id].state,
1687 stream_id
1688 );
1689 return;
1690 };
1691 endpoint.end_stream(token, stream_id, context)
1692 }
1693
1694 pub fn end_stream<L>(&mut self, stream: GlobalStreamId, context: &mut Context<L>)
1695 where
1696 L: ListenerHandler + L7ListenerHandler,
1697 {
1698 if self.stream != Some(stream) {
1699 error!(
1700 "{} end_stream called with stream {} but expected {:?}",
1701 log_context!(self),
1702 stream,
1703 self.stream
1704 );
1705 return;
1706 }
1707 // Reached only on the matched-stream path: the connection's active
1708 // stream is exactly the one being ended.
1709 debug_assert_eq!(
1710 self.stream,
1711 Some(stream),
1712 "end_stream past the guard must target the active stream"
1713 );
1714 context.unlink_stream(stream);
1715 // Post: whatever backend token this stream was Linked to no longer
1716 // lists it in the reverse index. `unlink_stream` is idempotent — it
1717 // evicts only while the stream is still `Linked` — so a subsequent
1718 // end/close cannot double-remove it. It is NOT the module's only
1719 // eviction point: `remove_backend_stream` has direct callers here and
1720 // in `h2.rs`. Extra eviction is harmless; what this post-condition
1721 // claims is that THIS path evicted.
1722 // (The `state` field is still `Linked` here; the arms below retire it.)
1723 #[cfg(debug_assertions)]
1724 if let StreamState::Linked(token) = context.streams[stream].state {
1725 debug_assert!(
1726 context
1727 .backend_streams
1728 .get(&token)
1729 .is_none_or(|ids| !ids.contains(&stream)),
1730 "unlink_stream must evict the stream from the backend reverse index"
1731 );
1732 }
1733 let stream_id = stream;
1734 let stream = &mut context.streams[stream_id];
1735 let answers_rc = stream.answers.clone();
1736 let stream_context = &mut stream.context;
1737 trace!(
1738 "{} end H1 stream {:?}: {:#?}",
1739 log_context!(self),
1740 self.stream,
1741 stream_context
1742 );
1743 match &mut self.position {
1744 Position::Client(_, _, BackendStatus::Connecting(_)) => {
1745 self.stream = None;
1746 if stream.state != StreamState::Recycle {
1747 stream.state = StreamState::Unlinked;
1748 }
1749 // Post: the client connection detaches from its stream and the
1750 // slot is retired (Unlinked) unless already marked for reuse —
1751 // never left dangling in an open/Linked state.
1752 debug_assert!(
1753 self.stream.is_none(),
1754 "client end_stream must detach the stream"
1755 );
1756 debug_assert!(
1757 !matches!(stream.state, StreamState::Linked(_)),
1758 "detached stream must not remain Linked"
1759 );
1760 self.readiness.interest.remove(Ready::ALL);
1761 self.force_disconnect();
1762 }
1763 Position::Client(_, _, status @ BackendStatus::Connected) => {
1764 self.stream = None;
1765 if stream.state != StreamState::Recycle {
1766 stream.state = StreamState::Unlinked;
1767 }
1768 debug_assert!(
1769 self.stream.is_none(),
1770 "client end_stream must detach the stream"
1771 );
1772 debug_assert!(
1773 !matches!(stream.state, StreamState::Linked(_)),
1774 "detached stream must not remain Linked"
1775 );
1776 self.readiness.interest.remove(Ready::ALL);
1777 // keep alive should probably be used only if the http context is fully reset
1778 // in case end_stream occurs due to an error the connection state is probably
1779 // unrecoverable and should be terminated
1780 // Both messages must be complete: a backend that answered
1781 // before the whole request was written to it still expects
1782 // the rest of the body, and would read the next request
1783 // pooled onto it as that body (RFC 9112 §9.3,
1784 // sozu-proxy/sozu#1721).
1785 if stream_context.keep_alive_backend
1786 && stream.back.is_terminated()
1787 && stream.front.is_terminated()
1788 && stream.front.is_completed()
1789 {
1790 *status = BackendStatus::KeepAlive;
1791 } else {
1792 self.force_disconnect();
1793 }
1794 }
1795 Position::Client(_, _, BackendStatus::KeepAlive)
1796 | Position::Client(_, _, BackendStatus::Disconnecting) => {
1797 error!(
1798 "{} end_stream called on KeepAlive or Disconnecting H1 client",
1799 log_context!(self)
1800 );
1801 }
1802 Position::Server => match end_stream_decision(stream) {
1803 EndStreamAction::ForwardTerminated => {
1804 debug!("{} CLOSING H1 TERMINATED STREAM", log_context!(self));
1805 stream.state = StreamState::Unlinked;
1806 self.readiness.interest.insert(Ready::WRITABLE);
1807 // End-of-stream was already queued into kawa by the parser;
1808 // no fresh WRITABLE event will arrive from the kernel.
1809 self.readiness.signal_pending_write();
1810 }
1811 EndStreamAction::CloseDelimited => {
1812 debug!("{} CLOSE DELIMITED", log_context!(self));
1813 stream.state = StreamState::Unlinked;
1814 self.readiness.arm_writable();
1815 }
1816 EndStreamAction::ForwardUnterminated => {
1817 debug!("{} CLOSING H1 UNTERMINATED STREAM", log_context!(self));
1818 forcefully_terminate_answer(
1819 stream,
1820 &mut self.readiness,
1821 H2Error::InternalError,
1822 );
1823 }
1824 EndStreamAction::SendDefault(status) => {
1825 let answers = answers_rc.borrow();
1826 set_default_answer(stream, &mut self.readiness, status, &answers);
1827 }
1828 EndStreamAction::Reconnect => {
1829 debug!("{} H1 RECONNECT", log_context!(self));
1830 stream.state = StreamState::Link;
1831 context.pending_links.push_back(stream_id);
1832 }
1833 EndStreamAction::ReplayOnFreshBackend => match stream.queue_upstream_replay() {
1834 Some(len) => {
1835 debug!(
1836 "{} H1 REPLAY {} request bytes on a fresh backend",
1837 log_context!(self),
1838 len
1839 );
1840 incr!(
1841 names::backend::RETRY_STALE_UPSTREAM,
1842 stream.context.cluster_id.as_deref(),
1843 stream.context.backend_id.as_deref(),
1844 stream.context.cluster_metrics_incarnation()
1845 );
1846 stream.state = StreamState::Link;
1847 context.pending_links.push_back(stream_id);
1848 // `Router::plan_connect` still gates on `stream.attempts`
1849 // against `max_connection_attempts`, so a cluster whose backends
1850 // are all stale cannot loop: the budget runs out and
1851 // the caller answers 503.
1852 }
1853 None => {
1854 // Unreachable while `end_stream_decision` only picks
1855 // this action behind `can_replay_on_fresh_upstream`,
1856 // which requires the buffer. Degrade to the answer
1857 // the old code sent rather than stranding the stream.
1858 error!(
1859 "{} replay selected with no captured request",
1860 log_context!(self)
1861 );
1862 let answers = answers_rc.borrow();
1863 set_default_answer(stream, &mut self.readiness, 502, &answers);
1864 }
1865 },
1866 },
1867 }
1868 }
1869
1870 pub fn start_stream<L>(&mut self, stream: GlobalStreamId, context: &mut Context<L>) -> bool
1871 where
1872 L: ListenerHandler + L7ListenerHandler,
1873 {
1874 trace!(
1875 "{} start H1 stream {} {:?}",
1876 log_context!(self),
1877 stream,
1878 self.readiness
1879 );
1880 self.readiness.interest.insert(Ready::ALL);
1881 self.stream = Some(stream);
1882 debug_assert_eq!(
1883 self.stream,
1884 Some(stream),
1885 "start_stream must pin the connection's active stream"
1886 );
1887 match &mut self.position {
1888 Position::Client(_, _, status @ BackendStatus::KeepAlive) => {
1889 *status = BackendStatus::Connected;
1890 // This stream is being written onto a socket that has been
1891 // idle in the pool, so the peer may already have closed it
1892 // without sozu noticing. Record the provenance and arm
1893 // request capture so the write path below can keep the bytes
1894 // needed to replay elsewhere (sozu-proxy/sozu#1442).
1895 self.reused_from_pool = true;
1896 context.streams[stream].arm_upstream_replay();
1897 // A keep-alive client transitions to Connected when it picks up
1898 // a new stream; it must not stay parked in KeepAlive.
1899 debug_assert!(
1900 matches!(
1901 self.position,
1902 Position::Client(_, _, BackendStatus::Connected)
1903 ),
1904 "a reused keep-alive client must become Connected on start_stream"
1905 );
1906 }
1907 Position::Client(_, _, BackendStatus::Disconnecting) => {
1908 error!(
1909 "{} start_stream called on Disconnecting H1 client",
1910 log_context!(self)
1911 );
1912 return false;
1913 }
1914 Position::Client(_, _, _) => {}
1915 Position::Server => {
1916 error!(
1917 "{} start_stream must not be called on H1 server connection",
1918 log_context!(self)
1919 );
1920 return false;
1921 }
1922 }
1923 true
1924 }
1925}
1926
1927#[cfg(test)]
1928mod tests {
1929 use std::{cell::Cell, cell::RefCell, io::Write, rc::Rc};
1930
1931 use super::*;
1932 use crate::{
1933 Protocol as TransportKind,
1934 pool::Pool,
1935 protocol::{
1936 kawa_h1::editor::HttpContext,
1937 mux::{
1938 BackendId, BackendSlot, Connection,
1939 connection::{EndpointClient, EndpointServer},
1940 router::Router,
1941 tcp_info_reads,
1942 test_support::{connected_socket, test_context},
1943 },
1944 },
1945 socket::SessionTcpStream,
1946 };
1947
1948 // ── The `peer=` slot of the MUX-H1 log prefix ───────────────────────
1949 //
1950 // These pin that the slot is the address the connection snapshotted at
1951 // construction, not a live `getpeername(2)` taken per expansion. The
1952 // difference is invisible while a connection is healthy and is the whole
1953 // story once it is not: `getpeername(2)` answers ENOTCONN after the peer
1954 // resets, and it reports the transport peer — the load balancer — on a
1955 // PROXY-protocol frontend.
1956
1957 /// Address the handler caches. Deliberately non-loopback so it cannot
1958 /// collide with whatever ephemeral port a live lookup would report.
1959 const CACHED_PEER: &str = "10.0.0.42:12345";
1960
1961 fn cached_peer() -> std::net::SocketAddr {
1962 CACHED_PEER
1963 .parse()
1964 .expect("the cached peer literal must parse")
1965 }
1966
1967 /// A live, established loopback connection plus the address
1968 /// `getpeername(2)` reports for it. The listener is returned so the
1969 /// connection stays up for the whole test: these tests assert the snapshot
1970 /// wins even while the live lookup is perfectly healthy, so a half-dead
1971 /// socket would weaken them rather than strengthen them.
1972 fn connected_loopback_stream() -> (
1973 std::net::TcpListener,
1974 mio::net::TcpStream,
1975 std::net::SocketAddr,
1976 ) {
1977 let listener = std::net::TcpListener::bind("127.0.0.1:0")
1978 .expect("test listener must bind to a loopback port");
1979 let live_peer = listener
1980 .local_addr()
1981 .expect("test listener must report its local address");
1982 let stream =
1983 std::net::TcpStream::connect(live_peer).expect("loopback connect must complete");
1984 stream
1985 .set_nonblocking(true)
1986 .expect("mio requires a nonblocking stream");
1987 (listener, mio::net::TcpStream::from_std(stream), live_peer)
1988 }
1989
1990 /// A socket that was never connected, and therefore one whose
1991 /// `getpeername(2)` fails with `ENOTCONN` *deterministically*.
1992 ///
1993 /// This is the one reliable way to stage a failing live lookup. The
1994 /// obvious alternative — connect to a closed port and wait for the RST —
1995 /// is a race: whether the kernel has collected the RST yet, and so whether
1996 /// `getpeername(2)` has started refusing, is not something a test may
1997 /// assert on. An unconnected socket is in the refusing state from birth,
1998 /// which is the state a reset peer leaves behind and the state these
1999 /// tests are about.
2000 fn unconnected_stream() -> mio::net::TcpStream {
2001 let socket = socket2::Socket::new(
2002 socket2::Domain::IPV4,
2003 socket2::Type::STREAM,
2004 Some(socket2::Protocol::TCP),
2005 )
2006 .expect("a test socket must be creatable");
2007 socket
2008 .set_nonblocking(true)
2009 .expect("mio requires a nonblocking stream");
2010 mio::net::TcpStream::from_std(std::net::TcpStream::from(socket))
2011 }
2012
2013 /// An opaque backend id for a `Position::Client` connection. The slot is
2014 /// never resolved by anything under test — `log_context!` renders
2015 /// `position` and nothing looks the backend up — so a standalone id is
2016 /// enough and spares these tests a whole `Mux` and backend registry.
2017 fn test_backend_id(address: std::net::SocketAddr) -> BackendId {
2018 BackendId {
2019 slot: BackendSlot(0),
2020 backend_id: Rc::from("test-backend"),
2021 address,
2022 metric_incarnation: Default::default(),
2023 }
2024 }
2025
2026 /// Unwrap the H1 arm of a freshly built connection.
2027 fn h1_of<Front: SocketHandler>(connection: Connection<Front>) -> ConnectionH1<Front> {
2028 match connection {
2029 Connection::H1(connection) => connection,
2030 Connection::H2(_) => unreachable!("new_h1_* builds an H1 connection"),
2031 }
2032 }
2033
2034 /// Symptom 1 — `getpeername(2)` answers `ENOTCONN` once the peer has
2035 /// reset, so the pre-fix macro rendered `peer=None` on exactly the
2036 /// `error!` lines an operator reads during an incident. The address was
2037 /// least available precisely when it mattered most.
2038 ///
2039 /// Staged with a never-connected socket rather than a reset one, because
2040 /// only the former refuses deterministically — see [`unconnected_stream`].
2041 /// A peer reset is one way to reach that state; what this pins is the
2042 /// rendering once the socket is in it, which is the part the macro owns.
2043 ///
2044 /// To SEE THIS RED: in `log_context!`, put
2045 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2046 /// `peer = $self.peer_address,`. The slot collapses to `peer=None`.
2047 #[test]
2048 fn log_context_renders_the_peer_when_the_live_lookup_fails() {
2049 let stream = unconnected_stream();
2050 let cached = cached_peer();
2051
2052 // Premise: the live lookup really is refusing, so the assertion below
2053 // cannot pass for the wrong reason.
2054 assert_eq!(
2055 stream.peer_addr().ok(),
2056 None,
2057 "an unconnected socket must refuse getpeername(2)"
2058 );
2059
2060 let session_ulid = Ulid::generate();
2061 let connection = h1_of(Connection::new_h1_server(
2062 session_ulid,
2063 SessionTcpStream::new(stream, session_ulid, Some(cached)),
2064 Duration::from_secs(30),
2065 ));
2066
2067 let rendered = log_context!(connection);
2068
2069 assert!(
2070 rendered.contains(&format!("peer=Some({cached})")),
2071 "the MUX-H1 peer= slot must survive a failed live lookup: {rendered}"
2072 );
2073 assert!(
2074 !rendered.contains("peer=None"),
2075 "the MUX-H1 peer= slot must not collapse to None while a snapshot \
2076 exists: {rendered}"
2077 );
2078 }
2079
2080 /// Symptom 2 — a backend connection is built from a nonblocking
2081 /// `connect()` that has not completed, so `getpeername(2)` refuses for the
2082 /// whole window in which an ECONNREFUSED line is emitted. The dial path
2083 /// caches the cluster-configured backend address into
2084 /// `SessionTcpStream::configured_peer` for exactly that reason, and the H1
2085 /// macro has to consult it rather than the raw stream.
2086 ///
2087 /// This is the `Position::Client` constructor, which `ConnectionH2` has no
2088 /// counterpart for: `ConnectionH1` serves backend connections too.
2089 ///
2090 /// To SEE THIS RED: in `log_context!`, put
2091 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2092 /// `peer = $self.peer_address,`. The backend id the operator needs is
2093 /// replaced by `peer=None`.
2094 #[test]
2095 fn log_context_renders_the_backend_peer_while_the_connect_is_in_flight() {
2096 let stream = unconnected_stream();
2097 let backend_address = cached_peer();
2098
2099 // Premise: this is the state a dial in flight really leaves the socket
2100 // in — the live lookup refuses.
2101 assert_eq!(
2102 stream.peer_addr().ok(),
2103 None,
2104 "a connect() still in flight must refuse getpeername(2)"
2105 );
2106
2107 let session_ulid = Ulid::generate();
2108 let connection = h1_of(Connection::new_h1_client(
2109 session_ulid,
2110 SessionTcpStream::new(stream, session_ulid, Some(backend_address)),
2111 "test-cluster".into(),
2112 test_backend_id(backend_address),
2113 Duration::from_secs(30),
2114 ));
2115
2116 let rendered = log_context!(connection);
2117
2118 assert!(
2119 rendered.contains(&format!("peer=Some({backend_address})")),
2120 "a backend MUX-H1 line must name the configured backend: {rendered}"
2121 );
2122 assert!(
2123 !rendered.contains("peer=None"),
2124 "a backend MUX-H1 line must not collapse to None while the dial is \
2125 in flight: {rendered}"
2126 );
2127 }
2128
2129 /// Symptom 3 — on a PROXY-protocol frontend the cached address is the
2130 /// advertised client while the socket's own peer is the load balancer.
2131 /// `upgrade_expect` adopts the advertised source into the handler's
2132 /// `configured_peer`, and the pre-fix macro read straight past it: for one
2133 /// request id the `HTTP` line named the client and the `MUX-H1` line named
2134 /// the load balancer.
2135 ///
2136 /// The live lookup is deliberately HEALTHY here and disagrees with the
2137 /// cache, which is what separates this from
2138 /// [`log_context_renders_the_peer_when_the_live_lookup_fails`] — a single
2139 /// test cannot be red for both reasons.
2140 ///
2141 /// This stages the cleartext expect-proxy route, whose handler really is a
2142 /// `SessionTcpStream`. The TLS route composes the same macro with
2143 /// `FrontRustls::peer_addr`, whose own PROXY seeding is pinned in
2144 /// `https.rs` by `front_rustls_peer_snapshot_is_the_session_peer_not_the_accepted_socket`.
2145 ///
2146 /// To SEE THIS RED: in `log_context!`, put
2147 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2148 /// `peer = $self.peer_address,`. The rendered line then carries the
2149 /// loopback address the socket is really connected to — the load balancer
2150 /// — so the first assertion fails on the missing advertised client.
2151 #[test]
2152 fn log_context_renders_the_proxy_advertised_peer_not_the_load_balancer() {
2153 let (_listener, stream, live_peer) = connected_loopback_stream();
2154 let advertised = cached_peer();
2155
2156 // Premise: the live lookup is healthy and disagrees with the cache, so
2157 // the assertions below cannot pass for the wrong reason.
2158 assert_eq!(
2159 stream.peer_addr().ok(),
2160 Some(live_peer),
2161 "the test socket must be genuinely connected, so a live lookup succeeds"
2162 );
2163 assert_ne!(
2164 advertised, live_peer,
2165 "the advertised and transport addresses must differ for this test to discriminate"
2166 );
2167
2168 let session_ulid = Ulid::generate();
2169 let connection = h1_of(Connection::new_h1_server(
2170 session_ulid,
2171 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2172 Duration::from_secs(30),
2173 ));
2174
2175 let rendered = log_context!(connection);
2176
2177 assert!(
2178 rendered.contains(&format!("peer=Some({advertised})")),
2179 "MUX-H1 must render the PROXY-advertised client: {rendered}"
2180 );
2181 assert!(
2182 !rendered.contains(&live_peer.to_string()),
2183 "MUX-H1 must not fall back to the transport peer, which is the load \
2184 balancer on a PROXY frontend: {rendered}"
2185 );
2186 }
2187
2188 /// The per-stream twin fills the same slot from the same snapshot.
2189 ///
2190 /// `log_context_stream!` has no production expansion in this file today
2191 /// and carries `#[allow(unused_macros)]`, so nothing else type-checks its
2192 /// body at all. That is the reason to pin it rather than a reason to skip
2193 /// it: leaving twin macros on different sources is how they drift apart,
2194 /// and the divergence would be worse than either being wrong alone — the
2195 /// same session would render two different peers depending on whether a
2196 /// stream happened to be in scope at the callsite.
2197 ///
2198 /// To SEE THIS RED: in `log_context_stream!`, put
2199 /// `peer = $self.socket.socket_ref().peer_addr().ok(),` back in place of
2200 /// `peer = $self.peer_address,`. The per-stream envelope then carries the
2201 /// loopback address while the connection envelope carries the cache.
2202 #[test]
2203 fn log_context_stream_renders_the_snapshot_not_a_live_lookup() {
2204 let (_listener, stream, live_peer) = connected_loopback_stream();
2205 let advertised = cached_peer();
2206
2207 assert_eq!(
2208 stream.peer_addr().ok(),
2209 Some(live_peer),
2210 "the test socket must be genuinely connected, so a live lookup succeeds"
2211 );
2212
2213 let session_ulid = Ulid::generate();
2214 let connection = h1_of(Connection::new_h1_server(
2215 session_ulid,
2216 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2217 Duration::from_secs(30),
2218 ));
2219 let http_context = test_http_context(session_ulid);
2220
2221 let rendered = log_context_stream!(connection, http_context);
2222
2223 assert!(
2224 rendered.contains(&format!("peer=Some({advertised})")),
2225 "the per-stream MUX-H1 envelope must render the snapshot: {rendered}"
2226 );
2227 assert!(
2228 !rendered.contains(&live_peer.to_string()),
2229 "the per-stream MUX-H1 envelope must not fall back to the live \
2230 getpeername(2) answer: {rendered}"
2231 );
2232 }
2233
2234 /// A [`SocketHandler`] that counts how often it is asked for the peer
2235 /// address, delegating every other method to a real loopback stream.
2236 ///
2237 /// The tests above pin WHICH address the log prefix renders. None of them
2238 /// can see how many times the connection reaches into the socket to get
2239 /// it, because both production handlers answer from a cache and so give
2240 /// the same answer however often they are asked. This handler makes the
2241 /// count observable.
2242 struct PeerAddrCountingSocket {
2243 stream: mio::net::TcpStream,
2244 peer: std::net::SocketAddr,
2245 calls: Rc<Cell<usize>>,
2246 }
2247
2248 impl SocketHandler for PeerAddrCountingSocket {
2249 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
2250 self.stream.socket_read(buf)
2251 }
2252
2253 fn socket_write(&mut self, buf: &[u8]) -> (usize, SocketResult) {
2254 self.stream.socket_write(buf)
2255 }
2256
2257 fn socket_write_vectored(&mut self, bufs: &[IoSlice]) -> (usize, SocketResult) {
2258 self.stream.socket_write_vectored(bufs)
2259 }
2260
2261 fn socket_ref(&self) -> &mio::net::TcpStream {
2262 &self.stream
2263 }
2264
2265 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
2266 &mut self.stream
2267 }
2268
2269 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
2270 self.calls.set(self.calls.get() + 1);
2271 Some(self.peer)
2272 }
2273
2274 fn protocol(&self) -> crate::socket::TransportProtocol {
2275 crate::socket::TransportProtocol::Tcp
2276 }
2277
2278 fn read_error(&self) {}
2279
2280 fn write_error(&self) {}
2281 }
2282
2283 /// The `peer=` slot is read from the socket exactly ONCE per connection —
2284 /// at construction — however many log lines the connection renders.
2285 ///
2286 /// This is the property that makes `peer_address` worth having, and it is
2287 /// the only one that separates the snapshot from simply calling the trait
2288 /// method in the macro. It is not about which address appears (the tests
2289 /// above own that): for a handler that already caches, reading the cache
2290 /// and reading a snapshot taken from that cache agree by construction, so
2291 /// substituting `peer = $self.socket.peer_addr(),` leaves every one of
2292 /// them green. What the snapshot changed is WHICH object a log line reads,
2293 /// and only a call count can observe that.
2294 ///
2295 /// TO SEE THIS RED: in `log_context!`, put
2296 /// `peer = $self.socket.peer_addr(),` — the call-the-trait-method shape —
2297 /// in place of `peer = $self.peer_address,`. The count then rises by one
2298 /// per rendered line and the final assertion fails with
2299 /// `the peer address must be read once, at construction, not once per log line:
2300 /// left: 4, right: 1`.
2301 #[test]
2302 fn log_context_reads_the_peer_address_once_per_connection() {
2303 let (_listener, stream, _live_peer) = connected_loopback_stream();
2304 let calls = Rc::new(Cell::new(0usize));
2305 let peer = cached_peer();
2306 let socket = PeerAddrCountingSocket {
2307 stream,
2308 peer,
2309 calls: Rc::clone(&calls),
2310 };
2311
2312 let connection = h1_of(Connection::new_h1_server(
2313 Ulid::generate(),
2314 socket,
2315 Duration::from_secs(30),
2316 ));
2317
2318 assert_eq!(
2319 calls.get(),
2320 1,
2321 "construction takes exactly one peer_addr() snapshot"
2322 );
2323
2324 // Premise: the rendered lines really do carry the address, so a zero
2325 // count below would mean the slot went missing rather than that it
2326 // became free.
2327 for _ in 0..3 {
2328 let rendered = log_context!(connection);
2329 assert!(
2330 rendered.contains(&format!("peer=Some({peer})")),
2331 "each rendered line must still carry the peer: {rendered}"
2332 );
2333 }
2334
2335 assert_eq!(
2336 calls.get(),
2337 1,
2338 "the peer address must be read once, at construction, not once per log line"
2339 );
2340 }
2341
2342 /// The three fields `log_context_stream!` reads out of an `HttpContext`,
2343 /// with every other field at an inert default. Built directly rather than
2344 /// through a `Stream`, because the macro touches no buffer and a real
2345 /// stream would drag a whole `Pool` in behind it.
2346 fn test_http_context(session_ulid: Ulid) -> HttpContext {
2347 HttpContext {
2348 keep_alive_backend: true,
2349 keep_alive_frontend: true,
2350 sticky_session_found: None,
2351 method: None,
2352 authority: None,
2353 path: None,
2354 status: None,
2355 reason: None,
2356 user_agent: None,
2357 x_request_id: None,
2358 xff_chain: None,
2359 #[cfg(feature = "opentelemetry")]
2360 otel: None,
2361 closing: false,
2362 session_id: session_ulid,
2363 id: Ulid::generate(),
2364 backend_id: None,
2365 cluster_id: None,
2366 cluster_metrics_incarnation: Default::default(),
2367 affinity_key: None,
2368 protocol: TransportKind::HTTP,
2369 public_address: "127.0.0.1:0"
2370 .parse()
2371 .expect("the public address literal must parse"),
2372 session_address: None,
2373 sticky_name: String::new(),
2374 sticky_session: None,
2375 backend_address: None,
2376 tls_server_name: None,
2377 tls_cert_names: None,
2378 strict_sni_binding: false,
2379 elide_x_real_ip: false,
2380 send_x_real_ip: false,
2381 forwarded_headers: sozu_command_lib::proto::command::ForwardedHeaders::Both,
2382 max_trailer_fields: 128,
2383 trailer_fields: 0,
2384 tls_version: None,
2385 tls_cipher: None,
2386 tls_alpn: None,
2387 sozu_id_header: String::from("Sozu-Id"),
2388 redirect_location: None,
2389 www_authenticate: None,
2390 original_authority: None,
2391 headers_response: Vec::new(),
2392 retry_after_seconds: None,
2393 frontend_redirect_template: None,
2394 redirect_status: None,
2395 tags: None,
2396 forwarding_hop: None,
2397 access_log_message: None,
2398 backends_unavailable: false,
2399 }
2400 }
2401
2402 /// `ConnectionH1`'s `Debug` renders the peer address the connection
2403 /// snapshotted at construction, not the transport address the kernel knows.
2404 ///
2405 /// This is the twin of `ConnectionH2`'s `Debug`, which already renders
2406 /// `peer_address` and names no socket at all. `ConnectionH1` was the last
2407 /// `Debug` in this module handing `mio::net::TcpStream`'s own `Debug` a
2408 /// `socket` field through `SocketHandler::socket_ref` — a local address, a
2409 /// peer address and a file descriptor — and so the last one whose rendered
2410 /// line could disagree with the `peer=` slot every `log_context!` line of
2411 /// the same connection already carries.
2412 ///
2413 /// Staged like
2414 /// [`log_context_renders_the_proxy_advertised_peer_not_the_load_balancer`]:
2415 /// a genuinely connected loopback socket whose live lookup is healthy and
2416 /// disagrees with the address its handler declares, which is the
2417 /// PROXY-protocol frontend's shape. This pins the VALUE rendered rather
2418 /// than a count — the two addresses differ, so only one of them can appear.
2419 ///
2420 /// To SEE THIS RED: in `impl Debug for ConnectionH1`, put
2421 /// `.field("socket", &self.socket.socket_ref())` back in place of
2422 /// `.field("peer_address", &self.peer_address)`. The rendered struct then
2423 /// carries the loopback address the socket is really connected to — the
2424 /// load balancer — so the first assertion fails on the missing advertised
2425 /// client and the second on the transport address being present.
2426 #[test]
2427 fn debug_renders_the_proxy_advertised_peer_not_the_transport_socket() {
2428 let (_listener, stream, live_peer) = connected_loopback_stream();
2429 let advertised = cached_peer();
2430
2431 // Premise: the live lookup is healthy and disagrees with the declared
2432 // address, so the assertions below cannot pass for the wrong reason.
2433 assert_eq!(
2434 stream.peer_addr().ok(),
2435 Some(live_peer),
2436 "the test socket must be genuinely connected, so a live lookup succeeds"
2437 );
2438 assert_ne!(
2439 advertised, live_peer,
2440 "the declared and transport addresses must differ for this test to discriminate"
2441 );
2442
2443 let session_ulid = Ulid::generate();
2444 let connection = h1_of(Connection::new_h1_server(
2445 session_ulid,
2446 SessionTcpStream::new(stream, session_ulid, Some(advertised)),
2447 Duration::from_secs(30),
2448 ));
2449
2450 let rendered = format!("{connection:?}");
2451
2452 assert!(
2453 rendered.contains(&format!("Some({advertised})")),
2454 "the ConnectionH1 Debug must render the declared peer: {rendered}"
2455 );
2456 assert!(
2457 !rendered.contains(&live_peer.to_string()),
2458 "the ConnectionH1 Debug must not render the transport address, which \
2459 is the load balancer on a PROXY frontend: {rendered}"
2460 );
2461 }
2462
2463 // ── `backend_header_time`, the H1 half (sozu-proxy/sozu#426) ─────────
2464 //
2465 // DO NOT READ THESE TESTS AS COVERING H2. They drive
2466 // `ConnectionH1::readable` only. The H2 twin lives in
2467 // `ConnectionH2::handle_headers_frame` (`lib/src/protocol/mux/h2.rs`) and
2468 // is pinned by its own test there.
2469
2470 /// A `Position::Client` H1 backend connection whose stream is linked to a
2471 /// frontend, staged at the exact moment a real dial completes: the
2472 /// connection is `Connected`, `backend_connected` is armed, and not one
2473 /// response byte has arrived.
2474 ///
2475 /// Both loopback peers are returned and must be held for the whole test —
2476 /// dropping either tears the connection down and turns the next
2477 /// `readable()` into a forced disconnect instead of a parse.
2478 /// Held together rather than returned as a tuple, the way
2479 /// `LedgerFixture` (`lib/src/protocol/mux/h2.rs`) is: the buffer pool and
2480 /// both loopback peers are lifetime ballast with no business in a test
2481 /// body, and a six-element tuple is `clippy::type_complexity`.
2482 struct BackendReadFixture {
2483 context: Context<crate::protocol::mux::test_support::TestListener>,
2484 frontend: Connection<mio::net::TcpStream>,
2485 client: ConnectionH1<mio::net::TcpStream>,
2486 backend_peer: std::net::TcpStream,
2487 _frontend_peer: std::net::TcpStream,
2488 _pool: Rc<RefCell<Pool>>,
2489 }
2490
2491 fn linked_backend_connection() -> BackendReadFixture {
2492 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2493 let mut context = test_context(&pool);
2494 context
2495 .create_stream(Ulid::generate(), 1 << 16)
2496 .expect("the test pool must hand out stream buffers");
2497
2498 let (front_socket, front_peer) = connected_socket();
2499 let frontend =
2500 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2501
2502 let (back_socket, back_peer) = connected_socket();
2503 let session_ulid = Ulid::generate();
2504 let mut client = h1_of(Connection::new_h1_client(
2505 session_ulid,
2506 back_socket,
2507 "test-cluster".into(),
2508 test_backend_id(cached_peer()),
2509 Duration::from_secs(60),
2510 ));
2511 // `new_h1_client` opens in `Connecting`; move it the way a completed
2512 // dial does, so the read path runs its `Connected` accounting.
2513 if let Position::Client(_, _, status) = &mut client.position {
2514 *status = BackendStatus::Connected;
2515 }
2516 client.stream = Some(0);
2517
2518 let stream = &mut context.streams[0];
2519 stream.state = StreamState::Linked(mio::Token(1));
2520 stream.metrics.backend_id = Some("test-backend".into());
2521 stream.metrics.backend_start();
2522 stream.metrics.backend_connected();
2523
2524 BackendReadFixture {
2525 context,
2526 frontend,
2527 client,
2528 backend_peer: back_peer,
2529 _frontend_peer: front_peer,
2530 _pool: pool,
2531 }
2532 }
2533
2534 /// Hand `bytes` to the backend peer and drive `ConnectionH1::readable`
2535 /// until `done` holds, bounded.
2536 ///
2537 /// The loop is not a retry papering over a flaky assertion: a loopback
2538 /// write is a syscall away, not instantaneous, so a single `readable()`
2539 /// may legitimately see `WouldBlock` and read nothing. The bound is what
2540 /// keeps a genuine failure a failure instead of a hang.
2541 fn feed_backend<F>(
2542 peer: &mut std::net::TcpStream,
2543 client: &mut ConnectionH1<mio::net::TcpStream>,
2544 context: &mut Context<crate::protocol::mux::test_support::TestListener>,
2545 frontend: &mut Connection<mio::net::TcpStream>,
2546 bytes: &[u8],
2547 done: F,
2548 ) where
2549 F: Fn(&Context<crate::protocol::mux::test_support::TestListener>) -> bool,
2550 {
2551 peer.write_all(bytes)
2552 .expect("the loopback peer must accept the staged response bytes");
2553 for _ in 0..64 {
2554 client.readiness.event.insert(Ready::READABLE);
2555 client.readable(context, EndpointServer(frontend));
2556 if done(context) {
2557 return;
2558 }
2559 }
2560 panic!("the backend read path never reached the staged state");
2561 }
2562
2563 /// The whole point of the metric, pinned as an ordering: the H1 backend
2564 /// time-to-first-header-byte instant is taken when the response HEADERS
2565 /// finish parsing, which is strictly before the response ENDS.
2566 ///
2567 /// Two phases, and the split is what makes this discriminating. After the
2568 /// headers alone (`Content-Length: 2`, body withheld) the header instant
2569 /// must already exist while `backend_stop` — the response-end marker every
2570 /// one of `ConnectionH1::writable`'s five sites owns — must still be
2571 /// absent. An instant placed at any of those sites cannot satisfy that.
2572 /// After the body, the instant must be UNCHANGED: the transition fires on
2573 /// the header -> body edge, not on every read.
2574 ///
2575 /// The ordering assertion is then `header_time <= response_time` on
2576 /// `Duration`s, not on the millisecond values the histogram stores: at
2577 /// millisecond resolution a fast test rounds both to 0 and the relation
2578 /// would hold however wrong the placement is.
2579 ///
2580 /// `backend_stop` is marked by the test rather than driven through
2581 /// `ConnectionH1::writable` because that pass calls
2582 /// `SessionMetrics::reset` immediately after its access log, which wipes
2583 /// every instant before a test could read one.
2584 ///
2585 /// To SEE THIS RED: move `parts.metrics.backend_headers_received();` out
2586 /// of the `!was_main_phase && self.position.is_client()` branch of
2587 /// `ConnectionH1::readable` and put it immediately after the
2588 /// `stream.metrics.backend_stop();` that precedes `Some("H1::Complete")`
2589 /// in `ConnectionH1::writable`. Phase one then reports no header time at
2590 /// all.
2591 #[test]
2592 fn the_h1_backend_header_instant_lands_on_the_headers_not_the_response_end() {
2593 let mut fixture = linked_backend_connection();
2594 let BackendReadFixture {
2595 context,
2596 frontend,
2597 client,
2598 backend_peer,
2599 ..
2600 } = &mut fixture;
2601
2602 // Premise: nothing has been received, so neither instant can be stale.
2603 assert_eq!(context.streams[0].metrics.backend_header_time(), None);
2604 assert_eq!(context.streams[0].metrics.backend_stop, None);
2605
2606 feed_backend(
2607 backend_peer,
2608 client,
2609 context,
2610 frontend,
2611 b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\n",
2612 |context| context.streams[0].back.is_main_phase(),
2613 );
2614
2615 let after_headers = context.streams[0]
2616 .metrics
2617 .backend_headers_received
2618 .expect("the response headers must arm the backend header instant");
2619 assert!(
2620 !context.streams[0].back.is_terminated(),
2621 "premise: the response is not over — its 2-byte body is still \
2622 outstanding, so this phase cannot be observing the response end"
2623 );
2624 assert_eq!(
2625 context.streams[0].metrics.backend_stop, None,
2626 "the response-end marker must still be absent while only the \
2627 headers have arrived"
2628 );
2629
2630 feed_backend(backend_peer, client, context, frontend, b"ok", |context| {
2631 context.streams[0].back.is_terminated()
2632 });
2633
2634 assert_eq!(
2635 context.streams[0].metrics.backend_headers_received,
2636 Some(after_headers),
2637 "the instant is taken on the header -> body edge, so the body \
2638 reads must not move it"
2639 );
2640
2641 // What the `Some("H1::Complete")` arm of `ConnectionH1::writable` does
2642 // once the whole response has been forwarded.
2643 context.streams[0].metrics.backend_stop();
2644
2645 let metrics = &context.streams[0].metrics;
2646 let header_time = metrics
2647 .backend_header_time()
2648 .expect("a completed H1 response must report a backend header time");
2649 let response_time = metrics
2650 .backend_response_time()
2651 .expect("a completed H1 response must report a backend response time");
2652 assert!(
2653 header_time <= response_time,
2654 "the first response-header byte arrives before the last response \
2655 byte: header_time {header_time:?} must not exceed response_time \
2656 {response_time:?}"
2657 );
2658 }
2659
2660 // ── The access log of a request the parse rejected (sozu-proxy/sozu#1085) ──
2661 //
2662 // DO NOT READ THESE TESTS AS COVERING H2. They drive a `Position::Server`
2663 // `ConnectionH1` only. An H2 request whose field block `handle_header`
2664 // (`lib/src/protocol/mux/pkawa.rs`) refuses takes another path,
2665 // `record_rejected_request` in the same file, and is covered by the
2666 // `h2` tests beside `rejected_request_line`
2667 // (`lib/src/protocol/mux/stream.rs`).
2668
2669 /// Drive `request` through a real `Position::Server` `ConnectionH1`, the
2670 /// way a client socket does: `readable` until the parse is rejected, then
2671 /// `writable` until the 400 is written and its access log emitted.
2672 /// Returns every log line the run produced.
2673 ///
2674 /// Driving both halves, rather than calling `Stream::generate_access_log`
2675 /// on a staged stream, is what makes these tests say which site emits the
2676 /// line and that the request bytes are still in the front buffer when it
2677 /// does.
2678 ///
2679 /// The loops are bounded for the reason `feed_backend` gives: a loopback
2680 /// write is a syscall away, not instantaneous.
2681 fn access_log_of_a_rejected_h1_request(request: &'static [u8]) -> String {
2682 crate::capture_test_logs(move || {
2683 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2684 let mut context = test_context(&pool);
2685 context
2686 .create_stream(Ulid::generate(), 1 << 16)
2687 .expect("the test pool must hand out stream buffers");
2688 let (front_socket, mut front_peer) = connected_socket();
2689 let mut server = h1_of(Connection::new_h1_server(
2690 Ulid::generate(),
2691 front_socket,
2692 Duration::from_secs(60),
2693 ));
2694 server.stream = Some(0);
2695 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2696
2697 front_peer
2698 .write_all(request)
2699 .expect("the loopback peer must accept the staged request bytes");
2700 for _ in 0..64 {
2701 server.readiness.event.insert(Ready::READABLE);
2702 server.readable(&mut context, EndpointClient(&mut router));
2703 if context.streams[0].front.is_error() {
2704 break;
2705 }
2706 }
2707 assert!(
2708 context.streams[0].front.is_error(),
2709 "premise: the staged request must be rejected by the parse"
2710 );
2711 assert_eq!(
2712 context.streams[0].context.method, None,
2713 "premise: the rejection happened before `HttpContext` captured \
2714 the request line, which is the whole defect"
2715 );
2716
2717 // `ConnectionH1::writable` resets the stream metrics right after
2718 // it emits the access log, so a cleared start instant is the
2719 // observable "the line went out".
2720 for _ in 0..64 {
2721 server.readiness.event.insert(Ready::WRITABLE);
2722 server.writable(&mut context, EndpointClient(&mut router));
2723 if context.streams[0].metrics.start.is_none() {
2724 break;
2725 }
2726 }
2727 })
2728 }
2729
2730 /// A request that fails to parse after its response started on the wire
2731 /// (a backend answering early and streaming its body while the client
2732 /// still uploads a chunked body, then a malformed chunk) must cut that
2733 /// response, never splice a complete `HTTP/1.1 400` into its body, which
2734 /// the client would read as part of the first response.
2735 ///
2736 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the
2737 /// `Position::Server if stream.back.consumed` arm. The 400 is then
2738 /// written: `no 400 may follow a response already on the wire`.
2739 #[test]
2740 fn a_request_error_after_the_response_started_cuts_it_instead_of_splicing_a_400() {
2741 use std::io::Read;
2742
2743 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2744 let mut context = test_context(&pool);
2745 context
2746 .create_stream(Ulid::generate(), 1 << 16)
2747 .expect("the test pool must hand out stream buffers");
2748 let (front_socket, mut front_peer) = connected_socket();
2749 front_peer
2750 .set_nonblocking(true)
2751 .expect("the loopback peer must switch to non-blocking");
2752 let mut server = h1_of(Connection::new_h1_server(
2753 Ulid::generate(),
2754 front_socket,
2755 Duration::from_secs(60),
2756 ));
2757 server.stream = Some(0);
2758 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2759 // The early response already put bytes on the client's wire.
2760 context.streams[0].back.consumed = true;
2761
2762 front_peer
2763 .write_all(
2764 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\nZZ\r\n",
2765 )
2766 .expect("the loopback peer must accept the staged request bytes");
2767 let mut result = MuxResult::Continue;
2768 for _ in 0..64 {
2769 server.readiness.event.insert(Ready::READABLE);
2770 result = server.readable(&mut context, EndpointClient(&mut router));
2771 if context.streams[0].front.is_error() {
2772 break;
2773 }
2774 }
2775 assert!(
2776 context.streams[0].front.is_error(),
2777 "premise: the malformed chunk must be rejected by the parse"
2778 );
2779
2780 let mut received = Vec::new();
2781 for _ in 0..16 {
2782 server.readiness.event.insert(Ready::WRITABLE);
2783 if server.readiness.filter_interest().is_writable() {
2784 server.writable(&mut context, EndpointClient(&mut router));
2785 }
2786 let mut buf = [0u8; 4096];
2787 if let Ok(n) = front_peer.read(&mut buf) {
2788 received.extend_from_slice(&buf[..n]);
2789 }
2790 }
2791 assert!(
2792 !received.windows(12).any(|w| w == b"HTTP/1.1 400"),
2793 "no 400 may follow a response already on the wire, got {:?}",
2794 String::from_utf8_lossy(&received)
2795 );
2796 assert_ne!(
2797 context.streams[0].context.status,
2798 Some(400),
2799 "the started response must not be replaced by a 400"
2800 );
2801 assert!(
2802 context.streams[0].back.is_error() && matches!(result, MuxResult::CloseSession),
2803 "the response is cut and the session closes, got {:?} / {:?}",
2804 context.streams[0].back.parsing_phase,
2805 result
2806 );
2807 }
2808
2809 /// A request that fails to parse after its stream was linked, and after
2810 /// the backend's complete response already started on the wire, cuts that
2811 /// response and also ends the backend stream (sozu-proxy/sozu#1716). The
2812 /// backend connection holds part of the rejected request, so it must leave
2813 /// the `backend_streams` reverse index and be disconnected. It must not stay
2814 /// attached to the stream slot, and must not go back to the keep-alive pool,
2815 /// although its response is complete.
2816 ///
2817 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the block of the
2818 /// `Position::Server if stream.back.consumed` arm that clears
2819 /// `keep_alive_backend` and calls `endpoint.end_stream`. The reverse index
2820 /// then still lists the stream: `the rejected stream must leave the
2821 /// backend reverse index`. Keeping `end_stream` but not the flag instead
2822 /// pools the connection: `a backend holding part of a rejected request
2823 /// must be disconnected, not pooled`.
2824 #[test]
2825 fn a_request_error_after_a_linked_response_started_ends_the_backend_stream() {
2826 const BACKEND: mio::Token = mio::Token(1);
2827
2828 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2829 let mut context = test_context(&pool);
2830 context
2831 .create_stream(Ulid::generate(), 1 << 16)
2832 .expect("the test pool must hand out stream buffers");
2833 let (front_socket, mut front_peer) = connected_socket();
2834 let mut frontend =
2835 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2836 if let Connection::H1(server) = &mut frontend {
2837 server.stream = Some(0);
2838 }
2839 let (back_socket, mut back_peer) = connected_socket();
2840 let backend_ulid = Ulid::generate();
2841 let mut client = h1_of(Connection::new_h1_client(
2842 backend_ulid,
2843 SessionTcpStream::new(back_socket, backend_ulid, None),
2844 "test-cluster".into(),
2845 test_backend_id(cached_peer()),
2846 Duration::from_secs(60),
2847 ));
2848 if let Position::Client(_, _, status) = &mut client.position {
2849 *status = BackendStatus::KeepAlive;
2850 }
2851 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2852
2853 // The request head and a first chunk: the stream is routed.
2854 front_peer
2855 .write_all(
2856 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHello\r\n",
2857 )
2858 .expect("the loopback peer must accept the staged request head");
2859 for _ in 0..64 {
2860 frontend.readiness_mut().event.insert(Ready::READABLE);
2861 frontend.readable(&mut context, EndpointClient(&mut router));
2862 if context.streams[0].state == StreamState::Link {
2863 break;
2864 }
2865 }
2866 assert_eq!(
2867 context.streams[0].state,
2868 StreamState::Link,
2869 "premise: the request head must be parsed and queued for linking"
2870 );
2871
2872 // What the router does with a pooled backend connection.
2873 assert!(
2874 client.start_stream(0, &mut context),
2875 "premise: the pooled backend must accept the stream"
2876 );
2877 context.link_stream(0, BACKEND);
2878 router.backends.insert(BACKEND, Connection::H1(client));
2879
2880 // The backend answers early and completely, and that response has
2881 // started on the client's wire.
2882 back_peer
2883 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
2884 .expect("the loopback backend peer must accept the response");
2885 for _ in 0..64 {
2886 let Some(backend) = router.backends.get_mut(&BACKEND) else {
2887 unreachable!("the backend was inserted")
2888 };
2889 backend.readiness_mut().event.insert(Ready::READABLE);
2890 backend.readable(&mut context, EndpointServer(&mut frontend));
2891 if context.streams[0].back.is_terminated() {
2892 break;
2893 }
2894 }
2895 assert!(
2896 context.streams[0].back.is_terminated(),
2897 "premise: the backend response must be read whole"
2898 );
2899 context.streams[0].back.consumed = true;
2900
2901 // A malformed chunk-size line rejects the request.
2902 front_peer
2903 .write_all(b"ZZ\r\n")
2904 .expect("the loopback peer must accept the malformed chunk");
2905 let mut result = MuxResult::Continue;
2906 for _ in 0..64 {
2907 frontend.readiness_mut().event.insert(Ready::READABLE);
2908 result = frontend.readable(&mut context, EndpointClient(&mut router));
2909 if context.streams[0].front.is_error() {
2910 break;
2911 }
2912 }
2913 assert!(
2914 context.streams[0].front.is_error(),
2915 "premise: the malformed chunk must be rejected by the parse"
2916 );
2917 assert!(
2918 matches!(result, MuxResult::CloseSession),
2919 "the started response is cut and the session closes, got {result:?}"
2920 );
2921
2922 assert!(
2923 context
2924 .backend_streams
2925 .get(&BACKEND)
2926 .is_none_or(|ids| !ids.contains(&0)),
2927 "the rejected stream must leave the backend reverse index"
2928 );
2929 let Some(Connection::H1(client)) = router.backends.get(&BACKEND) else {
2930 unreachable!("the backend was inserted as H1")
2931 };
2932 assert_eq!(
2933 client.stream, None,
2934 "the backend connection must no longer carry the rejected stream"
2935 );
2936 assert!(
2937 matches!(
2938 client.position,
2939 Position::Client(_, _, BackendStatus::Disconnecting)
2940 ),
2941 "a backend holding part of a rejected request must be disconnected, not pooled"
2942 );
2943 }
2944
2945 /// A request that fails to parse after its stream was linked, before any
2946 /// byte of the response reached the client, is answered 400 and also ends
2947 /// the backend stream (sozu-proxy/sozu#1716). The backend connection holds
2948 /// part of the rejected request, so it must leave the `backend_streams`
2949 /// reverse index and be disconnected, not stay attached to the stream slot
2950 /// nor go back to the keep-alive pool, although its response is complete.
2951 ///
2952 /// TO SEE THIS RED: in `ConnectionH1::readable`, delete the block of the
2953 /// `Position::Server` arm (the one that answers 400) that clears the
2954 /// response and calls `endpoint.end_stream`. The reverse index then still
2955 /// lists the stream: `the rejected stream must leave the backend reverse
2956 /// index`.
2957 #[test]
2958 fn a_request_error_answered_400_after_linking_ends_the_backend_stream() {
2959 const BACKEND: mio::Token = mio::Token(1);
2960
2961 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
2962 let mut context = test_context(&pool);
2963 context
2964 .create_stream(Ulid::generate(), 1 << 16)
2965 .expect("the test pool must hand out stream buffers");
2966 let (front_socket, mut front_peer) = connected_socket();
2967 let mut frontend =
2968 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
2969 if let Connection::H1(server) = &mut frontend {
2970 server.stream = Some(0);
2971 }
2972 let (back_socket, mut back_peer) = connected_socket();
2973 let backend_ulid = Ulid::generate();
2974 let mut client = h1_of(Connection::new_h1_client(
2975 backend_ulid,
2976 SessionTcpStream::new(back_socket, backend_ulid, None),
2977 "test-cluster".into(),
2978 test_backend_id(cached_peer()),
2979 Duration::from_secs(60),
2980 ));
2981 if let Position::Client(_, _, status) = &mut client.position {
2982 *status = BackendStatus::KeepAlive;
2983 }
2984 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
2985
2986 // The request head and a first chunk: the stream is routed.
2987 front_peer
2988 .write_all(
2989 b"POST /upload HTTP/1.1\r\nHost: localhost\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHello\r\n",
2990 )
2991 .expect("the loopback peer must accept the staged request head");
2992 for _ in 0..64 {
2993 frontend.readiness_mut().event.insert(Ready::READABLE);
2994 frontend.readable(&mut context, EndpointClient(&mut router));
2995 if context.streams[0].state == StreamState::Link {
2996 break;
2997 }
2998 }
2999 assert_eq!(
3000 context.streams[0].state,
3001 StreamState::Link,
3002 "premise: the request head must be parsed and queued for linking"
3003 );
3004
3005 // What the router does with a pooled backend connection.
3006 assert!(
3007 client.start_stream(0, &mut context),
3008 "premise: the pooled backend must accept the stream"
3009 );
3010 context.link_stream(0, BACKEND);
3011 router.backends.insert(BACKEND, Connection::H1(client));
3012
3013 // The backend answers early and completely, but no byte of that
3014 // response has reached the client yet.
3015 back_peer
3016 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
3017 .expect("the loopback backend peer must accept the response");
3018 for _ in 0..64 {
3019 let Some(backend) = router.backends.get_mut(&BACKEND) else {
3020 unreachable!("the backend was inserted")
3021 };
3022 backend.readiness_mut().event.insert(Ready::READABLE);
3023 backend.readable(&mut context, EndpointServer(&mut frontend));
3024 if context.streams[0].back.is_terminated() {
3025 break;
3026 }
3027 }
3028 assert!(
3029 context.streams[0].back.is_terminated(),
3030 "premise: the backend response must be read whole"
3031 );
3032 assert!(
3033 !context.streams[0].back.consumed,
3034 "premise: the response must not have started on the client's wire"
3035 );
3036
3037 // A malformed chunk-size line rejects the request.
3038 front_peer
3039 .write_all(b"ZZ\r\n")
3040 .expect("the loopback peer must accept the malformed chunk");
3041 let mut result = MuxResult::Continue;
3042 for _ in 0..64 {
3043 frontend.readiness_mut().event.insert(Ready::READABLE);
3044 result = frontend.readable(&mut context, EndpointClient(&mut router));
3045 if context.streams[0].front.is_error() {
3046 break;
3047 }
3048 }
3049 assert!(
3050 context.streams[0].front.is_error(),
3051 "premise: the malformed chunk must be rejected by the parse"
3052 );
3053 assert!(
3054 matches!(result, MuxResult::Continue),
3055 "the request is answered 400 on the client connection, got {result:?}"
3056 );
3057
3058 assert!(
3059 context
3060 .backend_streams
3061 .get(&BACKEND)
3062 .is_none_or(|ids| !ids.contains(&0)),
3063 "the rejected stream must leave the backend reverse index"
3064 );
3065 let Some(Connection::H1(client)) = router.backends.get(&BACKEND) else {
3066 unreachable!("the backend was inserted as H1")
3067 };
3068 assert_eq!(
3069 client.stream, None,
3070 "the backend connection must no longer carry the rejected stream"
3071 );
3072 assert!(
3073 matches!(
3074 client.position,
3075 Position::Client(_, _, BackendStatus::Disconnecting)
3076 ),
3077 "a backend holding part of a rejected request must be disconnected, not pooled"
3078 );
3079 }
3080
3081 /// The access log of an H1 request carries the frontend round-trip time,
3082 /// the connection's one sample, taken here because this is its first
3083 /// line, and no backend one when the request never reached a backend.
3084 ///
3085 /// TO SEE THIS RED: in `ConnectionH1::writable`, at the `H1::Complete`
3086 /// access log that writes the rejected request's 400, replace the
3087 /// `self.rtt()` of `client_rtt` with `None`. The
3088 /// line then carries `-` in that cell and the first assertion fails.
3089 #[test]
3090 fn the_h1_access_log_carries_the_frontend_rtt() {
3091 let output =
3092 access_log_of_a_rejected_h1_request(b"GET /rtt HTTP/1.1\r\nBad Header: x\r\n\r\n");
3093 let line = output
3094 .lines()
3095 .find(|line| line.contains("GET /rtt 400"))
3096 .unwrap_or_else(|| panic!("the 400 must be logged, got: {output}"));
3097 let cells: Vec<&str> = line
3098 .split_whitespace()
3099 .find_map(|token| {
3100 let cells: Vec<&str> = token.split('/').collect();
3101 (cells.len() == 5).then_some(cells)
3102 })
3103 .unwrap_or_else(|| panic!("the line must carry the five durations: {line}"));
3104 assert_ne!(
3105 cells[3], "-",
3106 "the H1 access log must carry the frontend client_rtt, got: {line}"
3107 );
3108 assert_eq!(
3109 cells[4], "-",
3110 "a request that never reached a backend has no server_rtt, got: {line}"
3111 );
3112 }
3113
3114 /// Twenty keep-alive requests on one frontend connection, each answered
3115 /// through the same backend connection taken back out of the keep-alive
3116 /// pool, cost one `getsockopt(TCP_INFO)` per side — not one per request
3117 /// and side — and every one of the twenty access lines still carries both
3118 /// RTTs, the same value on each line.
3119 ///
3120 /// Driven through the real `H1::Complete` site of
3121 /// `ConnectionH1::writable` and the real `EndpointClient::peer_rtt`, with
3122 /// the backend recycled by `ConnectionH1::end_stream` and
3123 /// `ConnectionH1::start_stream` exactly as a `Mux` does between two
3124 /// requests. The request side is staged rather than parsed: what is under
3125 /// test is the log emission, not routing.
3126 ///
3127 /// TO SEE THIS RED: in `memoized_rtt` (`lib/src/protocol/mux/mod.rs`),
3128 /// delete the early return on `memo.get()`. Every request then reads both
3129 /// sockets again and the count assertion fails with `left: 40`,
3130 /// `right: 2`.
3131 #[test]
3132 fn keep_alive_requests_read_tcp_info_once_per_connection() {
3133 const REQUESTS: usize = 20;
3134 const BACKEND: mio::Token = mio::Token(1);
3135 let (reads_sender, reads_receiver) = std::sync::mpsc::channel();
3136
3137 let output = crate::capture_test_logs(move || {
3138 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3139 let mut context = test_context(&pool);
3140 context
3141 .create_stream(Ulid::generate(), 1 << 16)
3142 .expect("the test pool must hand out stream buffers");
3143 let (front_socket, mut front_peer) = connected_socket();
3144 front_peer
3145 .set_nonblocking(true)
3146 .expect("the frontend peer is drained without blocking");
3147 let mut frontend =
3148 Connection::new_h1_server(Ulid::generate(), front_socket, Duration::from_secs(60));
3149 let (back_socket, mut back_peer) = connected_socket();
3150 let backend_ulid = Ulid::generate();
3151 let mut client = h1_of(Connection::new_h1_client(
3152 backend_ulid,
3153 SessionTcpStream::new(back_socket, backend_ulid, None),
3154 "test-cluster".into(),
3155 test_backend_id(cached_peer()),
3156 Duration::from_secs(60),
3157 ));
3158 // The first request finds the connection freshly dialled; every
3159 // later one takes it back out of the pool through `start_stream`.
3160 if let Position::Client(_, _, status) = &mut client.position {
3161 *status = BackendStatus::KeepAlive;
3162 }
3163 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3164 router.backends.insert(BACKEND, Connection::H1(client));
3165
3166 let before = tcp_info_reads();
3167 let mut drained = [0u8; 4096];
3168 for request in 0..REQUESTS {
3169 let Some(Connection::H1(client)) = router.backends.get_mut(&BACKEND) else {
3170 unreachable!("the backend was inserted as H1")
3171 };
3172 assert!(
3173 client.start_stream(0, &mut context),
3174 "premise: the pooled backend must accept request {request}"
3175 );
3176 let stream = &mut context.streams[0];
3177 stream.state = StreamState::Linked(BACKEND);
3178 stream.context.keep_alive_frontend = true;
3179 // The staged request is complete and fully written: only then
3180 // may either connection outlive it (sozu-proxy/sozu#1721).
3181 stream.front.parsing_phase = kawa::ParsingPhase::Terminated;
3182 stream.metrics.service_start();
3183 stream.metrics.backend_id = Some("test-backend".into());
3184 stream.metrics.backend_start();
3185 stream.metrics.backend_connected();
3186
3187 back_peer
3188 .write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok")
3189 .expect("the loopback backend peer must accept the response");
3190 for _ in 0..64 {
3191 client.readiness.event.insert(Ready::READABLE);
3192 client.readable(&mut context, EndpointServer(&mut frontend));
3193 if context.streams[0].back.is_terminated() {
3194 break;
3195 }
3196 }
3197 assert!(
3198 context.streams[0].back.is_terminated(),
3199 "premise: response {request} must be read whole"
3200 );
3201
3202 for _ in 0..64 {
3203 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3204 frontend.writable(&mut context, EndpointClient(&mut router));
3205 if context.streams[0].metrics.start.is_none() {
3206 break;
3207 }
3208 }
3209 assert_eq!(
3210 context.streams[0].state,
3211 StreamState::Idle,
3212 "premise: request {request} must complete through the \
3213 keep-alive branch of `H1::Complete`"
3214 );
3215 while let Ok(read) = std::io::Read::read(&mut front_peer, &mut drained) {
3216 if read == 0 {
3217 break;
3218 }
3219 }
3220 }
3221 reads_sender
3222 .send(tcp_info_reads() - before)
3223 .expect("the test thread must report its TCP_INFO reads");
3224 });
3225
3226 let lines: Vec<&str> = output
3227 .lines()
3228 .filter(|line| line.contains("H1::Complete"))
3229 .collect();
3230 assert_eq!(
3231 lines.len(),
3232 REQUESTS,
3233 "every request must be logged, got: {output}"
3234 );
3235 let mut rtts = Vec::with_capacity(REQUESTS);
3236 for line in &lines {
3237 let cells: Vec<&str> = line
3238 .split_whitespace()
3239 .find_map(|token| {
3240 let cells: Vec<&str> = token.split('/').collect();
3241 (cells.len() == 5).then_some(cells)
3242 })
3243 .unwrap_or_else(|| panic!("the line must carry the five durations: {line}"));
3244 assert_ne!(cells[3], "-", "every line must carry client_rtt: {line}");
3245 assert_ne!(cells[4], "-", "every line must carry server_rtt: {line}");
3246 rtts.push((cells[3], cells[4]));
3247 }
3248 assert_eq!(
3249 reads_receiver
3250 .recv()
3251 .expect("the test thread must report its TCP_INFO reads"),
3252 2,
3253 "{REQUESTS} keep-alive requests must read TCP_INFO once for the \
3254 frontend and once for the backend"
3255 );
3256 assert!(
3257 rtts.windows(2).all(|pair| pair[0] == pair[1]),
3258 "every request of one connection reports that connection's one \
3259 sample, got: {rtts:?}"
3260 );
3261 }
3262
3263 /// A backend connection that answered before the whole request was
3264 /// written to it still expects the rest of the body: `end_stream` must not
3265 /// pool it, or the next request would be read as that body
3266 /// (sozu-proxy/sozu#1721). The same connection, once the request is
3267 /// complete too, is pooled: that half pins the guard is not a blanket
3268 /// refusal.
3269 ///
3270 /// A request received whole but not yet fully written upstream is just
3271 /// as incomplete for that backend.
3272 ///
3273 /// TO SEE THIS RED: in `ConnectionH1::end_stream`, drop the two
3274 /// `stream.front` conditions from the `BackendStatus::Connected` arm. The
3275 /// incomplete request then leaves the connection `KeepAlive`.
3276 #[test]
3277 fn a_backend_that_answered_before_the_whole_request_is_not_pooled() {
3278 const BACKEND: mio::Token = mio::Token(1);
3279 // (request phase, request bytes still unwritten, pooled?)
3280 for (request_phase, unwritten, expect_pooled) in [
3281 (kawa::ParsingPhase::Body, false, false),
3282 (kawa::ParsingPhase::Chunks { first: false }, false, false),
3283 (kawa::ParsingPhase::Terminated, true, false),
3284 (kawa::ParsingPhase::Terminated, false, true),
3285 ] {
3286 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3287 let mut context = test_context(&pool);
3288 context
3289 .create_stream(Ulid::generate(), 1 << 16)
3290 .expect("the test pool must hand out stream buffers");
3291 let (back_socket, _back_peer) = connected_socket();
3292 let backend_ulid = Ulid::generate();
3293 let mut client = h1_of(Connection::new_h1_client(
3294 backend_ulid,
3295 SessionTcpStream::new(back_socket, backend_ulid, None),
3296 "test-cluster".into(),
3297 test_backend_id(cached_peer()),
3298 Duration::from_secs(60),
3299 ));
3300 if let Position::Client(_, _, status) = &mut client.position {
3301 *status = BackendStatus::Connected;
3302 }
3303 client.stream = Some(0);
3304 let stream = &mut context.streams[0];
3305 stream.state = StreamState::Linked(BACKEND);
3306 stream.context.keep_alive_backend = true;
3307 // The response is complete; the request is as staged.
3308 stream.back.parsing_phase = kawa::ParsingPhase::Terminated;
3309 stream.front.parsing_phase = request_phase;
3310 if unwritten {
3311 // Received whole, but its end was never written upstream.
3312 stream
3313 .front
3314 .blocks
3315 .push_back(kawa::Block::Flags(kawa::Flags {
3316 end_body: true,
3317 end_chunk: false,
3318 end_header: false,
3319 end_stream: true,
3320 }));
3321 }
3322
3323 client.end_stream(0, &mut context);
3324
3325 let pooled = matches!(
3326 client.position,
3327 Position::Client(_, _, BackendStatus::KeepAlive)
3328 );
3329 assert_eq!(
3330 pooled,
3331 expect_pooled,
3332 "a request in {request_phase:?} (unwritten bytes: {unwritten}) must {}pool the backend connection",
3333 if expect_pooled { "" } else { "not " }
3334 );
3335 }
3336 }
3337
3338 /// A frontend socket whose `close_notify` is left pending by the close and
3339 /// flushed by the next write, as a TLS socket whose peer had not drained
3340 /// it yet: the close is deferred, and `writable` runs again on the same
3341 /// connection once the flush went through.
3342 #[derive(Debug)]
3343 struct PendingCloseNotifySocket {
3344 stream: mio::net::TcpStream,
3345 closing: bool,
3346 }
3347
3348 impl SocketHandler for PendingCloseNotifySocket {
3349 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
3350 self.stream.socket_read(buf)
3351 }
3352
3353 fn socket_write(&mut self, buf: &[u8]) -> (usize, SocketResult) {
3354 self.stream.socket_write(buf)
3355 }
3356
3357 fn socket_write_vectored(&mut self, bufs: &[IoSlice]) -> (usize, SocketResult) {
3358 // The pending `close_notify` leaves with this write.
3359 self.closing = false;
3360 self.stream.socket_write_vectored(bufs)
3361 }
3362
3363 fn socket_wants_write(&self) -> bool {
3364 self.closing
3365 }
3366
3367 fn socket_close(&mut self) {
3368 self.closing = true;
3369 }
3370
3371 fn socket_ref(&self) -> &mio::net::TcpStream {
3372 &self.stream
3373 }
3374
3375 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
3376 &mut self.stream
3377 }
3378
3379 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
3380 self.stream.peer_addr().ok()
3381 }
3382
3383 fn protocol(&self) -> crate::socket::TransportProtocol {
3384 crate::socket::TransportProtocol::Tcp
3385 }
3386
3387 fn read_error(&self) {}
3388
3389 fn write_error(&self) {}
3390 }
3391
3392 /// A frontend socket that still reports buffered TLS records and answers
3393 /// every write with `status`, as a TLS socket whose peer stopped reading
3394 /// (`WouldBlock`) or whose write met a socket error (`Error`).
3395 #[derive(Debug)]
3396 struct StuckTlsSocket {
3397 stream: mio::net::TcpStream,
3398 status: SocketResult,
3399 }
3400
3401 impl SocketHandler for StuckTlsSocket {
3402 fn socket_read(&mut self, buf: &mut [u8]) -> (usize, SocketResult) {
3403 self.stream.socket_read(buf)
3404 }
3405
3406 fn socket_write(&mut self, _buf: &[u8]) -> (usize, SocketResult) {
3407 (0, self.status)
3408 }
3409
3410 fn socket_write_vectored(&mut self, _bufs: &[IoSlice]) -> (usize, SocketResult) {
3411 (0, self.status)
3412 }
3413
3414 fn socket_wants_write(&self) -> bool {
3415 true
3416 }
3417
3418 fn socket_ref(&self) -> &mio::net::TcpStream {
3419 &self.stream
3420 }
3421
3422 fn socket_mut(&mut self) -> &mut mio::net::TcpStream {
3423 &mut self.stream
3424 }
3425
3426 fn peer_addr(&self) -> Option<std::net::SocketAddr> {
3427 self.stream.peer_addr().ok()
3428 }
3429
3430 fn protocol(&self) -> crate::socket::TransportProtocol {
3431 crate::socket::TransportProtocol::Tls1_3
3432 }
3433
3434 fn read_error(&self) {}
3435
3436 fn write_error(&self) {}
3437 }
3438
3439 /// A TLS flush that did not answer `Continue` leaves WRITABLE to the next
3440 /// kernel edge, even while the socket still reports records: re-raising
3441 /// it would make `Mux::ready_inner` retry the same refused or failed
3442 /// write on every inner iteration until `MAX_LOOP_ITERATIONS`
3443 /// (sozu-proxy/sozu#1780).
3444 ///
3445 /// Both flushes are covered: the one with no stream, and the TLS-only
3446 /// flush of a stream with nothing left to write.
3447 ///
3448 /// On this server-side connection an `Error` flush instead closes the
3449 /// session through `ConnectionH1::client_write_failed`, before that check
3450 /// (sozu-proxy/sozu#1779): it stops reporting pending output, and leaves
3451 /// WRITABLE unraised too.
3452 ///
3453 /// TO SEE THIS RED: in either flush of `ConnectionH1::writable`, drop the
3454 /// `status == SocketResult::Continue` condition. The `WouldBlock` case
3455 /// then re-raises WRITABLE.
3456 #[test]
3457 fn a_tls_flush_that_did_not_continue_leaves_writable_to_the_kernel() {
3458 for (status, with_stream) in [
3459 (SocketResult::WouldBlock, false),
3460 (SocketResult::Error, false),
3461 (SocketResult::WouldBlock, true),
3462 (SocketResult::Error, true),
3463 ] {
3464 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 4, 16384)));
3465 let mut context = test_context(&pool);
3466 if with_stream {
3467 context
3468 .create_stream(Ulid::generate(), 1 << 16)
3469 .expect("the test pool must hand out stream buffers");
3470 }
3471 let (socket, _peer) = connected_socket();
3472 let mut frontend = Connection::new_h1_server(
3473 Ulid::generate(),
3474 StuckTlsSocket {
3475 stream: socket,
3476 status,
3477 },
3478 Duration::from_secs(60),
3479 );
3480 if let Connection::H1(server) = &mut frontend {
3481 server.stream = with_stream.then_some(0);
3482 }
3483 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3484 frontend.readiness_mut().interest.insert(Ready::WRITABLE);
3485 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3486
3487 let result = frontend.writable(&mut context, EndpointClient(&mut router));
3488
3489 if status == SocketResult::Error {
3490 assert!(
3491 matches!(result, MuxResult::CloseSession),
3492 "a failed flush (stream: {with_stream}) must close the session"
3493 );
3494 assert!(
3495 !frontend.has_pending_write(),
3496 "a failed flush (stream: {with_stream}) must stop reporting output"
3497 );
3498 } else {
3499 assert!(matches!(result, MuxResult::Continue));
3500 assert!(
3501 frontend.has_pending_write(),
3502 "premise: the socket must still report records"
3503 );
3504 }
3505 assert!(
3506 !frontend.readiness().event.is_writable(),
3507 "a flush that answered {status:?} (stream: {with_stream}) must not re-raise \
3508 WRITABLE, got {:?}",
3509 frontend.readiness()
3510 );
3511 }
3512 }
3513
3514 /// Once `writable` decided to close after a response, a deferred TLS
3515 /// close must not run the completion again: the next pass would log the
3516 /// request a second time, count it twice, and re-take the keep-alive
3517 /// decision after `close_notify` — keeping the connection if the body
3518 /// finished in between (sozu-proxy/sozu#1721).
3519 ///
3520 /// Once `close_notify` is flushed, the request still incomplete, the
3521 /// connection starts its lingering close (RFC 9112 §9.6) and closes the
3522 /// session once the client closes.
3523 ///
3524 /// TO SEE THIS RED: in `ConnectionH1::writable`, delete the
3525 /// `stream.context.closing = true;` of the close path. The second pass
3526 /// then logs a second `H1::Complete` line and resets the stream to
3527 /// `Idle` instead of closing the session.
3528 #[test]
3529 fn a_deferred_tls_close_completes_the_response_once() {
3530 const BACKEND: mio::Token = mio::Token(1);
3531 let (states_sender, states_receiver) = std::sync::mpsc::channel();
3532
3533 let output = crate::capture_test_logs(move || {
3534 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3535 let mut context = test_context(&pool);
3536 context
3537 .create_stream(Ulid::generate(), 1 << 16)
3538 .expect("the test pool must hand out stream buffers");
3539 let (front_socket, mut front_peer) = connected_socket();
3540 front_peer
3541 .set_nonblocking(true)
3542 .expect("the frontend peer is drained without blocking");
3543 let mut frontend = Connection::new_h1_server(
3544 Ulid::generate(),
3545 PendingCloseNotifySocket {
3546 stream: front_socket,
3547 closing: false,
3548 },
3549 Duration::from_secs(60),
3550 );
3551 if let Connection::H1(server) = &mut frontend {
3552 server.stream = Some(0);
3553 }
3554 let (back_socket, mut back_peer) = connected_socket();
3555 let backend_ulid = Ulid::generate();
3556 let mut client = h1_of(Connection::new_h1_client(
3557 backend_ulid,
3558 SessionTcpStream::new(back_socket, backend_ulid, None),
3559 "test-cluster".into(),
3560 test_backend_id(cached_peer()),
3561 Duration::from_secs(60),
3562 ));
3563 if let Position::Client(_, _, status) = &mut client.position {
3564 *status = BackendStatus::KeepAlive;
3565 }
3566 assert!(
3567 client.start_stream(0, &mut context),
3568 "premise: the backend must accept the request"
3569 );
3570 let stream = &mut context.streams[0];
3571 stream.state = StreamState::Linked(BACKEND);
3572 stream.context.keep_alive_frontend = true;
3573 // An upload still in its body: the response completes first.
3574 stream.front.parsing_phase = kawa::ParsingPhase::Body;
3575 stream.metrics.service_start();
3576 stream.metrics.backend_id = Some("test-backend".into());
3577 stream.metrics.backend_start();
3578 stream.metrics.backend_connected();
3579
3580 back_peer
3581 .write_all(b"HTTP/1.1 413 Content Too Large\r\nContent-Length: 0\r\n\r\n")
3582 .expect("the loopback backend peer must accept the response");
3583 for _ in 0..64 {
3584 client.readiness.event.insert(Ready::READABLE);
3585 client.readable(&mut context, EndpointServer(&mut frontend));
3586 if context.streams[0].back.is_terminated() {
3587 break;
3588 }
3589 }
3590 assert!(
3591 context.streams[0].back.is_terminated(),
3592 "premise: the early response must be read whole"
3593 );
3594 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3595 router.backends.insert(BACKEND, Connection::H1(client));
3596
3597 let mut states = Vec::new();
3598 for pass in 0..2 {
3599 if pass == 1 {
3600 // The body finishes after the close began.
3601 context.streams[0].front.parsing_phase = kawa::ParsingPhase::Terminated;
3602 }
3603 frontend.readiness_mut().event.insert(Ready::WRITABLE);
3604 let result = frontend.writable(&mut context, EndpointClient(&mut router));
3605 states.push((result, context.streams[0].state));
3606 if pass == 0 {
3607 assert_eq!(
3608 context.streams[0].state,
3609 StreamState::Unlinked,
3610 "premise: the first pass completes the response and closes"
3611 );
3612 }
3613 }
3614 let Connection::H1(server) = &mut frontend else {
3615 unreachable!("the frontend is H1");
3616 };
3617 let lingering = server.is_lingering();
3618 let peer_eof = read_to_eof(&mut front_peer).is_some();
3619 // The client closes: the drain meets its EOF and the session closes.
3620 drop(front_peer);
3621 let mut after_client_close = MuxResult::Continue;
3622 for _ in 0..1000 {
3623 server.readiness.event.insert(Ready::READABLE);
3624 after_client_close = server.readable(&mut context, EndpointClient(&mut router));
3625 if matches!(after_client_close, MuxResult::CloseSession) {
3626 break;
3627 }
3628 std::thread::sleep(Duration::from_millis(1));
3629 }
3630 states_sender
3631 .send((states, lingering, peer_eof, after_client_close))
3632 .expect("the test thread must report its states");
3633 });
3634
3635 let (states, lingering, peer_eof, after_client_close) = states_receiver
3636 .recv()
3637 .expect("the test thread must report its states");
3638 let completions = output
3639 .lines()
3640 .filter(|line| line.contains("H1::Complete"))
3641 .count();
3642 assert_eq!(
3643 completions, 1,
3644 "the response must be completed and logged once, got: {output}"
3645 );
3646 for (pass, (_, state)) in states.iter().enumerate() {
3647 assert_ne!(
3648 *state,
3649 StreamState::Idle,
3650 "pass {pass}: no keep-alive reset after the close began"
3651 );
3652 }
3653 assert!(
3654 matches!(states[0].0, MuxResult::Continue),
3655 "the first pass defers the close behind the pending close_notify"
3656 );
3657 assert!(
3658 matches!(states[1].0, MuxResult::Continue) && lingering,
3659 "once close_notify is flushed the connection lingers, got {:?}",
3660 states[1].0
3661 );
3662 assert!(
3663 peer_eof,
3664 "the lingering close sends the FIN after the response"
3665 );
3666 assert!(
3667 matches!(after_client_close, MuxResult::CloseSession),
3668 "the session closes once the client closed, got {after_client_close:?}"
3669 );
3670 }
3671
3672 /// Read `peer` until its EOF, retrying a nonblocking read for up to about
3673 /// one second. `None` when no EOF arrived in that time.
3674 fn read_to_eof(peer: &mut std::net::TcpStream) -> Option<Vec<u8>> {
3675 let mut received = Vec::new();
3676 let mut buf = [0u8; 4096];
3677 for _ in 0..1000 {
3678 match std::io::Read::read(peer, &mut buf) {
3679 Ok(0) => return Some(received),
3680 Ok(size) => received.extend_from_slice(&buf[..size]),
3681 Err(e) if e.kind() == std::io::ErrorKind::WouldBlock => {
3682 std::thread::sleep(Duration::from_millis(1));
3683 }
3684 Err(_) => return None,
3685 }
3686 }
3687 None
3688 }
3689
3690 /// A frontend connection lingering over a live loopback socket, and the
3691 /// client end of that socket.
3692 fn lingering_frontend(
3693 deadline: Instant,
3694 ) -> (ConnectionH1<SessionTcpStream>, std::net::TcpStream) {
3695 let (front_socket, front_peer) = connected_socket();
3696 let ulid = Ulid::generate();
3697 let mut server = h1_of(Connection::new_h1_server(
3698 ulid,
3699 SessionTcpStream::new(front_socket, ulid, None),
3700 Duration::from_secs(10),
3701 ));
3702 server.linger = Linger::Pending { deadline };
3703 assert!(
3704 matches!(
3705 server.defer_close_for_tls_flush("test"),
3706 MuxResult::Continue
3707 ),
3708 "a pending linger starts instead of closing"
3709 );
3710 (server, front_peer)
3711 }
3712
3713 /// Drive `readable` until it closes the session or reads everything
3714 /// queued. Returns the last result.
3715 fn drain_passes<L: ListenerHandler + L7ListenerHandler>(
3716 server: &mut ConnectionH1<SessionTcpStream>,
3717 context: &mut Context<L>,
3718 router: &mut Router,
3719 ) -> MuxResult {
3720 let mut result = MuxResult::Continue;
3721 for _ in 0..100 {
3722 server.readiness.event.insert(Ready::READABLE);
3723 result = server.readable(context, EndpointClient(router));
3724 if matches!(result, MuxResult::CloseSession) {
3725 break;
3726 }
3727 std::thread::sleep(Duration::from_millis(1));
3728 }
3729 result
3730 }
3731
3732 /// RFC 9112 §9.6 lingering close: the write side is shut down first, the
3733 /// rest of the request is read and dropped without pushing the deadline
3734 /// out, and the drain ends on the client's EOF.
3735 ///
3736 /// TO SEE THIS RED: in `ConnectionH1::readable`, move the
3737 /// `if self.is_lingering()` early return after `self.arm_timeout(...)`:
3738 /// the deadline moves with each read.
3739 #[test]
3740 fn a_lingering_close_half_closes_then_drains_to_the_client_eof() {
3741 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3742 let mut context = test_context(&pool);
3743 context
3744 .create_stream(Ulid::generate(), 1 << 16)
3745 .expect("the test pool must hand out stream buffers");
3746 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3747 let deadline = Instant::now() + Duration::from_secs(10);
3748 let (mut server, mut front_peer) = lingering_frontend(deadline);
3749
3750 assert!(server.is_lingering(), "the connection drains");
3751 assert_eq!(
3752 server.poll_timeout(),
3753 Some(deadline),
3754 "the drain is bounded"
3755 );
3756 assert!(
3757 !server.readiness.interest.is_writable(),
3758 "nothing is written while lingering"
3759 );
3760 assert_eq!(
3761 read_to_eof(&mut front_peer),
3762 Some(Vec::new()),
3763 "the client sees the FIN while it may still send"
3764 );
3765
3766 // The client keeps sending: sozu drops it, and the deadline stays.
3767 front_peer
3768 .write_all(&vec![b'y'; 100 * 1024])
3769 .expect("the client may still send after the FIN");
3770 context.now = Instant::now();
3771 let result = drain_passes(&mut server, &mut context, &mut router);
3772 assert!(
3773 matches!(result, MuxResult::Continue),
3774 "the drain waits for more, got {result:?}"
3775 );
3776 match server.linger {
3777 Linger::Draining { remaining, .. } => assert_eq!(
3778 remaining,
3779 LINGER_MAX_BYTES - 100 * 1024,
3780 "every byte sent is drained and counted"
3781 ),
3782 other => panic!("the connection must still drain, got {other:?}"),
3783 }
3784 assert_eq!(
3785 server.poll_timeout(),
3786 Some(deadline),
3787 "a drained read never pushes the deadline out"
3788 );
3789
3790 drop(front_peer);
3791 let result = drain_passes(&mut server, &mut context, &mut router);
3792 assert!(
3793 matches!(result, MuxResult::CloseSession),
3794 "the client's EOF ends the drain, got {result:?}"
3795 );
3796 }
3797
3798 /// The drain is bounded in bytes and in time: past either bound the
3799 /// session closes although the client is still sending.
3800 ///
3801 /// TO SEE THIS RED: in `ConnectionH1::drain_linger`, read `buf.len()`
3802 /// bytes instead of `remaining.min(buf.len())` (the budget case reads
3803 /// past its budget), or delete the `now >= deadline` check (the deadline
3804 /// case keeps draining).
3805 #[test]
3806 fn a_lingering_close_stops_at_its_byte_budget_and_its_deadline() {
3807 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
3808 let mut context = test_context(&pool);
3809 context
3810 .create_stream(Ulid::generate(), 1 << 16)
3811 .expect("the test pool must hand out stream buffers");
3812 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
3813
3814 // Byte budget: the client sends more than is left of it.
3815 let deadline = Instant::now() + Duration::from_secs(10);
3816 let (mut server, mut front_peer) = lingering_frontend(deadline);
3817 server.linger = Linger::Draining {
3818 deadline,
3819 remaining: 1024,
3820 };
3821 front_peer
3822 .write_all(&[b'y'; 4096])
3823 .expect("the client may still send after the FIN");
3824 context.now = Instant::now();
3825 let result = drain_passes(&mut server, &mut context, &mut router);
3826 assert!(
3827 matches!(result, MuxResult::CloseSession),
3828 "past its byte budget the drain closes, got {result:?}"
3829 );
3830 assert_eq!(
3831 server.linger,
3832 Linger::Draining {
3833 deadline,
3834 remaining: 0
3835 },
3836 "the drain read exactly its budget"
3837 );
3838
3839 // Deadline: the client still sends when it passes.
3840 let (mut server, mut front_peer) = lingering_frontend(deadline);
3841 front_peer
3842 .write_all(&[b'y'; 4096])
3843 .expect("the client may still send after the FIN");
3844 context.now = deadline;
3845 server.readiness.event.insert(Ready::READABLE);
3846 let result = server.readable(&mut context, EndpointClient(&mut router));
3847 assert!(
3848 matches!(result, MuxResult::CloseSession),
3849 "past its deadline the drain closes, got {result:?}"
3850 );
3851 }
3852
3853 /// A header the parser refuses, after a well-formed request line: the
3854 /// access log must still name the method and the path.
3855 ///
3856 /// The authority is asserted ABSENT, on purpose. This request carries a
3857 /// `Host` line before the bad one, so a `Host` block exists here — but a
3858 /// client that puts the bad line first gets no `Host` block at all, so
3859 /// reading it would log an unvalidated value whenever the client chose
3860 /// to. Only an authority the request line itself carries is logged.
3861 ///
3862 /// To SEE THIS RED: in `Stream::generate_access_log`
3863 /// (`lib/src/protocol/mux/stream.rs`), replace the
3864 /// `rejected_request_line(&self.front)` call with
3865 /// `None::<RejectedRequestLine<'_>>`. The line then renders
3866 /// `- - - 400`.
3867 #[test]
3868 fn a_header_parse_error_keeps_the_method_and_path_in_the_access_log() {
3869 let output = access_log_of_a_rejected_h1_request(
3870 b"GET /diag?x=1 HTTP/1.1\r\nHost: example.com\r\nBad Header: x\r\n\r\n",
3871 );
3872
3873 assert!(
3874 output.contains("GET /diag?x=1 400"),
3875 "the access log of a request rejected on a header must carry its \
3876 method and path, got: {output}"
3877 );
3878 assert!(
3879 output.contains("- GET /diag?x=1 400"),
3880 "the authority of an origin-form request rejected on a header must \
3881 not be read from a `Host` line, got: {output}"
3882 );
3883 assert!(
3884 output.contains("H1::Complete"),
3885 "the 400 of a parse error is logged by `ConnectionH1::writable` once \
3886 the answer is written, not at session close, got: {output}"
3887 );
3888 }
3889
3890 /// Sōzu's own CL.TE guard in `HttpContext::on_request_headers`
3891 /// (`lib/src/protocol/kawa_h1/editor.rs`) rejects a request kawa parsed
3892 /// cleanly, and returns before the request line is captured. Here kawa's
3893 /// `process_headers` already resolved the authority and the path, so all
3894 /// three fields are logged.
3895 ///
3896 /// `identity` then `chunked` is the pair that reaches that guard: kawa
3897 /// combines it to a chunked-final coding and accepts it, and the guard
3898 /// refuses to forward two TE lines. A lone `Transfer-Encoding: gzip`
3899 /// would not — kawa refuses it itself, before resolving the authority.
3900 ///
3901 /// To SEE THIS RED: the same substitution as
3902 /// `a_header_parse_error_keeps_the_method_and_path_in_the_access_log`.
3903 #[test]
3904 fn a_cl_te_rejection_keeps_the_whole_request_line_in_the_access_log() {
3905 let output = access_log_of_a_rejected_h1_request(
3906 b"POST /upload HTTP/1.1\r\nHost: example.com\r\n\
3907 Transfer-Encoding: identity\r\nTransfer-Encoding: chunked\r\n\r\n",
3908 );
3909
3910 assert!(
3911 output.contains("example.com POST /upload 400"),
3912 "the access log of a request rejected by the CL.TE guard must carry \
3913 its authority, method and path, got: {output}"
3914 );
3915 }
3916
3917 /// The one authority a header rejection may log: the one the request
3918 /// line itself carries. An absolute-form target names it, so it is
3919 /// logged, split from the path the way kawa splits it.
3920 ///
3921 /// To SEE THIS RED: the same substitution as
3922 /// `a_header_parse_error_keeps_the_method_and_path_in_the_access_log`.
3923 #[test]
3924 fn a_header_parse_error_logs_the_authority_an_absolute_form_carries() {
3925 let output = access_log_of_a_rejected_h1_request(
3926 b"GET http://example.com:8080/abs HTTP/1.1\r\nBad Header: x\r\n\r\n",
3927 );
3928
3929 assert!(
3930 output.contains("example.com:8080 GET /abs 400"),
3931 "the access log of an absolute-form request rejected on a header \
3932 must carry the authority of its request-target, got: {output}"
3933 );
3934 }
3935
3936 // ── A warm H1 write pass allocates nothing ───────────────────────────
3937 //
3938 // DO NOT READ THESE TESTS AS COVERING H2. `H2Shell::write_streams`
3939 // (`lib/src/protocol/mux/h2.rs`) is a separate write path with its own
3940 // allocation test.
3941
3942 /// `Store` blocks each measured pass queues. A fresh `Vec<IoSlice>`
3943 /// reserves four descriptors on its first push, so a pass over more than
3944 /// four blocks also exercises the growth a per-pass vector would pay.
3945 /// One H1 header block is already dozens of them: the `BlockConverter`
3946 /// emits every name, separator, value and CRLF as its own `Store`.
3947 const WARM_PASS_BLOCKS: usize = 16;
3948
3949 /// Queue [`WARM_PASS_BLOCKS`] blocks on `kawa`, drive two write passes
3950 /// through `write`, and return the heap allocations each one made.
3951 ///
3952 /// The first pass is the cold one of a fresh connection and may grow
3953 /// whatever the connection keeps; the second queues the same blocks again
3954 /// and is the warm measurement.
3955 /// Both go to a live loopback peer, so the write is a real `writev(2)`.
3956 /// The blocks are `Store::Static`, so queueing them touches no storage
3957 /// and the kawa never terminates: the pass stops after the write, before
3958 /// the completion arm and its access log, which is not the hot path.
3959 fn allocations_of_two_write_passes(
3960 context: &mut Context<crate::protocol::mux::test_support::TestListener>,
3961 outgoing: fn(
3962 &mut crate::protocol::mux::Stream,
3963 ) -> &mut crate::protocol::mux::GenericHttpStream,
3964 mut write: impl FnMut(&mut Context<crate::protocol::mux::test_support::TestListener>),
3965 ) -> [usize; 2] {
3966 let mut measured = [0; 2];
3967 for (pass, slot) in measured.iter_mut().enumerate() {
3968 let kawa = outgoing(&mut context.streams[0]);
3969 for _ in 0..WARM_PASS_BLOCKS {
3970 kawa.out
3971 .push_back(kawa::OutBlock::Store(kawa::Store::Static(
3972 b"x-warm: pass\r\n",
3973 )));
3974 }
3975 let before = crate::test_allocations::allocations();
3976 write(context);
3977 let allocations = crate::test_allocations::allocations() - before;
3978 assert!(
3979 outgoing(&mut context.streams[0]).out.is_empty(),
3980 "premise: write pass {pass} must drain every queued block, or \
3981 the measured pass would start from a different state"
3982 );
3983 *slot = allocations;
3984 }
3985 measured
3986 }
3987
3988 /// The frontend side: a `Position::Server` pass writing the response.
3989 ///
3990 /// TO SEE THIS RED: in `ConnectionH1::writable`, declare
3991 /// `let mut io_slices: Vec<IoSlice<'static>> = Vec::new();` above the
3992 /// `gather` call and hand that local to `gather`, the emptiness checks,
3993 /// the write, the replay capture and `confirm` in place of
3994 /// `self.io_slices`. Measured with 16 blocks: `left: 3, right: 0` under
3995 /// both `cargo test` and `cargo test --release` — one allocation and two
3996 /// `realloc`s per pass, as the per-pass vector grows 4 → 8 → 16.
3997 #[test]
3998 fn a_warm_h1_response_write_pass_allocates_nothing() {
3999 let mut fixture = linked_backend_connection();
4000 let BackendReadFixture {
4001 context, frontend, ..
4002 } = &mut fixture;
4003 let Connection::H1(server) = frontend else {
4004 unreachable!("new_h1_server builds an H1 connection");
4005 };
4006 server.stream = Some(0);
4007 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4008
4009 let [_, warm] = allocations_of_two_write_passes(
4010 context,
4011 |stream| &mut stream.back,
4012 |context| {
4013 server.readiness.event.insert(Ready::WRITABLE);
4014 server.writable(context, EndpointClient(&mut router));
4015 },
4016 );
4017
4018 assert_eq!(warm, 0, "a warm H1 response write pass must not allocate");
4019 }
4020
4021 /// The backend side: a `Position::Client` pass writing the request.
4022 ///
4023 /// The fixture's connection was dialled fresh, not taken from the
4024 /// keep-alive pool, so the replay capture stays off: its `reserve` is the
4025 /// one allocation a pooled upstream is documented to pay, and it is not
4026 /// what this pins.
4027 ///
4028 /// TO SEE THIS RED: the same substitution as
4029 /// `a_warm_h1_response_write_pass_allocates_nothing`.
4030 #[test]
4031 fn a_warm_h1_request_write_pass_allocates_nothing() {
4032 let mut fixture = linked_backend_connection();
4033 let BackendReadFixture {
4034 context,
4035 frontend,
4036 client,
4037 ..
4038 } = &mut fixture;
4039 assert!(
4040 !client.reused_from_pool,
4041 "premise: a freshly dialled upstream does not capture for replay"
4042 );
4043
4044 let [_, warm] = allocations_of_two_write_passes(
4045 context,
4046 |stream| &mut stream.front,
4047 |context| {
4048 client.readiness.event.insert(Ready::WRITABLE);
4049 client.writable(context, EndpointServer(frontend));
4050 },
4051 );
4052
4053 assert_eq!(warm, 0, "a warm H1 request write pass must not allocate");
4054 }
4055
4056 /// #1610: an H1 frontend sizes its session's link queue for the one
4057 /// request it has in flight, not the four a first `push_back` reserves.
4058 ///
4059 /// Measured against a control whose queue already holds room for one
4060 /// link, so the difference is the queue's own allocation and nothing else
4061 /// the parse allocates.
4062 ///
4063 /// TO SEE THIS RED: drop the `reserve_exact(1)` before the
4064 /// `context.pending_links.push_back(stream_id)` that queues a parsed
4065 /// request in `ConnectionH1::readable`. The queue then allocates four
4066 /// slots.
4067 #[test]
4068 fn a_parsed_h1_request_queues_its_link_in_a_queue_sized_for_one() {
4069 use crate::test_allocations::bytes;
4070
4071 let parse = |presized: bool| {
4072 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
4073 let mut context = test_context(&pool);
4074 context
4075 .create_stream(Ulid::generate(), 1 << 16)
4076 .expect("the test pool must hand out stream buffers");
4077 if presized {
4078 context.pending_links.reserve_exact(1);
4079 }
4080 let (front_socket, mut front_peer) = connected_socket();
4081 let mut server = h1_of(Connection::new_h1_server(
4082 Ulid::generate(),
4083 front_socket,
4084 Duration::from_secs(60),
4085 ));
4086 server.stream = Some(0);
4087 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4088 front_peer
4089 .write_all(b"GET / HTTP/1.1\r\nHost: example.com\r\n\r\n")
4090 .expect("the loopback peer must accept the staged request bytes");
4091
4092 let before = bytes();
4093 for _ in 0..64 {
4094 server.readiness.event.insert(Ready::READABLE);
4095 server.readable(&mut context, EndpointClient(&mut router));
4096 if !context.pending_links.is_empty() {
4097 break;
4098 }
4099 }
4100 let parsed = bytes() - before;
4101 assert_eq!(
4102 context.pending_links,
4103 [0],
4104 "premise: the parsed request must be queued for linking"
4105 );
4106 parsed
4107 };
4108
4109 // The thread's first parse also initialises state that outlives the
4110 // session; run one before measuring.
4111 let _ = parse(true);
4112 assert_eq!(
4113 parse(false) - parse(true),
4114 std::mem::size_of::<GlobalStreamId>(),
4115 "an H1 frontend must queue its link in a queue sized for one"
4116 );
4117 }
4118
4119 /// #1610: the first write pass of a fresh connection sizes its descriptor
4120 /// vector in ONE allocation, on both sides.
4121 ///
4122 /// Measured against a control that is the same pass on a connection whose
4123 /// `io_slices` already holds [`WARM_PASS_BLOCKS`] descriptors, so the
4124 /// difference is the vector's own cost and nothing else the first pass
4125 /// sets up (which differs between debug and release builds).
4126 ///
4127 /// TO SEE THIS RED: drop the `io_slices.reserve(kawa.out.len())` in
4128 /// `h2_transmit::gather`. The fresh vector then doubles 4 → 8 → 16 over the
4129 /// [`WARM_PASS_BLOCKS`] blocks: three allocations per side.
4130 #[test]
4131 fn a_cold_h1_write_pass_sizes_its_descriptor_vector_once() {
4132 let response = |presized: bool| {
4133 let mut fixture = linked_backend_connection();
4134 let BackendReadFixture {
4135 context, frontend, ..
4136 } = &mut fixture;
4137 let Connection::H1(server) = frontend else {
4138 unreachable!("new_h1_server builds an H1 connection");
4139 };
4140 if presized {
4141 server.io_slices.reserve(WARM_PASS_BLOCKS);
4142 }
4143 server.stream = Some(0);
4144 let mut router = Router::new(Duration::from_secs(10), Duration::from_secs(10));
4145 allocations_of_two_write_passes(
4146 context,
4147 |stream| &mut stream.back,
4148 |context| {
4149 server.readiness.event.insert(Ready::WRITABLE);
4150 server.writable(context, EndpointClient(&mut router));
4151 },
4152 )[0]
4153 };
4154 let request = |presized: bool| {
4155 let mut fixture = linked_backend_connection();
4156 let BackendReadFixture {
4157 context,
4158 frontend,
4159 client,
4160 ..
4161 } = &mut fixture;
4162 if presized {
4163 client.io_slices.reserve(WARM_PASS_BLOCKS);
4164 }
4165 allocations_of_two_write_passes(
4166 context,
4167 |stream| &mut stream.front,
4168 |context| {
4169 client.readiness.event.insert(Ready::WRITABLE);
4170 client.writable(context, EndpointServer(frontend));
4171 },
4172 )[0]
4173 };
4174
4175 // The thread's first pass also initialises state that outlives the
4176 // connection; run one of each before measuring.
4177 let _ = (response(true), request(true));
4178 assert_eq!(
4179 response(false) - response(true),
4180 1,
4181 "a fresh H1 frontend must size its descriptor vector in one allocation"
4182 );
4183 assert_eq!(
4184 request(false) - request(true),
4185 1,
4186 "a fresh H1 backend must size its descriptor vector in one allocation"
4187 );
4188 }
4189
4190 /// What kawa's H1 serializer writes for a `kind` message framed by
4191 /// `Content-Length: 5`, holding `hello`, after `pkawa::handle_trailer`
4192 /// queued an H2 trailer block of `fields` and the H1 write path ran
4193 /// `drop_length_framed_trailers`, which returns whether it dropped one.
4194 fn h1_bytes_of_a_length_framed_message(
4195 kind: kawa::Kind,
4196 fields: &[(&[u8], &[u8])],
4197 ) -> (bool, String) {
4198 let mut pool = Pool::with_capacity(1, 1, 4096);
4199 let checkout = pool
4200 .checkout()
4201 .expect("the test pool must hand out a buffer");
4202 let mut kawa: super::super::GenericHttpStream =
4203 kawa::Kawa::new(kind, kawa::Buffer::new(checkout));
4204 kawa.body_size = kawa::BodySize::Length(5);
4205 // One DATA frame, as `handle_data` queues it for a length-framed
4206 // message.
4207 kawa.push_block(kawa::Block::Chunk(kawa::Chunk {
4208 data: kawa::Store::Static(b"hello"),
4209 }));
4210 let mut encoder = super::super::hpack::Encoder::new();
4211 let mut encoded = Vec::new();
4212 for &(name, value) in fields {
4213 encoder.encode_header_into((name, value), &mut encoded);
4214 }
4215 let result = super::super::pkawa::handle_trailer(
4216 &mut kawa,
4217 &encoded,
4218 true,
4219 &mut super::super::hpack::Decoder::new(),
4220 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4221 u32::MAX,
4222 false,
4223 &mut Vec::new(),
4224 );
4225 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4226
4227 let dropped = ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa);
4228 kawa.prepare(&mut kawa::h1::BlockConverter);
4229 let buffer = kawa.storage.buffer();
4230 let bytes: Vec<u8> = kawa
4231 .out
4232 .iter()
4233 .flat_map(|block| match block {
4234 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4235 kawa::OutBlock::Delimiter => Vec::new(),
4236 })
4237 .collect();
4238 (dropped, String::from_utf8_lossy(&bytes).into_owned())
4239 }
4240
4241 /// An H2 trailer block on a Content-Length-framed message adds nothing
4242 /// after the body on HTTP/1.1, which carries trailers only with chunked
4243 /// coding (RFC 9112 §6.3, §7.1): the fields and the empty line are
4244 /// dropped, for a request towards an H1 backend and for a response
4245 /// towards an H1 client, with one trailer field or none.
4246 ///
4247 /// TO SEE THIS RED: make `drop_length_framed_trailers` return `false`
4248 /// before touching the block queue.
4249 #[test]
4250 fn a_length_framed_message_writes_no_trailer_to_an_h1_peer() {
4251 let with_field: &[(&[u8], &[u8])] = &[(b"grpc-status", b"0")];
4252 for kind in [kawa::Kind::Request, kawa::Kind::Response] {
4253 for fields in [with_field, &[]] {
4254 assert_eq!(
4255 h1_bytes_of_a_length_framed_message(kind, fields),
4256 (true, "hello".to_owned()),
4257 "{kind:?} with {} trailer field(s)",
4258 fields.len()
4259 );
4260 }
4261 }
4262 }
4263
4264 /// What `ConnectionH1::writable` writes to an H1 client for a response
4265 /// from an H2 backend whose header section `head` arrived without
4266 /// END_STREAM, ended by a trailer HEADERS block of `trailer` fields when
4267 /// `trailer` is `Some`, or by an empty DATA frame with END_STREAM
4268 /// otherwise. `body_size`, when `Some`, overrides the framing
4269 /// `pkawa::handle_header` resolved. Returns the resolved framing and the
4270 /// bytes, written in one pass like a backend that sent the whole
4271 /// response before the client side became writable.
4272 fn h1_bytes_of_a_bodiless_response(
4273 head: &[(&[u8], &[u8])],
4274 body_size: Option<kawa::BodySize>,
4275 trailer: Option<&[(&[u8], &[u8])]>,
4276 ) -> (kawa::BodySize, String) {
4277 struct NoCallbacks;
4278 impl kawa::h1::ParserCallbacks<crate::pool::Checkout> for NoCallbacks {
4279 fn on_headers(&mut self, _kawa: &mut super::super::GenericHttpStream) {}
4280 }
4281 let mut pool = Pool::with_capacity(1, 1, 4096);
4282 let checkout = pool
4283 .checkout()
4284 .expect("the test pool must hand out a buffer");
4285 let mut kawa: super::super::GenericHttpStream =
4286 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4287 let mut decoder = super::super::hpack::Decoder::new();
4288 let mut encoder = super::super::hpack::Encoder::new();
4289 let mut encoded = Vec::new();
4290 for &(name, value) in head {
4291 encoder.encode_header_into((name, value), &mut encoded);
4292 }
4293 let (_, result) = super::super::pkawa::handle_header(
4294 &mut decoder,
4295 &mut crate::protocol::mux::h2_scheduler::Prioriser::default(),
4296 1,
4297 &mut kawa,
4298 &encoded,
4299 false,
4300 &mut NoCallbacks,
4301 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4302 u32::MAX,
4303 false,
4304 );
4305 assert!(result.is_ok(), "handle_header failed: {:?}", result.err());
4306 if let Some(body_size) = body_size {
4307 kawa.body_size = body_size;
4308 }
4309 match trailer {
4310 Some(fields) => {
4311 let mut encoded = Vec::new();
4312 for &(name, value) in fields {
4313 encoder.encode_header_into((name, value), &mut encoded);
4314 }
4315 let result = super::super::pkawa::handle_trailer(
4316 &mut kawa,
4317 &encoded,
4318 true,
4319 &mut decoder,
4320 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4321 u32::MAX,
4322 false,
4323 &mut Vec::new(),
4324 );
4325 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4326 }
4327 // The blocks `handle_data_frame` queues for an empty DATA frame
4328 // with END_STREAM.
4329 None => {
4330 kawa.push_block(kawa::Block::Chunk(kawa::Chunk {
4331 data: kawa::Store::Static(b""),
4332 }));
4333 let end_chunk = kawa.is_streaming();
4334 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4335 end_body: true,
4336 end_chunk,
4337 end_header: false,
4338 end_stream: true,
4339 }));
4340 }
4341 }
4342 let body_size = kawa.body_size;
4343
4344 ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa);
4345 ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa);
4346 kawa.prepare(&mut kawa::h1::BlockConverter);
4347 let buffer = kawa.storage.buffer();
4348 let bytes: Vec<u8> = kawa
4349 .out
4350 .iter()
4351 .flat_map(|block| match block {
4352 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4353 kawa::OutBlock::Delimiter => Vec::new(),
4354 })
4355 .collect();
4356 (body_size, String::from_utf8_lossy(&bytes).into_owned())
4357 }
4358
4359 /// A response to HEAD, a 204 or a 304 ends with its header section on
4360 /// HTTP/1.1 (RFC 9112 §6.3 rule 1): whatever its framing, nothing
4361 /// follows the head towards an H1 client, neither a last chunk nor a
4362 /// trailer section (RFC 9110 §6.5.1), so the next response on a
4363 /// keep-alive connection starts right after it. Covers chunked framing,
4364 /// `Content-Length` framing and `BodySize::Empty`, each ended by a
4365 /// trailer block with one field or none, or by an empty DATA frame. A
4366 /// `:status 200` stands for the response to a HEAD: with no callbacks,
4367 /// `pkawa::handle_header` does not know the method and frames it chunked,
4368 /// with `Transfer-Encoding`, while it gives a 204 or a 304 no framing and
4369 /// removes a 204's `content-length` (RFC 9110 §8.6).
4370 ///
4371 /// TO SEE THIS RED: make `drop_bodiless_response_framing` return `false`
4372 /// before touching the block queue.
4373 #[test]
4374 fn a_bodiless_response_writes_nothing_after_its_head_to_an_h1_client() {
4375 let with_field: &[(&[u8], &[u8])] = &[(b"grpc-status", b"0")];
4376 for status in [&b"204"[..], b"304", b"200"] {
4377 let status_line = String::from_utf8_lossy(status);
4378 let (unframed_size, unframed) = if status == b"200" {
4379 (kawa::BodySize::Chunked, "Transfer-Encoding: chunked\r\n")
4380 } else {
4381 (kawa::BodySize::Empty, "")
4382 };
4383 let length_framed = |length: usize, field: &'static str| {
4384 if status == b"204" {
4385 (kawa::BodySize::Empty, "")
4386 } else {
4387 (kawa::BodySize::Length(length), field)
4388 }
4389 };
4390 let (zero_size, zero) = length_framed(0, "content-length: 0\r\n");
4391 let (five_size, five) = length_framed(5, "content-length: 5\r\n");
4392 for (content_length, body_size, expected_size, framing) in [
4393 (None, None, unframed_size, unframed),
4394 (
4395 None,
4396 Some(kawa::BodySize::Chunked),
4397 kawa::BodySize::Chunked,
4398 unframed,
4399 ),
4400 (Some(&b"0"[..]), None, zero_size, zero),
4401 (Some(b"5"), None, five_size, five),
4402 (
4403 None,
4404 Some(kawa::BodySize::Empty),
4405 kawa::BodySize::Empty,
4406 unframed,
4407 ),
4408 ] {
4409 let mut head: Vec<(&[u8], &[u8])> = vec![(b":status", status)];
4410 if let Some(length) = content_length {
4411 head.push((b"content-length", length));
4412 }
4413 let expected = format!("HTTP/1.1 {status_line} FromH2\r\n{framing}\r\n");
4414 for trailer in [Some(with_field), Some(&[][..]), None] {
4415 assert_eq!(
4416 h1_bytes_of_a_bodiless_response(&head, body_size, trailer),
4417 (expected_size, expected.clone()),
4418 "{status_line} {expected_size:?} ended by {trailer:?}"
4419 );
4420 }
4421 }
4422 }
4423 }
4424
4425 /// The trailer block of a bodiless response queued alone, its header
4426 /// section written in an earlier pass, is dropped whole and counted;
4427 /// a queue with no trailer block reports none.
4428 #[test]
4429 fn a_bodiless_response_trailer_block_queued_after_its_head_is_dropped() {
4430 let mut pool = Pool::with_capacity(1, 1, 4096);
4431 let checkout = pool
4432 .checkout()
4433 .expect("the test pool must hand out a buffer");
4434 let mut kawa: super::super::GenericHttpStream =
4435 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4436 kawa.body_size = kawa::BodySize::Chunked;
4437 let mut encoded = Vec::new();
4438 super::super::hpack::Encoder::new()
4439 .encode_header_into((b"grpc-status", b"0"), &mut encoded);
4440 let result = super::super::pkawa::handle_trailer(
4441 &mut kawa,
4442 &encoded,
4443 true,
4444 &mut super::super::hpack::Decoder::new(),
4445 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4446 u32::MAX,
4447 false,
4448 &mut Vec::new(),
4449 );
4450 assert!(result.is_ok(), "handle_trailer failed: {:?}", result.err());
4451 assert!(ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa));
4452 assert!(
4453 !kawa
4454 .blocks
4455 .iter()
4456 .any(|block| matches!(block, kawa::Block::Header(_))),
4457 "the trailer fields are removed"
4458 );
4459 kawa.prepare(&mut kawa::h1::BlockConverter);
4460 assert!(kawa.out.is_empty(), "nothing is written after the head");
4461 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_bodiless_response_framing(&mut kawa));
4462 }
4463
4464 /// What kawa's H1 serializer writes to an H1 client for the header
4465 /// section `head` of an H2 backend response that arrived without
4466 /// END_STREAM, to a `method` request, and whether the response was then
4467 /// complete (`ParsingPhase::Terminated`).
4468 fn h1_head_of_an_h2_response(
4469 method: crate::protocol::kawa_h1::parser::Method,
4470 head: &[(&[u8], &[u8])],
4471 ) -> (String, bool) {
4472 let mut pool = Pool::with_capacity(1, 1, 4096);
4473 let checkout = pool
4474 .checkout()
4475 .expect("the test pool must hand out a buffer");
4476 let mut kawa: super::super::GenericHttpStream =
4477 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4478 let mut context = test_http_context(Ulid::generate());
4479 context.method = Some(method);
4480 let mut encoded = Vec::new();
4481 let mut encoder = super::super::hpack::Encoder::new();
4482 for &(name, value) in head {
4483 encoder.encode_header_into((name, value), &mut encoded);
4484 }
4485 let (_, result) = super::super::pkawa::handle_header(
4486 &mut super::super::hpack::Decoder::new(),
4487 &mut crate::protocol::mux::h2_scheduler::Prioriser::default(),
4488 1,
4489 &mut kawa,
4490 &encoded,
4491 false,
4492 &mut context,
4493 super::super::h2::MAX_HEADER_LIST_SIZE as u32,
4494 u32::MAX,
4495 false,
4496 );
4497 assert!(result.is_ok(), "handle_header failed: {:?}", result.err());
4498 let terminated = kawa.is_terminated();
4499 kawa.prepare(&mut kawa::h1::BlockConverter);
4500 let buffer = kawa.storage.buffer();
4501 let bytes: Vec<u8> = kawa
4502 .out
4503 .iter()
4504 .flat_map(|block| match block {
4505 kawa::OutBlock::Store(store) => store.data(buffer).to_vec(),
4506 kawa::OutBlock::Delimiter => Vec::new(),
4507 })
4508 .collect();
4509 (String::from_utf8_lossy(&bytes).into_owned(), terminated)
4510 }
4511
4512 /// An H2 response whose header section arrives without END_STREAM gains
4513 /// no `Transfer-Encoding` towards an H1 client when it has no content by
4514 /// definition (RFC 9110 §6.4.1): a 1xx or a 204 (RFC 9112 §6.1 MUST NOT),
4515 /// a 304 or a response to HEAD. A 1xx or a 204 also loses the
4516 /// `content-length` the backend sent, which a server MUST NOT send in
4517 /// them (RFC 9110 §8.6), while a 304 or a response to HEAD keeps it. A
4518 /// 1xx is complete at its head (`ParsingPhase::Terminated`), the final
4519 /// response following on the same stream; any other response waits for
4520 /// the END_STREAM of its stream (RFC 9113 §8.1). A `200` to GET still
4521 /// gains chunked framing.
4522 ///
4523 /// TO SEE THIS RED: drop the `no_content` guard of the chunked upgrade in
4524 /// `pkawa::handle_header`, or its removal of a 1xx or 204
4525 /// `content-length`.
4526 #[test]
4527 fn a_bodiless_h2_response_gains_no_transfer_encoding_towards_an_h1_client() {
4528 use crate::protocol::kawa_h1::parser::Method;
4529 /// The header fields of a response, `:status` first.
4530 type Head = &'static [(&'static [u8], &'static [u8])];
4531 let cases: [(Method, Head, &str, bool); 10] = [
4532 (
4533 Method::Get,
4534 &[(b":status", b"204")],
4535 "HTTP/1.1 204 FromH2\r\n",
4536 false,
4537 ),
4538 (
4539 Method::Get,
4540 &[(b":status", b"204"), (b"content-length", b"0")],
4541 "HTTP/1.1 204 FromH2\r\n",
4542 false,
4543 ),
4544 (
4545 Method::Get,
4546 &[(b":status", b"304")],
4547 "HTTP/1.1 304 FromH2\r\n",
4548 false,
4549 ),
4550 (
4551 Method::Get,
4552 &[(b":status", b"304"), (b"content-length", b"5")],
4553 "HTTP/1.1 304 FromH2\r\ncontent-length: 5\r\n",
4554 false,
4555 ),
4556 (
4557 Method::Get,
4558 &[(b":status", b"103"), (b"link", b"</a.css>")],
4559 "HTTP/1.1 103 FromH2\r\nlink: </a.css>\r\n",
4560 true,
4561 ),
4562 (
4563 Method::Get,
4564 &[
4565 (b":status", b"103"),
4566 (b"content-length", b"5"),
4567 (b"link", b"</a.css>"),
4568 ],
4569 "HTTP/1.1 103 FromH2\r\nlink: </a.css>\r\n",
4570 true,
4571 ),
4572 (
4573 Method::Head,
4574 &[(b":status", b"200")],
4575 "HTTP/1.1 200 FromH2\r\n",
4576 false,
4577 ),
4578 (
4579 Method::Head,
4580 &[(b":status", b"200"), (b"content-length", b"5")],
4581 "HTTP/1.1 200 FromH2\r\ncontent-length: 5\r\n",
4582 false,
4583 ),
4584 (
4585 Method::Head,
4586 &[(b":status", b"200"), (b"content-length", b"0")],
4587 "HTTP/1.1 200 FromH2\r\ncontent-length: 0\r\n",
4588 false,
4589 ),
4590 (
4591 Method::Get,
4592 &[(b":status", b"200")],
4593 "HTTP/1.1 200 FromH2\r\nTransfer-Encoding: chunked\r\n",
4594 false,
4595 ),
4596 ];
4597 for (method, head, status_and_fields, terminated) in cases {
4598 let (bytes, complete) = h1_head_of_an_h2_response(method.clone(), head);
4599 let bytes = bytes
4600 .split("\r\n")
4601 .filter(|line| !line.starts_with("Sozu-Id: "))
4602 .collect::<Vec<_>>()
4603 .join("\r\n");
4604 assert_eq!(
4605 (bytes, complete),
4606 (format!("{status_and_fields}\r\n"), terminated),
4607 "{method:?} {head:?}"
4608 );
4609 }
4610 }
4611
4612 /// Which responses `response_has_no_body` treats as bodiless.
4613 #[test]
4614 fn a_response_has_no_body_for_head_204_and_304_only() {
4615 use crate::protocol::kawa_h1::parser::Method;
4616 let cases = [
4617 (Some(Method::Head), Some(200), true),
4618 (Some(Method::Get), Some(204), true),
4619 (Some(Method::Get), Some(304), true),
4620 (Some(Method::Get), Some(200), false),
4621 (Some(Method::Post), Some(205), false),
4622 (None, None, false),
4623 ];
4624 for (method, status, expected) in cases {
4625 let mut context = test_http_context(Ulid::generate());
4626 context.method = method.clone();
4627 context.status = status;
4628 assert_eq!(
4629 ConnectionH1::<mio::net::TcpStream>::response_has_no_body(&context),
4630 expected,
4631 "{method:?} {status:?}"
4632 );
4633 }
4634 }
4635
4636 /// The header section of a length-framed message closed with
4637 /// `end_stream` (a message with no body) is not a trailer block: it is
4638 /// written whole.
4639 #[test]
4640 fn a_length_framed_header_section_is_not_taken_for_trailers() {
4641 let mut pool = Pool::with_capacity(1, 1, 4096);
4642 let checkout = pool
4643 .checkout()
4644 .expect("the test pool must hand out a buffer");
4645 let mut kawa: super::super::GenericHttpStream =
4646 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4647 kawa.body_size = kawa::BodySize::Length(0);
4648 kawa.push_block(kawa::Block::StatusLine);
4649 kawa.push_block(kawa::Block::Header(kawa::Pair {
4650 key: kawa::Store::Static(b"Content-Length"),
4651 val: kawa::Store::Static(b"0"),
4652 }));
4653 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4654 end_body: false,
4655 end_chunk: false,
4656 end_header: true,
4657 end_stream: true,
4658 }));
4659 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4660 assert_eq!(kawa.blocks.len(), 3, "the header section stays whole");
4661 }
4662
4663 /// A `Cookies` block belongs to a header section: a length-framed
4664 /// request whose header section ends with its cookies and closes with
4665 /// `end_stream` is not a trailer block, and is written whole.
4666 ///
4667 /// TO SEE THIS RED: drop the `kawa::Block::Cookies` arm from the
4668 /// header-section guard of `drop_length_framed_trailers`.
4669 #[test]
4670 fn a_length_framed_header_section_ending_with_cookies_is_not_taken_for_trailers() {
4671 let mut pool = Pool::with_capacity(1, 1, 4096);
4672 let checkout = pool
4673 .checkout()
4674 .expect("the test pool must hand out a buffer");
4675 let mut kawa: super::super::GenericHttpStream =
4676 kawa::Kawa::new(kawa::Kind::Request, kawa::Buffer::new(checkout));
4677 kawa.body_size = kawa::BodySize::Length(0);
4678 kawa.push_block(kawa::Block::StatusLine);
4679 kawa.push_block(kawa::Block::Header(kawa::Pair {
4680 key: kawa::Store::Static(b"Content-Length"),
4681 val: kawa::Store::Static(b"0"),
4682 }));
4683 kawa.push_block(kawa::Block::Cookies);
4684 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4685 end_body: false,
4686 end_chunk: false,
4687 end_header: true,
4688 end_stream: true,
4689 }));
4690 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4691 assert_eq!(kawa.blocks.len(), 4, "the header section stays whole");
4692 assert!(
4693 matches!(
4694 kawa.blocks.back(),
4695 Some(kawa::Block::Flags(kawa::Flags {
4696 end_header: true,
4697 ..
4698 }))
4699 ),
4700 "the header section keeps its closing empty line"
4701 );
4702 }
4703
4704 /// A response to HEAD declares the length of the body it does not carry
4705 /// (RFC 9110 §9.3.2): its header section alone ends the message with
4706 /// `end_stream`, under a non-zero `Content-Length`. It is not a trailer
4707 /// block, and is written whole.
4708 ///
4709 /// TO SEE THIS RED: drop the `kawa::Block::StatusLine` arm from the
4710 /// header-section guard of `drop_length_framed_trailers`.
4711 #[test]
4712 fn a_header_only_head_response_is_not_taken_for_trailers() {
4713 let mut pool = Pool::with_capacity(1, 1, 4096);
4714 let checkout = pool
4715 .checkout()
4716 .expect("the test pool must hand out a buffer");
4717 let mut kawa: super::super::GenericHttpStream =
4718 kawa::Kawa::new(kawa::Kind::Response, kawa::Buffer::new(checkout));
4719 kawa.body_size = kawa::BodySize::Length(5);
4720 kawa.push_block(kawa::Block::StatusLine);
4721 kawa.push_block(kawa::Block::Header(kawa::Pair {
4722 key: kawa::Store::Static(b"Content-Length"),
4723 val: kawa::Store::Static(b"5"),
4724 }));
4725 kawa.push_block(kawa::Block::Flags(kawa::Flags {
4726 end_body: false,
4727 end_chunk: false,
4728 end_header: true,
4729 end_stream: true,
4730 }));
4731 assert!(!ConnectionH1::<mio::net::TcpStream>::drop_length_framed_trailers(&mut kawa));
4732 assert_eq!(kawa.blocks.len(), 3, "the header section stays whole");
4733 assert!(
4734 matches!(
4735 kawa.blocks.back(),
4736 Some(kawa::Block::Flags(kawa::Flags {
4737 end_header: true,
4738 ..
4739 }))
4740 ),
4741 "the header section keeps its closing empty line"
4742 );
4743 }
4744
4745 /// `ConnectionH1::terminate_close_delimited` at a backend EOF: only a body
4746 /// with neither `Content-Length` nor chunked coding is delimited by the
4747 /// close (RFC 9112 §6.3 rule 8). A `Content-Length` body still missing
4748 /// bytes (rule 5) and a chunked body without its terminating zero chunk
4749 /// (§7.1) are truncated and end in the Error phase, which the H2
4750 /// converter turns into RST_STREAM and the H1 frontend into a close.
4751 ///
4752 /// Red on `d5161919`: the `Content-Length` case ended `Terminated`
4753 /// (sozu-proxy/sozu#1633).
4754 #[test]
4755 fn only_a_close_delimited_body_ends_cleanly_at_the_backend_eof() {
4756 let cases: [(&[u8], bool); 3] = [
4757 (b"HTTP/1.1 200 OK\r\nContent-Length: 10\r\n\r\nabcd", true),
4758 (
4759 b"HTTP/1.1 200 OK\r\nTransfer-Encoding: chunked\r\n\r\n4\r\nabcd\r\n",
4760 true,
4761 ),
4762 (b"HTTP/1.1 200 OK\r\n\r\nabcd", false),
4763 ];
4764 for (bytes, truncated) in cases {
4765 let pool = Rc::new(RefCell::new(Pool::with_capacity(4, 8, 16384)));
4766 let mut context = test_context(&pool);
4767 let id = context
4768 .create_stream(Ulid::generate(), 1 << 16)
4769 .expect("the test pool must hand out stream buffers");
4770 let kawa = &mut context.streams[id].back;
4771 kawa.storage.space()[..bytes.len()].copy_from_slice(bytes);
4772 kawa.storage.fill(bytes.len());
4773 kawa::h1::parse(kawa, &mut kawa::h1::NoCallbacks);
4774 assert!(
4775 kawa.is_main_phase() && !kawa.is_terminated(),
4776 "premise: {:?} is in its body phase",
4777 kawa.body_size
4778 );
4779 ConnectionH1::<mio::net::TcpStream>::terminate_close_delimited(kawa, id);
4780 if truncated {
4781 assert!(
4782 kawa.is_error(),
4783 "a truncated {:?} body must end in Error, got {:?}",
4784 kawa.body_size,
4785 kawa.parsing_phase
4786 );
4787 } else {
4788 assert!(
4789 kawa.is_terminated(),
4790 "a close-delimited body ends cleanly, got {:?}",
4791 kawa.parsing_phase
4792 );
4793 }
4794 }
4795 }
4796}