sozu_lib/protocol/mux/stream.rs
1//! Per-request stream state shared by the H1 and H2 mux paths.
2//!
3//! A [`Stream`] owns the front/back kawa buffers, HTTP context, and metrics
4//! for a single request/response pair. [`StreamParts`] splits it along the
5//! read/write axis so callers can borrow both sides of the pipe at the same
6//! time without fighting the borrow checker.
7
8use std::{
9 cell::{Cell, RefCell},
10 fmt::Debug,
11 ops::{Deref, DerefMut},
12 rc::Rc,
13 time::Duration,
14};
15
16use mio::Token;
17use sozu_command::logging::ansi_palette;
18
19use super::{
20 GenericHttpStream, Position,
21 h2::{DEFAULT_INITIAL_WINDOW_SIZE, MetricEvent},
22};
23use crate::metrics::names;
24use crate::{
25 L7ListenerHandler, ListenerHandler, Protocol, SessionMetrics,
26 protocol::http::{answers::HttpAnswers, editor::HttpContext, parser::Method},
27};
28
29/// Module-level prefix used on every log line emitted from the stream module.
30/// Streams have no direct peer reference so a single `MUX-STREAM` label is
31/// used, colored bold bright-white (uniform across every protocol) when the
32/// logger supports ANSI.
33macro_rules! log_module_context {
34 () => {{
35 let (open, reset, _, _, _) = ansi_palette();
36 format!("{open}MUX-STREAM{reset}\t >>>", open = open, reset = reset)
37 }};
38}
39
40#[derive(Debug, Clone, Copy, PartialEq, Eq)]
41pub enum StreamState {
42 Idle,
43 /// the Stream is asking for connection, this will trigger a call to connect
44 Link,
45 /// the Stream is linked to a Client (note that the client might not be connected)
46 Linked(Token),
47 /// the Stream was linked to a Client, but the connection closed, the client was removed
48 /// and this Stream could not be retried (it should be terminated)
49 Unlinked,
50 /// the Stream is unlinked and can be reused
51 Recycle,
52}
53
54impl StreamState {
55 pub fn is_open(&self) -> bool {
56 !matches!(self, StreamState::Idle | StreamState::Recycle)
57 }
58}
59
60/// Ceiling on the request captures one worker may hold armed at once
61/// (sozu-proxy/sozu#1450).
62///
63/// Captures live on the global allocator, outside the buffer
64/// [`Pool`](crate::pool::Pool), so no
65/// `max_buffers` accounting sees them. Before this ceiling their only bound
66/// was transitive: a capture can exist only on a live [`Stream`], and
67/// [`Stream::new`] takes exactly two [`BufferSource::checkout`](super::buffer_source::BufferSource::checkout)
68/// calls, each served by that same [`Pool`](crate::pool::Pool), so at most
69/// `max_buffers / 2` captures can be armed at once. At the defaults
70/// (`max_buffers` 1000, `buffer_size` 16393) that is 500 captures of at most
71/// 16400 bytes each, about 8.2 MB — and it scales with `max_buffers`, so
72/// raising that knob to 20000 would take the same heap to roughly 164 MB.
73///
74/// 512 is chosen so the ceiling does NOT bite at the defaults: 500 possible
75/// captures fit under it, so a stock deployment replays exactly what it
76/// replayed before. What it removes is the growth: the heap stops tracking
77/// `max_buffers` and becomes a constant.
78///
79/// The bound is `2 * MAX_ARMED_REPLAY_CAPTURES * buffer_size` and not a byte
80/// budget, because each capture is independently bounded — a write that would
81/// carry one past its front kawa's `storage.capacity()` drops it whole
82/// (`super::h1::ConnectionH1::writable`), which is HAProxy's "Requests not
83/// fitting in a single buffer will never be retried". Counting captures is
84/// therefore a memory bound, not a proxy for one.
85///
86/// The factor of two is `Vec`'s amortized growth and is part of the bound,
87/// not a footnote to it. `ConnectionH1::writable` calls `Vec::reserve`, which
88/// grows to `max(2 * old_capacity, required)`, while the guard beside it
89/// bounds `len` — not `capacity` — by `storage.capacity()`. A capture written
90/// in one pass has `capacity == len`; one assembled over several partial
91/// writes can reach twice it. Measured on this tree at the defaults: a single
92/// 16393-byte write gives `len 16393 / capacity 16393`, and writes of
93/// `[8192, 8192, 9]` give `len 16393 / capacity 32768`. So 512 captures carry
94/// at most about 8.4 MB and may have allocated about 16.8 MB.
95///
96/// Past the ceiling nothing is refused and no frontend parks:
97/// [`Stream::arm_upstream_replay`] installs no buffer, the request proceeds
98/// un-replayable, and a stale pooled upstream answers the same
99/// `502 Bad Gateway` it answered before the replay existed. That graceful
100/// degradation is the reason the captures are not pool-allocated, where the
101/// same memory pressure would answer `503` and park frontends instead.
102pub const MAX_ARMED_REPLAY_CAPTURES: usize = 512;
103
104thread_local! {
105 /// Request captures currently armed on this worker, the quantity
106 /// [`MAX_ARMED_REPLAY_CAPTURES`] bounds.
107 ///
108 /// Thread-local rather than a process-wide static because that is the
109 /// scope of everything it is reconciled against: a Sōzu worker is one
110 /// event-loop thread, its [`Pool`](crate::pool::Pool) is an `Rc<RefCell<Pool>>` that cannot
111 /// leave it, and the `backend.retry.captures_armed` gauge this counter
112 /// feeds lives in the `thread_local!` `crate::metrics::METRICS`. A shared
113 /// static would let one worker thread in a multi-worker test process
114 /// exhaust another's budget while their gauges disagreed about it.
115 static ARMED_REPLAY_CAPTURES: Cell<usize> = const { Cell::new(0) };
116}
117
118/// A request capture that owns its charge against
119/// [`MAX_ARMED_REPLAY_CAPTURES`].
120///
121/// The charge is acquired by `ReplayCapture::try_arm` and released by
122/// [`Drop`], so it is released wherever the capture is — `Option::take`,
123/// assigning `None` through [`StreamParts`], or the [`Stream`] being dropped
124/// on a client hangup, an idle timeout or a session teardown. That last path
125/// has no code site of its own, and wiring decrements into the four that do
126/// would leak a charge on every torn-down armed request until the ceiling
127/// disarmed replay for the rest of the worker's life. This is the reasoning
128/// `super::h2::ConnectionH2`'s gauge teardown and `crate::pool::Checkout`
129/// already apply: teardown in `Drop` is symmetric whichever path ran.
130///
131/// Derefs to the captured bytes, so the write path appends to it exactly as
132/// it appended to the bare `Vec<u8>` this replaced.
133pub struct ReplayCapture {
134 bytes: Vec<u8>,
135}
136
137impl ReplayCapture {
138 /// Charge one capture against this worker's budget, or refuse.
139 ///
140 /// `None` means the budget is full; the caller emits
141 /// `backend.retry.captures_declined` and carries on without a capture.
142 fn try_arm() -> Option<Self> {
143 let armed = ARMED_REPLAY_CAPTURES.get();
144 if armed >= MAX_ARMED_REPLAY_CAPTURES {
145 return None;
146 }
147 ARMED_REPLAY_CAPTURES.set(armed + 1);
148 gauge_add!(names::backend::RETRY_CAPTURES_ARMED, 1);
149 Some(Self { bytes: Vec::new() })
150 }
151
152 /// Take the captured bytes out, releasing the charge as `self` drops.
153 ///
154 /// `Vec` cannot be moved out of a type that implements [`Drop`], so the
155 /// bytes are swapped for an empty `Vec` and the husk is dropped normally
156 /// — which is what keeps the release on the single `Drop` site.
157 ///
158 /// Do NOT "simplify" this with `std::mem::forget(self)` to skip the drop.
159 /// The drop IS the release: forgetting it leaks one charge per replay
160 /// until the ceiling disarms replay for the rest of the worker's life,
161 /// with `backend.retry.captures_armed` pinned at
162 /// [`MAX_ARMED_REPLAY_CAPTURES`] to show it. `tests::
163 /// queueing_a_replay_releases_the_capture_charge` is the guard, and it is
164 /// the only test in the suite that catches that mutation.
165 fn into_bytes(mut self) -> Vec<u8> {
166 std::mem::take(&mut self.bytes)
167 }
168}
169
170impl Drop for ReplayCapture {
171 fn drop(&mut self) {
172 let armed = ARMED_REPLAY_CAPTURES.get();
173 // Budget-accounting invariant: every live `ReplayCapture` was paired
174 // with a `set(armed + 1)` in `try_arm`, so the counter must be
175 // strictly positive when one is dropped. A zero here is an unbalanced
176 // arm/release, which would wrap the counter to `usize::MAX` and
177 // disarm replay for the life of the worker. Mirrors the same guard on
178 // `crate::pool::Checkout`'s buffer gauge.
179 debug_assert!(
180 armed >= 1,
181 "armed-capture budget underflow on release: count was {armed} before decrement"
182 );
183 ARMED_REPLAY_CAPTURES.set(armed.saturating_sub(1));
184 gauge_add!(names::backend::RETRY_CAPTURES_ARMED, -1);
185 }
186}
187
188impl Deref for ReplayCapture {
189 type Target = Vec<u8>;
190
191 fn deref(&self) -> &Self::Target {
192 &self.bytes
193 }
194}
195
196impl DerefMut for ReplayCapture {
197 fn deref_mut(&mut self) -> &mut Self::Target {
198 &mut self.bytes
199 }
200}
201
202pub struct Stream {
203 /// RFC 9113 §6.9 send window of this stream on the FRONTEND connection:
204 /// the credit the client granted for the response DATA Sōzu writes to
205 /// it. Sized by the client's `SETTINGS_INITIAL_WINDOW_SIZE` when the
206 /// stream is created and moved only by that connection's SETTINGS and
207 /// WINDOW_UPDATE frames. Unused when the frontend speaks H1.
208 pub front_window: i32,
209 /// RFC 9113 §6.9 send window of this stream on the BACKEND connection:
210 /// the credit the H2 backend granted for the request DATA Sōzu writes
211 /// to it. Flow control is hop-by-hop, so it is independent of
212 /// [`Self::front_window`]: `ConnectionH2::start_stream` sizes it from the
213 /// backend's `SETTINGS_INITIAL_WINDOW_SIZE` each time the stream is
214 /// opened on a backend connection, and only that connection's SETTINGS
215 /// and WINDOW_UPDATE frames move it. Unused when the backend speaks H1.
216 pub back_window: i32,
217 pub attempts: u8,
218 /// Addresses of the backends this request failed to connect to: refused,
219 /// timed out, or reporting a socket error once the dial completed. A
220 /// retry prefers any other backend (`BackendMap::reserve_backend_excluding`
221 /// in `lib/src/backends.rs`, sozu-proxy/sozu#1800). Cleared with
222 /// [`Self::attempts`] for each request; empty, and unallocated, on every
223 /// request whose first dial succeeds.
224 pub tried_backends: Vec<std::net::SocketAddr>,
225 pub state: StreamState,
226 /// True when the frontend connection has received end_of_stream from the client.
227 pub front_received_end_of_stream: bool,
228 /// True when the backend connection has received end_of_stream from the backend server.
229 pub back_received_end_of_stream: bool,
230 /// Tracks total DATA payload bytes received on the frontend for content-length validation (RFC 9113 §8.1.1)
231 pub front_data_received: usize,
232 /// Tracks total DATA payload bytes received on the backend for content-length validation (RFC 9113 §8.1.1)
233 pub back_data_received: usize,
234 /// True when `gauge_add!(names::http::ACTIVE_REQUESTS, 1)` was emitted for this stream.
235 /// Prevents underflow when `generate_access_log` is called for streams that never
236 /// had their request fully parsed (idle timeouts, malformed requests).
237 pub request_counted: bool,
238 pub front: GenericHttpStream,
239 pub back: GenericHttpStream,
240 /// The serialized request already written to the upstream, kept so it can
241 /// be replayed on a fresh connection when a POOLED keep-alive upstream
242 /// turns out to have been closed by its peer before it answered.
243 ///
244 /// `None` means "not replayable" and is the state on every path that is
245 /// not the stale-pool race: a freshly dialled upstream never fills it
246 /// (see [`super::h1::ConnectionH1`]'s `reused_from_pool`), a response
247 /// byte clears it, and a request too large to fit one front buffer
248 /// truncates it back to `None`. `Some` therefore carries both the bytes
249 /// and the proof that replay is allowed.
250 ///
251 /// This mirrors pingora's `RetryType::ReusedOnly` + `retry_buffer_
252 /// truncated()` pair and HAProxy's "requires to allocate a buffer and
253 /// copy the whole request into it […] Requests not fitting in a single
254 /// buffer will never be retried" — replaying a request that kawa has
255 /// already consumed is impossible without holding its bytes.
256 ///
257 /// The capture is charged against [`MAX_ARMED_REPLAY_CAPTURES`] for as
258 /// long as it is `Some`; see [`ReplayCapture`].
259 pub retry_buffer: Option<ReplayCapture>,
260 /// True once an H2 backend connection has HPACK-encoded this request
261 /// into `front.out` (`ConnectionH2::poll_write_target`'s
262 /// `H2WritePhase::Prepare` arm, `Position::Client` only).
263 ///
264 /// Those frames carry that connection's stream id and field blocks
265 /// encoded against that connection's HPACK encoder, and the request's
266 /// header blocks are gone from `front.blocks`: the request can no longer
267 /// be sent on any other connection, nor encoded again. Until a request
268 /// byte reaches the socket (`front.consumed`), nothing distinguishes it
269 /// from an untouched request, so this is what keeps
270 /// `end_stream_decision` and `ConnectionH2::handle_goaway_frame` from
271 /// linking it to another backend, where the stale frames would decode
272 /// against another table — fields another request of this frontend
273 /// connection inserted (a backend connection belongs to one `Mux`), or a
274 /// COMPRESSION_ERROR that takes that connection down (sozu-proxy/sozu#1632). An H1 backend never sets it: its output is
275 /// protocol bytes any fresh H1 connection can send as they are.
276 ///
277 /// Cleared with the front kawa, wherever the slot takes a new request.
278 pub front_bound_to_backend: bool,
279 pub context: HttpContext,
280 pub metrics: SessionMetrics,
281 /// The listener answer registry this stream renders its default answers
282 /// from, captured when the request that owns the slot arrived and held
283 /// for the rest of the stream's life.
284 ///
285 /// Every `set_default_answer` site in the mux reads this handle instead
286 /// of borrowing [`Context::listener`](super::Context::listener) again, so
287 /// an operator listener reload landing mid-request cannot change the
288 /// template a stream already in flight is about to render.
289 /// `HttpListener::update_config` / `HttpsListener::update_config`
290 /// publish a *new* registry rather than overwriting this one, which is
291 /// what makes the captured handle a snapshot and not just a second name
292 /// for the live one. See `LIFECYCLE.md` §2.5.
293 ///
294 /// `Rc` so the capture is a refcount bump on a path that runs once per
295 /// request; the inner `RefCell` is the registry's own, not a mutation
296 /// point for the mux — nothing under `mux/` ever takes it mutably.
297 pub answers: Rc<RefCell<HttpAnswers>>,
298}
299
300struct KawaSummary<'a>(&'a GenericHttpStream);
301impl Debug for KawaSummary<'_> {
302 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
303 f.debug_struct("Kawa")
304 .field("kind", &self.0.kind)
305 .field("parsing_phase", &self.0.parsing_phase)
306 .field("body_size", &self.0.body_size)
307 .field("consumed", &self.0.consumed)
308 .field("expects", &self.0.expects)
309 .field("blocks", &self.0.blocks.len())
310 .field("out", &self.0.out.len())
311 .field("storage_start", &self.0.storage.start)
312 .field("storage_head", &self.0.storage.head)
313 .field("storage_end", &self.0.storage.end)
314 .finish()
315 }
316}
317impl Debug for Stream {
318 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
319 f.debug_struct("Stream")
320 .field("front_window", &self.front_window)
321 .field("back_window", &self.back_window)
322 .field("attempts", &self.attempts)
323 .field("tried_backends", &self.tried_backends)
324 .field("state", &self.state)
325 .field(
326 "front_received_end_of_stream",
327 &self.front_received_end_of_stream,
328 )
329 .field(
330 "back_received_end_of_stream",
331 &self.back_received_end_of_stream,
332 )
333 .field("front_data_received", &self.front_data_received)
334 .field("back_data_received", &self.back_data_received)
335 .field("request_counted", &self.request_counted)
336 .field("front", &KawaSummary(&self.front))
337 .field("back", &KawaSummary(&self.back))
338 .field(
339 "retry_buffer",
340 &self.retry_buffer.as_ref().map(|bytes| bytes.len()),
341 )
342 .field("front_bound_to_backend", &self.front_bound_to_backend)
343 .field("context", &self.context)
344 .field("metrics", &self.metrics)
345 .finish()
346 }
347}
348
349/// This struct allows to mutably borrow the read and write buffers (dependant on the position)
350/// as well as the context and metrics of a Stream at the same time
351pub struct StreamParts<'a> {
352 /// This connection's send window for the stream: [`Stream::back_window`]
353 /// on a backend connection, [`Stream::front_window`] on a frontend one.
354 pub window: &'a mut i32,
355 pub rbuffer: &'a mut GenericHttpStream,
356 pub wbuffer: &'a mut GenericHttpStream,
357 /// Tracks whether end_of_stream has been received on the read side of this connection.
358 pub received_end_of_stream: &'a mut bool,
359 /// Tracks total DATA payload bytes received on the read side (for content-length validation).
360 pub data_received: &'a mut usize,
361 pub context: &'a mut HttpContext,
362 pub metrics: &'a mut SessionMetrics,
363 /// [`Stream::retry_buffer`], reachable from the write path so the H1
364 /// client can record the exact bytes it hands the upstream socket before
365 /// `kawa::Kawa::consume` drops them from the front buffer.
366 pub retry_buffer: &'a mut Option<ReplayCapture>,
367 /// [`Stream::front_bound_to_backend`], set by the H2 write path when a
368 /// backend connection encodes the request.
369 pub front_bound_to_backend: &'a mut bool,
370}
371
372impl Stream {
373 /// `None` when `buffers` cannot supply the pair. Both halves are asked
374 /// for together and neither is kept without the other, so a stream that
375 /// cannot be served leaves the source exactly as it found it — which is
376 /// what makes the caller's `RST_STREAM(REFUSED_STREAM)` a refusal of one
377 /// stream rather than a leak charged to the next.
378 pub fn new(
379 buffers: &mut dyn super::buffer_source::BufferSource,
380 context: HttpContext,
381 answers: Rc<RefCell<HttpAnswers>>,
382 window: u32,
383 ) -> Option<Self> {
384 let (front_buffer, back_buffer) = match (buffers.checkout(), buffers.checkout()) {
385 (Some(front_buffer), Some(back_buffer)) => (front_buffer, back_buffer),
386 _ => return None,
387 };
388 let stream = Self {
389 state: StreamState::Idle,
390 attempts: 0,
391 tried_backends: Vec::new(),
392 front_window: i32::try_from(window).unwrap_or(i32::MAX),
393 back_window: i32::try_from(DEFAULT_INITIAL_WINDOW_SIZE).unwrap_or(i32::MAX),
394 front_received_end_of_stream: false,
395 back_received_end_of_stream: false,
396 front_data_received: 0,
397 back_data_received: 0,
398 request_counted: false,
399 front: GenericHttpStream::new(kawa::Kind::Request, kawa::Buffer::new(front_buffer)),
400 back: GenericHttpStream::new(kawa::Kind::Response, kawa::Buffer::new(back_buffer)),
401 retry_buffer: None,
402 front_bound_to_backend: false,
403 context,
404 metrics: SessionMetrics::new(None),
405 answers,
406 };
407 // Post: a freshly checked-out stream is a clean, closed slot — no
408 // request has been counted yet (so `generate_access_log` won't
409 // gauge-underflow `http.active_requests`) and no DATA has been seen on
410 // either half (the content-length reconciliation counters start at 0).
411 debug_assert_eq!(stream.state, StreamState::Idle, "new stream must be Idle");
412 debug_assert!(
413 !stream.state.is_open(),
414 "an Idle stream slot must not report as open"
415 );
416 debug_assert!(
417 !stream.request_counted,
418 "new stream must not have a counted request (gauge-underflow guard)"
419 );
420 debug_assert_eq!(
421 (stream.front_data_received, stream.back_data_received),
422 (0, 0),
423 "new stream DATA counters must start at 0"
424 );
425 debug_assert!(
426 !stream.front_bound_to_backend,
427 "a new stream's request is bound to no backend connection"
428 );
429 #[cfg(debug_assertions)]
430 stream.check_invariants();
431 Some(stream)
432 }
433
434 /// Cross-field invariant sweep for the per-request stream state machine.
435 ///
436 /// Encodes the relationships that must hold for ANY `Stream` regardless of
437 /// the mux path (H1 or H2) that drives it:
438 /// - `state.is_open()` agrees with the `Idle`/`Recycle` discriminants
439 /// (the open/closed split is the load-bearing predicate for shutdown and
440 /// slot reuse).
441 /// - a `Recycle` slot is fully reset — no counted request can be left
442 /// pending on a slot advertised as reusable, or `create_stream` would
443 /// resurrect a stale `http.active_requests` charge.
444 /// - a `Linked` stream names a backend token; the `Linked(token)`
445 /// discriminant and `linked_token()` must agree (the access-log and
446 /// reverse-index lookups both depend on this equivalence).
447 ///
448 /// Compiled only with `debug_assertions`; the optimizer drops every call
449 /// in release. Network input never reaches a hard `assert!` here — these
450 /// fire only on our own logic bugs.
451 #[cfg(debug_assertions)]
452 pub(super) fn check_invariants(&self) {
453 debug_assert_eq!(
454 self.state.is_open(),
455 !matches!(self.state, StreamState::Idle | StreamState::Recycle),
456 "is_open() must agree with the Idle/Recycle discriminants"
457 );
458 if self.state == StreamState::Recycle {
459 debug_assert!(
460 !self.request_counted,
461 "a Recycle slot must not carry a counted request (active-requests leak)"
462 );
463 }
464 // `linked_token()` is the canonical accessor for the backend token; it
465 // must return Some iff the slot is `Linked`, since the reverse index
466 // and the access-log RTT lookup both branch on it.
467 debug_assert_eq!(
468 self.linked_token().is_some(),
469 matches!(self.state, StreamState::Linked(_)),
470 "linked_token() must be Some iff the stream is Linked"
471 );
472 }
473 /// Convenience accessor for the backend token when the stream is `Linked`.
474 /// Used by access-log emission sites to look up the backend socket on the
475 /// owning `Endpoint`/`Router` without re-pattern-matching `state` inline.
476 pub fn linked_token(&self) -> Option<Token> {
477 match self.state {
478 StreamState::Linked(token) => Some(token),
479 _ => None,
480 }
481 }
482
483 /// Returns true when both front and back kawa buffers are in a terminal
484 /// or initial state with no pending data. Used during shutdown to skip
485 /// streams that have already completed their work.
486 pub fn is_quiesced(&self) -> bool {
487 let front_done =
488 (self.front.is_initial() || self.front.is_completed() || self.front.is_terminated())
489 && self.front.storage.is_empty();
490 let back_done =
491 (self.back.is_initial() || self.back.is_completed() || self.back.is_terminated())
492 && self.back.storage.is_empty();
493 front_done && back_done
494 }
495
496 /// The RFC 9113 §6.9 send window the connection at `position` holds for
497 /// this stream: [`Self::back_window`] on a backend connection
498 /// (`Position::Client`), [`Self::front_window`] on a frontend one. The
499 /// same selection as [`Self::split`]'s `window`, for the paths that
500 /// adjust a window without splitting the stream.
501 pub fn send_window_mut(&mut self, position: &Position) -> &mut i32 {
502 match position {
503 Position::Client(..) => &mut self.back_window,
504 Position::Server => &mut self.front_window,
505 }
506 }
507
508 pub fn split(&mut self, position: &Position) -> StreamParts<'_> {
509 // Pre: the front buffer always parses requests and the back buffer
510 // always parses responses. `split` only re-labels them as read/write
511 // for the caller's position — it must never swap their kawa kinds.
512 debug_assert_eq!(
513 self.front.kind,
514 kawa::Kind::Request,
515 "front buffer must hold a Request kawa"
516 );
517 debug_assert_eq!(
518 self.back.kind,
519 kawa::Kind::Response,
520 "back buffer must hold a Response kawa"
521 );
522 match position {
523 Position::Client(..) => StreamParts {
524 window: &mut self.back_window,
525 rbuffer: &mut self.back,
526 wbuffer: &mut self.front,
527 received_end_of_stream: &mut self.back_received_end_of_stream,
528 data_received: &mut self.back_data_received,
529 context: &mut self.context,
530 metrics: &mut self.metrics,
531 retry_buffer: &mut self.retry_buffer,
532 front_bound_to_backend: &mut self.front_bound_to_backend,
533 },
534 Position::Server => StreamParts {
535 window: &mut self.front_window,
536 rbuffer: &mut self.front,
537 wbuffer: &mut self.back,
538 received_end_of_stream: &mut self.front_received_end_of_stream,
539 data_received: &mut self.front_data_received,
540 context: &mut self.context,
541 metrics: &mut self.metrics,
542 retry_buffer: &mut self.retry_buffer,
543 front_bound_to_backend: &mut self.front_bound_to_backend,
544 },
545 }
546 }
547
548 /// Arm request capture for an attempt on a reused keep-alive upstream.
549 ///
550 /// Idempotent WITHIN one attempt: an already-armed buffer is left alone
551 /// so a multi-pass write keeps accumulating into the same allocation.
552 ///
553 /// It is NOT once per request. `super::h1::ConnectionH1::start_stream`
554 /// calls this on every `KeepAlive -> Connected` transition and
555 /// `reused_from_pool` is never cleared, so a replay that lands on
556 /// another pooled connection re-arms a fresh capture and may itself be
557 /// replayed. `Router::plan_connect`'s gate of `stream.attempts` against the
558 /// cluster's `max_connection_attempts` is the only bound on how many times
559 /// one request is re-issued.
560 ///
561 /// Arming is BEST EFFORT. Past [`MAX_ARMED_REPLAY_CAPTURES`] no buffer is
562 /// installed, `backend.retry.captures_declined` is incremented, and the
563 /// request proceeds un-replayable: [`Stream::can_replay_on_fresh_upstream`]
564 /// reads the absent buffer as "not replayable", so a stale pooled upstream
565 /// yields the same `502 Bad Gateway` it yielded before the replay existed.
566 /// Nothing is refused and no frontend parks — which is exactly what
567 /// pool-allocating the captures would have cost under the same memory
568 /// pressure (sozu-proxy/sozu#1450).
569 ///
570 /// A NON-IDEMPOTENT request is not captured at all, and does not spend a
571 /// charge. [`Stream::can_replay_on_fresh_upstream`] vetoes the method, so
572 /// such a capture could only ever be held for the life of the attempt and
573 /// thrown away. Before the ceiling that was pure waste; with one it is
574 /// also a slot a replayable request cannot have — on a POST-heavy pooled
575 /// workload it would be most of the budget, while
576 /// `backend.retry.captures_armed` sat at the ceiling showing an operator
577 /// nothing about why.
578 ///
579 /// The method is known here. `crate::protocol::http::editor::HttpContext`
580 /// sets it in `on_request_headers` during the frontend parse, and
581 /// `super::router::Router::plan_connect` routes on it — `route_from_request`,
582 /// which fails with `RetrieveClusterError::NoMethod` without it — before
583 /// it reaches `super::h1::ConnectionH1::start_stream`, the sole caller of
584 /// this function.
585 ///
586 /// This makes the idempotence conjunct in
587 /// [`Stream::can_replay_on_fresh_upstream`] unreachable in production
588 /// rather than redundant by accident. It is deliberately KEPT as defense
589 /// in depth: it is the conjunct a later widening of this guard would
590 /// silently undo, and it is the one the replay's whole justification
591 /// rests on (RFC 9110 §9.2.2).
592 pub fn arm_upstream_replay(&mut self) {
593 if self.retry_buffer.is_some() {
594 return;
595 }
596 if !self
597 .context
598 .method
599 .as_ref()
600 .is_some_and(Method::is_idempotent)
601 {
602 return;
603 }
604 match ReplayCapture::try_arm() {
605 Some(capture) => self.retry_buffer = Some(capture),
606 None => incr!(names::backend::RETRY_CAPTURES_DECLINED),
607 }
608 }
609
610 /// Forget the captured request.
611 ///
612 /// Called as soon as the upstream produces its first byte: past that
613 /// point the attempt is no longer replayable (the boundary below), so
614 /// holding the copy would only cost memory.
615 pub fn forget_upstream_replay(&mut self) {
616 self.retry_buffer = None;
617 }
618
619 /// May this stream's request be re-issued on a fresh upstream
620 /// connection?
621 ///
622 /// The boundary is **no response byte has been received**, narrowed to
623 /// the stale-pool race:
624 ///
625 /// - `retry_buffer.is_some()` proves BOTH that the whole serialized
626 /// request is still held AND that it went onto a reused keep-alive
627 /// connection, because that is the only path that arms the capture.
628 /// This is pingora's `RetryType::ReusedOnly`. It is a POLICY, not a
629 /// diagnosis: sozu cannot tell a stale pool socket from an origin
630 /// that half-closed after processing the request, or from one that
631 /// crashed mid-request — `super::h1::ConnectionH1::readable` treats
632 /// every `size == 0` alike. Restricting replay to pooled connections
633 /// narrows it to the case where an unobserved idle close is
634 /// plausible; the conjunct below is what makes re-issuing permissible.
635 /// - the method is idempotent, which RFC 9110 §9.2.2 defines as exactly
636 /// this permission: re-issuing it has the same intended effect as
637 /// issuing it once, so a client cannot observe the difference. That is
638 /// the load-bearing justification for the whole feature. nginx refuses
639 /// `POST, LOCK, PATCH` "if a request has been sent to an upstream
640 /// server" unless `non_idempotent` is set; pingora vetoes on
641 /// `!method.is_idempotent()`; HAProxy provides an
642 /// `http-request disable-l7-retry` action and gives POST as the
643 /// rationale for reaching for it.
644 /// - the upstream produced nothing at all: no byte forwarded
645 /// (`!back.consumed`) and no byte even buffered
646 /// (`back.storage.is_empty()`). nginx: "passing a request to the next
647 /// server is only possible if nothing has been sent to a client yet".
648 /// Requiring an empty back buffer is stricter than that — a partial
649 /// status line is HAProxy's `junk-response`, which it keeps out of
650 /// every default.
651 ///
652 /// The caller must additionally have established that no response is
653 /// available at all; `super::shared::end_stream_decision` owns that part
654 /// and is the only caller.
655 pub fn can_replay_on_fresh_upstream(&self) -> bool {
656 self.retry_buffer.is_some()
657 && self
658 .context
659 .method
660 .as_ref()
661 .is_some_and(Method::is_idempotent)
662 && !self.back.consumed
663 && self.back.storage.is_empty()
664 }
665
666 /// Queue the captured request for re-serialization onto a fresh upstream.
667 ///
668 /// The bytes go back into `front.out` as an owned `Store::Alloc`, and
669 /// they are PREPENDED. `out` is not necessarily empty at this point:
670 /// [`super::h1::ConnectionH1::writable`] answers a partial
671 /// `socket_write_vectored` by signalling a pending write and returning,
672 /// and `kawa::Kawa::consume` pushes the partially consumed store back to
673 /// the FRONT of `out` (kawa-0.7.1 `storage/repr.rs`), so the bytes the
674 /// kernel refused are still queued here. The capture holds exactly the
675 /// bytes the socket DID accept, so capture and remainder are the
676 /// complementary halves of one serialization and the capture belongs
677 /// ahead of the remainder. `kawa::Kawa::push_out` appends, which would
678 /// put `[tail][head]` on the wire — a request mangled mid-token.
679 ///
680 /// `VecDeque::push_front` preserves the relative order of what is already
681 /// queued, so this is correct however many entries the remainder spans:
682 /// `consume` pushes back at most ONE partially consumed store and drops
683 /// every entry ahead of it.
684 ///
685 /// Prepending an owned `Store::Alloc` is also safe for kawa's storage
686 /// bookkeeping. `Kawa::leftmost_ref` scans `out` for the first
687 /// `Store::Slice` and skips an `Alloc`, so buffer reclamation is
688 /// unchanged, and `Store::push_left` is a no-op on an `Alloc`, whose
689 /// bytes live outside `storage` and survive a shift.
690 ///
691 /// `front.blocks` was drained by the `prepare` that preceded the write,
692 /// so the next `writable` pass's `prepare` contributes nothing of its
693 /// own. Replaying the SERIALIZED form (rather than re-running the block
694 /// converter) also makes the retried request byte-identical to the first
695 /// attempt, `Sozu-Id` and `X-Forwarded-*` included.
696 ///
697 /// Returns the number of bytes queued, or `None` when nothing was held.
698 pub fn queue_upstream_replay(&mut self) -> Option<usize> {
699 let request = self.retry_buffer.take()?.into_bytes();
700 let len = request.len();
701 self.front
702 .out
703 .push_front(kawa::OutBlock::Store(kawa::Store::from_vec(request)));
704 Some(len)
705 }
706
707 /// Emit the access log for this stream.
708 ///
709 /// `client_rtt`/`server_rtt` are passed in by the caller because the
710 /// `Stream` does not own a socket reference — the frontend socket lives
711 /// on the parent `Mux`/connection and the backend socket lives on
712 /// `Router.backends.get(token)`. Each caller snapshots the two
713 /// `getsockopt(TCP_INFO)` values from the sockets it can reach, mirroring
714 /// the inline pattern used by the `pipe` and TCP-frontend access-log
715 /// sites.
716 /// Generate the access log, and return the metric events the caller must
717 /// record.
718 ///
719 /// **The bound is two, and it is saturated by exactly these two events**:
720 /// [`MetricEvent::ActiveRequestFinished`], emitted when `request_counted`
721 /// was set, and [`MetricEvent::AccessLogUnsent`], emitted when the logger
722 /// refused the record. A fixed array rather than a `Vec` because the
723 /// count is known: this function is allocation-free and must stay so, and
724 /// a caller that is its own shell has no queue to lend. Slots are filled
725 /// by explicit index, never through a `push` helper — a `push` that
726 /// overflowed a fixed array would silently drop an event, and a dropped
727 /// `-1` is an upward drift that never underflows, so nothing logs and
728 /// nothing saturates. A third event means changing this type, which is a
729 /// compile error at every call site rather than a truncation.
730 ///
731 /// The three remaining metric sites in this body stay `incr!` macros on
732 /// purpose: they carry `cluster_id`/`backend_id` labels, and carrying
733 /// those in a `MetricEvent` means owned `Option<String>`s, which measures
734 /// at `size_of::<MetricEvent>()` 24 -> 48 bytes for every queued event
735 /// and costs the enum its `Copy` — for sites that fire on every access
736 /// log. Same trade as `names::backend::RETRY_STALE_UPSTREAM`, and worse,
737 /// because that one fires only on a stale-upstream retry.
738 #[must_use]
739 pub(super) fn generate_access_log<L>(
740 &mut self,
741 error: bool,
742 message: Option<&str>,
743 listener: Rc<RefCell<L>>,
744 client_rtt: Option<Duration>,
745 server_rtt: Option<Duration>,
746 ) -> [Option<MetricEvent>; 2]
747 where
748 L: ListenerHandler + L7ListenerHandler,
749 {
750 let mut events: [Option<MetricEvent>; 2] = [None, None];
751 let context = &self.context;
752 let metric_incarnation = self.context.cluster_metrics_incarnation();
753 // Fall back to the per-stream timeout discriminator
754 // (`access_log_message`) when the caller did not supply an explicit
755 // `message`. The discriminator is set by `MuxState::timeout` before
756 // `set_default_answer` / `forcefully_terminate_answer` so the
757 // access log can distinguish a timeout-driven 408/504 from a
758 // backend-error 504. Caller-supplied `message` (e.g. parsing
759 // errors) takes precedence when both are present.
760 let message = message.or(context.access_log_message);
761 // Pair the `http.active_requests` gauge `-1` with `request_counted`:
762 // it must transition true -> false exactly once so a re-entry (H1
763 // keep-alive, double access-log on the same stream) cannot
764 // double-decrement the gauge into underflow. `request_counted` is set
765 // true at the matching `gauge_add!(.., 1)` in the H1/H2 readable paths.
766 let was_counted = self.request_counted;
767 if self.request_counted {
768 events[0] = Some(MetricEvent::ActiveRequestFinished);
769 self.request_counted = false;
770 }
771 debug_assert!(
772 !self.request_counted,
773 "generate_access_log must leave request_counted false (gauge-underflow guard)"
774 );
775 // The flag may only move true->false here (one `-1`); it must never be
776 // observed flipping back on within this call.
777 debug_assert!(
778 was_counted >= self.request_counted,
779 "request_counted must only clear here, never spontaneously set"
780 );
781 if error {
782 // Labelled with `(cluster_id, backend_id)`. Since the unreachable
783 // `kawa_h1::Http` session was removed (sozu#1346) this is the SOLE
784 // `names::http::ERRORS` emission site in the crate, so the labels
785 // written here are the whole cardinality contract for `http.errors`;
786 // the backend label is dropped centrally, by detail level, in
787 // `metrics::filter_labels_for_detail` (`lib/src/metrics/mod.rs`).
788 // `pipe::log_request_error` is a different metric
789 // (`names::pipe::ERRORS`) and is not a second source of this one.
790 incr!(
791 names::http::ERRORS,
792 context.cluster_id.as_deref(),
793 context.backend_id.as_deref(),
794 metric_incarnation
795 );
796 }
797 let protocol = match context.protocol {
798 Protocol::HTTP => "http",
799 Protocol::HTTPS => "https",
800 other => {
801 error!(
802 "{} mux streams only handle HTTP or HTTPS protocols, got {:?}",
803 log_module_context!(),
804 other
805 );
806 "unknown"
807 }
808 };
809
810 // Save the HTTP status code of the backend response. Emits the bucket
811 // counter unconditionally, plus the per-code counter from
812 // `crate::metrics::http_status_code_metric_name` when the status is on
813 // the short-list that file maintains. This is the ONLY HTTP status
814 // bucketer left since `kawa_h1::save_http_status_metric` was removed
815 // with the unreachable H1 session (sozu#1346, 2026-09-20).
816 let bucket_key = if let Some(status) = context.status {
817 match status {
818 100..=199 => names::http::STATUS_1XX,
819 200..=299 => names::http::STATUS_2XX,
820 300..=399 => names::http::STATUS_3XX,
821 400..=499 => names::http::STATUS_4XX,
822 500..=599 => names::http::STATUS_5XX,
823 _ => names::http::STATUS_OTHER,
824 }
825 } else {
826 "http.status.none"
827 };
828 incr!(
829 bucket_key,
830 context.cluster_id.as_deref(),
831 context.backend_id.as_deref(),
832 metric_incarnation
833 );
834
835 if let Some(status) = context.status
836 && let Some(per_code) = crate::metrics::http_status_code_metric_name(status)
837 {
838 incr!(
839 per_code,
840 context.cluster_id.as_deref(),
841 context.backend_id.as_deref(),
842 metric_incarnation
843 );
844 }
845
846 // A request the parse rejected before `HttpContext` captured its
847 // request line (sozu-proxy/sozu#1085) is logged from the front
848 // buffer, borrowed: see `rejected_request_line` for why this is a
849 // second path and not a call to the nominal capture.
850 let rejected = if context.method.is_none() {
851 rejected_request_line(&self.front)
852 } else {
853 None
854 };
855 debug_assert!(
856 rejected.is_none() || self.front.is_error(),
857 "only a rejected request is logged from the front buffer"
858 );
859 debug_assert!(
860 rejected.is_none() || context.method.is_none(),
861 "a request line the context captured must never be overridden"
862 );
863 let endpoint = match &rejected {
864 Some(line) => sozu_command::logging::EndpointRecord::Http {
865 method: line.method,
866 authority: line.authority,
867 path: line.path,
868 reason: context.reason.as_deref(),
869 status: context.status,
870 },
871 None => sozu_command::logging::EndpointRecord::Http {
872 method: context.method.as_deref(),
873 authority: context.authority.as_deref(),
874 path: context.path.as_deref(),
875 reason: context.reason.as_deref(),
876 status: context.status,
877 },
878 };
879
880 let listener = listener.borrow();
881 // Tags resolved by the router from the frontend rule that actually
882 // matched this request win: they are the only ones that can be
883 // right for a wildcard, regex, ported or differently-cased
884 // frontend. The listener's authority-keyed map is written under
885 // the frontend RULE's hostname and read here under the REQUEST's
886 // authority, so it only ever answers for an exact literal
887 // frontend (sozu#1379).
888 //
889 // It stays as the fallback for a request that never reached
890 // routing at all — a malformed request, an unknown host, a TLS
891 // SNI/authority mismatch — where there is no matched frontend to
892 // ask and the pre-existing best-effort answer is better than none.
893 let tags = context.tags.as_deref().or_else(|| {
894 context.authority.as_deref().and_then(|host| {
895 let hostname = match host.split_once(':') {
896 None => host,
897 Some((hostname, _)) => hostname,
898 };
899 listener.get_tags(hostname)
900 })
901 });
902
903 log_access! {
904 error,
905 on_failure: { events[1] = Some(MetricEvent::AccessLogUnsent) },
906 message,
907 context: context.log_context(),
908 session_address: context.session_address,
909 backend_address: context.backend_address,
910 protocol,
911 endpoint,
912 tags,
913 client_rtt,
914 server_rtt,
915 service_time: self.metrics.service_time(),
916 response_time: self.metrics.backend_response_time(),
917 request_time: self.metrics.request_time(),
918 start_time_ns: self.metrics.start_wall_ns(),
919 bytes_in: self.metrics.bin,
920 bytes_out: self.metrics.bout,
921 user_agent: context.user_agent.as_deref(),
922 x_request_id: context.x_request_id.as_deref(),
923 tls_version: context.tls_version,
924 tls_cipher: context.tls_cipher,
925 tls_sni: context.tls_server_name.as_deref(),
926 tls_alpn: context.tls_alpn,
927 xff_chain: context.xff_chain.as_deref(),
928 #[cfg(feature = "opentelemetry")]
929 otel: context.otel.as_ref(),
930 #[cfg(not(feature = "opentelemetry"))]
931 otel: None,
932 };
933 self.metrics
934 .register_end_of_session_for_incarnation(&context.log_context(), metric_incarnation);
935
936 events
937 }
938}
939
940/// The request line of a rejected request, borrowed from the front buffer.
941/// See [`rejected_request_line`].
942struct RejectedRequestLine<'a> {
943 method: Option<&'a str>,
944 authority: Option<&'a str>,
945 path: Option<&'a str>,
946}
947
948/// The request line of a request the parse rejected before [`HttpContext`]
949/// captured it, borrowed from the front buffer (sozu-proxy/sozu#1085).
950/// `None` unless `front` is in error and holds a parsed request line.
951/// HTTP/1.1 and HTTP/2 both reach here; the H2 case has its own section
952/// below.
953///
954/// # Two paths fill the access log's request line, on purpose
955///
956/// The nominal one is `HttpContext::on_request_headers`
957/// (`lib/src/protocol/kawa_h1/editor.rs`), which copies method, authority
958/// and path into owned `Option<String>`s: routing, redirects and header
959/// edits read them long after the parse. This one serves the access log
960/// alone, on the rejection path, and BORROWS: `EndpointRecord::Http` already
961/// takes `&str`, and the access-log path stays allocation-free. Do not
962/// replace it with a call to the nominal capture — that brings back two to
963/// three allocations per rejected request, a rate the client chooses.
964///
965/// Borrowing is sound because the bytes are still there: an H1 front is only
966/// ever reset through `kawa::Kawa::clear`, which returns
967/// `detached.status_line` to `StatusLine::Unknown` in the same call, so a
968/// `StatusLine::Request` here always points into the request it was parsed
969/// from.
970///
971/// # What is recovered, and what is refused
972///
973/// - kawa refused a header, or the framing in `process_headers`, after the
974/// request line. Its authority and path are still empty, so the
975/// request-target is split with `kawa::h1::parser::primitives::parse_url`,
976/// which answers `Store::Slice`/`Store::Static` and allocates nothing.
977/// - Sōzu's CL.TE guard in `HttpContext::on_request_headers` refused a
978/// request kawa had accepted, returning before the capture. kawa already
979/// resolved the authority and the path; they are logged as-is.
980///
981/// The authority of an origin-form request is NEVER read from a `Host`
982/// block. When kawa refuses a header, whether the `Host` line was reached is
983/// the client's choice — put the bad line first and no `Host` block exists —
984/// and a reached one was never validated. Only an authority the request
985/// line itself carries (absolute-form, `CONNECT`) is logged. Do not
986/// "complete" this with a `Host` lookup.
987///
988/// # HTTP/2
989///
990/// An H2 request `handle_header` (`lib/src/protocol/mux/pkawa.rs`) refused
991/// reaches here through `record_rejected_request` in the same file, which
992/// marks the front in error and keeps the pseudo-headers decoded before the
993/// refusal as a `Version::V20` line. Each is logged as stored, and a missing
994/// one as `-`: there is no request-target to split, and `:path` may be the
995/// very field that was missing. The authority is `:authority`, and only
996/// when it was validated — `record_rejected_request`'s caller empties it
997/// when it was refused, repeated, or disputed by a `host` field — never a
998/// `host` field. Borrowing is sound for the same reason as in H1: the
999/// stream is out of the connection's stream table once reset, so nothing
1000/// writes its front again, and a slot is reused only through
1001/// `Context::create_stream` (`lib/src/protocol/mux/mod.rs`), which clears
1002/// `front` and `front.storage` together.
1003fn rejected_request_line(front: &GenericHttpStream) -> Option<RejectedRequestLine<'_>> {
1004 if !front.is_error() {
1005 return None;
1006 }
1007 let kawa::StatusLine::Request {
1008 version,
1009 method,
1010 uri,
1011 authority,
1012 path,
1013 } = &front.detached.status_line
1014 else {
1015 return None;
1016 };
1017 let buf = front.storage.buffer();
1018 if matches!(version, kawa::Version::V20) {
1019 debug_assert!(
1020 borrowed_bytes(uri, buf).is_none(),
1021 "a rejected H2 request line carries no request-target"
1022 );
1023 return Some(RejectedRequestLine {
1024 method: borrowed_str(method, buf),
1025 authority: borrowed_str(authority, buf),
1026 path: borrowed_str(path, buf),
1027 });
1028 }
1029 let method_bytes = borrowed_bytes(method, buf)?;
1030 let method = std::str::from_utf8(method_bytes).ok();
1031
1032 if let Some(path) = borrowed_str(path, buf) {
1033 // `process_headers` ran, so the refusal is Sōzu's own.
1034 return Some(RejectedRequestLine {
1035 method,
1036 authority: borrowed_str(authority, buf),
1037 path: Some(path),
1038 });
1039 }
1040 debug_assert!(
1041 borrowed_bytes(authority, buf).is_none(),
1042 "kawa resolves the authority and the path together"
1043 );
1044 let (authority, path) = borrowed_bytes(uri, buf)
1045 .and_then(|uri| kawa::h1::parser::primitives::parse_url(buf, method_bytes, uri))
1046 .map_or((None, None), |(authority, path)| {
1047 (borrowed_str(&authority, buf), borrowed_str(&path, buf))
1048 });
1049 Some(RejectedRequestLine {
1050 method,
1051 authority,
1052 path,
1053 })
1054}
1055
1056/// A `kawa::Store`'s bytes, borrowed from `buf` or from static data. `None`
1057/// for every variant that owns its bytes, and for an empty store.
1058fn borrowed_bytes<'a>(store: &kawa::Store, buf: &'a [u8]) -> Option<&'a [u8]> {
1059 match store {
1060 kawa::Store::Slice(slice) => slice.data_opt(buf),
1061 kawa::Store::Static(bytes) => Some(bytes),
1062 _ => None,
1063 }
1064}
1065
1066/// [`borrowed_bytes`], as UTF-8. Non-UTF-8 bytes are dropped, the way the
1067/// nominal capture in `HttpContext::on_request_headers` drops them.
1068fn borrowed_str<'a>(store: &kawa::Store, buf: &'a [u8]) -> Option<&'a str> {
1069 borrowed_bytes(store, buf).and_then(|bytes| std::str::from_utf8(bytes).ok())
1070}
1071
1072#[cfg(test)]
1073mod tests {
1074 use std::net::{IpAddr, Ipv4Addr, SocketAddr};
1075
1076 use rusty_ulid::Ulid;
1077 use sozu_command::proto::command::filtered_metrics;
1078
1079 use super::*;
1080 use crate::{
1081 metrics::METRICS,
1082 pool::Pool,
1083 protocol::mux::{
1084 buffer_source::PoolBufferSource,
1085 shared::{self, EndStreamAction},
1086 test_support::TestListener,
1087 },
1088 };
1089
1090 /// A bare `Stream` holding two real pool buffers, built the way the
1091 /// sibling test above builds one. Enough for the capture-budget tests:
1092 /// they exercise `Stream`'s own arm/release surface, not a mux.
1093 ///
1094 /// `context.method` is left UNSET deliberately. `arm_upstream_replay`
1095 /// captures only an idempotent request, so every test that means to arm
1096 /// one states its own method and none of them inherits that precondition
1097 /// from the fixture.
1098 fn test_stream(pool: &Rc<RefCell<Pool>>) -> Stream {
1099 let context = HttpContext::new(
1100 Ulid::generate(),
1101 Ulid::generate(),
1102 Protocol::HTTP,
1103 SocketAddr::new(IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1)), 8080),
1104 Some(SocketAddr::new(
1105 IpAddr::V4(Ipv4Addr::new(10, 0, 0, 1)),
1106 54321,
1107 )),
1108 "SERVERID".to_owned(),
1109 "Sozu-Id".to_owned(),
1110 false,
1111 false,
1112 );
1113 Stream::new(
1114 &mut PoolBufferSource::new(Rc::downgrade(pool)),
1115 context,
1116 crate::protocol::mux::test_support::test_answers(),
1117 65535,
1118 )
1119 .expect("test stream checkout")
1120 }
1121
1122 /// The current value of one proxy-level metric for this test thread.
1123 /// `METRICS` is a `thread_local!`, so this reads what this thread emitted;
1124 /// every assertion below is nonetheless a DELTA against a baseline taken
1125 /// at the top of the test, which stays correct under `--test-threads=1`
1126 /// where libtest reuses one thread. Mirrors `server.rs`'s
1127 /// `active_flows_gauge`.
1128 fn proxy_metric(name: &str) -> i64 {
1129 METRICS.with(|metrics| {
1130 metrics
1131 .borrow_mut()
1132 .dump_local_proxy_metrics()
1133 .get(name)
1134 .and_then(|metric| match metric.inner {
1135 Some(filtered_metrics::Inner::Gauge(value)) => Some(value as i64),
1136 Some(filtered_metrics::Inner::Count(value)) => Some(value),
1137 _ => None,
1138 })
1139 .unwrap_or(0)
1140 })
1141 }
1142
1143 /// Take every charge the budget has left, and hold them.
1144 ///
1145 /// Bounded by construction rather than by `while try_arm().is_some()`: a
1146 /// ceiling-less `try_arm` would never end that loop, and a test that hangs
1147 /// instead of failing proves nothing. Charges are taken through the same
1148 /// `ReplayCapture::try_arm` `Stream::arm_upstream_replay` calls, so this
1149 /// fills the real budget and not a stand-in for it.
1150 fn fill_the_capture_budget() -> Vec<ReplayCapture> {
1151 let held: Vec<ReplayCapture> = (0..MAX_ARMED_REPLAY_CAPTURES)
1152 .filter_map(|_| ReplayCapture::try_arm())
1153 .collect();
1154 // Reachability, not the property under test: the budget was empty, so
1155 // every charge was granted and it is now exactly full. It holds with
1156 // or without the CEILING, so removing the ceiling never reddens a test
1157 // here — but it does NOT hold under a mutation that leaks charges,
1158 // where it fires at `left: 511 / right: 512` before the assertion the
1159 // test is actually about. Any release-path mutation must therefore be
1160 // checked against a test that does not call this helper;
1161 // `queueing_a_replay_releases_the_capture_charge` is that test.
1162 assert_eq!(
1163 held.len(),
1164 MAX_ARMED_REPLAY_CAPTURES,
1165 "an empty budget must grant every one of its charges"
1166 );
1167 held
1168 }
1169
1170 /// `queue_upstream_replay` is the one release path that works AROUND
1171 /// [`Drop`]: a `Vec` cannot be moved out of a type that implements it, so
1172 /// [`ReplayCapture::into_bytes`] swaps in an empty `Vec` and lets the husk
1173 /// drop. The simplification a later contributor reaches for — a
1174 /// `std::mem::forget(self)` to "avoid the pointless drop" — leaks the
1175 /// charge instead, one per replay, until the ceiling disarms replay for
1176 /// the rest of the worker's life with `backend.retry.captures_armed`
1177 /// pinned at 512.
1178 ///
1179 /// This is the release path that most needs a test. The other three
1180 /// clearing sites are plain `= None` assignments, where drop-on-assign is
1181 /// not something an edit can quietly remove; this one is a hand-written
1182 /// dance around `Drop`. `super::tests::
1183 /// queueing_a_replay_moves_the_captured_bytes_into_the_front_buffer`
1184 /// covers the bytes and the taken buffer, and looks at neither the budget
1185 /// nor the gauge.
1186 ///
1187 /// Deliberately does not call `fill_the_capture_budget`: that helper's own
1188 /// reachability assertion fires under a leaking mutation, and would hide
1189 /// this one.
1190 ///
1191 /// To SEE THIS RED: insert `std::mem::forget(self);` before the returned
1192 /// `bytes` in [`ReplayCapture::into_bytes`].
1193 #[test]
1194 fn queueing_a_replay_releases_the_capture_charge() {
1195 setup_test_logger!();
1196 const REQUEST: &[u8] = b"GET /api HTTP/1.1\r\nHost: localhost\r\n\r\n";
1197 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1198 let charged_before = ARMED_REPLAY_CAPTURES.get();
1199 let gauged_before = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
1200
1201 let mut stream = test_stream(&pool);
1202 stream.context.method = Some(Method::Get);
1203 stream.arm_upstream_replay();
1204 stream
1205 .retry_buffer
1206 .as_mut()
1207 .expect("an idempotent request under the ceiling must be captured")
1208 .extend_from_slice(REQUEST);
1209
1210 let queued = stream
1211 .queue_upstream_replay()
1212 .expect("the armed stream carries a capture");
1213
1214 // Reachability: the capture really carried the request and really was
1215 // spent, so what is asserted below is the release of a SPENT capture
1216 // and not of an empty one.
1217 assert_eq!(
1218 queued,
1219 REQUEST.len(),
1220 "the whole captured request must be queued for the fresh upstream"
1221 );
1222
1223 assert_eq!(
1224 ARMED_REPLAY_CAPTURES.get(),
1225 charged_before,
1226 "queueing a replay must release the capture's charge"
1227 );
1228 assert_eq!(
1229 proxy_metric(names::backend::RETRY_CAPTURES_ARMED),
1230 gauged_before,
1231 "queueing a replay must return the armed gauge to where it started"
1232 );
1233 }
1234
1235 /// A non-idempotent request is not captured and spends no charge.
1236 /// [`Stream::can_replay_on_fresh_upstream`] vetoes the method, so the
1237 /// capture could only ever be held for the life of the attempt and thrown
1238 /// away. Before the ceiling that was waste; with one it is also a slot a
1239 /// replayable request cannot have — on a POST-heavy pooled workload it
1240 /// would be most of the budget.
1241 ///
1242 /// The idempotent half is load-bearing: without it this test would pass
1243 /// against an `arm_upstream_replay` that captured nothing at all.
1244 ///
1245 /// The final assertion pins the metric's MEANING, not just its value:
1246 /// `backend.retry.captures_declined` counts refusals for BUDGET, and a
1247 /// method veto is not one. Counting it there would make the counter read
1248 /// as lost retries when nothing was lost.
1249 ///
1250 /// To SEE THIS RED: delete the `Method::is_idempotent` early return from
1251 /// [`Stream::arm_upstream_replay`].
1252 #[test]
1253 fn a_non_idempotent_request_is_never_charged_to_the_capture_budget() {
1254 setup_test_logger!();
1255 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1256 let charged_before = ARMED_REPLAY_CAPTURES.get();
1257 let declined_before = proxy_metric(names::backend::RETRY_CAPTURES_DECLINED);
1258
1259 let mut idempotent = test_stream(&pool);
1260 idempotent.context.method = Some(Method::Get);
1261 idempotent.arm_upstream_replay();
1262 assert!(
1263 idempotent.retry_buffer.is_some(),
1264 "an idempotent request under the ceiling must be captured"
1265 );
1266 assert_eq!(
1267 ARMED_REPLAY_CAPTURES.get(),
1268 charged_before + 1,
1269 "an idempotent request must spend a charge"
1270 );
1271 drop(idempotent);
1272
1273 // `PATCH` parses as `Method::Custom`, which is how sozu refuses every
1274 // method whose semantics it does not know.
1275 for method in [Method::Post, Method::new(b"PATCH")] {
1276 let mut stream = test_stream(&pool);
1277 stream.context.method = Some(method);
1278
1279 stream.arm_upstream_replay();
1280
1281 assert!(
1282 stream.retry_buffer.is_none(),
1283 "a non-idempotent request must not be captured"
1284 );
1285 assert_eq!(
1286 ARMED_REPLAY_CAPTURES.get(),
1287 charged_before,
1288 "a non-idempotent request must not spend a capture charge"
1289 );
1290 }
1291
1292 assert_eq!(
1293 proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
1294 0,
1295 "a method veto is not a budget refusal and must not be counted as one"
1296 );
1297 }
1298
1299 /// The ceiling of sozu-proxy/sozu#1450. Past [`MAX_ARMED_REPLAY_CAPTURES`]
1300 /// armed captures, [`Stream::arm_upstream_replay`] installs NO buffer —
1301 /// and the request it belongs to still completes, un-replayable, answered
1302 /// with exactly the `502 Bad Gateway` `end_stream_decision` returned for
1303 /// every consumed request before the replay existed. Nothing is refused,
1304 /// no frontend parks, no session is answered `503`: that graceful
1305 /// degradation is the whole reason the captures were not moved into the
1306 /// buffer [`Pool`].
1307 ///
1308 /// The under-ceiling half is load-bearing. Without it this test would pass
1309 /// against an `arm_upstream_replay` that armed nothing at all, which is
1310 /// the same observation as "past the ceiling it arms nothing".
1311 ///
1312 /// To SEE THIS RED: in [`ReplayCapture::try_arm`], delete the
1313 /// `if armed >= MAX_ARMED_REPLAY_CAPTURES { return None; }` early return so
1314 /// the budget is never consulted.
1315 #[test]
1316 fn past_the_ceiling_a_pooled_request_is_armed_with_no_buffer_and_still_completes() {
1317 setup_test_logger!();
1318 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1319
1320 let mut under_the_ceiling = test_stream(&pool);
1321 under_the_ceiling.context.method = Some(Method::Get);
1322 under_the_ceiling.arm_upstream_replay();
1323 assert!(
1324 under_the_ceiling.retry_buffer.is_some(),
1325 "under the ceiling arm_upstream_replay must install a capture"
1326 );
1327 // Releases both the charge and the two pool buffers the next stream
1328 // checks out.
1329 drop(under_the_ceiling);
1330
1331 let _held = fill_the_capture_budget();
1332
1333 let mut stream = test_stream(&pool);
1334 stream.context.method = Some(Method::Get);
1335 stream.arm_upstream_replay();
1336 assert!(
1337 stream.retry_buffer.is_none(),
1338 "past the ceiling arm_upstream_replay must install no capture"
1339 );
1340
1341 // The request was written to the upstream (`front.consumed`) and the
1342 // upstream produced nothing — the exact shape sozu-proxy/sozu#1442
1343 // replays. With no capture it is not replayable, and the answer is the
1344 // pre-#1442 one rather than a refusal.
1345 stream.front.consumed = true;
1346 assert_eq!(
1347 shared::end_stream_decision(&stream),
1348 EndStreamAction::SendDefault(502),
1349 "a request the budget declined to capture must still be answered, \
1350 un-replayable, exactly as it was before the replay existed"
1351 );
1352 }
1353
1354 /// Queue a GET request on `stream`'s request side, closed with
1355 /// END_STREAM, the way a parsed request waits for its backend.
1356 fn queue_get(stream: &mut Stream) {
1357 let kawa = &mut stream.front;
1358 kawa.detached.status_line = kawa::StatusLine::Request {
1359 version: kawa::Version::V11,
1360 method: kawa::Store::Static(b"GET"),
1361 uri: kawa::Store::Static(b"/"),
1362 authority: kawa::Store::Static(b"example.com"),
1363 path: kawa::Store::Static(b"/"),
1364 };
1365 kawa.push_block(kawa::Block::StatusLine);
1366 kawa.push_block(kawa::Block::Header(kawa::Pair {
1367 key: kawa::Store::Static(b"Host"),
1368 val: kawa::Store::Static(b"example.com"),
1369 }));
1370 kawa.push_block(kawa::Block::Flags(kawa::Flags {
1371 end_body: false,
1372 end_chunk: false,
1373 end_header: true,
1374 end_stream: true,
1375 }));
1376 kawa.parsing_phase = kawa::ParsingPhase::Terminated;
1377 }
1378
1379 /// H1 non-regression for sozu-proxy/sozu#1632: an H1 backend's write pass
1380 /// prepared the request (its blocks are converted to H1 bytes in
1381 /// `front.out`) and the socket took none of it before the backend went
1382 /// away. Those bytes are protocol-level and any fresh H1 connection can
1383 /// send them as they are, so the untouched request is still reconnected.
1384 ///
1385 /// TO SEE THIS RED: in `shared::end_stream_decision`, test
1386 /// `!stream.front.out.is_empty()` instead of
1387 /// `stream.front_bound_to_backend`. The request is then refused:
1388 /// `left: SendDefault(502), right: Reconnect`.
1389 #[test]
1390 fn an_untouched_request_prepared_for_an_h1_backend_is_still_reconnected() {
1391 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1392 let mut stream = test_stream(&pool);
1393 queue_get(&mut stream);
1394 stream.front.prepare(&mut kawa::h1::BlockConverter);
1395 assert!(
1396 !stream.front.out.is_empty() && !stream.front.consumed,
1397 "premise: the H1 bytes are prepared and unsent"
1398 );
1399 assert!(
1400 !stream.front_bound_to_backend,
1401 "premise: only an H2 backend binds a request"
1402 );
1403 assert_eq!(
1404 shared::end_stream_decision(&stream),
1405 EndStreamAction::Reconnect,
1406 "an untouched request prepared for H1 must still be retried"
1407 );
1408 }
1409
1410 /// sozu-proxy/sozu#1632: a request an H2 backend encoded and did not
1411 /// send is refused a reconnect, since its frames belong to that
1412 /// connection and its blocks are gone. It is answered like a request that
1413 /// reached the backend; a response already started still wins, and a
1414 /// request that reached the backend keeps its replay decision.
1415 ///
1416 /// TO SEE THIS RED: in `shared::end_stream_decision`, delete the
1417 /// `stream.front_bound_to_backend` branch: `left: Reconnect, right:
1418 /// SendDefault(502)`.
1419 #[test]
1420 fn a_request_encoded_for_an_h2_backend_is_not_reconnected() {
1421 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1422 let mut stream = test_stream(&pool);
1423 queue_get(&mut stream);
1424 // What an H2 backend's write pass leaves: frames in `front.out`, the
1425 // blocks gone, nothing written.
1426 stream.front.prepare(&mut kawa::h1::BlockConverter);
1427 stream.front_bound_to_backend = true;
1428 assert_eq!(
1429 shared::end_stream_decision(&stream),
1430 EndStreamAction::SendDefault(502),
1431 "a request encoded for one H2 backend must not be linked to another"
1432 );
1433 stream.front.consumed = true;
1434 assert_eq!(
1435 shared::end_stream_decision(&stream),
1436 EndStreamAction::SendDefault(502),
1437 "a request that reached the backend keeps its own decision"
1438 );
1439 }
1440
1441 /// The two metrics of sozu-proxy/sozu#1450.
1442 /// `backend.retry.captures_armed` follows arm and release;
1443 /// `backend.retry.captures_declined` moves when — and only when — a
1444 /// request is refused a capture for budget. An invisible heap
1445 /// proportional to a fraction of the pool is not an operational signal;
1446 /// these two are.
1447 ///
1448 /// To SEE THIS RED, one revert per assertion:
1449 /// - the arm gauge: delete the
1450 /// `gauge_add!(names::backend::RETRY_CAPTURES_ARMED, 1)` from
1451 /// [`ReplayCapture::try_arm`];
1452 /// - the release gauge: delete the matching
1453 /// `gauge_add!(names::backend::RETRY_CAPTURES_ARMED, -1)` from
1454 /// `ReplayCapture`'s `impl Drop`;
1455 /// - the declined counter: replace
1456 /// `None => incr!(names::backend::RETRY_CAPTURES_DECLINED)` in
1457 /// [`Stream::arm_upstream_replay`] with `None => {}`.
1458 #[test]
1459 fn the_armed_gauge_and_the_declined_counter_track_the_capture_budget() {
1460 setup_test_logger!();
1461 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1462 let armed_before = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
1463 let declined_before = proxy_metric(names::backend::RETRY_CAPTURES_DECLINED);
1464
1465 let mut stream = test_stream(&pool);
1466 stream.context.method = Some(Method::Get);
1467 stream.arm_upstream_replay();
1468 assert_eq!(
1469 proxy_metric(names::backend::RETRY_CAPTURES_ARMED) - armed_before,
1470 1,
1471 "arming a capture must raise the armed gauge by exactly one"
1472 );
1473 assert_eq!(
1474 proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
1475 0,
1476 "a capture the budget granted must not be counted as declined"
1477 );
1478
1479 stream.forget_upstream_replay();
1480 assert_eq!(
1481 proxy_metric(names::backend::RETRY_CAPTURES_ARMED) - armed_before,
1482 0,
1483 "releasing a capture must return the armed gauge to where it started"
1484 );
1485
1486 let _held = fill_the_capture_budget();
1487 let armed_at_the_ceiling = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
1488
1489 stream.arm_upstream_replay();
1490
1491 assert_eq!(
1492 proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
1493 1,
1494 "a capture refused for budget must increment the declined counter \
1495 exactly once"
1496 );
1497 assert_eq!(
1498 proxy_metric(names::backend::RETRY_CAPTURES_ARMED),
1499 armed_at_the_ceiling,
1500 "a declined capture installs nothing, so it must not move the \
1501 armed gauge"
1502 );
1503 }
1504
1505 /// A stream torn down while a capture is still armed — a client hangup, an
1506 /// idle timeout, a session teardown — must release its charge.
1507 ///
1508 /// That path has no code site of its own: nothing clears `retry_buffer`
1509 /// there, the `Stream` is simply dropped. Releasing at the four sites that
1510 /// DO clear the field would leak a charge on every one of those teardowns
1511 /// until the budget was exhausted, at which point replay would be silently
1512 /// disarmed for the rest of the worker's life. So the release belongs to
1513 /// [`ReplayCapture`]'s `impl Drop` and nowhere else — the reasoning
1514 /// `super::super::h2::ConnectionH2`'s gauge teardown and
1515 /// [`crate::pool::Checkout`] already apply.
1516 ///
1517 /// To SEE THIS RED: delete the `ARMED_REPLAY_CAPTURES.set(...)` line from
1518 /// `ReplayCapture`'s `impl Drop`, leaving its `gauge_add!` in place. Its
1519 /// `debug_assert!` does not fire on this path — the counter is 1, not 0 —
1520 /// so the failure is this test's own.
1521 #[test]
1522 fn a_stream_dropped_with_a_capture_armed_releases_its_charge() {
1523 setup_test_logger!();
1524 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1525 let armed_before = ARMED_REPLAY_CAPTURES.get();
1526
1527 let mut stream = test_stream(&pool);
1528 stream.context.method = Some(Method::Get);
1529 stream.arm_upstream_replay();
1530 assert_eq!(
1531 ARMED_REPLAY_CAPTURES.get(),
1532 armed_before + 1,
1533 "arming a capture must charge the budget"
1534 );
1535
1536 drop(stream);
1537
1538 assert_eq!(
1539 ARMED_REPLAY_CAPTURES.get(),
1540 armed_before,
1541 "a stream dropped with a capture still armed must release its charge"
1542 );
1543 }
1544
1545 /// A backend response status line is wire data, not a Sōzu-side invariant.
1546 ///
1547 /// kawa 0.7.1 reads the status with `take(3)` followed by
1548 /// `str::parse::<u16>()` and applies no range check
1549 /// (`kawa/src/protocol/h1/parser/primitives.rs:194-203`); the
1550 /// `Kind::Response` arm stores the resulting `code` verbatim
1551 /// (`.../h1/parser/mod.rs:249-258`). `"000".parse::<u16>()` is `Ok(0)`, so
1552 /// a backend that answers `HTTP/1.1 000 …` drives `code == 0` through
1553 /// [`HttpContext::on_response_headers`] into `context.status` and then into
1554 /// the status bucketer at the top of [`Stream::generate_access_log`], which
1555 /// buckets it as `http.status.other` — exactly what the catch-all arm is
1556 /// for.
1557 ///
1558 /// Ported on 2026-09-20 from
1559 /// `kawa_h1::tests::a_backend_status_line_below_100_is_bucketed_not_asserted`,
1560 /// which asserted the same property against `kawa_h1::save_http_status_metric`.
1561 /// That function and the `kawa_h1::Http` session it belonged to were removed
1562 /// with the unreachable H1 state machine (sozu#1346), so the assertion now
1563 /// guards the LIVE mux bucketer instead of a path no binary could enter.
1564 ///
1565 /// To SEE THIS RED: in [`Stream::generate_access_log`], insert
1566 /// `debug_assert!((100..=999).contains(&status), "generate_access_log got a
1567 /// non-3-digit status: {status}");` as the first statement of the
1568 /// `if let Some(status) = context.status` bucket arm — this test then panics
1569 /// with `generate_access_log got a non-3-digit status: 0`, i.e. a panic on
1570 /// network input in every debug, test, e2e and fuzz build (sozu#1279).
1571 #[test]
1572 fn a_backend_status_line_below_100_is_bucketed_not_asserted() {
1573 setup_test_logger!();
1574 const RESPONSE: &[u8] = b"HTTP/1.1 000 Nope\r\nContent-Length: 0\r\n\r\n";
1575
1576 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 4096)));
1577 let context = HttpContext::new(
1578 Ulid::generate(),
1579 Ulid::generate(),
1580 Protocol::HTTP,
1581 SocketAddr::new(IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1)), 8080),
1582 Some(SocketAddr::new(
1583 IpAddr::V4(Ipv4Addr::new(10, 0, 0, 1)),
1584 54321,
1585 )),
1586 "SERVERID".to_owned(),
1587 "Sozu-Id".to_owned(),
1588 false,
1589 false,
1590 );
1591 let mut stream = Stream::new(
1592 &mut PoolBufferSource::new(Rc::downgrade(&pool)),
1593 context,
1594 crate::protocol::mux::test_support::test_answers(),
1595 65535,
1596 )
1597 .expect("test stream checkout");
1598
1599 let space = stream.back.storage.space();
1600 space[..RESPONSE.len()].copy_from_slice(RESPONSE);
1601 stream.back.storage.fill(RESPONSE.len());
1602 kawa::h1::parse(&mut stream.back, &mut stream.context);
1603
1604 // Reachability: the value handed to the metric bucketer came off the
1605 // wire through the real parser and the real response-header callback,
1606 // not from a hand-written `Some(0)`.
1607 assert_eq!(
1608 stream.context.status,
1609 Some(0),
1610 "kawa must surface the backend's out-of-range status verbatim"
1611 );
1612
1613 // The call itself is the assertion: with a range precondition in place
1614 // this panics instead of incrementing `http.status.other`.
1615 // This test asserts on the access log, not on metrics.
1616 let _ = stream.generate_access_log(
1617 false,
1618 None,
1619 Rc::new(RefCell::new(TestListener::new())),
1620 None,
1621 None,
1622 );
1623 }
1624
1625 // ── The access log of an H2 request whose field block was refused ──
1626 // (sozu-proxy/sozu#1566, the HTTP/2 half of #1085)
1627
1628 /// HPACK-encode `headers`, hand the block to the real
1629 /// `pkawa::handle_header` (`lib/src/protocol/mux/pkawa.rs`) on a real
1630 /// `Stream`'s front, with the stream's own `HttpContext` as the
1631 /// callbacks, exactly as `ConnectionH2` does for an initial HEADERS; then
1632 /// emit the access log the way the session-close sweep in
1633 /// `Mux::close` (`lib/src/protocol/mux/mod.rs`) does for the reset
1634 /// stream. Returns every log line the run produced.
1635 fn access_log_of_a_rejected_h2_request(
1636 headers: &'static [(&'static [u8], &'static [u8])],
1637 ) -> String {
1638 crate::capture_test_logs(move || {
1639 let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
1640 let mut stream = test_stream(&pool);
1641 let mut encoder = crate::protocol::mux::hpack::Encoder::new();
1642 let mut block = Vec::new();
1643 for &(name, value) in headers {
1644 encoder.encode_header_into((name, value), &mut block);
1645 }
1646 let mut decoder = crate::protocol::mux::hpack::Decoder::new();
1647 let mut prioriser = crate::protocol::mux::h2_scheduler::Prioriser::default();
1648 let (_events, status) = crate::protocol::mux::pkawa::handle_header(
1649 &mut decoder,
1650 &mut prioriser,
1651 1,
1652 &mut stream.front,
1653 &block,
1654 true,
1655 &mut stream.context,
1656 crate::protocol::mux::h2::MAX_HEADER_LIST_SIZE as u32,
1657 u32::MAX,
1658 false,
1659 );
1660 assert!(
1661 matches!(status, Err((_, false))),
1662 "premise: the staged field block must be refused as a stream \
1663 error, got {status:?}"
1664 );
1665 assert_eq!(
1666 stream.context.method, None,
1667 "premise: a refused block never reaches `HttpContext`'s capture"
1668 );
1669 let _ = stream.generate_access_log(
1670 true,
1671 Some("session close"),
1672 Rc::new(RefCell::new(TestListener::new())),
1673 None,
1674 None,
1675 );
1676 })
1677 }
1678
1679 /// The four pseudo-headers every H2 test below starts from.
1680 const H2_BASE: [(&[u8], &[u8]); 4] = [
1681 (b":method", b"GET"),
1682 (b":scheme", b"https"),
1683 (b":authority", b"lolcatho.st"),
1684 (b":path", b"/ok"),
1685 ];
1686
1687 fn assert_h2_line(output: &str, expected: &str, why: &str) {
1688 assert!(
1689 output.contains(&format!(" {expected} - | session close")),
1690 "{why}: expected `{expected}`, got: {output}"
1691 );
1692 }
1693
1694 /// A header refused after every pseudo-header was stored: all three are
1695 /// logged.
1696 ///
1697 /// To SEE THIS RED: in `record_rejected_request`
1698 /// (`lib/src/protocol/mux/pkawa.rs`), delete the `status_line`
1699 /// assignment. The line then renders `- - - -`, as it did before.
1700 #[test]
1701 fn a_refused_h2_header_keeps_the_pseudo_headers_in_the_access_log() {
1702 static CONNECTION: [(&[u8], &[u8]); 5] = [
1703 H2_BASE[0],
1704 H2_BASE[1],
1705 H2_BASE[2],
1706 H2_BASE[3],
1707 (b"connection", b"close"),
1708 ];
1709 let output = access_log_of_a_rejected_h2_request(&CONNECTION);
1710 assert_h2_line(
1711 &output,
1712 "lolcatho.st GET /ok",
1713 "a connection-specific header refused after the pseudo-headers",
1714 );
1715
1716 static UPPERCASE: [(&[u8], &[u8]); 5] = [
1717 H2_BASE[0],
1718 H2_BASE[1],
1719 H2_BASE[2],
1720 H2_BASE[3],
1721 (b"X-Upper", b"1"),
1722 ];
1723 let output = access_log_of_a_rejected_h2_request(&UPPERCASE);
1724 assert_h2_line(
1725 &output,
1726 "lolcatho.st GET /ok",
1727 "an uppercase field name refused after the pseudo-headers",
1728 );
1729 }
1730
1731 /// A missing or empty `:path` is logged `-`, and what was decoded around
1732 /// it still is.
1733 #[test]
1734 fn a_missing_or_empty_h2_path_logs_the_rest_of_the_request_line() {
1735 static MISSING: [(&[u8], &[u8]); 3] = [H2_BASE[0], H2_BASE[1], H2_BASE[2]];
1736 let output = access_log_of_a_rejected_h2_request(&MISSING);
1737 assert_h2_line(&output, "lolcatho.st GET -", "a missing :path");
1738
1739 static EMPTY: [(&[u8], &[u8]); 4] = [H2_BASE[0], H2_BASE[1], H2_BASE[2], (b":path", b"")];
1740 let output = access_log_of_a_rejected_h2_request(&EMPTY);
1741 assert_h2_line(&output, "lolcatho.st GET -", "an empty :path");
1742 }
1743
1744 /// A repeated `:method` or `:path` keeps the first value, as the H1
1745 /// rejection path logs what was parsed.
1746 #[test]
1747 fn a_repeated_h2_pseudo_header_logs_its_first_value() {
1748 static METHOD: [(&[u8], &[u8]); 5] = [
1749 H2_BASE[0],
1750 H2_BASE[1],
1751 H2_BASE[2],
1752 H2_BASE[3],
1753 (b":method", b"POST"),
1754 ];
1755 let output = access_log_of_a_rejected_h2_request(&METHOD);
1756 assert_h2_line(&output, "lolcatho.st GET /ok", "a repeated :method");
1757 }
1758
1759 /// The authority is logged only when it was validated. A second
1760 /// `:authority`, and a `host` field that disagrees with it, leave the
1761 /// first value stored in the buffer; it must still be logged `-`.
1762 ///
1763 /// To SEE THIS RED: in `handle_header` (`lib/src/protocol/mux/pkawa.rs`),
1764 /// make `origin_disputed` `false`. Both lines then carry `lolcatho.st`.
1765 #[test]
1766 fn an_unvalidated_h2_authority_is_never_logged() {
1767 static REPEATED: [(&[u8], &[u8]); 5] = [
1768 H2_BASE[0],
1769 H2_BASE[1],
1770 H2_BASE[2],
1771 H2_BASE[3],
1772 (b":authority", b"other.example"),
1773 ];
1774 let output = access_log_of_a_rejected_h2_request(&REPEATED);
1775 assert_h2_line(&output, "- GET /ok", "a repeated :authority");
1776
1777 static HOST: [(&[u8], &[u8]); 5] = [
1778 H2_BASE[0],
1779 H2_BASE[1],
1780 H2_BASE[2],
1781 H2_BASE[3],
1782 (b"host", b"other.example"),
1783 ];
1784 let output = access_log_of_a_rejected_h2_request(&HOST);
1785 assert_h2_line(&output, "- GET /ok", "a host field disputing :authority");
1786 }
1787
1788 /// No control byte reaches the log line, whose formatter escapes
1789 /// nothing: a pseudo value carrying one is refused before it is stored,
1790 /// so it is logged `-`.
1791 #[test]
1792 fn an_h2_pseudo_header_with_a_control_byte_is_logged_as_absent() {
1793 static PATH: [(&[u8], &[u8]); 4] =
1794 [H2_BASE[0], H2_BASE[1], H2_BASE[2], (b":path", b"/a\r\nb")];
1795 let output = access_log_of_a_rejected_h2_request(&PATH);
1796 assert_h2_line(&output, "lolcatho.st GET -", "a CR LF in :path");
1797 assert!(
1798 !output.contains("/a"),
1799 "no byte of a refused pseudo value may reach the log, got: {output}"
1800 );
1801
1802 // Last, because the decode stops handing fields over at the first
1803 // refusal: what follows a refused field is never stored.
1804 static METHOD: [(&[u8], &[u8]); 4] =
1805 [H2_BASE[1], H2_BASE[2], H2_BASE[3], (b":method", b"G\x01T")];
1806 let output = access_log_of_a_rejected_h2_request(&METHOD);
1807 assert_h2_line(&output, "lolcatho.st - /ok", "a control byte in :method");
1808 }
1809}