use std::{
cell::{Cell, RefCell},
fmt::Debug,
ops::{Deref, DerefMut},
rc::Rc,
time::Duration,
};
use mio::Token;
use sozu_command::logging::ansi_palette;
use super::{
GenericHttpStream, Position,
h2::{DEFAULT_INITIAL_WINDOW_SIZE, MetricEvent},
};
use crate::metrics::names;
use crate::{
L7ListenerHandler, ListenerHandler, Protocol, SessionMetrics,
protocol::http::{answers::HttpAnswers, editor::HttpContext, parser::Method},
};
macro_rules! log_module_context {
() => {{
let (open, reset, _, _, _) = ansi_palette();
format!("{open}MUX-STREAM{reset}\t >>>", open = open, reset = reset)
}};
}
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum StreamState {
Idle,
Link,
Linked(Token),
Unlinked,
Recycle,
}
impl StreamState {
pub fn is_open(&self) -> bool {
!matches!(self, StreamState::Idle | StreamState::Recycle)
}
}
pub const MAX_ARMED_REPLAY_CAPTURES: usize = 512;
thread_local! {
static ARMED_REPLAY_CAPTURES: Cell<usize> = const { Cell::new(0) };
}
pub struct ReplayCapture {
bytes: Vec<u8>,
}
impl ReplayCapture {
fn try_arm() -> Option<Self> {
let armed = ARMED_REPLAY_CAPTURES.get();
if armed >= MAX_ARMED_REPLAY_CAPTURES {
return None;
}
ARMED_REPLAY_CAPTURES.set(armed + 1);
gauge_add!(names::backend::RETRY_CAPTURES_ARMED, 1);
Some(Self { bytes: Vec::new() })
}
fn into_bytes(mut self) -> Vec<u8> {
std::mem::take(&mut self.bytes)
}
}
impl Drop for ReplayCapture {
fn drop(&mut self) {
let armed = ARMED_REPLAY_CAPTURES.get();
debug_assert!(
armed >= 1,
"armed-capture budget underflow on release: count was {armed} before decrement"
);
ARMED_REPLAY_CAPTURES.set(armed.saturating_sub(1));
gauge_add!(names::backend::RETRY_CAPTURES_ARMED, -1);
}
}
impl Deref for ReplayCapture {
type Target = Vec<u8>;
fn deref(&self) -> &Self::Target {
&self.bytes
}
}
impl DerefMut for ReplayCapture {
fn deref_mut(&mut self) -> &mut Self::Target {
&mut self.bytes
}
}
pub struct Stream {
pub front_window: i32,
pub back_window: i32,
pub attempts: u8,
pub tried_backends: Vec<std::net::SocketAddr>,
pub state: StreamState,
pub front_received_end_of_stream: bool,
pub back_received_end_of_stream: bool,
pub front_data_received: usize,
pub back_data_received: usize,
pub request_counted: bool,
pub front: GenericHttpStream,
pub back: GenericHttpStream,
pub retry_buffer: Option<ReplayCapture>,
pub front_bound_to_backend: bool,
pub context: HttpContext,
pub metrics: SessionMetrics,
pub answers: Rc<RefCell<HttpAnswers>>,
}
struct KawaSummary<'a>(&'a GenericHttpStream);
impl Debug for KawaSummary<'_> {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
f.debug_struct("Kawa")
.field("kind", &self.0.kind)
.field("parsing_phase", &self.0.parsing_phase)
.field("body_size", &self.0.body_size)
.field("consumed", &self.0.consumed)
.field("expects", &self.0.expects)
.field("blocks", &self.0.blocks.len())
.field("out", &self.0.out.len())
.field("storage_start", &self.0.storage.start)
.field("storage_head", &self.0.storage.head)
.field("storage_end", &self.0.storage.end)
.finish()
}
}
impl Debug for Stream {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
f.debug_struct("Stream")
.field("front_window", &self.front_window)
.field("back_window", &self.back_window)
.field("attempts", &self.attempts)
.field("tried_backends", &self.tried_backends)
.field("state", &self.state)
.field(
"front_received_end_of_stream",
&self.front_received_end_of_stream,
)
.field(
"back_received_end_of_stream",
&self.back_received_end_of_stream,
)
.field("front_data_received", &self.front_data_received)
.field("back_data_received", &self.back_data_received)
.field("request_counted", &self.request_counted)
.field("front", &KawaSummary(&self.front))
.field("back", &KawaSummary(&self.back))
.field(
"retry_buffer",
&self.retry_buffer.as_ref().map(|bytes| bytes.len()),
)
.field("front_bound_to_backend", &self.front_bound_to_backend)
.field("context", &self.context)
.field("metrics", &self.metrics)
.finish()
}
}
pub struct StreamParts<'a> {
pub window: &'a mut i32,
pub rbuffer: &'a mut GenericHttpStream,
pub wbuffer: &'a mut GenericHttpStream,
pub received_end_of_stream: &'a mut bool,
pub data_received: &'a mut usize,
pub context: &'a mut HttpContext,
pub metrics: &'a mut SessionMetrics,
pub retry_buffer: &'a mut Option<ReplayCapture>,
pub front_bound_to_backend: &'a mut bool,
}
impl Stream {
pub fn new(
buffers: &mut dyn super::buffer_source::BufferSource,
context: HttpContext,
answers: Rc<RefCell<HttpAnswers>>,
window: u32,
) -> Option<Self> {
let (front_buffer, back_buffer) = match (buffers.checkout(), buffers.checkout()) {
(Some(front_buffer), Some(back_buffer)) => (front_buffer, back_buffer),
_ => return None,
};
let stream = Self {
state: StreamState::Idle,
attempts: 0,
tried_backends: Vec::new(),
front_window: i32::try_from(window).unwrap_or(i32::MAX),
back_window: i32::try_from(DEFAULT_INITIAL_WINDOW_SIZE).unwrap_or(i32::MAX),
front_received_end_of_stream: false,
back_received_end_of_stream: false,
front_data_received: 0,
back_data_received: 0,
request_counted: false,
front: GenericHttpStream::new(kawa::Kind::Request, kawa::Buffer::new(front_buffer)),
back: GenericHttpStream::new(kawa::Kind::Response, kawa::Buffer::new(back_buffer)),
retry_buffer: None,
front_bound_to_backend: false,
context,
metrics: SessionMetrics::new(None),
answers,
};
debug_assert_eq!(stream.state, StreamState::Idle, "new stream must be Idle");
debug_assert!(
!stream.state.is_open(),
"an Idle stream slot must not report as open"
);
debug_assert!(
!stream.request_counted,
"new stream must not have a counted request (gauge-underflow guard)"
);
debug_assert_eq!(
(stream.front_data_received, stream.back_data_received),
(0, 0),
"new stream DATA counters must start at 0"
);
debug_assert!(
!stream.front_bound_to_backend,
"a new stream's request is bound to no backend connection"
);
#[cfg(debug_assertions)]
stream.check_invariants();
Some(stream)
}
#[cfg(debug_assertions)]
pub(super) fn check_invariants(&self) {
debug_assert_eq!(
self.state.is_open(),
!matches!(self.state, StreamState::Idle | StreamState::Recycle),
"is_open() must agree with the Idle/Recycle discriminants"
);
if self.state == StreamState::Recycle {
debug_assert!(
!self.request_counted,
"a Recycle slot must not carry a counted request (active-requests leak)"
);
}
debug_assert_eq!(
self.linked_token().is_some(),
matches!(self.state, StreamState::Linked(_)),
"linked_token() must be Some iff the stream is Linked"
);
}
pub fn linked_token(&self) -> Option<Token> {
match self.state {
StreamState::Linked(token) => Some(token),
_ => None,
}
}
pub fn is_quiesced(&self) -> bool {
let front_done =
(self.front.is_initial() || self.front.is_completed() || self.front.is_terminated())
&& self.front.storage.is_empty();
let back_done =
(self.back.is_initial() || self.back.is_completed() || self.back.is_terminated())
&& self.back.storage.is_empty();
front_done && back_done
}
pub fn send_window_mut(&mut self, position: &Position) -> &mut i32 {
match position {
Position::Client(..) => &mut self.back_window,
Position::Server => &mut self.front_window,
}
}
pub fn split(&mut self, position: &Position) -> StreamParts<'_> {
debug_assert_eq!(
self.front.kind,
kawa::Kind::Request,
"front buffer must hold a Request kawa"
);
debug_assert_eq!(
self.back.kind,
kawa::Kind::Response,
"back buffer must hold a Response kawa"
);
match position {
Position::Client(..) => StreamParts {
window: &mut self.back_window,
rbuffer: &mut self.back,
wbuffer: &mut self.front,
received_end_of_stream: &mut self.back_received_end_of_stream,
data_received: &mut self.back_data_received,
context: &mut self.context,
metrics: &mut self.metrics,
retry_buffer: &mut self.retry_buffer,
front_bound_to_backend: &mut self.front_bound_to_backend,
},
Position::Server => StreamParts {
window: &mut self.front_window,
rbuffer: &mut self.front,
wbuffer: &mut self.back,
received_end_of_stream: &mut self.front_received_end_of_stream,
data_received: &mut self.front_data_received,
context: &mut self.context,
metrics: &mut self.metrics,
retry_buffer: &mut self.retry_buffer,
front_bound_to_backend: &mut self.front_bound_to_backend,
},
}
}
pub fn arm_upstream_replay(&mut self) {
if self.retry_buffer.is_some() {
return;
}
if !self
.context
.method
.as_ref()
.is_some_and(Method::is_idempotent)
{
return;
}
match ReplayCapture::try_arm() {
Some(capture) => self.retry_buffer = Some(capture),
None => incr!(names::backend::RETRY_CAPTURES_DECLINED),
}
}
pub fn forget_upstream_replay(&mut self) {
self.retry_buffer = None;
}
pub fn can_replay_on_fresh_upstream(&self) -> bool {
self.retry_buffer.is_some()
&& self
.context
.method
.as_ref()
.is_some_and(Method::is_idempotent)
&& !self.back.consumed
&& self.back.storage.is_empty()
}
pub fn queue_upstream_replay(&mut self) -> Option<usize> {
let request = self.retry_buffer.take()?.into_bytes();
let len = request.len();
self.front
.out
.push_front(kawa::OutBlock::Store(kawa::Store::from_vec(request)));
Some(len)
}
#[must_use]
pub(super) fn generate_access_log<L>(
&mut self,
error: bool,
message: Option<&str>,
listener: Rc<RefCell<L>>,
client_rtt: Option<Duration>,
server_rtt: Option<Duration>,
) -> [Option<MetricEvent>; 2]
where
L: ListenerHandler + L7ListenerHandler,
{
let mut events: [Option<MetricEvent>; 2] = [None, None];
let context = &self.context;
let metric_incarnation = self.context.cluster_metrics_incarnation();
let message = message.or(context.access_log_message);
let was_counted = self.request_counted;
if self.request_counted {
events[0] = Some(MetricEvent::ActiveRequestFinished);
self.request_counted = false;
}
debug_assert!(
!self.request_counted,
"generate_access_log must leave request_counted false (gauge-underflow guard)"
);
debug_assert!(
was_counted >= self.request_counted,
"request_counted must only clear here, never spontaneously set"
);
if error {
incr!(
names::http::ERRORS,
context.cluster_id.as_deref(),
context.backend_id.as_deref(),
metric_incarnation
);
}
let protocol = match context.protocol {
Protocol::HTTP => "http",
Protocol::HTTPS => "https",
other => {
error!(
"{} mux streams only handle HTTP or HTTPS protocols, got {:?}",
log_module_context!(),
other
);
"unknown"
}
};
let bucket_key = if let Some(status) = context.status {
match status {
100..=199 => names::http::STATUS_1XX,
200..=299 => names::http::STATUS_2XX,
300..=399 => names::http::STATUS_3XX,
400..=499 => names::http::STATUS_4XX,
500..=599 => names::http::STATUS_5XX,
_ => names::http::STATUS_OTHER,
}
} else {
"http.status.none"
};
incr!(
bucket_key,
context.cluster_id.as_deref(),
context.backend_id.as_deref(),
metric_incarnation
);
if let Some(status) = context.status
&& let Some(per_code) = crate::metrics::http_status_code_metric_name(status)
{
incr!(
per_code,
context.cluster_id.as_deref(),
context.backend_id.as_deref(),
metric_incarnation
);
}
let rejected = if context.method.is_none() {
rejected_request_line(&self.front)
} else {
None
};
debug_assert!(
rejected.is_none() || self.front.is_error(),
"only a rejected request is logged from the front buffer"
);
debug_assert!(
rejected.is_none() || context.method.is_none(),
"a request line the context captured must never be overridden"
);
let endpoint = match &rejected {
Some(line) => sozu_command::logging::EndpointRecord::Http {
method: line.method,
authority: line.authority,
path: line.path,
reason: context.reason.as_deref(),
status: context.status,
},
None => sozu_command::logging::EndpointRecord::Http {
method: context.method.as_deref(),
authority: context.authority.as_deref(),
path: context.path.as_deref(),
reason: context.reason.as_deref(),
status: context.status,
},
};
let listener = listener.borrow();
let tags = context.tags.as_deref().or_else(|| {
context.authority.as_deref().and_then(|host| {
let hostname = match host.split_once(':') {
None => host,
Some((hostname, _)) => hostname,
};
listener.get_tags(hostname)
})
});
log_access! {
error,
on_failure: { events[1] = Some(MetricEvent::AccessLogUnsent) },
message,
context: context.log_context(),
session_address: context.session_address,
backend_address: context.backend_address,
protocol,
endpoint,
tags,
client_rtt,
server_rtt,
service_time: self.metrics.service_time(),
response_time: self.metrics.backend_response_time(),
request_time: self.metrics.request_time(),
start_time_ns: self.metrics.start_wall_ns(),
bytes_in: self.metrics.bin,
bytes_out: self.metrics.bout,
user_agent: context.user_agent.as_deref(),
x_request_id: context.x_request_id.as_deref(),
tls_version: context.tls_version,
tls_cipher: context.tls_cipher,
tls_sni: context.tls_server_name.as_deref(),
tls_alpn: context.tls_alpn,
xff_chain: context.xff_chain.as_deref(),
#[cfg(feature = "opentelemetry")]
otel: context.otel.as_ref(),
#[cfg(not(feature = "opentelemetry"))]
otel: None,
};
self.metrics
.register_end_of_session_for_incarnation(&context.log_context(), metric_incarnation);
events
}
}
struct RejectedRequestLine<'a> {
method: Option<&'a str>,
authority: Option<&'a str>,
path: Option<&'a str>,
}
fn rejected_request_line(front: &GenericHttpStream) -> Option<RejectedRequestLine<'_>> {
if !front.is_error() {
return None;
}
let kawa::StatusLine::Request {
version,
method,
uri,
authority,
path,
} = &front.detached.status_line
else {
return None;
};
let buf = front.storage.buffer();
if matches!(version, kawa::Version::V20) {
debug_assert!(
borrowed_bytes(uri, buf).is_none(),
"a rejected H2 request line carries no request-target"
);
return Some(RejectedRequestLine {
method: borrowed_str(method, buf),
authority: borrowed_str(authority, buf),
path: borrowed_str(path, buf),
});
}
let method_bytes = borrowed_bytes(method, buf)?;
let method = std::str::from_utf8(method_bytes).ok();
if let Some(path) = borrowed_str(path, buf) {
return Some(RejectedRequestLine {
method,
authority: borrowed_str(authority, buf),
path: Some(path),
});
}
debug_assert!(
borrowed_bytes(authority, buf).is_none(),
"kawa resolves the authority and the path together"
);
let (authority, path) = borrowed_bytes(uri, buf)
.and_then(|uri| kawa::h1::parser::primitives::parse_url(buf, method_bytes, uri))
.map_or((None, None), |(authority, path)| {
(borrowed_str(&authority, buf), borrowed_str(&path, buf))
});
Some(RejectedRequestLine {
method,
authority,
path,
})
}
fn borrowed_bytes<'a>(store: &kawa::Store, buf: &'a [u8]) -> Option<&'a [u8]> {
match store {
kawa::Store::Slice(slice) => slice.data_opt(buf),
kawa::Store::Static(bytes) => Some(bytes),
_ => None,
}
}
fn borrowed_str<'a>(store: &kawa::Store, buf: &'a [u8]) -> Option<&'a str> {
borrowed_bytes(store, buf).and_then(|bytes| std::str::from_utf8(bytes).ok())
}
#[cfg(test)]
mod tests {
use std::net::{IpAddr, Ipv4Addr, SocketAddr};
use rusty_ulid::Ulid;
use sozu_command::proto::command::filtered_metrics;
use super::*;
use crate::{
metrics::METRICS,
pool::Pool,
protocol::mux::{
buffer_source::PoolBufferSource,
shared::{self, EndStreamAction},
test_support::TestListener,
},
};
fn test_stream(pool: &Rc<RefCell<Pool>>) -> Stream {
let context = HttpContext::new(
Ulid::generate(),
Ulid::generate(),
Protocol::HTTP,
SocketAddr::new(IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1)), 8080),
Some(SocketAddr::new(
IpAddr::V4(Ipv4Addr::new(10, 0, 0, 1)),
54321,
)),
"SERVERID".to_owned(),
"Sozu-Id".to_owned(),
false,
false,
);
Stream::new(
&mut PoolBufferSource::new(Rc::downgrade(pool)),
context,
crate::protocol::mux::test_support::test_answers(),
65535,
)
.expect("test stream checkout")
}
fn proxy_metric(name: &str) -> i64 {
METRICS.with(|metrics| {
metrics
.borrow_mut()
.dump_local_proxy_metrics()
.get(name)
.and_then(|metric| match metric.inner {
Some(filtered_metrics::Inner::Gauge(value)) => Some(value as i64),
Some(filtered_metrics::Inner::Count(value)) => Some(value),
_ => None,
})
.unwrap_or(0)
})
}
fn fill_the_capture_budget() -> Vec<ReplayCapture> {
let held: Vec<ReplayCapture> = (0..MAX_ARMED_REPLAY_CAPTURES)
.filter_map(|_| ReplayCapture::try_arm())
.collect();
assert_eq!(
held.len(),
MAX_ARMED_REPLAY_CAPTURES,
"an empty budget must grant every one of its charges"
);
held
}
#[test]
fn queueing_a_replay_releases_the_capture_charge() {
setup_test_logger!();
const REQUEST: &[u8] = b"GET /api HTTP/1.1\r\nHost: localhost\r\n\r\n";
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let charged_before = ARMED_REPLAY_CAPTURES.get();
let gauged_before = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
let mut stream = test_stream(&pool);
stream.context.method = Some(Method::Get);
stream.arm_upstream_replay();
stream
.retry_buffer
.as_mut()
.expect("an idempotent request under the ceiling must be captured")
.extend_from_slice(REQUEST);
let queued = stream
.queue_upstream_replay()
.expect("the armed stream carries a capture");
assert_eq!(
queued,
REQUEST.len(),
"the whole captured request must be queued for the fresh upstream"
);
assert_eq!(
ARMED_REPLAY_CAPTURES.get(),
charged_before,
"queueing a replay must release the capture's charge"
);
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_ARMED),
gauged_before,
"queueing a replay must return the armed gauge to where it started"
);
}
#[test]
fn a_non_idempotent_request_is_never_charged_to_the_capture_budget() {
setup_test_logger!();
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let charged_before = ARMED_REPLAY_CAPTURES.get();
let declined_before = proxy_metric(names::backend::RETRY_CAPTURES_DECLINED);
let mut idempotent = test_stream(&pool);
idempotent.context.method = Some(Method::Get);
idempotent.arm_upstream_replay();
assert!(
idempotent.retry_buffer.is_some(),
"an idempotent request under the ceiling must be captured"
);
assert_eq!(
ARMED_REPLAY_CAPTURES.get(),
charged_before + 1,
"an idempotent request must spend a charge"
);
drop(idempotent);
for method in [Method::Post, Method::new(b"PATCH")] {
let mut stream = test_stream(&pool);
stream.context.method = Some(method);
stream.arm_upstream_replay();
assert!(
stream.retry_buffer.is_none(),
"a non-idempotent request must not be captured"
);
assert_eq!(
ARMED_REPLAY_CAPTURES.get(),
charged_before,
"a non-idempotent request must not spend a capture charge"
);
}
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
0,
"a method veto is not a budget refusal and must not be counted as one"
);
}
#[test]
fn past_the_ceiling_a_pooled_request_is_armed_with_no_buffer_and_still_completes() {
setup_test_logger!();
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let mut under_the_ceiling = test_stream(&pool);
under_the_ceiling.context.method = Some(Method::Get);
under_the_ceiling.arm_upstream_replay();
assert!(
under_the_ceiling.retry_buffer.is_some(),
"under the ceiling arm_upstream_replay must install a capture"
);
drop(under_the_ceiling);
let _held = fill_the_capture_budget();
let mut stream = test_stream(&pool);
stream.context.method = Some(Method::Get);
stream.arm_upstream_replay();
assert!(
stream.retry_buffer.is_none(),
"past the ceiling arm_upstream_replay must install no capture"
);
stream.front.consumed = true;
assert_eq!(
shared::end_stream_decision(&stream),
EndStreamAction::SendDefault(502),
"a request the budget declined to capture must still be answered, \
un-replayable, exactly as it was before the replay existed"
);
}
fn queue_get(stream: &mut Stream) {
let kawa = &mut stream.front;
kawa.detached.status_line = kawa::StatusLine::Request {
version: kawa::Version::V11,
method: kawa::Store::Static(b"GET"),
uri: kawa::Store::Static(b"/"),
authority: kawa::Store::Static(b"example.com"),
path: kawa::Store::Static(b"/"),
};
kawa.push_block(kawa::Block::StatusLine);
kawa.push_block(kawa::Block::Header(kawa::Pair {
key: kawa::Store::Static(b"Host"),
val: kawa::Store::Static(b"example.com"),
}));
kawa.push_block(kawa::Block::Flags(kawa::Flags {
end_body: false,
end_chunk: false,
end_header: true,
end_stream: true,
}));
kawa.parsing_phase = kawa::ParsingPhase::Terminated;
}
#[test]
fn an_untouched_request_prepared_for_an_h1_backend_is_still_reconnected() {
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let mut stream = test_stream(&pool);
queue_get(&mut stream);
stream.front.prepare(&mut kawa::h1::BlockConverter);
assert!(
!stream.front.out.is_empty() && !stream.front.consumed,
"premise: the H1 bytes are prepared and unsent"
);
assert!(
!stream.front_bound_to_backend,
"premise: only an H2 backend binds a request"
);
assert_eq!(
shared::end_stream_decision(&stream),
EndStreamAction::Reconnect,
"an untouched request prepared for H1 must still be retried"
);
}
#[test]
fn a_request_encoded_for_an_h2_backend_is_not_reconnected() {
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let mut stream = test_stream(&pool);
queue_get(&mut stream);
stream.front.prepare(&mut kawa::h1::BlockConverter);
stream.front_bound_to_backend = true;
assert_eq!(
shared::end_stream_decision(&stream),
EndStreamAction::SendDefault(502),
"a request encoded for one H2 backend must not be linked to another"
);
stream.front.consumed = true;
assert_eq!(
shared::end_stream_decision(&stream),
EndStreamAction::SendDefault(502),
"a request that reached the backend keeps its own decision"
);
}
#[test]
fn the_armed_gauge_and_the_declined_counter_track_the_capture_budget() {
setup_test_logger!();
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let armed_before = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
let declined_before = proxy_metric(names::backend::RETRY_CAPTURES_DECLINED);
let mut stream = test_stream(&pool);
stream.context.method = Some(Method::Get);
stream.arm_upstream_replay();
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_ARMED) - armed_before,
1,
"arming a capture must raise the armed gauge by exactly one"
);
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
0,
"a capture the budget granted must not be counted as declined"
);
stream.forget_upstream_replay();
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_ARMED) - armed_before,
0,
"releasing a capture must return the armed gauge to where it started"
);
let _held = fill_the_capture_budget();
let armed_at_the_ceiling = proxy_metric(names::backend::RETRY_CAPTURES_ARMED);
stream.arm_upstream_replay();
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_DECLINED) - declined_before,
1,
"a capture refused for budget must increment the declined counter \
exactly once"
);
assert_eq!(
proxy_metric(names::backend::RETRY_CAPTURES_ARMED),
armed_at_the_ceiling,
"a declined capture installs nothing, so it must not move the \
armed gauge"
);
}
#[test]
fn a_stream_dropped_with_a_capture_armed_releases_its_charge() {
setup_test_logger!();
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let armed_before = ARMED_REPLAY_CAPTURES.get();
let mut stream = test_stream(&pool);
stream.context.method = Some(Method::Get);
stream.arm_upstream_replay();
assert_eq!(
ARMED_REPLAY_CAPTURES.get(),
armed_before + 1,
"arming a capture must charge the budget"
);
drop(stream);
assert_eq!(
ARMED_REPLAY_CAPTURES.get(),
armed_before,
"a stream dropped with a capture still armed must release its charge"
);
}
#[test]
fn a_backend_status_line_below_100_is_bucketed_not_asserted() {
setup_test_logger!();
const RESPONSE: &[u8] = b"HTTP/1.1 000 Nope\r\nContent-Length: 0\r\n\r\n";
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 4096)));
let context = HttpContext::new(
Ulid::generate(),
Ulid::generate(),
Protocol::HTTP,
SocketAddr::new(IpAddr::V4(Ipv4Addr::new(127, 0, 0, 1)), 8080),
Some(SocketAddr::new(
IpAddr::V4(Ipv4Addr::new(10, 0, 0, 1)),
54321,
)),
"SERVERID".to_owned(),
"Sozu-Id".to_owned(),
false,
false,
);
let mut stream = Stream::new(
&mut PoolBufferSource::new(Rc::downgrade(&pool)),
context,
crate::protocol::mux::test_support::test_answers(),
65535,
)
.expect("test stream checkout");
let space = stream.back.storage.space();
space[..RESPONSE.len()].copy_from_slice(RESPONSE);
stream.back.storage.fill(RESPONSE.len());
kawa::h1::parse(&mut stream.back, &mut stream.context);
assert_eq!(
stream.context.status,
Some(0),
"kawa must surface the backend's out-of-range status verbatim"
);
let _ = stream.generate_access_log(
false,
None,
Rc::new(RefCell::new(TestListener::new())),
None,
None,
);
}
fn access_log_of_a_rejected_h2_request(
headers: &'static [(&'static [u8], &'static [u8])],
) -> String {
crate::capture_test_logs(move || {
let pool = Rc::new(RefCell::new(Pool::with_capacity(2, 2, 16384)));
let mut stream = test_stream(&pool);
let mut encoder = crate::protocol::mux::hpack::Encoder::new();
let mut block = Vec::new();
for &(name, value) in headers {
encoder.encode_header_into((name, value), &mut block);
}
let mut decoder = crate::protocol::mux::hpack::Decoder::new();
let mut prioriser = crate::protocol::mux::h2_scheduler::Prioriser::default();
let (_events, status) = crate::protocol::mux::pkawa::handle_header(
&mut decoder,
&mut prioriser,
1,
&mut stream.front,
&block,
true,
&mut stream.context,
crate::protocol::mux::h2::MAX_HEADER_LIST_SIZE as u32,
u32::MAX,
false,
);
assert!(
matches!(status, Err((_, false))),
"premise: the staged field block must be refused as a stream \
error, got {status:?}"
);
assert_eq!(
stream.context.method, None,
"premise: a refused block never reaches `HttpContext`'s capture"
);
let _ = stream.generate_access_log(
true,
Some("session close"),
Rc::new(RefCell::new(TestListener::new())),
None,
None,
);
})
}
const H2_BASE: [(&[u8], &[u8]); 4] = [
(b":method", b"GET"),
(b":scheme", b"https"),
(b":authority", b"lolcatho.st"),
(b":path", b"/ok"),
];
fn assert_h2_line(output: &str, expected: &str, why: &str) {
assert!(
output.contains(&format!(" {expected} - | session close")),
"{why}: expected `{expected}`, got: {output}"
);
}
#[test]
fn a_refused_h2_header_keeps_the_pseudo_headers_in_the_access_log() {
static CONNECTION: [(&[u8], &[u8]); 5] = [
H2_BASE[0],
H2_BASE[1],
H2_BASE[2],
H2_BASE[3],
(b"connection", b"close"),
];
let output = access_log_of_a_rejected_h2_request(&CONNECTION);
assert_h2_line(
&output,
"lolcatho.st GET /ok",
"a connection-specific header refused after the pseudo-headers",
);
static UPPERCASE: [(&[u8], &[u8]); 5] = [
H2_BASE[0],
H2_BASE[1],
H2_BASE[2],
H2_BASE[3],
(b"X-Upper", b"1"),
];
let output = access_log_of_a_rejected_h2_request(&UPPERCASE);
assert_h2_line(
&output,
"lolcatho.st GET /ok",
"an uppercase field name refused after the pseudo-headers",
);
}
#[test]
fn a_missing_or_empty_h2_path_logs_the_rest_of_the_request_line() {
static MISSING: [(&[u8], &[u8]); 3] = [H2_BASE[0], H2_BASE[1], H2_BASE[2]];
let output = access_log_of_a_rejected_h2_request(&MISSING);
assert_h2_line(&output, "lolcatho.st GET -", "a missing :path");
static EMPTY: [(&[u8], &[u8]); 4] = [H2_BASE[0], H2_BASE[1], H2_BASE[2], (b":path", b"")];
let output = access_log_of_a_rejected_h2_request(&EMPTY);
assert_h2_line(&output, "lolcatho.st GET -", "an empty :path");
}
#[test]
fn a_repeated_h2_pseudo_header_logs_its_first_value() {
static METHOD: [(&[u8], &[u8]); 5] = [
H2_BASE[0],
H2_BASE[1],
H2_BASE[2],
H2_BASE[3],
(b":method", b"POST"),
];
let output = access_log_of_a_rejected_h2_request(&METHOD);
assert_h2_line(&output, "lolcatho.st GET /ok", "a repeated :method");
}
#[test]
fn an_unvalidated_h2_authority_is_never_logged() {
static REPEATED: [(&[u8], &[u8]); 5] = [
H2_BASE[0],
H2_BASE[1],
H2_BASE[2],
H2_BASE[3],
(b":authority", b"other.example"),
];
let output = access_log_of_a_rejected_h2_request(&REPEATED);
assert_h2_line(&output, "- GET /ok", "a repeated :authority");
static HOST: [(&[u8], &[u8]); 5] = [
H2_BASE[0],
H2_BASE[1],
H2_BASE[2],
H2_BASE[3],
(b"host", b"other.example"),
];
let output = access_log_of_a_rejected_h2_request(&HOST);
assert_h2_line(&output, "- GET /ok", "a host field disputing :authority");
}
#[test]
fn an_h2_pseudo_header_with_a_control_byte_is_logged_as_absent() {
static PATH: [(&[u8], &[u8]); 4] =
[H2_BASE[0], H2_BASE[1], H2_BASE[2], (b":path", b"/a\r\nb")];
let output = access_log_of_a_rejected_h2_request(&PATH);
assert_h2_line(&output, "lolcatho.st GET -", "a CR LF in :path");
assert!(
!output.contains("/a"),
"no byte of a refused pseudo value may reach the log, got: {output}"
);
static METHOD: [(&[u8], &[u8]); 4] =
[H2_BASE[1], H2_BASE[2], H2_BASE[3], (b":method", b"G\x01T")];
let output = access_log_of_a_rejected_h2_request(&METHOD);
assert_h2_line(&output, "lolcatho.st - /ok", "a control byte in :method");
}
}