melin_server_runtime/response.rs
1//! io_uring-based response stage — routes matching output to connections via
2//! `IORING_OP_SEND`.
3//!
4//! Replaces the blocking `write(2)` + `BufWriter` flush path with batched
5//! io_uring sends. Instead of N `write(2)` syscalls (one per dirty connection
6//! on flush), we submit N SEND SQEs in a single `io_uring_enter` call.
7//!
8//! Same SPSC consumption and journal cursor gating as `response.rs`.
9//! Runs on a dedicated OS thread.
10
11use std::os::unix::io::RawFd;
12use std::sync::Arc;
13use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
14use std::sync::mpsc;
15use std::time::{Duration, Instant};
16
17use io_uring::{IoUring, opcode, types};
18use rustc_hash::FxHashMap;
19use tracing::{debug, error};
20
21use melin_pipeline::ring;
22use melin_pipeline::wait::WaitStrategy;
23
24use crate::ack_policy::{Blocker, CursorView, EvalStatus, MAX_CLUSTER_SIZE, Policy};
25use crate::durability_gate::{Admission, Backing, BatchEnds, DurabilityGate, GateInputs};
26pub use crate::durability_gate::{GatePolicy, GateStart};
27use crate::halt::{Refusal, RefusalQueue};
28use crate::replication::ReplicationMetrics;
29use melin_app::Application;
30use melin_app::amortized_timer::AmortizedTimer;
31use melin_transport_core::pipeline::{OutputSlot, StageUtilization};
32#[cfg(feature = "latency-trace")]
33use melin_transport_core::trace;
34use melin_transport_core::{DurableWireSeqCursor, WireSeq};
35
36use melin_wire_protocol::control::TransportResponse;
37use melin_wire_protocol::control_codec;
38
39use crate::connection_limit::{RingSizing, ring_setup_error};
40use crate::response_frame::{EncodeBuf, MAX_APP_FRAME, encode_slot_payload, frame_app_response};
41
42/// Maximum number of output slots consumed per batch.
43const MAX_BATCH: usize = 1024;
44
45/// Maximum accumulated send buffer per connection (64 KiB). If a client
46/// falls behind and the buffer exceeds this, the connection is dropped.
47/// 64 KiB holds ~500 response frames — well beyond any reasonable lag.
48const MAX_SEND_BUF: usize = 64 * 1024;
49
50/// Minimum interval between SEND retries to a connection whose socket
51/// buffer is full (`MSG_DONTWAIT` completed with `EAGAIN`). The stage
52/// busy-spins, so without pacing a blocked connection would cost one
53/// futile `io_uring_enter` per loop iteration. 100 µs adds no meaningful
54/// delivery delay: a full socket buffer drains at the client's read
55/// cadence (millisecond scale), and healthy connections are never paced.
56const BLOCKED_RETRY_INTERVAL: Duration = Duration::from_micros(100);
57
58/// Byte-threshold flush trigger for the consumed (busy) path — the
59/// still-open half of finding 4 in
60/// `docs/internal/latency-audit-2026-07.md`. Under sustained load with
61/// an open durability gate, neither the idle-path flush (SPSC never
62/// empties) nor the gate-path flush (no wait) runs, so without this
63/// trigger responses sit in `send_buf` until `MAX_SEND_BUF` *drops* the
64/// connection instead of serving it. Roughly one TCP MSS (1460 for
65/// standard Ethernet, minus margin): once a connection has a full
66/// segment buffered, flushing early costs nothing in wire efficiency,
67/// and the bound keeps `send_buf` ~45 flushes away from the disconnect
68/// cap instead of zero.
69const FLUSH_BYTES_THRESHOLD: usize = 1400;
70
71/// Slot-count flush trigger: how many appended slots may pass between
72/// flushes before one is forced, regardless of how few bytes any single
73/// connection has buffered.
74///
75/// [`FLUSH_BYTES_THRESHOLD`] bounds a *connection's* buffered bytes but
76/// not their *age*: the interval to the next flush is the time the
77/// busiest connection needs to accumulate an MSS, which grows with
78/// client count. At 4 clients that is microseconds; at 100 clients each
79/// sending ~40 B responses at a modest rate it is milliseconds, and every
80/// connection's already-encoded responses wait that long. Counting slots
81/// instead makes the bound depend on the stage's own throughput: one
82/// extra `io_uring_enter` per 256 responses is well amortized (~0.1 % of
83/// the per-slot cost at 1 M/s) and caps the wait at the time to encode
84/// 256 responses — tens of microseconds — however the load is spread.
85const FLUSH_SLOT_INTERVAL: usize = 256;
86
87/// The consumed path's flush cadence: both triggers plus the counter
88/// they share.
89///
90/// A struct rather than loose locals because the age counter has to be
91/// restarted by *every* flush site (consumed path, pre-gate-wait, idle),
92/// and a missed reset silently shortens the bound. One `on_flush` call
93/// per site is checkable by eye.
94#[derive(Default)]
95struct FlushCadence {
96 /// Slots appended since the last flush — the age bound.
97 slots_since_flush: usize,
98 /// Latched by the byte trigger, cleared by [`Self::on_flush`].
99 due: bool,
100}
101
102impl FlushCadence {
103 /// Record one appended slot on a connection that now holds
104 /// `buffered_bytes` unflushed.
105 #[inline]
106 fn on_append(&mut self, buffered_bytes: usize) {
107 self.slots_since_flush += 1;
108 self.due |= buffered_bytes >= FLUSH_BYTES_THRESHOLD;
109 }
110
111 /// Whether a flush must run before the next slot is encoded.
112 #[inline]
113 fn is_due(&self) -> bool {
114 self.due || self.slots_since_flush >= FLUSH_SLOT_INTERVAL
115 }
116
117 /// Restart both triggers. Call immediately after any `flush_sends`.
118 #[inline]
119 fn on_flush(&mut self) {
120 self.due = false;
121 self.slots_since_flush = 0;
122 }
123}
124
125/// How long a connection's socket may accept *zero* bytes while it has
126/// undelivered data before it is dropped. Partial progress restarts the
127/// clock — a slow-but-draining client is `MAX_SEND_BUF`'s problem, not
128/// this one's. Complements `MAX_SEND_BUF`, which only catches clients
129/// that lag while new responses keep *arriving* — a client that stops
130/// reading during a quiet period accumulates almost nothing (heartbeats
131/// only) and would otherwise pin its buffered bytes and its slot
132/// indefinitely.
133const BLOCKED_SEND_TIMEOUT: Duration = Duration::from_secs(5);
134
135pub use crate::ControlEvent;
136
137/// Encoder type alias: response encoder bound to the application's
138/// `Report` / `QueryResponse` types. Hides the long
139/// `dyn ResponseEncoder<Report = ..., Query = ...>` at call sites.
140pub type ResponseEncoderArc<A> = Arc<
141 dyn melin_app::encoder::ResponseEncoder<
142 Report = <A as Application>::Report,
143 Query = <A as Application>::QueryResponse,
144 >,
145>;
146
147/// Configuration and shared state for the response stage.
148pub struct Response<A: Application> {
149 /// Highest wire seq durably persisted on this node's journal.
150 /// In the same sequence space as `OutputSlot.wire_seq` and the
151 /// replica metrics (`metrics.in_memory_sequence` /
152 /// `metrics.acked_sequence`), so the durability gate can compare
153 /// these values numerically and the comparison is meaningful
154 /// regardless of `starting_sequence` (fresh vs recovered primary).
155 /// Typed [`DurableWireSeqCursor`] so the gate cannot be wired to a
156 /// ring-space counter — the pre-v14 bug class. Updated by the
157 /// journal stage after every fsync batch via `set_last_seq_publisher`.
158 pub journal_persisted_wire_seq: DurableWireSeqCursor,
159 /// The ack policy the gate starts under and the sources of its
160 /// changes — see [`GatePolicy`].
161 pub policy: GatePolicy,
162 /// Per-slot replica cursors. `None` for standalone deployments
163 /// (no replication wiring) — the policy then evaluates against the
164 /// primary alone.
165 pub replication_metrics: Option<Arc<ReplicationMetrics>>,
166 /// Per-slot replica active flags. Only "true" slots are included in
167 /// the cursor view fed to `Policy::evaluate`, so disconnected slots
168 /// don't pollute the view with stale zero cursors. When the
169 /// resulting view is too small to satisfy a clause, the policy
170 /// reports degraded and the gate stalls.
171 /// Mirrors `replication_metrics` — `None` in standalone.
172 pub replica_active: Option<[Arc<AtomicBool>; 2]>,
173 pub heartbeat_interval: Option<Duration>,
174 /// How this thread waits — on an empty output ring, and inside the
175 /// durability gate on the journal-disk and replication threads.
176 pub wait: WaitStrategy,
177 pub utilization: Arc<StageUtilization>,
178 /// Wire encoder for application-shaped payloads. The application's
179 /// encoder, constructed once at boot and shared with the DPDK
180 /// response stage.
181 pub encoder: ResponseEncoderArc<A>,
182 /// Node fencing state. When latched (a higher epoch was observed), the
183 /// stage exits *without* the best-effort flush — in-flight responses
184 /// for requests on a superseded epoch must not be acknowledged. Fencing
185 /// co-sets `shutdown`, so the latch is only consulted on the shutdown
186 /// path (zero steady-state cost). See `crate::fence`.
187 pub fence_state: Arc<melin_transport_core::fence::FenceState>,
188 /// Live-connection count shared with the accept loop's
189 /// `max_connections` gate. Incremented there after auth; decremented
190 /// here — the response stage owns the connection map, so "an entry
191 /// left the map" is the one place a connection verifiably dies
192 /// exactly once, whichever side (reader disconnect or a drop
193 /// decision here) initiated it.
194 pub active_connections: Arc<AtomicU64>,
195 /// Writes the reader refused while the node was halted. Each reply is
196 /// sent once everything published before the refused request has been
197 /// answered, so a client sees its replies in request order — see
198 /// [`crate::halt`].
199 pub refusals: RefusalQueue<A::Report>,
200 /// Sizes the stage's io_uring instance. A flush submits at most one
201 /// SEND per dirty connection, and the connection table never holds
202 /// more than `--max-connections` entries (the accept gate counts
203 /// them), so a ring sized from that cap holds a whole flush — see
204 /// [`RingSizing`].
205 pub ring_sizing: RingSizing,
206 /// Startup report: `Ok` once the stage holds its io_uring instance,
207 /// the creation error otherwise (and the stage returns without
208 /// running). The ring is created on the stage's own thread, which is
209 /// the only one allowed to submit to it, so this is how the spawner
210 /// learns the outcome before it carries on. `None` when nobody waits
211 /// for it; a creation failure is then only logged.
212 pub ready: Option<mpsc::SyncSender<std::io::Result<()>>>,
213 /// Release of held replies on this node's own fsync while it is
214 /// halted for want of a replica; `None` when off. See
215 /// [`crate::halt::DegradedRelease`].
216 pub degraded_release: Option<crate::halt::DegradedRelease>,
217 /// Test seam: called once per iteration right after the control
218 /// channel has been drained, so a test can hold the stage there and
219 /// choose what lands while it waits. The drain runs after the
220 /// output ring is read, and the seam guards that order: were the
221 /// drain moved back in front of the read, the seam would sit
222 /// between the two, and a `Connected` landing there would be
223 /// missed by the read that follows — which `registration_race`
224 /// checks. `None` runs the stage as production does; the field
225 /// itself is compiled out of non-test builds, so the loop pays
226 /// nothing.
227 #[cfg(test)]
228 pub pause_after_control_drain: Option<Box<dyn FnMut() + Send>>,
229}
230
231/// Per-connection state for batched io_uring sends.
232struct ConnectionEntry {
233 fd: RawFd,
234 /// Owns the write half of the socket to keep the fd alive.
235 _owner: Box<dyn Send>,
236 /// Accumulates encoded response frames between flushes.
237 /// The full wire frame (length prefix + payload) is appended here.
238 /// Vec's internal data pointer is heap-stable, so io_uring SEND SQEs
239 /// referencing `as_ptr()` remain valid even if the HashMap relocates
240 /// this struct. No SEND outlives its `flush_sends` call (every SQE
241 /// carries `MSG_DONTWAIT`, and the flush reaps all completions before
242 /// returning), so the Vec is never mutated while the kernel holds its
243 /// pointer.
244 send_buf: Vec<u8>,
245 /// Last time data was sent to this connection. Used for heartbeat scheduling.
246 last_send: Instant,
247 /// When this connection's socket last made zero forward progress:
248 /// set on `EAGAIN`, reset to the flush timestamp on a partial send
249 /// (bytes moved), cleared when the buffer fully drains. `None` while
250 /// the socket is accepting everything. Drives retry pacing and the
251 /// [`BLOCKED_SEND_TIMEOUT`] drop.
252 blocked_since: Option<Instant>,
253 /// Last SEND attempt. Read only while blocked, to pace retries at
254 /// [`BLOCKED_RETRY_INTERVAL`].
255 last_send_attempt: Instant,
256 /// Whether this connection is on the dirty list. A flag on the entry
257 /// rather than set membership: the append path already holds the
258 /// entry (and just wrote its `send_buf`), so the dedup test is a
259 /// byte in a cache line that is hot, instead of a hash + probe on
260 /// every one of the ~2 frames per request. See `dirty_connections`.
261 dirty: bool,
262}
263
264/// Run the io_uring response stage loop. Blocks the calling thread until shutdown.
265///
266/// Consumes from the output SPSC, waits for durability confirmation, and
267/// sends responses via io_uring SEND.
268///
269/// Ack gating: every gate iteration reads the journal cursor (this
270/// node's persisted) plus per-slot replica cursors (in-memory and
271/// persisted) from `replication_metrics` and feeds them through the
272/// configured [`Policy`]. See `evaluate_durability`.
273///
274/// Returns `true` once the stage has run and stopped on shutdown, `false`
275/// when it never started: its io_uring instance could not be created
276/// (reported through [`Response::ready`]), or nobody was left to report
277/// to.
278pub fn run<A: Application>(
279 mut consumer: ring::Consumer<OutputSlot<A::Report, A::QueryResponse>>,
280 control_rx: mpsc::Receiver<ControlEvent>,
281 config: Response<A>,
282 shutdown: &AtomicBool,
283) -> bool {
284 let Response {
285 journal_persisted_wire_seq,
286 policy,
287 replication_metrics,
288 replica_active,
289 heartbeat_interval,
290 wait,
291 utilization,
292 encoder,
293 fence_state,
294 active_connections,
295 mut refusals,
296 ring_sizing,
297 ready,
298 degraded_release,
299 #[cfg(test)]
300 mut pause_after_control_drain,
301 } = config;
302 // SINGLE_ISSUER: created and submitted from this thread only — the
303 // kernel skips SQ locking and rejects cross-thread submission with
304 // EEXIST instead of racing. Matches the journal/replication rings.
305 // Created first, before anything else the stage builds, so a node
306 // that cannot have it learns so before the stage touches anything.
307 let ring_entries = ring_sizing.ring_entries();
308 let mut ring: IoUring = match IoUring::builder().setup_single_issuer().build(ring_entries) {
309 Ok(ring) => ring,
310 Err(e) => {
311 let err = ring_setup_error("response", ring_entries, e);
312 match ready {
313 // Dropped send: a spawner that stopped waiting is
314 // unwinding, and the stage returns either way.
315 Some(ready) => {
316 let _ = ready.send(Err(err));
317 }
318 None => error!(error = %err, "response stage cannot start"),
319 }
320 return false;
321 }
322 };
323 // Started. A failed send means the spawner is no longer waiting — it
324 // is unwinding — so nothing would ever stop this stage: return.
325 if let Some(ready) = ready
326 && ready.send(Ok(())).is_err()
327 {
328 return false;
329 }
330 // The ack policy in force and the durability gate. The gate owns the
331 // policy for the stage's lifetime and switches it at the slots of
332 // journaled changes. Built here — before the first batch — so a
333 // degraded startup shows on `/healthz` and in the journal
334 // immediately. See `DurabilityGate`.
335 let mut gate = DurabilityGate::new(
336 GateInputs {
337 journal_persisted_wire_seq,
338 replication_metrics,
339 replica_active,
340 utilization: Arc::clone(&utilization),
341 wait,
342 degraded_release,
343 },
344 policy,
345 "response",
346 );
347
348 // Connection table: maps connection IDs to their state.
349 //
350 // `FxHashMap` rather than std's SipHash-1-3 map: this is looked up
351 // once per output slot on the hot path, and the keys are
352 // server-generated monotonic connection ids — a client cannot choose
353 // them, so the HashDoS resistance SipHash buys is worth nothing here
354 // while its ~20 ns/lookup is not. Pre-sized for a reasonable number
355 // of concurrent clients.
356 let mut connections: FxHashMap<u64, ConnectionEntry> =
357 FxHashMap::with_capacity_and_hasher(256, Default::default());
358
359 let mut encode_buf: EncodeBuf = [0u8; MAX_APP_FRAME];
360
361 /// Cadence at which the idle spin does its housekeeping *clock read*.
362 /// The heartbeat scan, the policy re-check and the trace-stats flush
363 /// each keep their own (coarser) interval; this only bounds how
364 /// often the loop asks the clock what time it is, so it must stay at
365 /// or below the finest of them (`trace::IDLE_FLUSH_INTERVAL`, 100 ms).
366 const IDLE_HOUSEKEEPING_INTERVAL: Duration = Duration::from_millis(10);
367
368 // Stage histograms registered with the global registry — see
369 // `melin_transport_core::trace`. The four breakdown stages
370 // (journal-wait, replica-wait, encode, egress) feed the bench's
371 // tick-to-trade decomposition; spsc/dispatch/server-e2e are kept
372 // alongside as overall sanity checks.
373 #[cfg(feature = "latency-trace")]
374 let mut spsc_rec =
375 trace::register_stage("response: SPSC wakeup (matching publish → response consume)");
376 #[cfg(feature = "latency-trace")]
377 let mut dispatch_rec = trace::register_stage("response: dispatch (consume → socket write)");
378 #[cfg(feature = "latency-trace")]
379 let mut server_e2e_rec = trace::register_stage("server e2e (reader recv → response flush)");
380 // Tick-to-trade breakdown: per-slot wait observed for each
381 // durability path (recorded only when the gate actually held us
382 // up — cache-hit paths skip to avoid inflating the metric with
383 // crossings that happened before we noticed). Encode is wall-time
384 // around `encode_transport_response`. Egress wraps a `flush_sends`
385 // call (one sample per io_uring flush, batching many slots).
386 // Gated on `tick-to-trade`, not `latency-trace`, because these
387 // stages roughly double the hot-path mutex traffic vs the lighter
388 // 4-stage mode.
389 #[cfg(feature = "tick-to-trade")]
390 let mut journal_wait_rec =
391 trace::register_stage("response: journal-wait (match_complete → journal cursor crossed)");
392 #[cfg(feature = "tick-to-trade")]
393 let mut replica_wait_rec = trace::register_stage(
394 "response: replica-wait (match_complete → replication cursor crossed)",
395 );
396 #[cfg(feature = "tick-to-trade")]
397 let mut encode_rec = trace::register_stage("response: encode (per-kind wire encoding)");
398 #[cfg(feature = "tick-to-trade")]
399 let mut egress_rec = trace::register_stage("response: egress (flush_sends elapsed)");
400 // Paces the idle-path recorder flush. Without it, every sample this
401 // thread recorded stays in its thread-local buffer once traffic
402 // stops — which is exactly when the bench scrapes /stats-dump.
403 #[cfg(feature = "latency-trace")]
404 let mut last_stats_flush = Instant::now();
405
406 // Server-side end-to-end samples awaiting a flush, tagged with the
407 // connection whose bytes they measure.
408 //
409 // The stage encodes into `send_buf` and hands the bytes to the
410 // kernel later, so closing the sample at encode time would omit
411 // every microsecond a response spends buffered — the interval this
412 // stage most needs to be honest about, since that is exactly where a
413 // deferred flush hides. Holding each frame's `recv_ts` until the
414 // flush completes measures reader-recv → kernel, which is what the
415 // stage name claims and what the DPDK path already records (it
416 // samples after `tx_producers.flush()`).
417 //
418 // The connection id is what lets a connection dropped without a
419 // flush have its samples thrown away rather than closed — see
420 // `discard_e2e_samples`. Two rules keep the queue honest, and every
421 // mutation of `dirty_connections` obeys one of them:
422 //
423 // - a clear-by-flush closes the queue (`close_e2e_samples`),
424 // - a removal-by-drop discards that connection's entries
425 // (`discard_e2e_samples`).
426 //
427 // Together they give the invariant "queue non-empty implies some
428 // connection is dirty", which is what makes the flush sites
429 // sufficient drain points.
430 //
431 // `Vec` rather than a per-connection map: entries are appended and
432 // then walked wholesale, order is irrelevant, and the dropped-
433 // connection lists they are matched against are almost always empty.
434 // A flat append is the cheapest thing that does that. Capacity is a
435 // starting point, not a bound — under saturation the output ring
436 // never empties, so the queue grows until something forces a flush.
437 //
438 // Only compiled under `latency-trace`; production builds carry
439 // neither the buffer nor the pushes.
440 #[cfg(feature = "latency-trace")]
441 let mut pending_e2e: Vec<(u64, trace::MonoTraceInstant)> = Vec::with_capacity(MAX_BATCH);
442
443 // Connections with buffered (unflushed) writes, carried across
444 // batches.
445 //
446 // `Vec<u64>` paired with `ConnectionEntry::dirty` rather than a
447 // `HashSet`: membership is never *queried*, only iterated and
448 // rebuilt, so the set's only contribution on the hot path was
449 // deduplicating repeat appends — which the entry flag does with a
450 // branch instead of a hash. Pre-sized to the connection table.
451 let mut dirty_connections: Vec<u64> = Vec::with_capacity(256);
452
453 // Flush triggers for the consumed path. Lives across batches because
454 // the regime the age bound exists for is a ring that never empties:
455 // the byte threshold is per connection, so with many low-rate
456 // clients no single `send_buf` reaches an MSS for milliseconds while
457 // the stage encodes continuously.
458 let mut flush = FlushCadence::default();
459
460 // Connections to remove after flush (send errors).
461 let mut to_remove: Vec<u64> = Vec::new();
462
463 // Pre-allocated CQE collection buffer. Must collect CQEs before
464 // processing because the CQ borrow must end before mutating connections.
465 // Pre-sized to the ring's depth (a flush's most SENDs) to avoid
466 // per-iteration heap allocation.
467 let mut cqes: Vec<(u64, i32)> = Vec::with_capacity(ring_entries as usize);
468
469 // Pre-encode the heartbeat response frame once. Full wire frame
470 // (length prefix + tag) for direct append to send_buf.
471 let heartbeat_wire_frame = {
472 let mut buf = [0u8; 8];
473 let written =
474 control_codec::encode_transport_response(&TransportResponse::Heartbeat, &mut buf)
475 .expect("heartbeat encodes");
476 buf[..written].to_vec()
477 };
478
479 // Pre-encode the ServerBusy frame the same way. Sent on behalf of
480 // the reader (`ControlEvent::PipelineBusy`) — this stage owns all
481 // egress on a client socket, so the busy notice appends to
482 // `send_buf` like any other frame instead of racing our sends from
483 // the reader thread.
484 let server_busy_wire_frame = {
485 let mut buf = [0u8; 8];
486 let written =
487 control_codec::encode_transport_response(&TransportResponse::ServerBusy, &mut buf)
488 .expect("ServerBusy encodes");
489 buf[..written].to_vec()
490 };
491
492 // Pre-encode the two request terminators once. Unlike the two above
493 // these are on the hot path — every request ends with one — and their
494 // bytes are constants, so re-encoding per request was pure overhead.
495 // A refusal always ends in the plain one: it is a definite answer,
496 // with nothing on any disk to qualify.
497 let batch_ends = BatchEnds::new();
498
499 // Coarse timestamp for heartbeat scan — avoids Instant::now() on every spin.
500 let mut last_heartbeat_scan = Instant::now();
501
502 // Gates the idle path's housekeeping clock read. The idle spin used
503 // to call `Instant::now()` twice per iteration (heartbeat scan gate,
504 // policy re-check) to decide it had nothing to do — the same vDSO
505 // tax the DPDK stage removed with this timer.
506 let mut idle_housekeeping_timer = AmortizedTimer::new();
507
508 let mut waiter = wait.waiter();
509
510 let mut busy_count: u64 = 0;
511 let mut idle_count: u64 = 0;
512
513 // Input sequence of the last output slot handled. Refused writes are
514 // released only where it changes — between two events' replies, never
515 // inside one. `u64::MAX` is no event's sequence.
516 let mut last_input_seq = u64::MAX;
517
518 'run: loop {
519 if shutdown.load(Ordering::Relaxed) {
520 // Fence: a superseded ex-primary must not acknowledge any
521 // further in-flight work — skip the best-effort flush so
522 // responses buffered for requests on the old epoch are dropped
523 // (the client sees a connection reset and reconciles on
524 // reconnect). Checked only here, not per slot: fencing always
525 // co-sets `shutdown` (`FenceState::fence_if_superseded` owns
526 // that invariant), and the gate wait comes straight back here
527 // on shutdown, so this branch is the first one a fenced node
528 // reaches and the steady-state loop pays nothing.
529 let flush = !fence_state.is_fenced();
530 // Best-effort flush before shutdown.
531 if flush && !dirty_connections.is_empty() {
532 flush_sends(
533 &mut ring,
534 &mut connections,
535 &mut dirty_connections,
536 &mut to_remove,
537 &mut cqes,
538 );
539 #[cfg(feature = "latency-trace")]
540 close_e2e_samples(&mut pending_e2e, &mut server_e2e_rec);
541 }
542 utilization.busy.store(busy_count, Ordering::Relaxed);
543 utilization.idle.store(idle_count, Ordering::Relaxed);
544 #[cfg(feature = "pipeline-stats")]
545 print_utilization("response", busy_count, idle_count);
546 return true;
547 }
548
549 // Borrow output slots from the matching stage in place.
550 //
551 // `read_contiguous` rather than `consume_batch`: the latter
552 // memcpy'd every ready slot into a stack array before the first
553 // one was touched, and `OutputSlot` embeds the application's
554 // largest query response (often hundreds of bytes), so the head
555 // slot of a deep batch paid for the whole copy before it could
556 // be encoded. Borrowing costs nothing and the loop below reads
557 // each slot exactly once anyway.
558 //
559 // The progress counter now moves *after* the batch instead of
560 // before it (`consume_batch` committed up front), so the
561 // matching stage cannot reclaim these slots until the loop —
562 // durability gate waits included — is done with them. That is
563 // at most `MAX_BATCH` of a 1 M-slot ring, and the ring fills at
564 // the same rate either way.
565 //
566 // Refusals follow the order `RefusalQueue` documents: the idle
567 // bound before the read, the sync between the read and the
568 // control drain.
569 let idle_refusal_bound = refusals.idle_bound();
570 let slots = consumer.read_contiguous(MAX_BATCH);
571 let refusals_waiting = refusals.sync();
572
573 // Poll the control channel (non-blocking) for connect and
574 // disconnect — after the ring is read, never before. A reply
575 // always trails its connection's `Connected`: the accept loop
576 // queues that event before it registers the socket with the
577 // reader, so no request can be read, let alone answered, until
578 // the event is in the channel. Every slot in `slots` was
579 // published before the read above, so its `Connected` was queued
580 // before that, and this drain sees it. Drained first, the stage
581 // could read the ring after a `Connected` it had not seen and
582 // drop the reply — which it did, now and then, on a fresh node
583 // under load. `registration_race` in the tests holds the stage
584 // right after this drain to pin the order.
585 while let Ok(event) = control_rx.try_recv() {
586 match event {
587 ControlEvent::Connected {
588 connection_id,
589 fd,
590 writer,
591 } => {
592 // The writer keeps the fd alive — store it as the owner.
593 let owner: Box<dyn Send> = Box::new(writer);
594 connections.insert(
595 connection_id,
596 ConnectionEntry {
597 fd,
598 _owner: owner,
599 send_buf: Vec::with_capacity(4096),
600 last_send: Instant::now(),
601 blocked_since: None,
602 last_send_attempt: Instant::now(),
603 dirty: false,
604 },
605 );
606 }
607 ControlEvent::Disconnected { connection_id } => {
608 // Reader-initiated teardown: the reader already
609 // closed its half. Decrement only if the entry was
610 // actually present — a response-initiated drop
611 // already removed it (and paid the decrement), and
612 // this event is its echo.
613 if connections.remove(&connection_id).is_some() {
614 active_connections.fetch_sub(1, Ordering::Relaxed);
615 }
616 unmark_dirty(connection_id, &mut dirty_connections);
617 // Anything this connection had buffered goes with
618 // it, so its queued samples measure bytes that will
619 // never be sent.
620 #[cfg(feature = "latency-trace")]
621 discard_e2e_samples(&mut pending_e2e, &[connection_id]);
622 }
623 ControlEvent::PipelineBusy { connection_id } => {
624 if let Some(entry) = connections.get_mut(&connection_id) {
625 // Overflow discipline: a busy notice to a peer
626 // already at its buffer cap is not worth more
627 // memory — skip it; the cap (or the blocked
628 // timeout) is about to drop the connection
629 // anyway. Missing entry likewise: best-effort.
630 if entry.send_buf.len() + server_busy_wire_frame.len() <= MAX_SEND_BUF {
631 entry.send_buf.extend_from_slice(&server_busy_wire_frame);
632 entry.last_send = Instant::now();
633 mark_dirty(entry, connection_id, &mut dirty_connections);
634 }
635 }
636 }
637 }
638 }
639
640 // Test seam: hold the stage right after the drain — see
641 // `Response::pause_after_control_drain`.
642 #[cfg(test)]
643 if let Some(pause) = pause_after_control_drain.as_mut() {
644 pause();
645 }
646
647 if slots.is_empty() {
648 // Every event published before a refusal up to the bound has
649 // been answered: send those refusals with this flush.
650 if let Some(bound) = idle_refusal_bound {
651 let now = Instant::now();
652 refusals.release(bound, |refusal| {
653 append_refusal(
654 refusal,
655 &*encoder,
656 &mut connections,
657 &mut encode_buf,
658 &batch_ends.policy,
659 now,
660 &mut dirty_connections,
661 &mut to_remove,
662 &mut flush,
663 );
664 });
665 // A refusal can overflow its connection's buffer; drop
666 // those before the flush, as the batch end does.
667 #[cfg(feature = "latency-trace")]
668 discard_e2e_samples(&mut pending_e2e, &to_remove);
669 for conn_id in to_remove.drain(..) {
670 if let Some(entry) = connections.remove(&conn_id) {
671 teardown_dropped(entry, &active_connections);
672 }
673 unmark_dirty(conn_id, &mut dirty_connections);
674 }
675 }
676
677 // SPSC is empty — flush all dirty connections via io_uring.
678 // This is the response-data egress path; heartbeat flushes
679 // below aren't sampled because they're admin traffic, not
680 // on the client RTT path.
681 if !dirty_connections.is_empty() {
682 #[cfg(feature = "tick-to-trade")]
683 let egress_start = trace::mono_trace_ns();
684 flush_sends(
685 &mut ring,
686 &mut connections,
687 &mut dirty_connections,
688 &mut to_remove,
689 &mut cqes,
690 );
691 flush.on_flush();
692 #[cfg(feature = "tick-to-trade")]
693 egress_rec.record_elapsed(egress_start, trace::mono_trace_ns());
694 #[cfg(feature = "latency-trace")]
695 close_e2e_samples(&mut pending_e2e, &mut server_e2e_rec);
696 for conn_id in to_remove.drain(..) {
697 if let Some(entry) = connections.remove(&conn_id) {
698 teardown_dropped(entry, &active_connections);
699 }
700 }
701 }
702
703 // Everything below is periodic housekeeping on
704 // sub-second-to-second cadences, and each check needs the
705 // current time only to discover it has nothing to do. One
706 // amortized tick per idle iteration replaces the two
707 // unconditional `Instant::now()` calls that decision used to
708 // cost; the inner intervals are unchanged, so cadences are
709 // the same (see `IDLE_HOUSEKEEPING_INTERVAL`).
710 //
711 // The timer's iteration mask is only engaged once the stage
712 // has been idle for a sustained stretch (the waiter resets
713 // on every consumed batch). That is deliberate: the mask
714 // trades cadence for clock reads, and it should only do so
715 // when clock reads are the loop's whole cost. A stage that
716 // is nearly saturated reaches this path a handful of times
717 // between batches — there the read is already rare, and
718 // masking it would stretch the one-second heartbeat scan
719 // into minutes. A yielding thread never masks either: the
720 // yield syscall dwarfs a vDSO read.
721 //
722 // "Busy-spinning, and has been for a while": under
723 // spin-then-yield a loop past its budget is no longer
724 // spinning, so the conjunction is only ever true under
725 // `BusySpin`.
726 if idle_housekeeping_timer
727 .tick(
728 IDLE_HOUSEKEEPING_INTERVAL,
729 waiter.spinning() && waiter.past_spin_budget(),
730 )
731 .is_some()
732 {
733 let now = Instant::now();
734
735 // Send heartbeats to idle connections. Only checked
736 // during idle periods (SPSC empty) to avoid overhead on
737 // the hot path.
738 //
739 // No end-to-end samples to close here: the sample
740 // queue's invariant is that a queued entry implies a
741 // dirty connection, so the flush above — which closes
742 // the queue whenever anything was dirty — leaves it
743 // empty. Anything dirtied from here on is heartbeat
744 // frames, which carry no samples.
745 if let Some(interval) = heartbeat_interval
746 // Coarse gate: only scan at most once per second.
747 && now.duration_since(last_heartbeat_scan) >= Duration::from_secs(1)
748 {
749 last_heartbeat_scan = now;
750 for (&conn_id, entry) in connections.iter_mut() {
751 if heartbeat_due(entry, now, interval, heartbeat_wire_frame.len()) {
752 entry.send_buf.extend_from_slice(&heartbeat_wire_frame);
753 entry.last_send = now;
754 mark_dirty(entry, conn_id, &mut dirty_connections);
755 }
756 }
757 // Flush the heartbeat sends immediately.
758 if !dirty_connections.is_empty() {
759 flush_sends(
760 &mut ring,
761 &mut connections,
762 &mut dirty_connections,
763 &mut to_remove,
764 &mut cqes,
765 );
766 flush.on_flush();
767 for conn_id in to_remove.drain(..) {
768 if let Some(entry) = connections.remove(&conn_id) {
769 teardown_dropped(entry, &active_connections);
770 }
771 }
772 }
773 }
774
775 // Re-evaluate the ack policy on a slow timer so the
776 // `policy_degraded` flag and the periodic warn track the
777 // cluster's real state even on an idle / quiet node —
778 // the no-batch counterpart of `gate.after_batch()`.
779 gate.idle_recheck(now);
780
781 // Hand buffered latency samples to the stats registry
782 // while we have nothing better to do. Reuses the
783 // housekeeping clock read, so the spin path picks up no
784 // extra `clock_gettime`.
785 #[cfg(feature = "latency-trace")]
786 if now.duration_since(last_stats_flush) >= trace::IDLE_FLUSH_INTERVAL {
787 last_stats_flush = now;
788 spsc_rec.flush();
789 dispatch_rec.flush();
790 server_e2e_rec.flush();
791 #[cfg(feature = "tick-to-trade")]
792 {
793 journal_wait_rec.flush();
794 replica_wait_rec.flush();
795 encode_rec.flush();
796 egress_rec.flush();
797 }
798 }
799 }
800
801 idle_count += 1;
802 if idle_count.is_multiple_of(1024) {
803 utilization.busy.store(busy_count, Ordering::Relaxed);
804 utilization.idle.store(idle_count, Ordering::Relaxed);
805 }
806 waiter.idle();
807 continue;
808 }
809 waiter.reset();
810 busy_count += 1;
811
812 #[cfg(feature = "latency-trace")]
813 let consume_ts = trace::mono_trace_ns();
814
815 // Wait for durability confirmation before sending responses.
816 //
817 // Gate on `wire_seq`, not `input_seq`. `input_seq` is in
818 // local-consumer space (the matching cursor on the input ring,
819 // starts at 0 in this process) while replica metrics and the
820 // primary's `journal_persisted_wire_seq` live in wire-seq space
821 // (allocated by the journal stage starting at
822 // `starting_sequence`). A `needed` derived from `input_seq` and
823 // compared against wire-seq cursors only works when
824 // `starting_sequence == 1`; a recovered primary (or any process
825 // whose journal already has prior content pushing
826 // `starting_sequence` above 1) would silently open the gate
827 // ahead of the replica's actual replicated state.
828 //
829 // Every cursor in the policy view (`journal_persisted_wire_seq`,
830 // `metrics.in_memory_sequence`, `metrics.acked_sequence`)
831 // carries "highest wire seq known to be in that state on node
832 // X". A slot's `wire_seq` is therefore the *exact* wire seq the
833 // gate must see — not `+1` — for that slot's event to be
834 // considered durable. The legacy `+1` was load-bearing only
835 // because `input_seq` was off by `starting_sequence - 1` from
836 // wire seq; with the wire-seq stamp it would over-shoot by one
837 // event and make the gate stall an extra round-trip per
838 // response.
839 //
840 // The gate is evaluated **per slot**, not once per batch against
841 // the batch's maximum `wire_seq`. Batch-max gating made every
842 // response in a batch wait for the newest event in it to become
843 // durable, so the oldest slot paid the durability latency of an
844 // event sequenced up to `MAX_BATCH` positions after it — a
845 // head-of-line block bounded only by the batch size, and one
846 // that bites hardest exactly when the stage has caught up to the
847 // durability frontier under load. Per-slot gating walks that
848 // frontier instead: each response is released as soon as its own
849 // event is durable.
850 //
851 // The extra waits are self-limiting. Slots arrive FIFO with
852 // monotonic `wire_seq`, and the journal publishes its cursor per
853 // fsync batch, so one wait typically advances the cursor past a
854 // whole run of following slots and they fall through without
855 // spinning. The number of waits (and so of flushes) tracks real
856 // durability boundaries, not the slot count. Correctness does
857 // not depend on that ordering — an unsorted batch would simply
858 // wait more often.
859 let batch_now = Instant::now();
860
861 // `flush` (see `FlushCadence`) is fed at append time and checked
862 // after every slot, so the flush runs *within* the batch.
863 // Deferring it to the end of the batch would reopen the defect
864 // the byte threshold exists to close: one MAX_BATCH batch of
865 // large frames (anything over ~64 bytes average) can push a
866 // healthy connection from empty past `MAX_SEND_BUF` before a
867 // batch-end flush ever ran, tearing it down with nothing
868 // written. A flag written at append time rather than a per-slot
869 // scan of the dirty set: the scan would cost a hash lookup per
870 // dirty connection on the hot path.
871 for slot in slots {
872 #[cfg(feature = "latency-trace")]
873 spsc_rec.record_elapsed(slot.match_complete_ts, consume_ts);
874
875 // First slot of an event: every event before it has been
876 // answered, so refusals stamped up to its sequence go first.
877 // Ahead of the gate, which holds this event, not them. A
878 // refusal due here was visible before the read, so the
879 // iteration's sync decides for the whole batch.
880 let first_of_event = slot.input_seq != last_input_seq;
881 last_input_seq = slot.input_seq;
882 if refusals_waiting && first_of_event {
883 refusals.release(slot.input_seq, |refusal| {
884 append_refusal(
885 refusal,
886 &*encoder,
887 &mut connections,
888 &mut encode_buf,
889 &batch_ends.policy,
890 batch_now,
891 &mut dirty_connections,
892 &mut to_remove,
893 &mut flush,
894 );
895 });
896 }
897
898 // Per-slot journal-wait / replica-wait tracker. See
899 // `GateCrossTracker` for the rationale (only records cursors
900 // that were actually on the critical path). Both the
901 // tracker's replica cursor and the attribution counters
902 // below are derived from the policy in force rather than a
903 // fixed level, so "which subsystem to optimize" answers for
904 // the deployment the operator actually configured. A slot
905 // that never waits leaves the tracker unobserved, and an
906 // unobserved tracker reports no crossing — so the fast path
907 // records nothing rather than a zero-length sample.
908 #[cfg(feature = "tick-to-trade")]
909 let mut gate_tracker = GateCrossTracker::new(slot.wire_seq);
910
911 // Admit the slot: held until its event is durable under the
912 // policy in force, and for a policy change, the switch point.
913 // `before_wait` runs only when it has to wait. What backs a
914 // reply decides its terminator: the policy, unless the gate
915 // released it on this node's own fsync while halted.
916 //
917 // Shutdown while the gate is closed: straight back to the
918 // top of the loop, where the shutdown branch decides what to
919 // flush. This slot's reply, which the policy never confirmed,
920 // is not appended, and the rest of the batch goes with it.
921 // Those clients see a reset, as after a crash, and reconcile
922 // on reconnect.
923 //
924 // A policy change slot is the gate's own: its frames go to no
925 // connection, whatever it is addressed to.
926 let (destination, backing) = match gate.admit(
927 slot,
928 shutdown,
929 #[cfg(feature = "tick-to-trade")]
930 &mut gate_tracker,
931 || {
932 // Drain buffered sends before blocking, never after.
933 //
934 // The steady-state flush happens on the `count == 0`
935 // path — once the output ring is empty. That batches
936 // many responses behind one `io_uring_enter`, which is
937 // the right trade on the fast path. But it means a
938 // response that has already cleared its own durability
939 // gate stays in `send_buf` while the loop blocks on a
940 // later event's gate, so a client waits out an fsync +
941 // replica round-trip for an event whose durability was
942 // confirmed before that event was even sequenced.
943 //
944 // Flushing here costs nothing in latency terms: it only
945 // fires when we are about to spin on the gate anyway, so
946 // the syscall overlaps time that would otherwise be
947 // dead. Slots whose gate is already satisfied fall
948 // straight through and keep their batching.
949 //
950 // Traced builds only: this delays the tracker's first
951 // `observe` by the flush duration, so a cursor that
952 // crosses mid-flush is attributed late (or, if it
953 // crosses past `needed`, not attributed at all). Bounded
954 // by one flush and confined to the tick-to-trade
955 // breakdown — the gate's own behaviour is unchanged.
956 if !dirty_connections.is_empty() {
957 #[cfg(feature = "tick-to-trade")]
958 let egress_start = trace::mono_trace_ns();
959 flush_sends(
960 &mut ring,
961 &mut connections,
962 &mut dirty_connections,
963 &mut to_remove,
964 &mut cqes,
965 );
966 flush.on_flush();
967 #[cfg(feature = "tick-to-trade")]
968 egress_rec.record_elapsed(egress_start, trace::mono_trace_ns());
969 #[cfg(feature = "latency-trace")]
970 close_e2e_samples(&mut pending_e2e, &mut server_e2e_rec);
971 // This slot and later ones addressed to a dropped
972 // connection are skipped by the
973 // `connections.get_mut` lookup below, so removing
974 // here is safe.
975 for conn_id in to_remove.drain(..) {
976 if let Some(entry) = connections.remove(&conn_id) {
977 teardown_dropped(entry, &active_connections);
978 }
979 }
980 }
981 },
982 ) {
983 Admission::Reply {
984 connection_id,
985 backing,
986 } => (Some(connection_id), backing),
987 Admission::GateOnly => (None, Backing::Policy),
988 Admission::Shutdown => continue 'run,
989 };
990
991 // Per-slot durability-gate breakdown. Recorded only when the
992 // gate actually held us up (the tracker captured a cross).
993 // The cross timestamp is this slot's own `wire_seq`, so the
994 // sample measures the wait that slot really paid — under
995 // batch-max gating it was the batch maximum's crossing,
996 // which overstated every slot but the last by up to the
997 // batch's matching span.
998 #[cfg(feature = "tick-to-trade")]
999 if let Some(ts) = gate_tracker.journal_crossed() {
1000 journal_wait_rec.record_elapsed(slot.match_complete_ts, ts);
1001 }
1002 #[cfg(feature = "tick-to-trade")]
1003 if let Some(ts) = gate_tracker.replica_crossed() {
1004 replica_wait_rec.record_elapsed(slot.match_complete_ts, ts);
1005 }
1006
1007 // Each slot expands to at most two wire frames: the
1008 // application payload (Report / Query / EngineError) and
1009 // an optional trailing `BatchEnd` when
1010 // `is_last_in_request` is set. Application-shaped
1011 // payloads go through the encoder; transport-shaped
1012 // frames (EngineError, BatchEnd) are encoded by the
1013 // runtime directly.
1014 if let Some((connection_id, entry)) =
1015 destination.and_then(|id| connections.get_mut(&id).map(|entry| (id, entry)))
1016 {
1017 // Frame 1: application payload (if any). BatchEnd
1018 // payloads carry no body — the terminator below
1019 // handles them via `is_last_in_request`.
1020 let payload_result = encode_slot_payload(&slot.payload, &*encoder, &mut encode_buf);
1021
1022 // Frame 2: the pre-encoded terminator, `BatchEnd` or
1023 // `BatchEndDegraded` as the slot is backed, appended with
1024 // the payload in one call.
1025 let trailer: &[u8] = if slot.is_last_in_request {
1026 gate.batch_end(backing, &batch_ends)
1027 } else {
1028 &[]
1029 };
1030
1031 #[cfg(feature = "tick-to-trade")]
1032 let encode_start = trace::mono_trace_ns();
1033 // Underscored: with both frames in one call there is no
1034 // second append to skip, so the outcome is purely
1035 // informational — `append_frames` has already queued an
1036 // overflowing connection for removal. Only the traced
1037 // build reads it, to avoid measuring bytes that were
1038 // never buffered.
1039 let _outcome = append_frames(
1040 payload_result,
1041 trailer,
1042 connection_id,
1043 entry,
1044 &encode_buf,
1045 batch_now,
1046 &mut dirty_connections,
1047 &mut to_remove,
1048 );
1049 #[cfg(feature = "tick-to-trade")]
1050 encode_rec.record_elapsed(encode_start, trace::mono_trace_ns());
1051
1052 // Queue the server-side end-to-end sample: reader recv ->
1053 // response flush. Only a request's last slot carries this
1054 // measurement; queued after the append so a dropped
1055 // connection doesn't skew the metric, and closed by
1056 // whichever flush ships the bytes.
1057 #[cfg(feature = "latency-trace")]
1058 if slot.is_last_in_request && matches!(_outcome, AppendOutcome::Continue) {
1059 pending_e2e.push((connection_id, slot.recv_ts));
1060 }
1061
1062 flush.on_append(entry.send_buf.len());
1063 } else if let Some(connection_id) = destination.filter(|&id| id != 0) {
1064 // A reply for a connection this stage does not hold: it
1065 // was dropped earlier in this batch, or went away before
1066 // its reply was encoded. The drain above runs after the
1067 // ring is read, so a connection that is merely new is
1068 // never a miss. Logged so a lost reply leaves a trace.
1069 // Connection 0 is a server-originated event — a seed, a
1070 // tick — whose reports have no client to go to, and is
1071 // skipped without a word.
1072 debug!(
1073 connection_id,
1074 wire_seq = slot.wire_seq,
1075 "reply dropped: connection not registered"
1076 );
1077 }
1078
1079 // Consumed-path flush — the still-open half of July-audit
1080 // finding 4, plus its age bound (August audit finding 3).
1081 // Under sustained load with an open gate this is the ONLY
1082 // flush that runs: the idle path needs an empty SPSC, the
1083 // gate path needs a durability wait, and heartbeats need
1084 // idleness. Without it, delivery on a busy stretch
1085 // degenerates to `MAX_SEND_BUF` evicting the very clients
1086 // being served. Trigger-gated so light traffic keeps full
1087 // batching; once a connection holds ~an MSS — or the stage
1088 // has encoded `FLUSH_SLOT_INTERVAL` responses since the last
1089 // flush, whichever comes first — the extra submit no longer
1090 // costs wire efficiency. MSG_DONTWAIT flushes cannot block,
1091 // so this adds no head-of-line exposure (the hazard that
1092 // deferred this trigger in July). Runs between slots, not
1093 // after the batch, so `MAX_SEND_BUF` can never trip on a
1094 // healthy connection within a single batch — a blocked peer
1095 // re-arms the flag on its later slots, but its paced retry
1096 // inside `flush_sends` keeps that cheap.
1097 if flush.is_due() {
1098 flush.on_flush();
1099 // Overflow-dropped connections leave first so the flush
1100 // skips them — same order as the batch-end cleanup, and
1101 // their queued samples go with them (they measure bytes
1102 // that will never be flushed). Later slots addressed to
1103 // them are skipped by the `connections.get_mut` miss
1104 // above.
1105 #[cfg(feature = "latency-trace")]
1106 discard_e2e_samples(&mut pending_e2e, &to_remove);
1107 for conn_id in to_remove.drain(..) {
1108 if let Some(entry) = connections.remove(&conn_id) {
1109 teardown_dropped(entry, &active_connections);
1110 }
1111 unmark_dirty(conn_id, &mut dirty_connections);
1112 }
1113 #[cfg(feature = "tick-to-trade")]
1114 let egress_start = trace::mono_trace_ns();
1115 flush_sends(
1116 &mut ring,
1117 &mut connections,
1118 &mut dirty_connections,
1119 &mut to_remove,
1120 &mut cqes,
1121 );
1122 #[cfg(feature = "tick-to-trade")]
1123 egress_rec.record_elapsed(egress_start, trace::mono_trace_ns());
1124 #[cfg(feature = "latency-trace")]
1125 close_e2e_samples(&mut pending_e2e, &mut server_e2e_rec);
1126 for conn_id in to_remove.drain(..) {
1127 if let Some(entry) = connections.remove(&conn_id) {
1128 teardown_dropped(entry, &active_connections);
1129 }
1130 }
1131 }
1132 }
1133
1134 // The borrowed slots are dead here, so the batch can be handed
1135 // back to the producer. Publishing progress is deliberately the
1136 // last thing the iteration does with the ring: every slot has
1137 // cleared its durability gate and been encoded by now.
1138 //
1139 // Invariant the event publisher depends on: this consumer's
1140 // progress never passes a slot that has not cleared the gate.
1141 // The publisher's consumer is chained behind this one (see
1142 // `build_pipeline_with_replication`), so this commit is what
1143 // releases events to it; committing earlier, or on the shutdown
1144 // path out of a gate wait (which goes back to the top of the
1145 // loop without committing), would broadcast events the ack
1146 // policy has not confirmed. The DPDK stage keeps the same one.
1147 consumer.commit();
1148
1149 // Remove connections that exceeded the send buffer limit. Like
1150 // the disconnect handler, this un-dirties a connection without
1151 // flushing it, so it has to discard that connection's queued
1152 // samples too — otherwise they outlive the bytes they measure
1153 // and land on some later, unrelated flush.
1154 #[cfg(feature = "latency-trace")]
1155 discard_e2e_samples(&mut pending_e2e, &to_remove);
1156 for conn_id in to_remove.drain(..) {
1157 if let Some(entry) = connections.remove(&conn_id) {
1158 teardown_dropped(entry, &active_connections);
1159 }
1160 unmark_dirty(conn_id, &mut dirty_connections);
1161 }
1162
1163 // Log degradation transitions / re-emit the reminder — after
1164 // dispatch, not before it. See `DurabilityGate::after_batch`.
1165 gate.after_batch();
1166
1167 #[cfg(feature = "latency-trace")]
1168 dispatch_rec.record_elapsed(consume_ts, trace::mono_trace_ns());
1169 }
1170}
1171
1172/// Close every queued server-side end-to-end sample against the flush
1173/// that just completed. Call immediately after `flush_sends`.
1174///
1175/// Closes the whole queue unconditionally, including entries for a
1176/// connection the flush then dropped on a send error. That is
1177/// deliberate: the stage measures "reader recv → response flush", which
1178/// ends when the bytes are handed to the kernel, not when the peer
1179/// acknowledges them. A failed SEND still produces a sample whose
1180/// duration is the real one for everything this stage controls.
1181/// Contrast [`discard_e2e_samples`], where no flush happens at all.
1182///
1183/// One clock read serves the whole queue: the samples all end at the
1184/// same flush, so reading per entry would only measure the drain loop.
1185#[cfg(feature = "latency-trace")]
1186fn close_e2e_samples(
1187 pending: &mut Vec<(u64, trace::MonoTraceInstant)>,
1188 rec: &mut trace::StageRecorder,
1189) {
1190 let flushed_at = trace::mono_trace_ns();
1191 for (_, recv_ts) in pending.drain(..) {
1192 rec.record_elapsed(recv_ts, flushed_at);
1193 }
1194}
1195
1196/// Drop queued samples belonging to connections going away *without* a
1197/// flush — the disconnect handler and the send-buffer-overflow drain.
1198///
1199/// Their buffered bytes are discarded along with the connection, so
1200/// there is no flush to close the samples against and nothing to
1201/// measure. Left queued, they would instead be timed against some later,
1202/// unrelated connection's flush: a millisecond-scale phantom in a
1203/// microsecond histogram, landing squarely in the tail this stage exists
1204/// to report.
1205///
1206/// Not to be used after `flush_sends`. `dropped` there can hold a
1207/// connection queued by an earlier append overflow whose buffered bytes
1208/// the flush nonetheless shipped — discarding would lose a legitimate
1209/// sample.
1210///
1211/// Linear scan per entry, but `dropped` is empty on every iteration that
1212/// loses no connection, which is essentially all of them, and the early
1213/// return keeps that case free.
1214#[cfg(feature = "latency-trace")]
1215fn discard_e2e_samples(pending: &mut Vec<(u64, trace::MonoTraceInstant)>, dropped: &[u64]) {
1216 if dropped.is_empty() {
1217 return;
1218 }
1219 pending.retain(|(conn_id, _)| !dropped.contains(conn_id));
1220}
1221
1222/// Whether this slot must wait on the durability gate before its
1223/// response is encoded: its own event is not yet known to be durable.
1224///
1225/// Every slot is subject to it. The one reply a halted node sends without
1226/// waiting — the refusal of a write — never enters the output ring (see
1227/// [`crate::halt`]).
1228///
1229/// Shared by both response stages, so the io_uring and DPDK paths cannot
1230/// drift apart on it.
1231#[inline]
1232pub(crate) fn slot_needs_gate<R: Copy, Q: Copy>(
1233 slot: &OutputSlot<R, Q>,
1234 cached_durable_pos: u64,
1235) -> bool {
1236 cached_durable_pos < slot.wire_seq
1237}
1238
1239/// Tear down a connection the *response stage* decided to drop (send
1240/// error, `MAX_SEND_BUF` overflow, blocked-send timeout).
1241///
1242/// Removing the map entry alone only drops this stage's dup of the
1243/// socket — the reader still holds its own dup, so the socket would
1244/// stay fully open: the dropped client's requests keep flowing through
1245/// the reader (whose idle timeout never fires while the client keeps
1246/// sending) with no response ever delivered, and the accept loop's
1247/// `max_connections` permit stays pinned forever. `shutdown(2)` reaches
1248/// every dup: the reader's multishot RECV completes with 0, it tears
1249/// down its slab entry and emits `Disconnected` — which finds this
1250/// entry already gone, so the permit is released exactly once.
1251fn teardown_dropped(entry: ConnectionEntry, active_connections: &AtomicU64) {
1252 // Best-effort: ENOTCONN just means the peer tore the socket down
1253 // first — dropping `entry` below still reclaims our dup.
1254 unsafe {
1255 libc::shutdown(entry.fd, libc::SHUT_RDWR);
1256 }
1257 active_connections.fetch_sub(1, Ordering::Relaxed);
1258}
1259
1260/// Outcome of a slot's append. `Continue` means the slot's bytes are
1261/// buffered (or there were none); `ConnectionDropped` means the
1262/// connection's send buffer overflowed and the connection has been
1263/// queued for removal — nothing further should be appended for it.
1264#[derive(Clone, Copy)]
1265enum AppendOutcome {
1266 Continue,
1267 ConnectionDropped,
1268}
1269
1270/// Whether the idle-path heartbeat scan should append a frame to this
1271/// connection: idle for a full interval — and able to receive it.
1272///
1273/// The two guards close the one append path that used to bypass
1274/// `MAX_SEND_BUF`. A blocked peer's socket is full, so a heartbeat
1275/// would only sit in `send_buf` — and an idle client that trickle-read
1276/// a few bytes per interval kept resetting the blocked clock while
1277/// unchecked heartbeat appends grew its buffer without bound, pinning
1278/// its connection permit on ever-growing memory. Skipping blocked
1279/// peers (they detect liveness by draining, not by new frames) and
1280/// cap-checking the append bounds the buffer; a peer that never drains
1281/// is then `BLOCKED_SEND_TIMEOUT`'s or `MAX_SEND_BUF`'s problem, as
1282/// designed. Residual: a trickling client still holds its permit while
1283/// it drains — bounded memory, and the reader's idle timeout covers
1284/// clients that stop sending entirely.
1285/// Put a connection on the dirty list if it isn't already there.
1286/// Idempotent — the entry flag is the dedup that the old `HashSet`
1287/// membership provided.
1288#[inline]
1289fn mark_dirty(entry: &mut ConnectionEntry, connection_id: u64, dirty: &mut Vec<u64>) {
1290 if !entry.dirty {
1291 entry.dirty = true;
1292 dirty.push(connection_id);
1293 }
1294}
1295
1296/// Take a connection off the dirty list — teardown paths only. `retain`
1297/// rather than a swap-remove scan because the ordering is cheap to keep
1298/// and this runs once per dropped connection, never per frame.
1299fn unmark_dirty(connection_id: u64, dirty: &mut Vec<u64>) {
1300 dirty.retain(|&id| id != connection_id);
1301}
1302
1303fn heartbeat_due(
1304 entry: &ConnectionEntry,
1305 now: Instant,
1306 interval: Duration,
1307 frame_len: usize,
1308) -> bool {
1309 now.duration_since(entry.last_send) >= interval
1310 && entry.blocked_since.is_none()
1311 && entry.send_buf.len() + frame_len <= MAX_SEND_BUF
1312}
1313
1314/// Copy a slot's wire bytes into the connection's send buffer with
1315/// overflow checking and dirty tracking: the encoded payload (from the
1316/// `ResponseEncoder` for application shapes, or
1317/// `encode_transport_response` for transport ones) followed by an
1318/// optional pre-encoded `trailer`.
1319///
1320/// One call per slot rather than one per frame. A request's last slot
1321/// carries a `BatchEnd` terminator behind its payload, and appending
1322/// them separately paid the cap check, the `last_send` stamp and the
1323/// dirty marking twice for every request — plus a re-encode of a frame
1324/// whose bytes never change.
1325#[allow(clippy::too_many_arguments)]
1326fn append_frames(
1327 payload: Option<Result<usize, &'static str>>,
1328 trailer: &[u8],
1329 connection_id: u64,
1330 entry: &mut ConnectionEntry,
1331 encode_buf: &[u8],
1332 batch_now: Instant,
1333 dirty_connections: &mut Vec<u64>,
1334 to_remove: &mut Vec<u64>,
1335) -> AppendOutcome {
1336 // An encode failure is this server's bug, not the client's — log it
1337 // and carry on with the trailer, exactly as when the two frames were
1338 // appended by separate calls.
1339 let written = match payload {
1340 Some(Ok(n)) => n,
1341 Some(Err(reason)) => {
1342 tracing::error!(connection_id, reason, "encode error");
1343 0
1344 }
1345 None => 0,
1346 };
1347 let total = written + trailer.len();
1348 if total == 0 {
1349 return AppendOutcome::Continue;
1350 }
1351
1352 // Drop slow clients whose send buffer has grown too large. This
1353 // prevents unbounded memory growth from a single laggy connection
1354 // causing allocator pressure and tail latency spikes. Checked
1355 // against both frames together, so a request is never delivered
1356 // without its terminator.
1357 if entry.send_buf.len() + total > MAX_SEND_BUF {
1358 debug!(
1359 connection_id,
1360 send_buf_len = entry.send_buf.len(),
1361 "send buffer exceeded limit, dropping connection"
1362 );
1363 to_remove.push(connection_id);
1364 return AppendOutcome::ConnectionDropped;
1365 }
1366
1367 // Append the full wire frames to the connection's send buffer.
1368 // `encode_buf` already holds a complete frame — header written by
1369 // `frame_app_response`, or by the control codec — so no extra
1370 // framing is needed.
1371 entry.send_buf.extend_from_slice(&encode_buf[..written]);
1372 entry.send_buf.extend_from_slice(trailer);
1373 entry.last_send = batch_now;
1374 mark_dirty(entry, connection_id, dirty_connections);
1375 AppendOutcome::Continue
1376}
1377
1378/// Append the reply to a write refused at ingress — the application's
1379/// rejection, then the request terminator — to its connection's send
1380/// buffer. A connection that has gone away loses nothing it can still
1381/// receive.
1382///
1383/// No durability gate: nothing was published, so there is nothing to wait
1384/// for. The caller has already waited for what comes before it on the
1385/// connection (see [`crate::halt`]).
1386#[allow(clippy::too_many_arguments)]
1387fn append_refusal<R: Copy, Q: Copy>(
1388 refusal: Refusal<R>,
1389 encoder: &dyn melin_app::encoder::ResponseEncoder<Report = R, Query = Q>,
1390 connections: &mut FxHashMap<u64, ConnectionEntry>,
1391 encode_buf: &mut EncodeBuf,
1392 batch_end_wire_frame: &[u8],
1393 now: Instant,
1394 dirty_connections: &mut Vec<u64>,
1395 to_remove: &mut Vec<u64>,
1396 flush: &mut FlushCadence,
1397) {
1398 let Some(entry) = connections.get_mut(&refusal.connection_id) else {
1399 debug!(
1400 connection_id = refusal.connection_id,
1401 "refusal dropped: connection not registered"
1402 );
1403 return;
1404 };
1405 let payload = frame_app_response(encode_buf, |body| {
1406 encoder.encode_report(&refusal.report, body)
1407 });
1408 append_frames(
1409 Some(payload),
1410 batch_end_wire_frame,
1411 refusal.connection_id,
1412 entry,
1413 encode_buf,
1414 now,
1415 dirty_connections,
1416 to_remove,
1417 );
1418 flush.on_append(entry.send_buf.len());
1419}
1420
1421/// Each dirty connection's accumulated send buffer is sent in a single
1422/// SEND operation, and the flush never blocks on a slow peer.
1423///
1424/// Every SEND carries `MSG_DONTWAIT`, so a full socket buffer completes
1425/// immediately with `EAGAIN` instead of parking the operation until the
1426/// peer reads. That matters because io_uring never surfaces `EAGAIN` for
1427/// a plain SEND — it arms an internal poll and withholds the CQE, which
1428/// is what let one zero-window client wedge this stage (and with it every
1429/// client's acks) behind the `submit_and_wait` below.
1430///
1431/// Undelivered bytes (EAGAIN or a partial send) stay in the connection's
1432/// `send_buf` and the connection stays in `dirty`; retries are paced by
1433/// [`BLOCKED_RETRY_INTERVAL`] and bounded by [`BLOCKED_SEND_TIMEOUT`].
1434/// `MAX_SEND_BUF` remains the growth cap while new responses accumulate.
1435///
1436/// On return, `dirty` holds exactly the connections that still have
1437/// undelivered bytes and were not queued in `to_remove` — callers must
1438/// not clear it. Failed connections are collected in `to_remove` for the
1439/// caller to purge from `connections`.
1440fn flush_sends(
1441 ring: &mut IoUring,
1442 connections: &mut FxHashMap<u64, ConnectionEntry>,
1443 dirty: &mut Vec<u64>,
1444 to_remove: &mut Vec<u64>,
1445 cqes: &mut Vec<(u64, i32)>,
1446) {
1447 // One clock read per flush, shared by the retry-pacing and
1448 // blocked-timeout decisions. Cheap next to the submit syscall below,
1449 // and flushes are already batched (one per drained SPSC batch or
1450 // idle-loop pass, not one per response).
1451 let now = Instant::now();
1452
1453 // Submit SEND SQEs for all dirty connections not in retry backoff.
1454 let mut pending: usize = 0;
1455 for &conn_id in dirty.iter() {
1456 let Some(entry) = connections.get_mut(&conn_id) else {
1457 continue;
1458 };
1459 if entry.send_buf.is_empty() {
1460 continue;
1461 }
1462 if let Some(blocked_at) = entry.blocked_since {
1463 // A peer that has refused bytes for the full timeout is not
1464 // coming back for them — reclaim the slot. Client-caused,
1465 // hence debug (see the log-level convention).
1466 if now.duration_since(blocked_at) >= BLOCKED_SEND_TIMEOUT {
1467 debug!(
1468 connection_id = conn_id,
1469 pending_bytes = entry.send_buf.len(),
1470 blocked_ms = now.duration_since(blocked_at).as_millis() as u64,
1471 "socket blocked past timeout, dropping connection"
1472 );
1473 to_remove.push(conn_id);
1474 continue;
1475 }
1476 if now.duration_since(entry.last_send_attempt) < BLOCKED_RETRY_INTERVAL {
1477 continue;
1478 }
1479 }
1480 entry.last_send_attempt = now;
1481
1482 let sqe = opcode::Send::new(
1483 types::Fd(entry.fd),
1484 entry.send_buf.as_ptr(),
1485 entry.send_buf.len() as u32,
1486 )
1487 .flags(libc::MSG_DONTWAIT)
1488 .build()
1489 .user_data(conn_id);
1490
1491 unsafe {
1492 ring.submission().push(&sqe).expect(
1493 "io_uring SQ full: a flush submits one SEND per connection, and the ring \
1494 is sized above --max-connections",
1495 );
1496 }
1497 pending += 1;
1498 }
1499
1500 if pending > 0 {
1501 // With MSG_DONTWAIT every SEND completes during submission
1502 // (success, partial, or EAGAIN — the flag sets the kernel's
1503 // no-wait path, so nothing is deferred to a poll retry). The
1504 // wait is bounded by op execution, never by a peer.
1505 //
1506 // EINTR must retry, not return: a signal (profilers use them
1507 // routinely) can interrupt the CQE wait *after* the submit phase
1508 // consumed the SQEs — the inline completions are already posted
1509 // by then. Returning without reaping would leave stale CQEs that
1510 // the next flush drains against *updated* buffer contents:
1511 // a delivered prefix gets re-sent and `drain(..sent)` double-
1512 // drains. The retry submits an empty SQ and finds the CQ already
1513 // holding `pending` entries, so it cannot stall.
1514 loop {
1515 match ring.submit_and_wait(pending) {
1516 Ok(_) => break,
1517 Err(ref e) if e.raw_os_error() == Some(libc::EINTR) => continue,
1518 Err(e) => {
1519 // Submit-phase failure (ENOMEM class — EBUSY cannot
1520 // happen: the CQ is twice the ring's depth and fully
1521 // reaped every flush, and `pending` — one SEND per
1522 // connection — is at most `--max-connections`, below
1523 // the depth `RingSizing` derives from it, so the CQ
1524 // never holds more than one flush). An error here means
1525 // the SQEs were NOT consumed: continuing would leave
1526 // them queued for the next flush's submit, by which
1527 // time their addr fields can point at drained or
1528 // reallocated send_bufs — garbage on client sockets,
1529 // on the ack path. The kernel is out of resources
1530 // and the stage cannot proceed without corruption
1531 // risk: fail loudly and let the accept loop's
1532 // pipeline-death detection take the server down.
1533 error!(error = %e, "io_uring submit_and_wait failed in response stage");
1534 panic!("response stage io_uring submit failed: {e}");
1535 }
1536 }
1537 }
1538
1539 // Drain completions into pre-allocated buffer. Must collect to
1540 // release CQ borrow before mutating connections.
1541 cqes.clear();
1542 cqes.extend(ring.completion().map(|cqe| (cqe.user_data(), cqe.result())));
1543
1544 for &(conn_id, result) in cqes.iter() {
1545 let Some(entry) = connections.get_mut(&conn_id) else {
1546 continue;
1547 };
1548 if result == -libc::EAGAIN {
1549 // Socket buffer full. Keep the bytes; the connection
1550 // stays dirty and retries at the paced cadence.
1551 if entry.blocked_since.is_none() {
1552 entry.blocked_since = Some(now);
1553 }
1554 continue;
1555 }
1556 if result < 0 {
1557 debug!(
1558 connection_id = conn_id,
1559 error = result,
1560 "send error, dropping connection"
1561 );
1562 to_remove.push(conn_id);
1563 continue;
1564 }
1565
1566 let sent = result as usize;
1567 if sent == 0 {
1568 // Unreachable for SOCK_STREAM sends of len > 0 (the
1569 // kernel reports -EAGAIN instead), but keep the
1570 // zero-progress invariant literal: 0 bytes must not
1571 // restart the blocked clock via the partial branch.
1572 if entry.blocked_since.is_none() {
1573 entry.blocked_since = Some(now);
1574 }
1575 } else if sent >= entry.send_buf.len() {
1576 entry.send_buf.clear();
1577 entry.blocked_since = None;
1578 } else {
1579 // Partial send — the socket buffer filled mid-copy. An
1580 // immediate retry would only report EAGAIN, so keep the
1581 // remainder for the paced retry. Bytes moved, though:
1582 // restart the blocked clock from this progress, so only
1583 // a peer accepting *zero* bytes for the full timeout is
1584 // dropped — a slow-but-draining client keeps its
1585 // connection (until `MAX_SEND_BUF` says otherwise).
1586 entry.send_buf.drain(..sent);
1587 entry.blocked_since = Some(now);
1588 }
1589 }
1590 }
1591
1592 // Keep exactly the connections that still hold undelivered bytes and
1593 // survived this flush. Runs even when nothing was submitted so a
1594 // blocked-timeout drop above still leaves the dirty list consistent.
1595 // The entry flag is cleared in lockstep — it is what keeps a
1596 // connection off the list until its next append.
1597 dirty.retain(|conn_id| {
1598 let keep = !to_remove.contains(conn_id)
1599 && connections
1600 .get(conn_id)
1601 .is_some_and(|e| !e.send_buf.is_empty());
1602 if !keep && let Some(entry) = connections.get_mut(conn_id) {
1603 entry.dirty = false;
1604 }
1605 keep
1606 });
1607}
1608
1609/// Read the live gate cursors and lend them to `f` as a [`CursorView`].
1610///
1611/// The view contains the primary followed by every *currently connected*
1612/// replica slot. Disconnected slots are omitted rather than entered with
1613/// zero cursors, so `CursorView::len` reflects how many nodes are
1614/// actually available to satisfy a clause — too few and the policy
1615/// reports degraded and the gate stalls. Node 0 is always the primary;
1616/// [`Policy::attribute_blocker`] relies on that index convention to tell
1617/// journal from replication.
1618///
1619/// The primary's in-memory cursor is modeled as `u64::MAX` because the
1620/// response stage only gates events the matching stage has already
1621/// processed — those are trivially in-memory on the primary.
1622///
1623/// Scoped-borrow shape rather than a returned view: `CursorView` holds a
1624/// slice, so it cannot outlive the array behind it. Lending it to a
1625/// closure keeps that array on this frame and off every caller's
1626/// signature.
1627#[inline]
1628fn with_cursor_view<R>(
1629 journal_pos: WireSeq,
1630 metrics: Option<&ReplicationMetrics>,
1631 replica_active: Option<&[Arc<AtomicBool>; 2]>,
1632 f: impl FnOnce(&CursorView<'_>) -> R,
1633) -> R {
1634 // Fixed-size array rather than a `Vec`: the cluster is capped at
1635 // MAX_CLUSTER_SIZE and this runs on the gate path, so a heap
1636 // allocation would be pure overhead. Raw `u64` in wire-seq space —
1637 // `journal_pos` leaves the type system here, alongside the replica
1638 // metrics gauges (the `Ack` frame's wire-seq fields verbatim).
1639 let mut nodes = [[0u64; 2]; MAX_CLUSTER_SIZE as usize];
1640 nodes[0] = [u64::MAX, journal_pos.get()];
1641 let mut len = 1;
1642 if let (Some(m), Some(active)) = (metrics, replica_active) {
1643 for (i, slot_active) in active.iter().enumerate() {
1644 // Skip inactive slots up-front.
1645 if !slot_active.load(Ordering::Acquire) {
1646 continue;
1647 }
1648 let in_mem = m.in_memory_sequence[i].load(Ordering::Acquire);
1649 let persisted = m.acked_sequence[i].load(Ordering::Acquire);
1650 nodes[len] = [in_mem, persisted];
1651 len += 1;
1652 }
1653 }
1654 f(&CursorView::new(&nodes[..len]))
1655}
1656
1657/// Highest sequence at which the policy is satisfied by the live
1658/// cursors, plus whether the cluster shape can satisfy it at all.
1659#[inline]
1660pub(crate) fn evaluate_durability(
1661 policy: &Policy,
1662 journal_pos: WireSeq,
1663 metrics: Option<&ReplicationMetrics>,
1664 replica_active: Option<&[Arc<AtomicBool>; 2]>,
1665) -> EvalStatus {
1666 with_cursor_view(journal_pos, metrics, replica_active, |view| {
1667 policy.evaluate_with_status(view)
1668 })
1669}
1670
1671/// One-snapshot gate evaluation: the policy's durable position plus,
1672/// when that position opens the gate (`>= needed`), which subsystem
1673/// supplied the binding cursor.
1674///
1675/// Both answers come from the *same* [`CursorView`]. Re-reading the
1676/// replica cursors for attribution after the evaluation that opened the
1677/// gate would rank a later snapshot — the replica side can advance
1678/// between the two reads and flip the verdict to a subsystem that was
1679/// not the one the gate actually opened on.
1680///
1681/// The blocker is `None` while the gate stays closed (attribution is
1682/// only read at the open, and ranking the clauses for it on every spin
1683/// iteration would be wasted work). At an open with `needed >= 1` it is
1684/// always `Some`: a policy left unsatisfiable by the cluster shape pins
1685/// `durable_pos` to 0, which cannot reach `needed`.
1686///
1687/// The attribution itself replaces the old "compare the journal cursor
1688/// against the minimum replica *persisted* cursor" heuristic, which
1689/// reported replication as the blocker under `disk` whenever a replica
1690/// merely lagged — a replica binds `persisted>=1` only when its fsync
1691/// leads the journal's — and read the persisted level under
1692/// `disk+ram`, which gates on in-memory.
1693#[inline]
1694pub(crate) fn evaluate_gate(
1695 policy: &Policy,
1696 needed: u64,
1697 journal_pos: WireSeq,
1698 metrics: Option<&ReplicationMetrics>,
1699 replica_active: Option<&[Arc<AtomicBool>; 2]>,
1700) -> (EvalStatus, Option<Blocker>) {
1701 with_cursor_view(journal_pos, metrics, replica_active, |view| {
1702 let status = policy.evaluate_with_status(view);
1703 let blocker = if status.durable_pos >= needed {
1704 policy.attribute_blocker(view)
1705 } else {
1706 None
1707 };
1708 (status, blocker)
1709 })
1710}
1711
1712/// The replica-side cursor the active policy is waiting on, for the
1713/// `tick-to-trade` replica-wait histogram. `None` when no clause is
1714/// replica-supplied (e.g. `disk`).
1715#[cfg(feature = "tick-to-trade")]
1716#[inline]
1717pub(crate) fn policy_replica_cursor(
1718 policy: &Policy,
1719 journal_pos: WireSeq,
1720 metrics: Option<&ReplicationMetrics>,
1721 replica_active: Option<&[Arc<AtomicBool>; 2]>,
1722) -> Option<u64> {
1723 with_cursor_view(journal_pos, metrics, replica_active, |view| {
1724 policy.replica_gate_cursor(view)
1725 })
1726}
1727
1728/// Hold-time before a state transition is committed to the log.
1729/// Suppresses log spam when a replica flaps faster than this — only
1730/// transitions that hold for at least this long emit warn/info
1731/// entries. The `/healthz` gauge updates immediately regardless,
1732/// so dashboards and alerts still see real-time state.
1733const DEGRADED_FLAP_HOLD: Duration = Duration::from_secs(1);
1734
1735/// Tracks degradation state across calls and emits warn/info logs
1736/// with sustained-state gating + a periodic heartbeat re-emit.
1737///
1738/// The hot path calls [`Self::tick`] every gate iteration / idle
1739/// poll with the current `degraded` value and the wall clock. The
1740/// logger handles:
1741///
1742/// - Updating the `policy_degraded` health gauge immediately.
1743/// - Suppressing log lines for transitions that don't hold for at
1744/// least [`DEGRADED_FLAP_HOLD`] — a replica flapping at sub-second
1745/// cadence produces no log noise, only a quietly-updating gauge.
1746/// - Emitting a warn at the moment a sustained degraded state
1747/// crosses the hold threshold, plus a periodic re-emit every
1748/// `heartbeat_interval` while it persists.
1749/// - Emitting an info when a sustained healthy state crosses the
1750/// hold threshold (the cluster is back to its target shape and
1751/// stayed there long enough that we trust the recovery).
1752pub(crate) struct DegradationLogger {
1753 /// Last value passed to `tick`; what we'd log about if it stayed
1754 /// at this value past the hold threshold.
1755 pending_state: bool,
1756 /// When `pending_state` first appeared. Reset on every flip.
1757 pending_since: Instant,
1758 /// Whether the current pending state has been logged yet. Only
1759 /// the *first* log per sustained streak crosses; subsequent
1760 /// re-emits while degraded are heartbeat warns.
1761 pending_logged: bool,
1762 /// When the last warn fired. Drives the periodic re-emit while
1763 /// degraded.
1764 last_log: Option<Instant>,
1765 /// Wall clock of the previous accrual. The interval since this
1766 /// instant is attributed to the state observed then (`pending_state`)
1767 /// and accumulated into the `policy_degraded_nanos` counter. Advanced
1768 /// by [`Self::accrue`] — reached on every `tick` (post-gate, idle, and
1769 /// the gate-wait pacing tick) and on `reseed`.
1770 last_tick: Instant,
1771}
1772
1773impl DegradationLogger {
1774 pub(crate) fn new(now: Instant) -> Self {
1775 Self {
1776 pending_state: false,
1777 pending_since: now,
1778 pending_logged: true, // healthy is the assumed initial state; nothing to log
1779 last_log: None,
1780 last_tick: now,
1781 }
1782 }
1783
1784 /// Use when the policy is known to start in a degraded state
1785 /// (e.g. a primary under `disk+ram` with no replica yet
1786 /// connected). Logs a startup warn immediately and treats the
1787 /// state as already-logged so the next tick doesn't re-emit.
1788 pub(crate) fn new_starting_degraded(now: Instant, policy: &Policy) -> Self {
1789 tracing::warn!(
1790 policy = %policy,
1791 "ack policy starts degraded — fewer connected nodes than the target count"
1792 );
1793 Self {
1794 pending_state: true,
1795 pending_since: now,
1796 pending_logged: true,
1797 last_log: Some(now),
1798 last_tick: now,
1799 }
1800 }
1801
1802 /// Charge the interval `[last_tick, now]` to the degraded-duration
1803 /// counter when `prev_degraded` (the state observed at the previous
1804 /// tick) was degraded, then advance `last_tick`. Drives the
1805 /// `_seconds_total` counter so `rate()` reflects time-in-degraded
1806 /// continuously, even mid-incident, rather than only stepping on
1807 /// recovery. Shared by [`Self::tick`] and [`Self::reseed`] so accrual
1808 /// is never skipped on a logger lifecycle boundary.
1809 #[inline]
1810 fn accrue(&mut self, utilization: &StageUtilization, prev_degraded: bool, now: Instant) {
1811 if prev_degraded {
1812 // `duration_since` saturates to zero when `now < last_tick`;
1813 // `now` is always >= `last_tick` here (single-thread monotonic
1814 // clock), matching the plain `duration_since` used elsewhere
1815 // in this file.
1816 let elapsed = now.duration_since(self.last_tick);
1817 // `as_nanos()` is u128; one inter-tick interval is sub-second
1818 // to a few seconds, far below the u64 nanos ceiling (~584
1819 // years), so the cast can't truncate. See the field doc on
1820 // `StageUtilization::policy_degraded_nanos`.
1821 utilization
1822 .policy_degraded_nanos
1823 .fetch_add(elapsed.as_nanos() as u64, Ordering::Relaxed);
1824 }
1825 self.last_tick = now;
1826 }
1827
1828 /// Flush in-flight degraded accrual up to `now`, then reset to a
1829 /// fresh healthy-start logger. Called on a runtime ack-policy
1830 /// swap, which is a logger lifecycle boundary: without flushing
1831 /// first, the pre-swap degraded interval — on the gate-wait path the
1832 /// entire wedge — would be silently dropped. The new policy's actual
1833 /// degraded state is re-derived by the next `tick`, so the brief
1834 /// swap-to-next-tick window is attributed healthy; that residual is
1835 /// bounded by one tick interval, the counter's inherent granularity.
1836 pub(crate) fn reseed(&mut self, utilization: &StageUtilization, now: Instant) {
1837 let prev_state = self.pending_state;
1838 self.accrue(utilization, prev_state, now);
1839 *self = Self::new(now);
1840 }
1841
1842 /// Update the gauge + emit transition/heartbeat logs as needed.
1843 /// Cheap on the hot path: one atomic store, a few branches, one
1844 /// `Instant::duration_since`.
1845 pub(crate) fn tick(
1846 &mut self,
1847 policy: &Policy,
1848 utilization: &StageUtilization,
1849 degraded_now: bool,
1850 now: Instant,
1851 heartbeat_interval: Duration,
1852 ) {
1853 // Charge the just-elapsed interval to the state observed at the
1854 // *previous* tick. Snapshot it up front, before the flap-hold
1855 // bookkeeping below mutates `pending_state`, so accrual stays
1856 // correct even if that block is later reordered.
1857 let prev_state = self.pending_state;
1858 self.accrue(utilization, prev_state, now);
1859
1860 utilization
1861 .policy_degraded
1862 .store(degraded_now, Ordering::Relaxed);
1863
1864 if degraded_now != self.pending_state {
1865 // State changed — start a new hold window. Don't log
1866 // until / unless this new state stays long enough.
1867 self.pending_state = degraded_now;
1868 self.pending_since = now;
1869 self.pending_logged = false;
1870 return;
1871 }
1872
1873 // State held. If we haven't yet logged this streak's onset,
1874 // and it's been pending for at least the flap-hold time,
1875 // emit the transition message and mark logged.
1876 if !self.pending_logged && now.duration_since(self.pending_since) >= DEGRADED_FLAP_HOLD {
1877 if degraded_now {
1878 tracing::warn!(
1879 policy = %policy,
1880 "ack policy operating degraded — fewer connected nodes than the target count, response gate stalled until the cluster recovers or the policy is swapped"
1881 );
1882 } else {
1883 tracing::info!(
1884 policy = %policy,
1885 "ack policy returned to target shape"
1886 );
1887 }
1888 self.pending_logged = true;
1889 self.last_log = Some(now);
1890 return;
1891 }
1892
1893 // Heartbeat re-emit while a degraded state persists.
1894 if degraded_now
1895 && self.pending_logged
1896 && self
1897 .last_log
1898 .is_none_or(|t| now.duration_since(t) >= heartbeat_interval)
1899 {
1900 tracing::warn!(
1901 policy = %policy,
1902 "ack policy still degraded — fewer connected nodes than the target count"
1903 );
1904 self.last_log = Some(now);
1905 }
1906 }
1907}
1908
1909/// Tracks per-cursor "first observed transition from below to >= needed"
1910/// inside the durability gate loop, to drive the journal-wait /
1911/// replica-wait histograms in the bench's tick-to-trade decomposition.
1912///
1913/// A sample is recorded only for cursors that were strictly below
1914/// `needed` at the loop's first observation. Cursors already past at
1915/// entry were not on the critical path for this batch, so attributing
1916/// "wait time" to them would inflate the metric with cursor-poll
1917/// observation timestamps that have nothing to do with how long the
1918/// stage actually held us up.
1919///
1920/// `now_ns` is taken as a parameter rather than read internally so
1921/// tests can supply deterministic timestamps. The caller's hot path
1922/// reads `trace::mono_trace_ns()` once per gate iteration and feeds it in.
1923#[cfg(feature = "tick-to-trade")]
1924pub(crate) struct GateCrossTracker {
1925 needed: u64,
1926 journal_crossed_ts: Option<trace::MonoTraceInstant>,
1927 replica_crossed_ts: Option<trace::MonoTraceInstant>,
1928 journal_was_below: bool,
1929 replica_was_below: bool,
1930 first: bool,
1931}
1932
1933#[cfg(feature = "tick-to-trade")]
1934impl GateCrossTracker {
1935 pub(crate) fn new(needed: u64) -> Self {
1936 Self {
1937 needed,
1938 journal_crossed_ts: None,
1939 replica_crossed_ts: None,
1940 journal_was_below: false,
1941 replica_was_below: false,
1942 first: true,
1943 }
1944 }
1945
1946 /// `replica_pos` is the replica-side cursor the *active policy*
1947 /// gates on — see [`policy_replica_cursor`]. `None` means no replica
1948 /// currently supplies a binding cursor, which happens permanently
1949 /// under `disk` and transiently when the binding replica drops out
1950 /// of the cursor view part-way through a wait.
1951 ///
1952 /// Both cases must leave `replica_crossed_ts` alone. Treating
1953 /// `None` as an infinite cursor would satisfy the crossing test and
1954 /// latch the timestamp at the *disconnect*, reporting a replica
1955 /// wait that ended when the link died rather than when the replica
1956 /// caught up — understating exactly the failover runs the histogram
1957 /// exists to measure. On the first observe it additionally leaves
1958 /// `replica_was_below` false, so a policy that never waits on a
1959 /// replica records no sample at all.
1960 pub(crate) fn observe(
1961 &mut self,
1962 journal_pos: u64,
1963 replica_pos: Option<u64>,
1964 now_ns: trace::MonoTraceInstant,
1965 ) {
1966 if self.first {
1967 self.journal_was_below = journal_pos < self.needed;
1968 self.replica_was_below = replica_pos.is_some_and(|p| p < self.needed);
1969 self.first = false;
1970 }
1971 if self.journal_was_below && self.journal_crossed_ts.is_none() && journal_pos >= self.needed
1972 {
1973 self.journal_crossed_ts = Some(now_ns);
1974 }
1975 if self.replica_was_below
1976 && self.replica_crossed_ts.is_none()
1977 && replica_pos.is_some_and(|p| p >= self.needed)
1978 {
1979 self.replica_crossed_ts = Some(now_ns);
1980 }
1981 }
1982
1983 pub(crate) fn journal_crossed(&self) -> Option<trace::MonoTraceInstant> {
1984 self.journal_crossed_ts
1985 }
1986
1987 pub(crate) fn replica_crossed(&self) -> Option<trace::MonoTraceInstant> {
1988 self.replica_crossed_ts
1989 }
1990}
1991
1992/// Print busy/idle utilization for a pipeline stage on shutdown.
1993#[cfg(feature = "pipeline-stats")]
1994fn print_utilization(stage: &str, busy: u64, idle: u64) {
1995 let total = busy + idle;
1996 if total == 0 {
1997 tracing::info!(stage, "no iterations recorded");
1998 return;
1999 }
2000 let pct = (busy as f64 / total as f64) * 100.0;
2001 tracing::info!(
2002 stage,
2003 pct_busy = format_args!("{pct:.2}%"),
2004 busy,
2005 idle,
2006 total,
2007 "pipeline utilization",
2008 );
2009}
2010
2011#[cfg(test)]
2012pub(crate) mod tests {
2013 #[cfg(feature = "tick-to-trade")]
2014 use super::GateCrossTracker;
2015 use super::{
2016 Blocker, DegradationLogger, OutputSlot, WireSeq, evaluate_durability, evaluate_gate,
2017 slot_needs_gate,
2018 };
2019 use crate::ack_policy::{AckPolicy, Clause, Level, Policy};
2020 use crate::replication::ReplicationMetrics;
2021
2022 /// Queued end-to-end samples survive a flush that dropped nothing,
2023 /// and are closed (drained) by it.
2024 #[cfg(feature = "latency-trace")]
2025 #[test]
2026 fn e2e_samples_survive_until_a_flush_closes_them() {
2027 let mut pending = vec![(1u64, 10u64), (2, 20), (1, 30)];
2028 super::discard_e2e_samples(&mut pending, &[]);
2029 assert_eq!(pending.len(), 3, "an empty drop list must lose nothing");
2030
2031 let mut rec = melin_transport_core::trace::register_stage("test::response_e2e_close");
2032 super::close_e2e_samples(&mut pending, &mut rec);
2033 assert!(pending.is_empty(), "a flush closes the whole queue");
2034 }
2035
2036 /// The defect this pairing exists to prevent: a dropped connection's
2037 /// buffered bytes are discarded with it, so its samples must not
2038 /// survive to be timed against some later connection's flush.
2039 #[cfg(feature = "latency-trace")]
2040 #[test]
2041 fn e2e_samples_for_a_dropped_connection_are_discarded() {
2042 let mut pending = vec![(1u64, 10u64), (2, 20), (1, 30), (3, 40)];
2043 super::discard_e2e_samples(&mut pending, &[1, 3]);
2044 assert_eq!(
2045 pending,
2046 vec![(2, 20)],
2047 "only the surviving connection's samples remain"
2048 );
2049
2050 // Dropping the last live connection empties the queue, which is
2051 // what restores "queue non-empty implies something is dirty" —
2052 // the invariant the flush sites rely on to be sufficient drain
2053 // points.
2054 super::discard_e2e_samples(&mut pending, &[2]);
2055 assert!(pending.is_empty());
2056 }
2057
2058 /// Output slot carrying only the fields the gate decision reads.
2059 /// `()` for the report/query types keeps the fixture independent of
2060 /// any concrete application.
2061 fn slot(wire_seq: u64) -> OutputSlot<(), ()> {
2062 OutputSlot {
2063 wire_seq,
2064 ..Default::default()
2065 }
2066 }
2067
2068 #[test]
2069 fn slot_gates_until_its_own_sequence_is_durable() {
2070 assert!(slot_needs_gate(&slot(10), 0));
2071 assert!(slot_needs_gate(&slot(10), 9));
2072 }
2073
2074 #[test]
2075 fn slot_clears_at_its_own_sequence_not_the_batch_maximum() {
2076 // The cursor reaching exactly this slot's `wire_seq` is enough —
2077 // an off-by-one here would stall every response an extra
2078 // durability round-trip. A later slot in the same batch needing
2079 // more must not hold this one back.
2080 assert!(!slot_needs_gate(&slot(10), 10));
2081 assert!(!slot_needs_gate(&slot(10), 11));
2082 }
2083
2084 /// Build a [`Policy`] from a mini DSL: one or more
2085 /// `"<level>>=<count>"` clauses joined with `&&`. Test-only
2086 /// ergonomics — production builds policies via
2087 /// [`AckPolicy::to_policy`].
2088 fn parse(s: &str) -> Result<Policy, String> {
2089 let mut clauses = Vec::new();
2090 for raw in s.split("&&") {
2091 let token = raw.trim();
2092 let (lvl, rhs) = token
2093 .split_once(">=")
2094 .ok_or_else(|| format!("clause `{token}` missing `>=`"))?;
2095 let level = match lvl.trim() {
2096 "persisted" => Level::Persisted,
2097 "in_memory" => Level::InMemory,
2098 other => return Err(format!("unknown level `{other}`")),
2099 };
2100 let count: u8 = rhs.trim().parse().map_err(|e| format!("bad count: {e}"))?;
2101 clauses.push(Clause { count, level });
2102 }
2103 Policy::new(clauses).map_err(|e| e.to_string())
2104 }
2105 use melin_transport_core::pipeline::StageUtilization;
2106 use std::sync::Arc;
2107 use std::sync::atomic::{AtomicBool, Ordering};
2108 use std::time::{Duration, Instant};
2109
2110 /// Build a `ReplicationMetrics` with both slots populated. Tests
2111 /// that need to simulate a disconnected slot use [`flags`] to mark
2112 /// it inactive — its cursors are then ignored regardless of value.
2113 fn metrics(slot0: (u64, u64), slot1: (u64, u64)) -> Arc<ReplicationMetrics> {
2114 let m = Arc::new(ReplicationMetrics::default());
2115 m.in_memory_sequence[0].store(slot0.0, Ordering::Relaxed);
2116 m.acked_sequence[0].store(slot0.1, Ordering::Relaxed);
2117 m.in_memory_sequence[1].store(slot1.0, Ordering::Relaxed);
2118 m.acked_sequence[1].store(slot1.1, Ordering::Relaxed);
2119 m
2120 }
2121
2122 /// Build a `[active; 2]` flags array.
2123 fn flags(slot0_active: bool, slot1_active: bool) -> [Arc<AtomicBool>; 2] {
2124 [
2125 Arc::new(AtomicBool::new(slot0_active)),
2126 Arc::new(AtomicBool::new(slot1_active)),
2127 ]
2128 }
2129
2130 /// Both replicas active — the common healthy-cluster case.
2131 fn both_active() -> [Arc<AtomicBool>; 2] {
2132 flags(true, true)
2133 }
2134
2135 // --- Standalone (no replicas wired) ---
2136
2137 #[test]
2138 fn standalone_persisted_one_gates_on_journal() {
2139 // No metrics → only the primary is in the view. `persisted>=1`
2140 // is satisfied by the primary alone at journal_pos.
2141 let p = parse("persisted>=1").unwrap();
2142 assert_eq!(
2143 evaluate_durability(&p, WireSeq::new(500), None, None).durable_pos,
2144 500
2145 );
2146 }
2147
2148 #[test]
2149 fn standalone_strict_persisted_two_never_opens() {
2150 // `persisted>=2` on a standalone primary stays at 0: the
2151 // operator asked for two copies and there is only one. The
2152 // policy surfaces as degraded so the operator sees the gate
2153 // is stalled because the cluster can't meet the policy.
2154 let p = parse("persisted>=2").unwrap();
2155 let r = evaluate_durability(&p, WireSeq::new(500), None, None);
2156 assert_eq!(r.durable_pos, 0);
2157 assert!(
2158 r.degraded,
2159 "policy structurally unsatisfiable on this shape → degraded",
2160 );
2161 }
2162
2163 // --- 2 replicas connected ---
2164
2165 #[test]
2166 fn quorum_both_replicas_ahead_of_journal() {
2167 // Both replicas persisted past journal. `persisted>=2` returns
2168 // the 2nd-largest persisted across {primary, slot0, slot1}.
2169 let p = parse("persisted>=2").unwrap();
2170 let m = metrics((100, 100), (120, 120));
2171 let a = both_active();
2172 assert_eq!(
2173 evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
2174 100
2175 );
2176 }
2177
2178 #[test]
2179 fn quorum_journal_ahead_of_both_replicas() {
2180 // Journal at 500, replicas at 100/120. 2nd-largest persisted = 120.
2181 let p = parse("persisted>=2").unwrap();
2182 let m = metrics((100, 100), (120, 120));
2183 let a = both_active();
2184 assert_eq!(
2185 evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a)).durable_pos,
2186 120
2187 );
2188 }
2189
2190 #[test]
2191 fn quorum_journal_between_slow_and_fast_replica() {
2192 // {primary=150, slot0_persisted=50, slot1_persisted=200}.
2193 // 2nd-largest = 150 (primary itself).
2194 let p = parse("persisted>=2").unwrap();
2195 let m = metrics((50, 50), (200, 200));
2196 let a = both_active();
2197 assert_eq!(
2198 evaluate_durability(&p, WireSeq::new(150), Some(&m), Some(&a)).durable_pos,
2199 150
2200 );
2201 }
2202
2203 #[test]
2204 fn ram_quorum_gates_on_replica_memory_not_on_any_disk() {
2205 // `ram` (`in_memory>=2`): the journal position must not
2206 // bind. Journal at 0 — nothing persisted anywhere on the
2207 // primary — while the replicas hold 100/120 in memory. The
2208 // 2nd-largest in-memory across {primary=MAX, 100, 120} is 120:
2209 // the gate is exactly the fastest replica's RAM receipt.
2210 let p = AckPolicy::Ram.to_policy();
2211 let m = metrics((100, 0), (120, 0));
2212 let a = both_active();
2213 let r = evaluate_durability(&p, WireSeq::new(0), Some(&m), Some(&a));
2214 assert_eq!(r.durable_pos, 120);
2215 assert!(!r.degraded);
2216 }
2217
2218 #[test]
2219 fn ram_quorum_stalls_with_no_replica_connected() {
2220 // Fail-closed: with only the primary in the view, `in_memory>=2`
2221 // is structurally unsatisfiable however far the journal is.
2222 let p = AckPolicy::Ram.to_policy();
2223 let r = evaluate_durability(&p, WireSeq::new(500), None, None);
2224 assert_eq!(r.durable_pos, 0);
2225 assert!(r.degraded);
2226 }
2227
2228 // --- Single replica connected ---
2229
2230 #[test]
2231 fn single_replica_strict_persisted_two_requires_both_survivors() {
2232 // Slot 0 connected, slot 1 disconnected. View = {primary, slot0}.
2233 // Strict `persisted>=2`: 2nd-largest of the 2-row view =
2234 // min(primary, slot0). Strictly stronger than legacy auto-
2235 // degrade-to-1-node in the same shape.
2236 let p = parse("persisted>=2").unwrap();
2237 let m = metrics((100, 100), (999, 999)); // slot 1 cursors ignored
2238 let a = flags(true, false);
2239 assert_eq!(
2240 evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
2241 50
2242 );
2243 assert_eq!(
2244 evaluate_durability(&p, WireSeq::new(200), Some(&m), Some(&a)).durable_pos,
2245 100
2246 );
2247 }
2248
2249 #[test]
2250 fn single_replica_persisted_two_requires_both_survivors() {
2251 // 2-node view (primary + surviving replica). `persisted>=2` is
2252 // satisfiable; the gate opens at the slower of the two and the
2253 // policy is not degraded.
2254 let p = parse("persisted>=2").unwrap();
2255 let m = metrics((100, 100), (999, 999));
2256 let a = flags(true, false);
2257 let r = evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a));
2258 assert_eq!(r.durable_pos, 50);
2259 assert!(!r.degraded);
2260 }
2261
2262 #[test]
2263 fn both_replicas_disconnected_strict_stalls() {
2264 // View has only the primary. Strict `persisted>=2` cannot be
2265 // satisfied — operator opted out of degrade.
2266 let p = parse("persisted>=2").unwrap();
2267 let m = metrics((999, 999), (999, 999));
2268 let a = flags(false, false);
2269 assert_eq!(
2270 evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a)).durable_pos,
2271 0
2272 );
2273 }
2274
2275 #[test]
2276 fn both_replicas_disconnected_strict_stalls_and_flags_degraded() {
2277 // With `persisted>=2` and both replicas down, the cursor view
2278 // collapses to {primary}: the clause's count (=2) exceeds the
2279 // view size, so the gate stays at 0 and the policy flags
2280 // degraded. Note the readers' separate halt at
2281 // `replicas_connected==0` refuses new writes before they reach
2282 // the gate; this verifies the gate semantics in isolation.
2283 let p = parse("persisted>=2").unwrap();
2284 let m = metrics((999, 999), (999, 999));
2285 let a = flags(false, false);
2286 let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
2287 assert_eq!(r.durable_pos, 0);
2288 assert!(r.degraded);
2289 }
2290
2291 // --- Mixed-level policies ---
2292
2293 #[test]
2294 fn persisted_one_and_in_memory_two() {
2295 // "Leader persists, plus one other node has it in memory" —
2296 // the cheap-but-non-zero durability target. Slot 0 has it in
2297 // memory, slot 1 disconnected.
2298 let p = parse("persisted>=1 && in_memory>=2").unwrap();
2299 // primary persisted=50, slot0 in_mem=80 / persisted=20.
2300 // persisted>=1: max(50, 20, 0) = 50.
2301 // in_memory>=2: primary in_mem=u64::MAX (always), slot0_eff=max(80, 20)=80,
2302 // slot1=0. 2nd-largest = 80.
2303 // min(50, 80) = 50.
2304 let m = metrics((80, 20), (999, 999));
2305 let a = flags(true, false);
2306 assert_eq!(
2307 evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
2308 50
2309 );
2310 }
2311
2312 // --- Edge: journal at 0 ---
2313
2314 #[test]
2315 fn journal_at_zero_with_replicas_persisted_one() {
2316 // Journal hasn't fsynced anything; both replicas have. With
2317 // `persisted>=1` the gate opens at the fastest replica.
2318 let p = parse("persisted>=1").unwrap();
2319 let m = metrics((100, 100), (200, 200));
2320 let a = both_active();
2321 assert_eq!(
2322 evaluate_durability(&p, WireSeq::new(0), Some(&m), Some(&a)).durable_pos,
2323 200
2324 );
2325 }
2326
2327 // --- gate-blocker attribution ---
2328 //
2329 // The attribution must follow the policy actually in force. The
2330 // previous heuristic compared the journal cursor against the
2331 // minimum replica *persisted* cursor unconditionally, which
2332 // reported replication as the blocker under `disk` whenever a
2333 // replica lagged (a replica binds `persisted>=1` only when its fsync
2334 // leads) and read the wrong level under `disk+ram` (which gates
2335 // replicas on in-memory).
2336 //
2337 // Attribution comes out of `evaluate_gate` alongside the durable
2338 // position, computed from the same cursor snapshot, and is `None`
2339 // while the gate stays closed — so each test passes a `needed` at
2340 // or below the scenario's durable position to model the iteration
2341 // on which the gate opens.
2342
2343 #[test]
2344 fn disk_policy_credits_journal_when_replicas_lag() {
2345 // `persisted>=1` is satisfied by the highest persisted cursor
2346 // in the cluster — here the primary's. A connected replica lagging
2347 // far behind is irrelevant to the gate, so it must not be
2348 // credited as the blocker. This is the case the old heuristic
2349 // got flatly wrong: journal_pos (500) > repl_min (10) sent it
2350 // down the `else` branch every single time.
2351 let p = parse("persisted>=1").unwrap();
2352 let m = metrics((10, 10), (10, 10));
2353 let a = both_active();
2354 assert_eq!(
2355 evaluate_gate(&p, 500, WireSeq::new(500), Some(&m), Some(&a)).1,
2356 Some(Blocker::Journal)
2357 );
2358 }
2359
2360 #[test]
2361 fn disk_policy_credits_replication_when_a_replica_fsync_leads() {
2362 // The mirror: policies count copies, not nodes. With the
2363 // primary's disk stalled at 10 and a replica persisted through
2364 // 500, `persisted>=1` opens on the replica's copy — and the
2365 // attribution must say so, or an operator reading the gate
2366 // counters would conclude the primary's disk was keeping up.
2367 let p = parse("persisted>=1").unwrap();
2368 let m = metrics((500, 500), (10, 10));
2369 let a = both_active();
2370 assert_eq!(
2371 evaluate_gate(&p, 500, WireSeq::new(10), Some(&m), Some(&a)).1,
2372 Some(Blocker::Replication)
2373 );
2374 }
2375
2376 #[test]
2377 fn disk_and_ram_reads_replica_in_memory_not_persisted() {
2378 // `persisted>=1 && in_memory>=2`. The replica has the event in
2379 // memory (400) well ahead of its own fsync (100), and the
2380 // primary's journal is behind that in-memory cursor (300).
2381 // The binding clause is therefore the primary's persisted
2382 // cursor → journal. Comparing against the replica's *persisted*
2383 // cursor (100) would have said replication.
2384 let p = parse("persisted>=1 && in_memory>=2").unwrap();
2385 let m = metrics((400, 100), (0, 0));
2386 let a = flags(true, false);
2387 assert_eq!(
2388 evaluate_gate(&p, 300, WireSeq::new(300), Some(&m), Some(&a)).1,
2389 Some(Blocker::Journal)
2390 );
2391
2392 // Same policy, replica in-memory now the laggard → replication.
2393 // The gate opens at the replica's in-memory cursor (200).
2394 let m = metrics((200, 100), (0, 0));
2395 assert_eq!(
2396 evaluate_gate(&p, 200, WireSeq::new(300), Some(&m), Some(&a)).1,
2397 Some(Blocker::Replication)
2398 );
2399 }
2400
2401 #[test]
2402 fn disk_and_ram_is_satisfied_by_the_faster_replica() {
2403 // `in_memory>=2` needs the primary plus *one* replica, so the
2404 // best replica binds, not the worst. Replica 0 holds the event
2405 // in memory at 400 with its own fsync trailing at 250 (behind
2406 // the primary, as the physical ordering requires); replica 1
2407 // lags badly at 10. The gate is not held up by replication —
2408 // the primary's persisted cursor (300) is the binding term.
2409 // Taking the min across replicas would have blamed the slow
2410 // slot.
2411 let p = parse("persisted>=1 && in_memory>=2").unwrap();
2412 let m = metrics((400, 250), (10, 10));
2413 let a = both_active();
2414 assert_eq!(
2415 evaluate_gate(&p, 300, WireSeq::new(300), Some(&m), Some(&a)).1,
2416 Some(Blocker::Journal)
2417 );
2418 }
2419
2420 #[test]
2421 fn two_disks_uses_second_largest_persisted() {
2422 // `persisted>=2` is met by the primary plus the *best* replica's
2423 // persisted cursor. With the primary ahead at 900 and replicas
2424 // at 400 and 10, the clause resolves at 400 — the fast replica —
2425 // not at the minimum of 10.
2426 let p = parse("persisted>=2").unwrap();
2427 let m = metrics((400, 400), (10, 10));
2428 let a = both_active();
2429 assert_eq!(
2430 evaluate_durability(&p, WireSeq::new(900), Some(&m), Some(&a)).durable_pos,
2431 400,
2432 "clause takes the second-largest persisted cursor, not the minimum"
2433 );
2434 // Replication binds, which is the norm for this policy: the
2435 // primary persists before it ships, so it is normally ahead of
2436 // every replica.
2437 assert_eq!(
2438 evaluate_gate(&p, 400, WireSeq::new(900), Some(&m), Some(&a)).1,
2439 Some(Blocker::Replication)
2440 );
2441 }
2442
2443 #[test]
2444 fn standalone_credits_the_journal() {
2445 // No replication wired: the primary is the only node, so the
2446 // journal is the only thing the gate can be waiting on.
2447 let p = parse("persisted>=1").unwrap();
2448 assert_eq!(
2449 evaluate_gate(&p, 500, WireSeq::new(500), None, None).1,
2450 Some(Blocker::Journal)
2451 );
2452 }
2453
2454 #[test]
2455 fn unsatisfiable_shape_never_opens_so_never_attributes() {
2456 // `persisted>=2` with no replica connected: the shape pins
2457 // `durable_pos` to 0, so the gate cannot open and no blocker is
2458 // ever produced — the stall is a missing node, not either
2459 // subsystem's progress. `policy_degraded` is the metric for it.
2460 let p = parse("persisted>=2").unwrap();
2461 let (status, blocker) = evaluate_gate(&p, 1, WireSeq::new(500), None, None);
2462 assert!(status.degraded);
2463 assert_eq!(status.durable_pos, 0);
2464 assert_eq!(blocker, None);
2465 }
2466
2467 #[test]
2468 fn closed_gate_yields_no_attribution() {
2469 // The policy is satisfiable and healthy, but the batch needs a
2470 // sequence the cursors haven't reached — the gate stays closed
2471 // and `evaluate_gate` must not spend a ranking pass (nor name a
2472 // blocker) on an iteration that keeps spinning.
2473 let p = parse("persisted>=1").unwrap();
2474 let (status, blocker) = evaluate_gate(&p, 501, WireSeq::new(500), None, None);
2475 assert!(!status.degraded);
2476 assert_eq!(status.durable_pos, 500);
2477 assert_eq!(blocker, None);
2478 }
2479
2480 #[test]
2481 fn attribution_skips_disconnected_slots() {
2482 // Slot 1 is disconnected, so its (very advanced) cursors must
2483 // not satisfy `in_memory>=2`; only slot 0 counts, and it lags.
2484 // The gate opens at slot 0's in-memory cursor (100).
2485 let p = parse("persisted>=1 && in_memory>=2").unwrap();
2486 let m = metrics((100, 100), (999, 999));
2487 let a = flags(true, false);
2488 assert_eq!(
2489 evaluate_gate(&p, 100, WireSeq::new(500), Some(&m), Some(&a)).1,
2490 Some(Blocker::Replication)
2491 );
2492 }
2493
2494 /// Fresh-cluster catch-up: a replica that handshakes at sequence
2495 /// 0 (the legitimate genesis case, not a stale-flag race) must be
2496 /// included in the cursor view with its zero cursors so the policy
2497 /// behaves the same way it would for a 1-replica deployment that
2498 /// has just produced its first batch. The disconnect-race
2499 /// mitigations (B1 seed-on-connect + B2 reorder) keep this from
2500 /// being conflated with the stale-flag-paired-with-zero-cursor
2501 /// case under normal cluster lifecycles.
2502 #[test]
2503 fn fresh_cluster_zero_cursors_included_in_view() {
2504 let p = parse("persisted>=2").unwrap();
2505 // Both replicas just handshook at seq 0, primary also at 0
2506 // (fresh cluster, no events yet). View = 3 nodes; the clause's
2507 // count (=2) is met by the view size, so the policy is not
2508 // degraded and the gate sits at the 2nd-largest persisted = 0.
2509 let m = metrics((0, 0), (0, 0));
2510 let a = both_active();
2511 let r = evaluate_durability(&p, WireSeq::new(0), Some(&m), Some(&a));
2512 assert_eq!(r.durable_pos, 0);
2513 assert!(
2514 !r.degraded,
2515 "all 3 nodes present, view meets clause target — should not flag degraded"
2516 );
2517 }
2518
2519 // -- Race-window regression tests --
2520 //
2521 // The replication senders fix two memory-ordering issues at the
2522 // active-flag transition points:
2523 //
2524 // B1 (`a84540a`): seed `metrics.{acked,in_memory}_sequence[i]`
2525 // to `handshake.last_sequence` BEFORE setting active_flag=true
2526 // on reconnect. Without this, the gate would observe (active=
2527 // true, cursor=0) for ~1 RTT after a replica catch-up completed,
2528 // pinning any multi-node clause — and thus the gate — to 0.
2529 //
2530 // B2 (`8888732`): zero `metrics.{acked,in_memory}_sequence[i]`
2531 // BEFORE setting active_flag=false on disconnect. Without this,
2532 // a weak-memory reader could observe (active=true, cursor=0)
2533 // for one iteration during the disconnect window.
2534 //
2535 // Both fixes are in the senders, but the gate's *behaviour* under
2536 // the race-window inputs is tested here. The intent is to lock in
2537 // the invariant: even under a hypothetical (active=true,cursor=0)
2538 // observation, the gate must not produce a spuriously-open answer
2539 // that would cause a client to be told "your event is durable"
2540 // when it isn't. Stalling-briefly is safe; opening-spuriously is
2541 // not.
2542
2543 #[test]
2544 fn race_b1_post_seed_gate_doesnt_freeze_on_reconnect() {
2545 // Post-B1-fix state: replica reconnected, cursors seeded to
2546 // `handshake.last_sequence` (480) before active flipped to
2547 // true. Primary kept moving and is at 500. The gate's view
2548 // is now [primary=500, slot=480]; the durable position dips
2549 // from 500 (primary alone, degraded) to 480 (both nodes).
2550 //
2551 // The dip is correct, not a bug: once a 2nd node is
2552 // connected, durability is bounded by the slower of the two.
2553 // Events 481-500 were already served as durable on primary
2554 // alone — they aren't unsent. New responses for seq>500 wait
2555 // until slot acks; we just don't freeze at 0.
2556 let p = parse("persisted>=2").unwrap();
2557 let m = metrics((480, 480), (999, 999));
2558 let a = flags(true, false);
2559 let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
2560 assert_eq!(
2561 r.durable_pos, 480,
2562 "post-seed reconnect should produce a coherent gate position equal to the slower node, not freeze at 0"
2563 );
2564 }
2565
2566 #[test]
2567 fn race_b1_pre_seed_freeze_is_what_the_fix_avoids() {
2568 // Pre-B1-fix state: cursors at 0, active=true. The gate sees
2569 // [primary=500, slot=[0,0]] and 2nd-largest persisted = 0.
2570 // The gate WOULD freeze at 0. This test documents the bug
2571 // the seeding fix is designed to avoid; the senders ensure
2572 // this state is never observed in production.
2573 let p = parse("persisted>=2").unwrap();
2574 let m = metrics((0, 0), (999, 999));
2575 let a = flags(true, false);
2576 let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
2577 assert_eq!(
2578 r.durable_pos, 0,
2579 "the gate behaviour under (active=true, cursor=0) — if the senders ever fail to seed before flipping active, this is the freeze the operator would see"
2580 );
2581 }
2582
2583 #[test]
2584 fn race_b2_disconnect_window_doesnt_open_gate_spuriously() {
2585 // Simulates the B2 race window: a weak-memory reader observes
2586 // (active=true, cursor=0) for one iteration during the
2587 // disconnect transition. The slot legitimately has cursor=0
2588 // because the disconnect handler just zeroed the metrics.
2589 //
2590 // Critical invariant: the gate must NOT produce a higher
2591 // durable_pos than it would with the slot correctly excluded.
2592 // Specifically: with primary at 500, slot stale-zero-included,
2593 // the gate must not "see" the primary alone and open at 500
2594 // — that would let a client be told a seq is durable when
2595 // only the primary has it under a `persisted>=2` policy that
2596 // demands 2 nodes.
2597 let p = parse("persisted>=2").unwrap();
2598 let m = metrics((0, 0), (999, 999));
2599 let a = flags(true, false);
2600 let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
2601 // 2nd-largest persisted across {primary=500, slot=0} = 0.
2602 // Gate stalls. ✓
2603 assert_eq!(r.durable_pos, 0);
2604
2605 // Post-disconnect (active=false): view shrinks to {primary}.
2606 // `persisted>=2` is structurally unsatisfiable on a 1-node
2607 // view, so the gate stays at 0 AND surfaces degraded. The
2608 // readers' `replicas_connected==0` halt is what stops
2609 // accepting new writes; the gate side's job is just to keep
2610 // the existing in-flight writes stalled and the alert lit.
2611 let a_disconnected = flags(false, false);
2612 let r_after = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a_disconnected));
2613 assert_eq!(r_after.durable_pos, 0);
2614 assert!(
2615 r_after.degraded,
2616 "post-disconnect view of size 1 cannot meet persisted>=2 → degraded"
2617 );
2618 }
2619
2620 #[test]
2621 fn race_invariant_zero_cursor_never_opens_gate_above_slower_node() {
2622 // Property under both B1 and B2 race windows: for any slot
2623 // observed at cursor=0 with active=true, the gate cannot
2624 // produce a durable_pos that exceeds what an honest 2-node
2625 // evaluation would give. Spot-check a handful of primary
2626 // positions to lock the invariant.
2627 let p = parse("persisted>=2").unwrap();
2628 let m = metrics((0, 0), (999, 999));
2629 let a = flags(true, false);
2630 for primary_pos in [0, 1, 100, 500, 1_000_000_000_u64] {
2631 let r = evaluate_durability(&p, WireSeq::new(primary_pos), Some(&m), Some(&a));
2632 // 2nd-largest of {primary_pos, 0} = 0 for any primary > 0.
2633 // For primary_pos = 0, also 0. So always 0.
2634 assert_eq!(
2635 r.durable_pos, 0,
2636 "race-window observation must not open the gate above 0 for any primary position (got {} for primary_pos={primary_pos})",
2637 r.durable_pos
2638 );
2639 }
2640 }
2641
2642 // ------------------------------------------------------------------
2643 // GateCrossTracker — per-cursor "first transition from below to
2644 // crossed" inside the gate loop, used by the journal-wait /
2645 // replica-wait histograms.
2646 // ------------------------------------------------------------------
2647
2648 #[cfg(feature = "tick-to-trade")]
2649 #[test]
2650 fn gate_cross_tracker_records_journal_when_strictly_below() {
2651 // Journal starts at 5 (< 10), repl_min already at 100.
2652 // Journal crosses on the second observation. Replica was already
2653 // past at entry, so no replica sample.
2654 let mut t = GateCrossTracker::new(10);
2655 t.observe(5, Some(100), 1_000);
2656 t.observe(15, Some(100), 2_000);
2657 assert_eq!(t.journal_crossed(), Some(2_000));
2658 assert_eq!(t.replica_crossed(), None);
2659 }
2660
2661 #[cfg(feature = "tick-to-trade")]
2662 #[test]
2663 fn gate_cross_tracker_records_replica_when_strictly_below() {
2664 // Mirror image: journal already past, replica below at entry.
2665 let mut t = GateCrossTracker::new(10);
2666 t.observe(50, Some(5), 1_000);
2667 t.observe(50, Some(12), 2_000);
2668 assert_eq!(t.journal_crossed(), None);
2669 assert_eq!(t.replica_crossed(), Some(2_000));
2670 }
2671
2672 #[cfg(feature = "tick-to-trade")]
2673 #[test]
2674 fn gate_cross_tracker_records_both_when_both_below() {
2675 // Both below at entry, both cross independently.
2676 let mut t = GateCrossTracker::new(100);
2677 t.observe(50, Some(60), 1_000); // both below
2678 t.observe(105, Some(60), 2_000); // journal crosses
2679 t.observe(105, Some(110), 3_000); // replica crosses
2680 assert_eq!(t.journal_crossed(), Some(2_000));
2681 assert_eq!(t.replica_crossed(), Some(3_000));
2682 }
2683
2684 #[cfg(feature = "tick-to-trade")]
2685 #[test]
2686 fn gate_cross_tracker_skips_cursor_already_past_at_entry() {
2687 // Both cursors already >= needed at first observation —
2688 // neither was on the critical path. No samples.
2689 let mut t = GateCrossTracker::new(10);
2690 t.observe(50, Some(100), 1_000);
2691 // Even later observations don't backfill: was_below is sticky.
2692 t.observe(60, Some(110), 2_000);
2693 assert_eq!(t.journal_crossed(), None);
2694 assert_eq!(t.replica_crossed(), None);
2695 }
2696
2697 #[cfg(feature = "tick-to-trade")]
2698 #[test]
2699 fn gate_cross_tracker_first_observation_only_for_cross_decision() {
2700 // A cursor that goes back below `needed` after first iteration
2701 // (impossible in practice — cursors are monotonic — but we
2702 // verify the first-iteration snapshot is what gates the
2703 // sample). Journal: 50 < 10 false → was_below=false → no sample.
2704 let mut t = GateCrossTracker::new(10);
2705 t.observe(50, Some(5), 1_000); // journal already past, replica below
2706 t.observe(20, Some(12), 2_000); // both >= needed now
2707 // Journal: was_below=false at entry → still no sample.
2708 assert_eq!(t.journal_crossed(), None);
2709 // Replica: was_below=true at entry, crosses on iter 2 → sample.
2710 assert_eq!(t.replica_crossed(), Some(2_000));
2711 }
2712
2713 #[cfg(feature = "tick-to-trade")]
2714 #[test]
2715 fn gate_cross_tracker_holds_first_cross_only() {
2716 // Once a cross is recorded, later observations don't
2717 // overwrite — the metric is "when did it first cross", not
2718 // "when was it last below".
2719 let mut t = GateCrossTracker::new(10);
2720 t.observe(5, Some(100), 1_000);
2721 t.observe(15, Some(100), 2_000); // first cross
2722 t.observe(25, Some(100), 3_000); // would otherwise re-record
2723 assert_eq!(t.journal_crossed(), Some(2_000));
2724 }
2725
2726 #[cfg(feature = "tick-to-trade")]
2727 #[test]
2728 fn gate_cross_tracker_ignores_replica_dropping_out_mid_wait() {
2729 // The regression this signature exists for. The replica is
2730 // behind at entry (was_below latches true), then disconnects
2731 // part-way through the wait so no replica supplies a binding
2732 // cursor. That must not be read as "caught up" — the histogram
2733 // would otherwise report a wait that ended at the disconnect.
2734 let mut t = GateCrossTracker::new(100);
2735 t.observe(50, Some(60), 1_000); // replica behind
2736 t.observe(105, None, 2_000); // replica drops out mid-wait
2737 t.observe(105, None, 3_000); // still gone
2738 assert_eq!(t.journal_crossed(), Some(2_000));
2739 assert_eq!(t.replica_crossed(), None);
2740 // Reconnecting past `needed` still records the real crossing.
2741 t.observe(105, Some(150), 4_000);
2742 assert_eq!(t.replica_crossed(), Some(4_000));
2743 }
2744
2745 #[cfg(feature = "tick-to-trade")]
2746 #[test]
2747 fn gate_cross_tracker_records_nothing_when_no_replica_clause() {
2748 // `local` never binds on a replica, so `policy_replica_cursor`
2749 // returns `None` for the whole wait: was_below stays false and
2750 // no replica sample is produced.
2751 let mut t = GateCrossTracker::new(100);
2752 t.observe(50, None, 1_000);
2753 t.observe(105, None, 2_000);
2754 assert_eq!(t.journal_crossed(), Some(2_000));
2755 assert_eq!(t.replica_crossed(), None);
2756 }
2757
2758 // -- DegradationLogger flap-suppression --
2759 //
2760 // The logger gates transition logs on a sustained-state hold so a
2761 // replica flapping at sub-second cadence doesn't spam the journal.
2762 // These tests don't observe the logs themselves (tracing is
2763 // process-global and brittle to capture in unit tests); they
2764 // assert the underlying state machine via the `policy_degraded`
2765 // gauge, which the logger updates on every tick regardless of
2766 // log emission.
2767
2768 fn logger_test_policy() -> crate::ack_policy::Policy {
2769 parse("persisted>=2").unwrap()
2770 }
2771
2772 /// Tick the logger N times at `step` intervals, alternating
2773 /// `degraded` per call. Returns the gauge value after the last
2774 /// tick — useful for asserting that flap cycles don't leak the
2775 /// AtomicBool into a wrong terminal state.
2776 fn drive_logger(
2777 logger: &mut DegradationLogger,
2778 utilization: &StageUtilization,
2779 policy: &crate::ack_policy::Policy,
2780 start: Instant,
2781 states: &[bool],
2782 step: Duration,
2783 ) -> bool {
2784 for (i, &state) in states.iter().enumerate() {
2785 let now = start + step.checked_mul(i as u32).unwrap_or(Duration::ZERO);
2786 logger.tick(policy, utilization, state, now, Duration::from_secs(5));
2787 }
2788 utilization.policy_degraded.load(Ordering::Relaxed)
2789 }
2790
2791 #[test]
2792 fn logger_gauge_tracks_state_immediately() {
2793 // The /healthz gauge reflects the *latest* state on every
2794 // tick — this is what dashboards / alerts read. Sustained-
2795 // state gating only affects the warn/info log emission.
2796 let p = logger_test_policy();
2797 let utilization = StageUtilization::new();
2798 let now = Instant::now();
2799 let mut logger = DegradationLogger::new(now);
2800
2801 logger.tick(&p, &utilization, true, now, Duration::from_secs(5));
2802 assert!(utilization.policy_degraded.load(Ordering::Relaxed));
2803
2804 logger.tick(
2805 &p,
2806 &utilization,
2807 false,
2808 now + Duration::from_millis(50),
2809 Duration::from_secs(5),
2810 );
2811 assert!(!utilization.policy_degraded.load(Ordering::Relaxed));
2812 }
2813
2814 #[test]
2815 fn logger_starting_degraded_marks_initial_state_logged() {
2816 // `new_starting_degraded` emits the startup warn and treats
2817 // the state as already-logged so the next tick at the same
2818 // cluster shape doesn't re-emit instantly. The gauge starts
2819 // at 1.
2820 let p = logger_test_policy();
2821 let utilization = StageUtilization::new();
2822 let now = Instant::now();
2823 let mut logger = DegradationLogger::new_starting_degraded(now, &p);
2824 // The logger doesn't write the gauge from the constructor —
2825 // first tick does. Tick at the same state to settle the
2826 // gauge. No new log line should fire (state hasn't changed).
2827 logger.tick(
2828 &p,
2829 &utilization,
2830 true,
2831 now + Duration::from_millis(10),
2832 Duration::from_secs(5),
2833 );
2834 assert!(utilization.policy_degraded.load(Ordering::Relaxed));
2835 }
2836
2837 #[test]
2838 fn logger_accumulates_degraded_seconds_only_while_degraded() {
2839 // The `policy_degraded_nanos` counter must advance by exactly
2840 // the wall-clock time spent in the degraded state and stay flat
2841 // while healthy. Each tick attributes the interval since the
2842 // previous tick to the state observed at that previous tick.
2843 let p = logger_test_policy();
2844 let utilization = StageUtilization::new();
2845 let start = Instant::now();
2846 let mut logger = DegradationLogger::new(start);
2847 let sec = Duration::from_secs(1);
2848
2849 // t0: healthy -> degraded. The zero-length interval before the
2850 // transition is attributed to the healthy start: no accrual.
2851 logger.tick(&p, &utilization, true, start, Duration::from_secs(5));
2852 assert_eq!(utilization.policy_degraded_nanos.load(Ordering::Relaxed), 0);
2853
2854 // t0..t1 spent degraded -> +1s.
2855 logger.tick(&p, &utilization, true, start + sec, Duration::from_secs(5));
2856 // t1..t2 still degraded, then flips healthy at the tick -> +1s.
2857 logger.tick(
2858 &p,
2859 &utilization,
2860 false,
2861 start + 2 * sec,
2862 Duration::from_secs(5),
2863 );
2864 assert_eq!(
2865 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2866 2 * sec.as_nanos() as u64
2867 );
2868
2869 // t2..t3 spent healthy -> counter holds flat.
2870 logger.tick(
2871 &p,
2872 &utilization,
2873 false,
2874 start + 3 * sec,
2875 Duration::from_secs(5),
2876 );
2877 assert_eq!(
2878 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2879 2 * sec.as_nanos() as u64
2880 );
2881 }
2882
2883 #[test]
2884 fn logger_starting_degraded_accrues_from_construction() {
2885 // A primary that boots already-degraded (e.g. `disk+ram` with no
2886 // replica yet) must accrue from construction, not from the first
2887 // observed transition — `new_starting_degraded` seeds the
2888 // degraded state so the first tick's interval counts.
2889 let p = logger_test_policy();
2890 let utilization = StageUtilization::new();
2891 let start = Instant::now();
2892 let mut logger = DegradationLogger::new_starting_degraded(start, &p);
2893
2894 logger.tick(
2895 &p,
2896 &utilization,
2897 true,
2898 start + Duration::from_secs(1),
2899 Duration::from_secs(5),
2900 );
2901 assert_eq!(
2902 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2903 Duration::from_secs(1).as_nanos() as u64
2904 );
2905 }
2906
2907 #[test]
2908 fn logger_reseed_flushes_in_flight_degraded_accrual() {
2909 // A runtime policy swap re-seeds the logger. On the gate-wait path
2910 // the swap can land after many seconds of wedged-degraded time
2911 // with no intervening tick, so `reseed` must flush that interval
2912 // before resetting — otherwise the whole wedge is silently lost,
2913 // which is exactly the incident the metric exists to measure.
2914 let p = logger_test_policy();
2915 let utilization = StageUtilization::new();
2916 let start = Instant::now();
2917 let sec = Duration::from_secs(1);
2918
2919 let mut logger = DegradationLogger::new_starting_degraded(start, &p);
2920 logger.tick(&p, &utilization, true, start, Duration::from_secs(5));
2921 assert_eq!(utilization.policy_degraded_nanos.load(Ordering::Relaxed), 0);
2922
2923 // 30s wedged-degraded with no tick (frozen spin), then swap.
2924 logger.reseed(&utilization, start + 30 * sec);
2925 assert_eq!(
2926 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2927 30 * sec.as_nanos() as u64
2928 );
2929
2930 // Post-reseed the logger is healthy-start; a healthy interval
2931 // does not accrue, and `last_tick` was rebased to the swap so
2932 // the next interval isn't double-counted.
2933 logger.tick(
2934 &p,
2935 &utilization,
2936 false,
2937 start + 31 * sec,
2938 Duration::from_secs(5),
2939 );
2940 assert_eq!(
2941 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2942 30 * sec.as_nanos() as u64
2943 );
2944 }
2945
2946 #[test]
2947 fn logger_starting_degraded_then_first_tick_healthy_counts_construction_interval() {
2948 // `new_starting_degraded` seeds the degraded state, so the
2949 // construction→first-tick interval is attributed degraded even
2950 // when the first observed state is already healthy (the cluster
2951 // recovered before the first tick). Locks this intentional edge.
2952 let p = logger_test_policy();
2953 let utilization = StageUtilization::new();
2954 let start = Instant::now();
2955 let mut logger = DegradationLogger::new_starting_degraded(start, &p);
2956
2957 logger.tick(
2958 &p,
2959 &utilization,
2960 false,
2961 start + Duration::from_secs(2),
2962 Duration::from_secs(5),
2963 );
2964 assert_eq!(
2965 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2966 Duration::from_secs(2).as_nanos() as u64
2967 );
2968 }
2969
2970 #[test]
2971 fn logger_counter_matches_total_degraded_time_across_flaps() {
2972 // The cumulative counter must equal exactly the wall time spent
2973 // in degraded states across a flap sequence — the guarantee
2974 // `rate(...degraded_seconds_total)` dashboards depend on.
2975 let p = logger_test_policy();
2976 let utilization = StageUtilization::new();
2977 let start = Instant::now();
2978 let step = Duration::from_millis(500);
2979 let mut logger = DegradationLogger::new(start);
2980
2981 // State observed at tick i (fired at start + i*step). The state
2982 // set at tick i holds over [tick i, tick i+1], so degraded wall
2983 // time = the spans where the *prior* tick's state was true:
2984 // [t1,t2], [t2,t3], [t4,t5] = 3 * step.
2985 let states = [false, true, true, false, true, false];
2986 for (i, &s) in states.iter().enumerate() {
2987 logger.tick(
2988 &p,
2989 &utilization,
2990 s,
2991 start + step * i as u32,
2992 Duration::from_secs(5),
2993 );
2994 }
2995
2996 assert_eq!(
2997 utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2998 (3 * step).as_nanos() as u64
2999 );
3000 }
3001
3002 #[test]
3003 fn logger_handles_rapid_flap_without_panic() {
3004 // Drive the logger through 100 alternating flips at 100ms
3005 // each (faster than the 1s flap-hold). The state machine
3006 // must remain coherent — no panics, gauge tracks final
3007 // state, and `pending_logged` doesn't get stuck.
3008 let p = logger_test_policy();
3009 let utilization = StageUtilization::new();
3010 let now = Instant::now();
3011 let mut logger = DegradationLogger::new(now);
3012 let states: Vec<bool> = (0..100u32).map(|i| i.is_multiple_of(2)).collect();
3013 let final_state = drive_logger(
3014 &mut logger,
3015 &utilization,
3016 &p,
3017 now,
3018 &states,
3019 Duration::from_millis(100),
3020 );
3021 // 100 states starting at i=0 → final state is i=99 → odd → false.
3022 assert!(!final_state);
3023 }
3024
3025 #[test]
3026 fn logger_sustained_degraded_eventually_settles() {
3027 // After a sustained-true state, the logger should be in the
3028 // "logged the onset" mode. Drive 5 ticks of degraded=true at
3029 // 500ms intervals — total 2s, well past the 1s flap-hold.
3030 // Last tick should leave gauge=1 and the heartbeat re-emit
3031 // window primed (last_log set).
3032 let p = logger_test_policy();
3033 let utilization = StageUtilization::new();
3034 let now = Instant::now();
3035 let mut logger = DegradationLogger::new(now);
3036 let final_state = drive_logger(
3037 &mut logger,
3038 &utilization,
3039 &p,
3040 now,
3041 &[true; 5],
3042 Duration::from_millis(500),
3043 );
3044 assert!(final_state);
3045 }
3046
3047 #[test]
3048 fn logger_recovery_to_healthy_settles_gauge() {
3049 // Sustained degraded → sustained healthy. Gauge should end at 0.
3050 let p = logger_test_policy();
3051 let utilization = StageUtilization::new();
3052 let now = Instant::now();
3053 let mut logger = DegradationLogger::new_starting_degraded(now, &p);
3054 let mut states = vec![true; 5]; // 2.5s degraded
3055 states.extend(vec![false; 5]); // 2.5s healthy
3056 let final_state = drive_logger(
3057 &mut logger,
3058 &utilization,
3059 &p,
3060 now,
3061 &states,
3062 Duration::from_millis(500),
3063 );
3064 assert!(!final_state);
3065 }
3066
3067 /// Dirty tracking: an entry flag for dedup plus a flat list for
3068 /// iteration, replacing the per-append `HashSet` insert.
3069 mod dirty_tracking {
3070 use super::super::{mark_dirty, unmark_dirty};
3071 use super::flush_sends::entry_for;
3072 use std::os::unix::net::UnixStream;
3073
3074 fn entry() -> super::super::ConnectionEntry {
3075 let (tx, _rx) = UnixStream::pair().expect("socketpair");
3076 let mut e = entry_for(tx, b"payload");
3077 e.dirty = false;
3078 e
3079 }
3080
3081 #[test]
3082 fn repeat_appends_enqueue_a_connection_once() {
3083 let mut e = entry();
3084 let mut dirty = Vec::new();
3085 for _ in 0..8 {
3086 mark_dirty(&mut e, 42, &mut dirty);
3087 }
3088 assert_eq!(dirty, vec![42], "the flag is the dedup");
3089 assert!(e.dirty);
3090 }
3091
3092 #[test]
3093 fn teardown_takes_a_connection_off_the_list() {
3094 let mut a = entry();
3095 let mut b = entry();
3096 let mut dirty = Vec::new();
3097 mark_dirty(&mut a, 1, &mut dirty);
3098 mark_dirty(&mut b, 2, &mut dirty);
3099 unmark_dirty(1, &mut dirty);
3100 assert_eq!(dirty, vec![2], "order of the survivors is preserved");
3101 }
3102 }
3103
3104 /// One append per slot: the encoded payload plus the request's
3105 /// pre-encoded `BatchEnd` terminator, sharing a single cap check and
3106 /// a single dirty marking.
3107 mod append_frames {
3108 use super::super::{AppendOutcome, ConnectionEntry, MAX_SEND_BUF, append_frames};
3109 use super::flush_sends::entry_for;
3110 use std::os::unix::net::UnixStream;
3111 use std::time::Instant;
3112
3113 const TRAILER: &[u8] = &[0xEE, 0xEE];
3114
3115 fn entry(prefill: usize) -> ConnectionEntry {
3116 let (tx, _rx) = UnixStream::pair().expect("socketpair");
3117 let mut e = entry_for(tx, &vec![0u8; prefill]);
3118 e.dirty = false;
3119 e
3120 }
3121
3122 #[test]
3123 fn payload_and_terminator_land_in_one_append() {
3124 let mut e = entry(0);
3125 let mut dirty = Vec::new();
3126 let mut to_remove = Vec::new();
3127 let encoded = [1u8, 2, 3, 4, 0xFF];
3128
3129 let outcome = append_frames(
3130 Some(Ok(4)),
3131 TRAILER,
3132 7,
3133 &mut e,
3134 &encoded,
3135 Instant::now(),
3136 &mut dirty,
3137 &mut to_remove,
3138 );
3139
3140 assert!(matches!(outcome, AppendOutcome::Continue));
3141 assert_eq!(
3142 e.send_buf,
3143 vec![1, 2, 3, 4, 0xEE, 0xEE],
3144 "payload then terminator, nothing past the encoder's length"
3145 );
3146 assert_eq!(dirty, vec![7], "one dirty marking for the pair");
3147 assert!(to_remove.is_empty());
3148 }
3149
3150 #[test]
3151 fn a_slot_with_no_bytes_does_not_dirty_the_connection() {
3152 // `OutputPayload::BatchEnd` mid-request: no payload, no
3153 // terminator. Marking it dirty would queue an empty send.
3154 let mut e = entry(0);
3155 let mut dirty = Vec::new();
3156 let mut to_remove = Vec::new();
3157
3158 let outcome = append_frames(
3159 None,
3160 &[],
3161 7,
3162 &mut e,
3163 &[],
3164 Instant::now(),
3165 &mut dirty,
3166 &mut to_remove,
3167 );
3168
3169 assert!(matches!(outcome, AppendOutcome::Continue));
3170 assert!(e.send_buf.is_empty());
3171 assert!(dirty.is_empty());
3172 assert!(!e.dirty);
3173 }
3174
3175 #[test]
3176 fn the_cap_is_checked_against_both_frames_together() {
3177 // Payload alone fits; payload + terminator does not. The
3178 // connection must be dropped *before* the payload lands —
3179 // never delivered without its terminator.
3180 let mut e = entry(MAX_SEND_BUF - 5);
3181 let mut dirty = Vec::new();
3182 let mut to_remove = Vec::new();
3183 let encoded = [1u8, 2, 3, 4];
3184
3185 let outcome = append_frames(
3186 Some(Ok(4)),
3187 TRAILER,
3188 7,
3189 &mut e,
3190 &encoded,
3191 Instant::now(),
3192 &mut dirty,
3193 &mut to_remove,
3194 );
3195
3196 assert!(matches!(outcome, AppendOutcome::ConnectionDropped));
3197 assert_eq!(to_remove, vec![7]);
3198 assert_eq!(e.send_buf.len(), MAX_SEND_BUF - 5, "no partial append");
3199 assert!(dirty.is_empty(), "a dropped connection is not queued");
3200 }
3201
3202 #[test]
3203 fn an_encode_failure_still_terminates_the_request() {
3204 // The payload is this server's bug; the client still needs
3205 // the terminator or it waits forever for the batch to end.
3206 let mut e = entry(0);
3207 let mut dirty = Vec::new();
3208 let mut to_remove = Vec::new();
3209
3210 let outcome = append_frames(
3211 Some(Err("encode error")),
3212 TRAILER,
3213 7,
3214 &mut e,
3215 &[],
3216 Instant::now(),
3217 &mut dirty,
3218 &mut to_remove,
3219 );
3220
3221 assert!(matches!(outcome, AppendOutcome::Continue));
3222 assert_eq!(e.send_buf, TRAILER);
3223 assert_eq!(dirty, vec![7]);
3224 }
3225 }
3226
3227 /// The consumed path's two flush triggers. The byte threshold bounds
3228 /// a connection's buffered *bytes*; the slot interval bounds their
3229 /// *age*, which is what many-low-rate-client deployments need (2026-08
3230 /// network audit, finding 3).
3231 mod flush_cadence {
3232 use super::super::{FLUSH_BYTES_THRESHOLD, FLUSH_SLOT_INTERVAL, FlushCadence};
3233
3234 #[test]
3235 fn byte_threshold_fires_on_a_single_fat_connection() {
3236 let mut c = FlushCadence::default();
3237 c.on_append(FLUSH_BYTES_THRESHOLD - 1);
3238 assert!(!c.is_due());
3239 c.on_append(FLUSH_BYTES_THRESHOLD);
3240 assert!(c.is_due());
3241 }
3242
3243 #[test]
3244 fn slot_interval_bounds_the_age_of_tiny_buffers() {
3245 // Every connection stays far below an MSS — the byte
3246 // trigger never fires, so before the age bound these
3247 // responses sat in `send_buf` until the ring went idle.
3248 let mut c = FlushCadence::default();
3249 for _ in 0..FLUSH_SLOT_INTERVAL - 1 {
3250 c.on_append(40);
3251 assert!(!c.is_due());
3252 }
3253 c.on_append(40);
3254 assert!(
3255 c.is_due(),
3256 "age bound must fire on the {FLUSH_SLOT_INTERVAL}th slot"
3257 );
3258 }
3259
3260 #[test]
3261 fn flushing_restarts_both_triggers() {
3262 let mut c = FlushCadence::default();
3263 for _ in 0..FLUSH_SLOT_INTERVAL {
3264 c.on_append(FLUSH_BYTES_THRESHOLD);
3265 }
3266 assert!(c.is_due());
3267 c.on_flush();
3268 assert!(
3269 !c.is_due(),
3270 "a flush restarts the byte flag and the counter"
3271 );
3272 // And the age bound counts from the flush, not from start.
3273 for _ in 0..FLUSH_SLOT_INTERVAL - 1 {
3274 c.on_append(1);
3275 }
3276 assert!(!c.is_due());
3277 c.on_append(1);
3278 assert!(c.is_due());
3279 }
3280 }
3281
3282 /// Regression tests for the slow-client head-of-line block fixed in
3283 /// the 2026-08 io_uring audit (docs/internal/io-uring-audit-2026-08.md,
3284 /// finding 1): `flush_sends` used to `submit_and_wait` on SENDs
3285 /// without `MSG_DONTWAIT`, and io_uring holds such a SEND's CQE back
3286 /// until the peer reads — so one zero-window client stalled every
3287 /// client's acks. These use real sockets and a real ring: the defect
3288 /// was kernel-level behaviour a mock would not reproduce.
3289 mod heartbeat {
3290 use super::super::{MAX_SEND_BUF, heartbeat_due};
3291 use super::flush_sends::entry_for;
3292 use std::os::unix::net::UnixStream;
3293 use std::time::{Duration, Instant};
3294
3295 const INTERVAL: Duration = Duration::from_secs(1);
3296 const FRAME_LEN: usize = 13;
3297
3298 /// Backdate `last_send` a full interval so only the receive-
3299 /// ability guards decide. `checked_sub` because a young
3300 /// monotonic clock can't be backdated (same pattern as the
3301 /// flush_sends tests).
3302 fn idle_entry(payload: &[u8]) -> Option<super::super::ConnectionEntry> {
3303 let (tx, _rx) = UnixStream::pair().unwrap();
3304 let mut entry = entry_for(tx, payload);
3305 entry.last_send = Instant::now().checked_sub(INTERVAL * 2)?;
3306 Some(entry)
3307 }
3308
3309 #[test]
3310 fn idle_unblocked_connection_gets_a_heartbeat() {
3311 let Some(entry) = idle_entry(&[]) else {
3312 eprintln!("monotonic clock too young to backdate; skipping");
3313 return;
3314 };
3315 assert!(heartbeat_due(&entry, Instant::now(), INTERVAL, FRAME_LEN));
3316 }
3317
3318 #[test]
3319 fn recently_active_connection_is_skipped() {
3320 let (tx, _rx) = UnixStream::pair().unwrap();
3321 let entry = entry_for(tx, &[]);
3322 assert!(
3323 !heartbeat_due(&entry, Instant::now(), INTERVAL, FRAME_LEN),
3324 "a connection inside the interval must not be pinged"
3325 );
3326 }
3327
3328 /// A blocked peer's socket is full — the frame would only grow
3329 /// `send_buf`. This is one half of the fix for the unbounded
3330 /// heartbeat growth on trickle-reading clients.
3331 #[test]
3332 fn blocked_connection_is_skipped() {
3333 let Some(mut entry) = idle_entry(&[]) else {
3334 eprintln!("monotonic clock too young to backdate; skipping");
3335 return;
3336 };
3337 entry.blocked_since = Some(Instant::now());
3338 assert!(!heartbeat_due(&entry, Instant::now(), INTERVAL, FRAME_LEN));
3339 }
3340
3341 /// The other half: heartbeats respect `MAX_SEND_BUF` like every
3342 /// other append — this was the one path that bypassed the cap.
3343 #[test]
3344 fn append_never_exceeds_the_send_buffer_cap() {
3345 let payload = vec![0u8; MAX_SEND_BUF - FRAME_LEN + 1];
3346 let Some(entry) = idle_entry(&payload) else {
3347 eprintln!("monotonic clock too young to backdate; skipping");
3348 return;
3349 };
3350 assert!(!heartbeat_due(&entry, Instant::now(), INTERVAL, FRAME_LEN));
3351
3352 let payload = vec![0u8; MAX_SEND_BUF - FRAME_LEN];
3353 let Some(entry) = idle_entry(&payload) else {
3354 eprintln!("monotonic clock too young to backdate; skipping");
3355 return;
3356 };
3357 assert!(
3358 heartbeat_due(&entry, Instant::now(), INTERVAL, FRAME_LEN),
3359 "a frame that exactly fits is allowed"
3360 );
3361 }
3362 }
3363
3364 mod flush_sends {
3365 use super::super::{
3366 BLOCKED_RETRY_INTERVAL, BLOCKED_SEND_TIMEOUT, ConnectionEntry, flush_sends,
3367 };
3368 use io_uring::IoUring;
3369 use rustc_hash::FxHashMap;
3370 use std::io::Read as _;
3371 use std::os::unix::io::{AsRawFd, RawFd};
3372 use std::os::unix::net::UnixStream;
3373 use std::time::{Duration, Instant};
3374
3375 pub(super) fn entry_for(stream: UnixStream, payload: &[u8]) -> ConnectionEntry {
3376 ConnectionEntry {
3377 fd: stream.as_raw_fd(),
3378 _owner: Box::new(stream),
3379 send_buf: payload.to_vec(),
3380 last_send: Instant::now(),
3381 blocked_since: None,
3382 last_send_attempt: Instant::now(),
3383 // Every entry these tests build is handed to `flush_sends`
3384 // on the dirty list, so the flag has to agree with it.
3385 dirty: true,
3386 }
3387 }
3388
3389 /// Fill `fd`'s socket send buffer with non-blocking writes until
3390 /// the kernel refuses more — the state a zero-window / non-reading
3391 /// client leaves a connection in.
3392 fn fill_socket(fd: RawFd) {
3393 let junk = [0u8; 4096];
3394 loop {
3395 let n =
3396 unsafe { libc::send(fd, junk.as_ptr().cast(), junk.len(), libc::MSG_DONTWAIT) };
3397 if n < 0 {
3398 let err = std::io::Error::last_os_error();
3399 assert_eq!(
3400 err.raw_os_error(),
3401 Some(libc::EAGAIN),
3402 "unexpected errno while filling socket"
3403 );
3404 break;
3405 }
3406 }
3407 }
3408
3409 /// The defect this module exists to prevent: a peer that stops
3410 /// reading must cost the flush nothing, and healthy peers on the
3411 /// same flush must still be delivered. Against the pre-fix code
3412 /// this test never returns.
3413 #[test]
3414 fn slow_peer_does_not_block_flush_and_healthy_peer_is_delivered() {
3415 let mut ring = IoUring::new(64).unwrap();
3416 let (slow_tx, _slow_rx) = UnixStream::pair().unwrap();
3417 let (fast_tx, mut fast_rx) = UnixStream::pair().unwrap();
3418 fill_socket(slow_tx.as_raw_fd());
3419
3420 let mut connections = FxHashMap::default();
3421 connections.insert(1u64, entry_for(slow_tx, &[0xAA; 1024]));
3422 connections.insert(2u64, entry_for(fast_tx, b"hello"));
3423 let mut dirty: Vec<u64> = vec![1, 2];
3424 let mut to_remove = Vec::new();
3425 let mut cqes = Vec::new();
3426
3427 let start = Instant::now();
3428 flush_sends(
3429 &mut ring,
3430 &mut connections,
3431 &mut dirty,
3432 &mut to_remove,
3433 &mut cqes,
3434 );
3435 // Generous bound to stay unflaky under CI load — the fixed
3436 // path completes in microseconds, the broken one only when
3437 // the slow peer reads (here: never).
3438 assert!(
3439 start.elapsed() < Duration::from_secs(1),
3440 "flush blocked on a slow peer"
3441 );
3442
3443 assert!(to_remove.is_empty(), "nobody dropped on first refusal");
3444 let slow = &connections[&1];
3445 assert!(
3446 !slow.send_buf.is_empty(),
3447 "slow peer keeps its undelivered bytes"
3448 );
3449 assert!(slow.blocked_since.is_some(), "slow peer marked blocked");
3450 assert!(dirty.contains(&1), "slow peer stays dirty for retry");
3451 assert!(slow.dirty, "and its flag agrees with the list");
3452
3453 assert!(connections[&2].send_buf.is_empty(), "healthy peer drained");
3454 assert!(!dirty.contains(&2), "healthy peer leaves the dirty set");
3455 // Flag and list must clear together: a stale `true` would
3456 // keep the connection off the list forever, since `mark_dirty`
3457 // only pushes when the flag is down.
3458 assert!(!connections[&2].dirty, "and its flag clears with it");
3459 fast_rx
3460 .set_read_timeout(Some(Duration::from_secs(1)))
3461 .unwrap();
3462 let mut buf = [0u8; 5];
3463 fast_rx.read_exact(&mut buf).unwrap();
3464 assert_eq!(&buf, b"hello", "healthy peer's bytes reached the socket");
3465 }
3466
3467 /// A payload larger than the socket buffer must be partially
3468 /// delivered, the remainder kept, and the connection treated as
3469 /// blocked (an immediate retry would only report EAGAIN).
3470 #[test]
3471 fn partial_send_keeps_remainder_and_marks_blocked() {
3472 let mut ring = IoUring::new(64).unwrap();
3473 let (tx, _rx) = UnixStream::pair().unwrap();
3474 // Shrink the send buffer so the payload cannot fit in one go.
3475 let sz: libc::c_int = 8192;
3476 let rc = unsafe {
3477 libc::setsockopt(
3478 tx.as_raw_fd(),
3479 libc::SOL_SOCKET,
3480 libc::SO_SNDBUF,
3481 (&raw const sz).cast(),
3482 size_of::<libc::c_int>() as libc::socklen_t,
3483 )
3484 };
3485 assert_eq!(rc, 0, "setsockopt(SO_SNDBUF) failed");
3486 let payload = vec![0x55u8; 512 * 1024];
3487
3488 // Enter the flush as an already-blocked peer with a stale
3489 // (but unexpired) block timestamp and an expired pacing
3490 // window, so the partial delivery below must *restart* the
3491 // blocked clock — the behaviour that keeps a slow-but-
3492 // draining client alive past BLOCKED_SEND_TIMEOUT.
3493 let Some(stale_block) = Instant::now().checked_sub(BLOCKED_SEND_TIMEOUT / 2) else {
3494 eprintln!("monotonic clock too young to backdate; skipping");
3495 return;
3496 };
3497 let mut entry = entry_for(tx, &payload);
3498 entry.blocked_since = Some(stale_block);
3499 entry.last_send_attempt = stale_block;
3500
3501 let mut connections = FxHashMap::default();
3502 connections.insert(1u64, entry);
3503 let mut dirty: Vec<u64> = vec![1];
3504 let mut to_remove = Vec::new();
3505 let mut cqes = Vec::new();
3506
3507 flush_sends(
3508 &mut ring,
3509 &mut connections,
3510 &mut dirty,
3511 &mut to_remove,
3512 &mut cqes,
3513 );
3514
3515 let entry = &connections[&1];
3516 assert!(entry.send_buf.len() < payload.len(), "some bytes were sent");
3517 assert!(!entry.send_buf.is_empty(), "remainder kept for retry");
3518 let refreshed = entry.blocked_since.expect("partial send marks blocked");
3519 assert!(
3520 refreshed > stale_block,
3521 "forward progress restarts the blocked clock"
3522 );
3523 assert!(dirty.contains(&1));
3524 assert!(to_remove.is_empty());
3525 }
3526
3527 /// A connection blocked past `BLOCKED_SEND_TIMEOUT` is dropped —
3528 /// the guard for clients that stop reading during quiet periods,
3529 /// where `MAX_SEND_BUF` never trips because nothing accumulates.
3530 #[test]
3531 fn blocked_past_timeout_is_dropped() {
3532 let mut ring = IoUring::new(64).unwrap();
3533 let (tx, _rx) = UnixStream::pair().unwrap();
3534 fill_socket(tx.as_raw_fd());
3535
3536 let mut entry = entry_for(tx, &[1u8; 64]);
3537 // `checked_sub`: a plain `-` panics when the monotonic clock
3538 // is younger than the timeout (fresh-boot CI microVMs).
3539 let Some(expired) = Instant::now().checked_sub(BLOCKED_SEND_TIMEOUT) else {
3540 eprintln!("monotonic clock too young to backdate; skipping");
3541 return;
3542 };
3543 entry.blocked_since = Some(expired);
3544 let mut connections = FxHashMap::default();
3545 connections.insert(7u64, entry);
3546 let mut dirty: Vec<u64> = vec![7];
3547 let mut to_remove = Vec::new();
3548 let mut cqes = Vec::new();
3549
3550 flush_sends(
3551 &mut ring,
3552 &mut connections,
3553 &mut dirty,
3554 &mut to_remove,
3555 &mut cqes,
3556 );
3557
3558 assert_eq!(to_remove, vec![7], "timed-out peer queued for removal");
3559 assert!(!dirty.contains(&7), "dropped peer leaves the dirty set");
3560 }
3561
3562 /// A blocked connection retried a moment ago is skipped — the
3563 /// pacing that keeps a busy-spinning stage from probing a full
3564 /// socket once per loop iteration.
3565 #[test]
3566 fn blocked_retry_is_paced() {
3567 let mut ring = IoUring::new(64).unwrap();
3568 let (tx, _rx) = UnixStream::pair().unwrap();
3569 fill_socket(tx.as_raw_fd());
3570
3571 let mut entry = entry_for(tx, &[1u8; 64]);
3572 entry.blocked_since = Some(Instant::now());
3573 // A future attempt timestamp makes the pacing skip
3574 // deterministic: `duration_since` saturates to zero, so no
3575 // CI-load preemption between here and the flush's own clock
3576 // read can open the 100 µs window and flake the assertion.
3577 entry.last_send_attempt = Instant::now() + Duration::from_secs(1);
3578 let attempted_at = entry.last_send_attempt;
3579 let mut connections = FxHashMap::default();
3580 connections.insert(3u64, entry);
3581 let mut dirty: Vec<u64> = vec![3];
3582 let mut to_remove = Vec::new();
3583 let mut cqes = Vec::new();
3584
3585 flush_sends(
3586 &mut ring,
3587 &mut connections,
3588 &mut dirty,
3589 &mut to_remove,
3590 &mut cqes,
3591 );
3592
3593 assert_eq!(
3594 connections[&3].last_send_attempt, attempted_at,
3595 "no SEND submitted inside the pacing window"
3596 );
3597 assert!(dirty.contains(&3), "paced peer stays dirty");
3598 assert!(to_remove.is_empty());
3599
3600 // Outside the pacing window the retry happens: backdate the
3601 // last attempt and verify the attempt timestamp advances.
3602 let Some(backdated) = Instant::now().checked_sub(BLOCKED_RETRY_INTERVAL * 2) else {
3603 eprintln!("monotonic clock too young to backdate; skipping");
3604 return;
3605 };
3606 connections.get_mut(&3).unwrap().last_send_attempt = backdated;
3607 flush_sends(
3608 &mut ring,
3609 &mut connections,
3610 &mut dirty,
3611 &mut to_remove,
3612 &mut cqes,
3613 );
3614 assert!(
3615 connections[&3].last_send_attempt > backdated,
3616 "retry submitted once the pacing window elapsed"
3617 );
3618 }
3619
3620 /// Review finding F1 (io-uring-audit-2026-08.md): a
3621 /// response-initiated drop must tear down the *whole* socket and
3622 /// release the `max_connections` permit. The reader holds its
3623 /// own dup of the socket, so merely dropping this stage's entry
3624 /// (closing our dup) leaves the socket open — the EOF below must
3625 /// arrive *despite* a live second dup, which only shutdown(2)
3626 /// achieves.
3627 #[test]
3628 fn teardown_shuts_the_socket_despite_other_dups_and_releases_the_permit() {
3629 use std::sync::atomic::{AtomicU64, Ordering};
3630
3631 let (tx, mut peer) = UnixStream::pair().unwrap();
3632 // Simulates the reader's half: still open across the drop.
3633 let reader_dup = tx.try_clone().unwrap();
3634 let entry = entry_for(tx, &[]);
3635 let active = AtomicU64::new(1);
3636
3637 super::super::teardown_dropped(entry, &active);
3638
3639 assert_eq!(active.load(Ordering::Relaxed), 0, "permit released");
3640 peer.set_read_timeout(Some(Duration::from_secs(1))).unwrap();
3641 let mut buf = [0u8; 1];
3642 assert_eq!(
3643 peer.read(&mut buf).expect("EOF, not a timeout"),
3644 0,
3645 "peer observes EOF even though another dup is still open"
3646 );
3647 drop(reader_dup);
3648 }
3649 }
3650
3651 /// The stage learns of a connection from its control channel and of
3652 /// that connection's replies from the output ring. A reply always
3653 /// trails its `Connected`, so reading the ring before draining the
3654 /// channel is enough for every slot read to find its connection.
3655 /// Drained first, the stage could read the ring after a `Connected`
3656 /// it had not seen — the accept loop queues that event only after
3657 /// the client holds `ServerReady`, so a first request is often on
3658 /// the wire before the stage has heard of its connection — and drop
3659 /// the reply. Seen as a first reply lost on a fresh node under
3660 /// full-suite load. The seam sits right
3661 /// after the drain: with the drain after the read that is harmless,
3662 /// with the drain before it the seam is the gap, and a `Connected`
3663 /// landing there is missed by the read that follows. Holding the
3664 /// stage at the seam makes the interleaving the test's rather than
3665 /// the scheduler's.
3666 mod registration_race {
3667 use std::io::{Read, Write};
3668 use std::os::unix::io::AsRawFd;
3669 use std::os::unix::net::UnixStream;
3670 use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
3671 use std::sync::{Arc, mpsc};
3672 use std::thread;
3673 use std::time::Duration;
3674
3675 use counter_server::{
3676 Counter, CounterQuery, CounterReport, KIND_RESP_ACK, ResponseEncoder,
3677 };
3678 use melin_pipeline::ring::DisruptorBuilder;
3679 use melin_pipeline::wait::WaitStrategy;
3680 use melin_transport_core::fence::FenceState;
3681 use melin_transport_core::pipeline::{OutputPayload, OutputSlot, StageUtilization};
3682 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
3683 use melin_wire_protocol::blocking::BlockingFrameWriter;
3684 use melin_wire_protocol::control_codec::TAG_APP;
3685
3686 use crate::ControlEvent;
3687 use crate::ack_policy::AckPolicy;
3688 use crate::response::{Response, run};
3689
3690 /// `CounterReport::Ack` on the wire: len(4) + tag(1), then the
3691 /// counter's body, kind(1) + value(8).
3692 const FRAME_LEN: usize = 14;
3693 /// Long enough that a genuine loss is distinguishable from
3694 /// scheduler noise on a loaded box, short enough to fail in
3695 /// bounded time.
3696 const READ_TIMEOUT: Duration = Duration::from_secs(5);
3697
3698 #[test]
3699 fn a_reply_that_lands_with_its_connection_is_delivered() {
3700 let (mut producer, mut consumers) =
3701 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
3702 .add_consumer()
3703 .build(WaitStrategy::SpinThenYield);
3704 let consumer = consumers.pop().expect("one consumer was requested");
3705
3706 let (server_sock, mut client_sock) = UnixStream::pair().expect("socketpair");
3707 let server_fd = server_sock.as_raw_fd();
3708 let writer = BlockingFrameWriter::new(Box::new(server_sock) as Box<dyn Write + Send>);
3709 client_sock
3710 .set_read_timeout(Some(READ_TIMEOUT))
3711 .expect("set read timeout");
3712
3713 // The stage reports reaching the gap on `parked` and waits on
3714 // `resume` — once, on its first iteration.
3715 let (parked_tx, parked_rx) = mpsc::channel::<()>();
3716 let (resume_tx, resume_rx) = mpsc::channel::<()>();
3717 let mut held = false;
3718 let pause = move || {
3719 if !held {
3720 held = true;
3721 parked_tx.send(()).expect("the test is waiting");
3722 resume_rx.recv().expect("the test resumes the stage");
3723 }
3724 };
3725
3726 let (control_tx, control_rx) = mpsc::channel();
3727 let shutdown = AtomicBool::new(false);
3728 let config = Response::<Counter> {
3729 // The journal is already past the one event, so the gate
3730 // is open and delivery hinges on registration alone.
3731 journal_persisted_wire_seq: DurableWireSeqCursor::detached(WireSeq::new(1)),
3732 policy: crate::response::GatePolicy {
3733 start: crate::response::GateStart::settled(AckPolicy::Disk),
3734 forced: melin_transport_core::lineage::forced_policy_cell().1,
3735 },
3736 replication_metrics: None,
3737 replica_active: None,
3738 heartbeat_interval: None,
3739 wait: WaitStrategy::SpinThenYield,
3740 utilization: Arc::new(StageUtilization::default()),
3741 encoder: Arc::new(ResponseEncoder),
3742 fence_state: Arc::new(FenceState::new(0)),
3743 active_connections: Arc::new(AtomicU64::new(0)),
3744 // No reader: nothing is ever refused.
3745 refusals: crate::halt::refusal_channel(Arc::new(
3746 melin_pipeline::padding::CachePadded::new(AtomicU64::new(0)),
3747 ))
3748 .1,
3749 ring_sizing: crate::connection_limit::RingSizing::for_max_connections(1)
3750 .expect("a supported cap"),
3751 ready: None,
3752 degraded_release: None,
3753 pause_after_control_drain: Some(Box::new(pause)),
3754 };
3755
3756 thread::scope(|scope| {
3757 let stage = scope.spawn(|| run::<Counter>(consumer, control_rx, config, &shutdown));
3758
3759 // The stage has drained an empty control channel and is
3760 // held at the seam. Now both arrive: read after drain,
3761 // the next iteration finds the slot and then its
3762 // connection; drain after read, the read would find the
3763 // slot and the connection would still be in the channel.
3764 parked_rx.recv().expect("the stage reaches the seam");
3765 control_tx
3766 .send(ControlEvent::Connected {
3767 connection_id: 1,
3768 fd: server_fd,
3769 writer,
3770 })
3771 .expect("stage is running");
3772 producer.publish(OutputSlot {
3773 connection_id: 1,
3774 wire_seq: 1,
3775 payload: OutputPayload::Report(CounterReport::Ack { new_value: 7 }),
3776 // No trailing `BatchEnd`: one frame on the wire.
3777 is_last_in_request: false,
3778 ..Default::default()
3779 });
3780 resume_tx.send(()).expect("the stage is parked");
3781
3782 let mut frame = [0u8; FRAME_LEN];
3783 let delivered = client_sock.read_exact(&mut frame);
3784 shutdown.store(true, Ordering::Relaxed);
3785 stage.join().expect("stage panicked");
3786 delivered.expect(
3787 "the reply was dropped: the control channel was drained before the ring was read",
3788 );
3789 assert_eq!(
3790 frame[4..6],
3791 [TAG_APP, KIND_RESP_ACK],
3792 "an application frame carrying the counter's ack"
3793 );
3794 assert_eq!(
3795 u64::from_le_bytes(frame[6..].try_into().expect("8 bytes")),
3796 7,
3797 "the ack carries the counter's value"
3798 );
3799 });
3800 }
3801 }
3802
3803 /// A write refused at ingress is answered in request order: after the
3804 /// replies to everything published before it — even while one of
3805 /// those is held by the durability gate — and before anything
3806 /// published after it. Replies carry no request id, so a refusal sent
3807 /// early would be paired with the wrong request.
3808 ///
3809 /// Its frame classifier and refusal builder are shared with the DPDK
3810 /// stage's tests (`dpdk_response.rs`).
3811 pub(crate) mod refusal_order {
3812 use std::io::{ErrorKind, Read, Write};
3813 use std::os::unix::io::AsRawFd;
3814 use std::os::unix::net::UnixStream;
3815 use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
3816 use std::sync::{Arc, mpsc};
3817 use std::thread;
3818 use std::time::Duration;
3819
3820 use counter_server::{
3821 Counter, CounterQuery, CounterReport, KIND_RESP_ACK, KIND_RESP_REJECTED,
3822 ResponseEncoder,
3823 };
3824 use melin_pipeline::padding::CachePadded;
3825 use melin_pipeline::ring::DisruptorBuilder;
3826 use melin_pipeline::wait::WaitStrategy;
3827 use melin_transport_core::fence::FenceState;
3828 use melin_transport_core::pipeline::{OutputPayload, OutputSlot, StageUtilization};
3829 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
3830 use melin_wire_protocol::blocking::BlockingFrameWriter;
3831 use melin_wire_protocol::control_codec::{TAG_APP, TAG_BATCH_END};
3832
3833 use crate::ControlEvent;
3834 use crate::ack_policy::AckPolicy;
3835 use crate::halt::{Refusal, RefusalQueue, refusal_channel};
3836 use crate::response::{Response, run};
3837
3838 /// Bounds a read that must succeed; generous for a loaded box.
3839 const READ_TIMEOUT: Duration = Duration::from_secs(5);
3840 /// How long the test watches for a frame that must not arrive yet.
3841 const QUIET: Duration = Duration::from_millis(100);
3842
3843 /// What one frame on the wire was: a counter response, by the
3844 /// kind its body starts with, or one of the protocol's own frames,
3845 /// by its tag.
3846 #[derive(Debug, PartialEq, Eq)]
3847 pub(crate) enum Seen {
3848 App(u8),
3849 Protocol(u8),
3850 }
3851
3852 impl Seen {
3853 /// What a frame with this payload (its length prefix stripped)
3854 /// is.
3855 pub(crate) fn of(payload: &[u8]) -> Self {
3856 match *payload {
3857 [TAG_APP, kind, ..] => Seen::App(kind),
3858 // Every counter response carries a kind.
3859 [TAG_APP] => panic!("a counter response with an empty body"),
3860 [tag, ..] => Seen::Protocol(tag),
3861 [] => panic!("an empty frame on the wire"),
3862 }
3863 }
3864 }
3865
3866 /// Read one frame and say what it was.
3867 pub(super) fn read_frame(sock: &mut UnixStream) -> std::io::Result<Seen> {
3868 let mut len = [0u8; 4];
3869 sock.read_exact(&mut len)?;
3870 let mut payload = vec![0u8; u32::from_le_bytes(len) as usize];
3871 sock.read_exact(&mut payload)?;
3872 Ok(Seen::of(&payload))
3873 }
3874
3875 /// Read one frame into `seen`; false if none arrived.
3876 fn read_into(sock: &mut UnixStream, seen: &mut Vec<Seen>) -> bool {
3877 match read_frame(sock) {
3878 Ok(frame) => {
3879 seen.push(frame);
3880 true
3881 }
3882 Err(_) => false,
3883 }
3884 }
3885
3886 #[test]
3887 fn a_refusal_waits_for_earlier_replies_and_precedes_later_ones() {
3888 let (mut producer, mut consumers) =
3889 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
3890 .add_consumer()
3891 .build(WaitStrategy::SpinThenYield);
3892 let consumer = consumers.pop().expect("one consumer was requested");
3893
3894 let (connected, mut client_sock) = connection(1);
3895
3896 // The test plays the matching stage: it publishes the one
3897 // event's reply, then moves the progress past it.
3898 let matching_progress = Arc::new(CachePadded::new(AtomicU64::new(0)));
3899 let (mut refusals, refusal_rx) = refusal_channel(Arc::clone(&matching_progress));
3900 // The event's gate is shut until the test opens it.
3901 let journal_cursor = DurableWireSeqCursor::detached(WireSeq::new(0));
3902
3903 let (control_tx, control_rx) = mpsc::channel();
3904 control_tx.send(connected).expect("channel open");
3905 let shutdown = AtomicBool::new(false);
3906 let config = config(
3907 journal_cursor.clone(),
3908 Arc::new(FenceState::new(0)),
3909 refusal_rx,
3910 None,
3911 );
3912
3913 // What a reader does for: refused write, accepted write,
3914 // refused write — refusals visible before the event published
3915 // after them. All in place before the stage starts, so its
3916 // first iteration reads the event with both refusals behind
3917 // it: the first goes out ahead of the event (the batch path),
3918 // the second once the ring is empty (the idle path).
3919 refusals.try_send(refusal(1, 0)).expect("queue has room");
3920 refusals.try_send(refusal(1, 1)).expect("queue has room");
3921 refusals.flush();
3922 producer.publish(OutputSlot {
3923 connection_id: 1,
3924 input_seq: 0,
3925 wire_seq: 1,
3926 payload: OutputPayload::Report(CounterReport::Ack { new_value: 7 }),
3927 is_last_in_request: true,
3928 ..Default::default()
3929 });
3930 matching_progress.get().store(1, Ordering::Release);
3931
3932 thread::scope(|scope| {
3933 let stage = scope.spawn(|| run::<Counter>(consumer, control_rx, config, &shutdown));
3934
3935 let mut seen = Vec::new();
3936
3937 // The first refusal came before the held event: it goes
3938 // out while the gate is shut.
3939 let first = read_into(&mut client_sock, &mut seen)
3940 && read_into(&mut client_sock, &mut seen);
3941
3942 // The second came after it: nothing more until the gate
3943 // opens.
3944 client_sock
3945 .set_read_timeout(Some(QUIET))
3946 .expect("set read timeout");
3947 let mut probe = [0u8; 1];
3948 // Anything but a timeout — bytes, or the stage closing the
3949 // socket — means something went out early.
3950 let early = !matches!(
3951 client_sock.read(&mut probe),
3952 Err(e) if matches!(e.kind(), ErrorKind::WouldBlock | ErrorKind::TimedOut)
3953 );
3954 client_sock
3955 .set_read_timeout(Some(READ_TIMEOUT))
3956 .expect("set read timeout");
3957
3958 journal_cursor.store(WireSeq::new(1));
3959 let rest = !early && (0..4).all(|_| read_into(&mut client_sock, &mut seen));
3960
3961 // Stop the stage before asserting, so a failure cannot
3962 // leave the scope waiting on a spinning thread.
3963 shutdown.store(true, Ordering::Relaxed);
3964 stage.join().expect("stage panicked");
3965
3966 assert!(first, "the refusal ahead of the held event never arrived");
3967 assert!(
3968 !early,
3969 "the later refusal overtook the reply the gate was holding"
3970 );
3971 assert!(rest, "replies missing after the gate opened: {seen:x?}");
3972 assert_eq!(
3973 seen,
3974 [
3975 Seen::App(KIND_RESP_REJECTED),
3976 Seen::Protocol(TAG_BATCH_END),
3977 Seen::App(KIND_RESP_ACK),
3978 Seen::Protocol(TAG_BATCH_END),
3979 Seen::App(KIND_RESP_REJECTED),
3980 Seen::Protocol(TAG_BATCH_END),
3981 ],
3982 "replies out of request order"
3983 );
3984 });
3985 }
3986
3987 /// A refusal reaches the stage only with its connection registered.
3988 /// The reader refuses a new connection's first request as soon as
3989 /// that connection's `Connected` is queued, so a refusal made
3990 /// visible while the stage is past its control drain can belong to
3991 /// a connection the stage has not heard of. Released in that
3992 /// iteration it would be dropped, and the client left without a
3993 /// reply.
3994 ///
3995 /// The seam holds the stage after its drain twice. The first hold
3996 /// lands connection 1's refusal, which the next iteration's idle
3997 /// path is then due to release; the second hold, in that iteration,
3998 /// lands connection 2 and its refusal just ahead of the release.
3999 #[test]
4000 fn a_refusal_is_not_released_ahead_of_its_connection() {
4001 let (_producer, mut consumers) =
4002 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
4003 .add_consumer()
4004 .build(WaitStrategy::SpinThenYield);
4005 let consumer = consumers.pop().expect("one consumer was requested");
4006 let (connected_1, mut client_1) = connection(1);
4007 let (connected_2, mut client_2) = connection(2);
4008
4009 // Nothing is ever published, so no refusal waits on an event.
4010 let progress = Arc::new(CachePadded::new(AtomicU64::new(0)));
4011 let (mut refusals, refusal_rx) = refusal_channel(progress);
4012 let (control_tx, control_rx) = mpsc::channel();
4013 control_tx.send(connected_1).expect("channel open");
4014
4015 let (parked_tx, parked_rx) = mpsc::channel::<()>();
4016 let (resume_tx, resume_rx) = mpsc::channel::<()>();
4017 let mut holds = 0;
4018 let pause = move || {
4019 if holds < 2 {
4020 holds += 1;
4021 parked_tx.send(()).expect("the test is waiting");
4022 resume_rx.recv().expect("the test resumes the stage");
4023 }
4024 };
4025 let shutdown = AtomicBool::new(false);
4026 let config = config(
4027 DurableWireSeqCursor::detached(WireSeq::new(0)),
4028 Arc::new(FenceState::new(0)),
4029 refusal_rx,
4030 Some(Box::new(pause)),
4031 );
4032
4033 thread::scope(|scope| {
4034 let stage = scope.spawn(|| run::<Counter>(consumer, control_rx, config, &shutdown));
4035
4036 parked_rx.recv().expect("the stage reaches the seam");
4037 refusals.try_send(refusal(1, 0)).expect("queue has room");
4038 refusals.flush();
4039 resume_tx.send(()).expect("the stage is parked");
4040
4041 parked_rx.recv().expect("the stage reaches the seam again");
4042 control_tx.send(connected_2).expect("stage is running");
4043 refusals.try_send(refusal(2, 0)).expect("queue has room");
4044 refusals.flush();
4045 resume_tx.send(()).expect("the stage is parked");
4046
4047 let mut seen_1 = Vec::new();
4048 let mut seen_2 = Vec::new();
4049 let got_1 = (0..2).all(|_| read_into(&mut client_1, &mut seen_1));
4050 let got_2 = (0..2).all(|_| read_into(&mut client_2, &mut seen_2));
4051 shutdown.store(true, Ordering::Relaxed);
4052 stage.join().expect("stage panicked");
4053
4054 assert!(got_1, "connection 1's refusal never arrived: {seen_1:x?}");
4055 assert!(
4056 got_2,
4057 "connection 2's refusal was dropped: released before its connection registered"
4058 );
4059 for seen in [seen_1, seen_2] {
4060 assert_eq!(
4061 seen,
4062 [Seen::App(KIND_RESP_REJECTED), Seen::Protocol(TAG_BATCH_END)]
4063 );
4064 }
4065 });
4066 }
4067
4068 /// A registered connection: its `Connected` event, and the client's
4069 /// end of the socket.
4070 pub(super) fn connection(connection_id: u64) -> (ControlEvent, UnixStream) {
4071 let (server_sock, client_sock) = UnixStream::pair().expect("socketpair");
4072 client_sock
4073 .set_read_timeout(Some(READ_TIMEOUT))
4074 .expect("set read timeout");
4075 let event = ControlEvent::Connected {
4076 connection_id,
4077 fd: server_sock.as_raw_fd(),
4078 writer: BlockingFrameWriter::new(Box::new(server_sock) as Box<dyn Write + Send>),
4079 };
4080 (event, client_sock)
4081 }
4082
4083 pub(crate) fn refusal(connection_id: u64, input_seq: u64) -> Refusal<CounterReport> {
4084 Refusal {
4085 connection_id,
4086 input_seq,
4087 report: CounterReport::Rejected,
4088 }
4089 }
4090
4091 /// A stage gating on `journal_cursor` under `disk`, fed `refusals`.
4092 pub(super) fn config(
4093 journal_cursor: DurableWireSeqCursor,
4094 fence_state: Arc<FenceState>,
4095 refusals: RefusalQueue<CounterReport>,
4096 pause_after_control_drain: Option<Box<dyn FnMut() + Send>>,
4097 ) -> Response<Counter> {
4098 Response::<Counter> {
4099 journal_persisted_wire_seq: journal_cursor,
4100 policy: crate::response::GatePolicy {
4101 start: crate::response::GateStart::settled(AckPolicy::Disk),
4102 forced: melin_transport_core::lineage::forced_policy_cell().1,
4103 },
4104 replication_metrics: None,
4105 replica_active: None,
4106 heartbeat_interval: None,
4107 wait: WaitStrategy::SpinThenYield,
4108 utilization: Arc::new(StageUtilization::default()),
4109 encoder: Arc::new(ResponseEncoder),
4110 fence_state,
4111 active_connections: Arc::new(AtomicU64::new(0)),
4112 refusals,
4113 ring_sizing: crate::connection_limit::RingSizing::for_max_connections(4)
4114 .expect("a supported cap"),
4115 ready: None,
4116 degraded_release: None,
4117 pause_after_control_drain,
4118 }
4119 }
4120 }
4121
4122 /// A halted node past the grace period answers a held write once its
4123 /// own journal holds it, ending in `BatchEndDegraded`, and the
4124 /// refusals around it keep their place and end in a plain `BatchEnd`.
4125 /// With the switch off the held write, and the refusal behind it, wait.
4126 mod degraded_release {
4127 use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
4128 use std::sync::{Arc, mpsc};
4129 use std::thread;
4130 use std::time::Duration;
4131
4132 use counter_server::{
4133 Counter, CounterQuery, CounterReport, KIND_RESP_ACK, KIND_RESP_REJECTED,
4134 };
4135 use melin_pipeline::padding::CachePadded;
4136 use melin_pipeline::ring::DisruptorBuilder;
4137 use melin_pipeline::wait::WaitStrategy;
4138 use melin_transport_core::fence::FenceState;
4139 use melin_transport_core::pipeline::{OutputPayload, OutputSlot};
4140 use melin_transport_core::replica_presence::ReplicaPresence;
4141 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
4142 use melin_wire_protocol::control_codec::{TAG_BATCH_END, TAG_BATCH_END_DEGRADED};
4143
4144 use super::refusal_order::{Seen, config, connection, read_frame, refusal};
4145 use crate::ack_policy::AckPolicy;
4146 use crate::halt::{DegradedRelease, refusal_channel};
4147 use crate::replication::ReplicationMetrics;
4148 use crate::response::run;
4149
4150 /// Run a stage under `disk+ram` on a primary whose one replica is
4151 /// gone, with degraded release `on` (no grace) or off, holding one
4152 /// write the primary's journal already holds between two
4153 /// refusals. Returns what the client read before `quiet` passed
4154 /// with nothing more.
4155 fn run_halted(on: bool, quiet: Duration) -> Vec<Seen> {
4156 let (mut producer, mut consumers) =
4157 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
4158 .add_consumer()
4159 .build(WaitStrategy::SpinThenYield);
4160 let consumer = consumers.pop().expect("one consumer was requested");
4161 let (connected, mut client) = connection(1);
4162 let matching_progress = Arc::new(CachePadded::new(AtomicU64::new(0)));
4163 let (mut refusals, refusal_rx) = refusal_channel(Arc::clone(&matching_progress));
4164
4165 let journal_cursor = DurableWireSeqCursor::detached(WireSeq::new(1));
4166 let mut config = config(
4167 journal_cursor,
4168 Arc::new(FenceState::new(0)),
4169 refusal_rx,
4170 None,
4171 );
4172 config.policy = crate::response::GatePolicy {
4173 start: crate::response::GateStart::settled(AckPolicy::DiskAndRam),
4174 forced: melin_transport_core::lineage::forced_policy_cell().1,
4175 };
4176 config.replication_metrics = Some(Arc::new(ReplicationMetrics::default()));
4177 config.replica_active = Some([
4178 Arc::new(AtomicBool::new(false)),
4179 Arc::new(AtomicBool::new(false)),
4180 ]);
4181 // No replica ever streaming: halted from the start.
4182 config.degraded_release = on.then(|| DegradedRelease {
4183 presence: Arc::new(ReplicaPresence::new()),
4184 grace: Duration::ZERO,
4185 });
4186
4187 let (control_tx, control_rx) = mpsc::channel();
4188 control_tx.send(connected).expect("channel open");
4189 refusals.try_send(refusal(1, 0)).expect("queue has room");
4190 refusals.try_send(refusal(1, 1)).expect("queue has room");
4191 refusals.flush();
4192 producer.publish(OutputSlot {
4193 connection_id: 1,
4194 input_seq: 0,
4195 wire_seq: 1,
4196 payload: OutputPayload::Report(CounterReport::Ack { new_value: 7 }),
4197 is_last_in_request: true,
4198 ..Default::default()
4199 });
4200 matching_progress.get().store(1, Ordering::Release);
4201
4202 let shutdown = AtomicBool::new(false);
4203 let mut seen = Vec::new();
4204 thread::scope(|scope| {
4205 let stage = scope.spawn(|| run::<Counter>(consumer, control_rx, config, &shutdown));
4206 client
4207 .set_read_timeout(Some(quiet))
4208 .expect("set read timeout");
4209 while let Ok(frame) = read_frame(&mut client) {
4210 seen.push(frame);
4211 }
4212 shutdown.store(true, Ordering::Relaxed);
4213 stage.join().expect("stage panicked");
4214 });
4215 seen
4216 }
4217
4218 #[test]
4219 fn a_held_write_is_answered_degraded_and_refusals_end_in_a_plain_batch_end() {
4220 let seen = run_halted(true, Duration::from_millis(500));
4221 assert_eq!(
4222 seen,
4223 [
4224 Seen::App(KIND_RESP_REJECTED),
4225 Seen::Protocol(TAG_BATCH_END),
4226 Seen::App(KIND_RESP_ACK),
4227 Seen::Protocol(TAG_BATCH_END_DEGRADED),
4228 Seen::App(KIND_RESP_REJECTED),
4229 Seen::Protocol(TAG_BATCH_END),
4230 ],
4231 "in request order, only the held write marked"
4232 );
4233 }
4234
4235 #[test]
4236 fn with_the_switch_off_the_held_write_and_the_refusal_behind_it_wait() {
4237 let seen = run_halted(false, Duration::from_millis(300));
4238 assert_eq!(
4239 seen,
4240 [Seen::App(KIND_RESP_REJECTED), Seen::Protocol(TAG_BATCH_END)],
4241 "only the refusal ahead of the held write goes out"
4242 );
4243 }
4244 }
4245
4246 /// A node stopped while a reply is held by the ack policy. The gate
4247 /// may never open — every replica gone under a policy that needs one —
4248 /// and the shutdown sequence joins the stage without a timeout, so the
4249 /// stage must leave the gate on shutdown. It leaves without sending
4250 /// the held reply, which the policy never confirmed. A fence co-sets
4251 /// shutdown and takes the same exit.
4252 mod stop_while_gated {
4253 use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
4254 use std::sync::{Arc, mpsc};
4255 use std::thread;
4256 use std::time::{Duration, Instant};
4257
4258 use counter_server::{Counter, CounterQuery, CounterReport, KIND_RESP_ACK};
4259 use melin_pipeline::padding::CachePadded;
4260 use melin_pipeline::ring::DisruptorBuilder;
4261 use melin_pipeline::wait::WaitStrategy;
4262 use melin_transport_core::fence::FenceState;
4263 use melin_transport_core::pipeline::{OutputPayload, OutputSlot};
4264 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
4265 use melin_wire_protocol::control_codec::TAG_BATCH_END;
4266
4267 use super::refusal_order::{Seen, config, connection, read_frame};
4268 use crate::halt::refusal_channel;
4269 use crate::response::run;
4270
4271 /// How long the stage gets to exit once told to; generous for a
4272 /// loaded box.
4273 const EXIT_TIMEOUT: Duration = Duration::from_secs(10);
4274
4275 fn stop_while_gated(fenced: bool) {
4276 let (mut producer, mut consumers) =
4277 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
4278 .add_consumer()
4279 .build(WaitStrategy::SpinThenYield);
4280 let consumer = consumers.pop().expect("one consumer was requested");
4281 let (connected, mut client) = connection(1);
4282 let (control_tx, control_rx) = mpsc::channel();
4283 control_tx.send(connected).expect("channel open");
4284
4285 // The journal confirms the first event and never the second.
4286 let journal_cursor = DurableWireSeqCursor::detached(WireSeq::new(1));
4287 let fence = Arc::new(FenceState::new(0));
4288 let refusals = refusal_channel(Arc::new(CachePadded::new(AtomicU64::new(0)))).1;
4289 let config = config(journal_cursor, Arc::clone(&fence), refusals, None);
4290 for wire_seq in [1, 2] {
4291 producer.publish(OutputSlot {
4292 connection_id: 1,
4293 input_seq: wire_seq - 1,
4294 wire_seq,
4295 payload: OutputPayload::Report(CounterReport::Ack {
4296 new_value: wire_seq,
4297 }),
4298 is_last_in_request: true,
4299 ..Default::default()
4300 });
4301 }
4302
4303 // Not a scoped thread: a stage that never leaves the gate
4304 // would hang a scoped join, and that hang is the failure this
4305 // test exists to catch. The flag is leaked for the same
4306 // reason — the thread may outlive the test, and dies with the
4307 // process.
4308 let shutdown: &'static AtomicBool = Box::leak(Box::new(AtomicBool::new(false)));
4309 let stage =
4310 thread::spawn(move || run::<Counter>(consumer, control_rx, config, shutdown));
4311
4312 // The confirmed reply goes out before the stage blocks on the
4313 // gate.
4314 let mut seen = Vec::new();
4315 for _ in 0..2 {
4316 seen.push(read_frame(&mut client).expect("the confirmed reply arrives"));
4317 }
4318 assert_eq!(
4319 seen,
4320 [Seen::App(KIND_RESP_ACK), Seen::Protocol(TAG_BATCH_END)]
4321 );
4322
4323 if fenced {
4324 assert!(fence.fence(), "first latch");
4325 }
4326 shutdown.store(true, Ordering::Relaxed);
4327 let deadline = Instant::now() + EXIT_TIMEOUT;
4328 while !stage.is_finished() {
4329 assert!(
4330 Instant::now() < deadline,
4331 "the stage did not leave the gate on shutdown"
4332 );
4333 thread::sleep(Duration::from_millis(10));
4334 }
4335 stage.join().expect("stage panicked");
4336
4337 // The held reply never went out: the stage closed the
4338 // connection with nothing more on it.
4339 assert!(
4340 read_frame(&mut client).is_err(),
4341 "a reply the policy never confirmed was sent"
4342 );
4343 }
4344
4345 #[test]
4346 fn a_stopped_stage_leaves_the_gate_and_drops_the_held_reply() {
4347 stop_while_gated(false);
4348 }
4349
4350 #[test]
4351 fn a_fenced_stage_leaves_the_gate_and_drops_the_held_reply() {
4352 stop_while_gated(true);
4353 }
4354 }
4355
4356 /// A journaled policy change reaches the running stage as a slot that
4357 /// sends nothing, and a forced change frees a held reply only once its
4358 /// own entry is on disk. The switch itself is pinned by the gate's
4359 /// tests (`durability_gate.rs`), the in-force gauge by
4360 /// `tests/ack_policy_changes.rs`.
4361 mod policy_change {
4362 use std::io::ErrorKind;
4363 use std::os::unix::io::AsRawFd;
4364 use std::os::unix::net::UnixStream;
4365 use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
4366 use std::sync::{Arc, mpsc};
4367 use std::thread;
4368 use std::time::{Duration, Instant};
4369
4370 use counter_server::{Counter, CounterQuery, CounterReport, KIND_RESP_ACK};
4371 use melin_journal::AckPolicyChange;
4372 use melin_pipeline::padding::CachePadded;
4373 use melin_pipeline::ring::DisruptorBuilder;
4374 use melin_pipeline::wait::WaitStrategy;
4375 use melin_transport_core::fence::FenceState;
4376 use melin_transport_core::lineage::{ForcedPolicy, forced_policy_cell};
4377 use melin_transport_core::pipeline::{OutputPayload, OutputSlot};
4378 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
4379 use melin_wire_protocol::control_codec::TAG_BATCH_END;
4380
4381 use super::refusal_order::{Seen, config, connection, read_frame};
4382 use crate::ack_policy::AckPolicy;
4383 use crate::halt::refusal_channel;
4384 use crate::response::run;
4385
4386 /// How long the test waits for the stage to reach a state.
4387 const SETTLE_TIMEOUT: Duration = Duration::from_secs(10);
4388
4389 /// How long a held reply is watched for: long enough that a stage
4390 /// wrongly releasing it would have sent it.
4391 const HOLD: Duration = Duration::from_millis(50);
4392
4393 fn reply(wire_seq: u64) -> OutputSlot<CounterReport, CounterQuery> {
4394 OutputSlot {
4395 connection_id: 1,
4396 input_seq: wire_seq - 1,
4397 wire_seq,
4398 payload: OutputPayload::Report(CounterReport::Ack {
4399 new_value: wire_seq,
4400 }),
4401 is_last_in_request: true,
4402 ..Default::default()
4403 }
4404 }
4405
4406 /// No frame waiting on the client's socket.
4407 fn nothing_sent(client: &UnixStream) -> bool {
4408 let mut byte = 0u8;
4409 // Safety: a live socket fd and a one-byte buffer; MSG_PEEK
4410 // leaves anything there for the reads that follow.
4411 let n = unsafe {
4412 libc::recv(
4413 client.as_raw_fd(),
4414 (&raw mut byte).cast(),
4415 1,
4416 libc::MSG_PEEK | libc::MSG_DONTWAIT,
4417 )
4418 };
4419 n < 0 && std::io::Error::last_os_error().kind() == ErrorKind::WouldBlock
4420 }
4421
4422 #[test]
4423 fn a_change_slot_sends_nothing_and_a_forced_one_waits_for_its_entry() {
4424 let (mut producer, mut consumers) =
4425 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
4426 .add_consumer()
4427 .build(WaitStrategy::SpinThenYield);
4428 let consumer = consumers.pop().expect("one consumer was requested");
4429 let (connected, mut client) = connection(1);
4430 let (control_tx, control_rx) = mpsc::channel();
4431 control_tx.send(connected).expect("channel open");
4432
4433 // Everything up to the reply after the change is on disk; a
4434 // standalone stage cannot satisfy `two-disks` at all.
4435 let journal_cursor = DurableWireSeqCursor::detached(WireSeq::new(3));
4436 let refusals = refusal_channel(Arc::new(CachePadded::new(AtomicU64::new(0)))).1;
4437 let mut config = config(
4438 journal_cursor.clone(),
4439 Arc::new(FenceState::new(0)),
4440 refusals,
4441 None,
4442 );
4443 let (mut forced_writer, forced) = forced_policy_cell();
4444 config.policy.forced = forced;
4445 let utilization = Arc::clone(&config.utilization);
4446
4447 producer.publish(reply(1));
4448 producer.publish(OutputSlot {
4449 // Addressed to the client's own connection, which the
4450 // matching stage never does: the change still sends it
4451 // nothing, not even a batch end.
4452 connection_id: 1,
4453 input_seq: 1,
4454 wire_seq: 2,
4455 payload: OutputPayload::AckPolicyChange(AckPolicyChange {
4456 policy: AckPolicy::TwoDisks.to_byte(),
4457 unwitnessed: false,
4458 }),
4459 is_last_in_request: true,
4460 ..Default::default()
4461 });
4462 producer.publish(reply(3));
4463
4464 let shutdown = AtomicBool::new(false);
4465 thread::scope(|scope| {
4466 let stage = scope.spawn(|| run::<Counter>(consumer, control_rx, config, &shutdown));
4467
4468 // The reply before the change goes out; once the stage has
4469 // taken the change, it has sent nothing for it (and the
4470 // reply after it is held by `two-disks`).
4471 let before = [read_frame(&mut client), read_frame(&mut client)];
4472 let deadline = Instant::now() + SETTLE_TIMEOUT;
4473 while utilization.ack_policy_in_force.load() != Some(AckPolicy::TwoDisks.to_byte())
4474 && Instant::now() < deadline
4475 {
4476 thread::sleep(Duration::from_millis(1));
4477 }
4478 thread::sleep(HOLD);
4479 let the_change_sent_nothing = nothing_sent(&client);
4480
4481 // A forced swap back to `disk`, not yet on disk itself.
4482 forced_writer.store(ForcedPolicy {
4483 wire_seq: WireSeq::new(4),
4484 policy: AckPolicy::Disk.to_byte(),
4485 });
4486 thread::sleep(HOLD);
4487 let held_until_the_entry_is_on_disk = nothing_sent(&client);
4488 journal_cursor.store(WireSeq::new(4));
4489 let after = [read_frame(&mut client), read_frame(&mut client)];
4490
4491 shutdown.store(true, Ordering::Relaxed);
4492 stage.join().expect("stage panicked");
4493
4494 for frames in [before, after] {
4495 let frames = frames.map(|frame| frame.expect("a reply arrived"));
4496 assert_eq!(
4497 frames,
4498 [Seen::App(KIND_RESP_ACK), Seen::Protocol(TAG_BATCH_END)]
4499 );
4500 }
4501 assert!(
4502 the_change_sent_nothing,
4503 "a frame went out for the change slot, or the reply it holds"
4504 );
4505 assert!(
4506 held_until_the_entry_is_on_disk,
4507 "the forced swap applied before its entry was on disk"
4508 );
4509 });
4510 }
4511 }
4512
4513 /// The stage reports whether it holds its io_uring instance before it
4514 /// runs, so the node can refuse to start instead of losing the stage
4515 /// to a panic on a thread nobody is watching.
4516 mod startup_report {
4517 use std::sync::atomic::{AtomicBool, AtomicU64};
4518 use std::sync::{Arc, mpsc};
4519
4520 use counter_server::{Counter, CounterQuery, CounterReport};
4521 use melin_pipeline::padding::CachePadded;
4522 use melin_pipeline::ring::DisruptorBuilder;
4523 use melin_pipeline::wait::WaitStrategy;
4524 use melin_transport_core::fence::FenceState;
4525 use melin_transport_core::pipeline::OutputSlot;
4526 use melin_transport_core::{DurableWireSeqCursor, WireSeq};
4527
4528 use super::refusal_order::config;
4529 use crate::connection_limit::RingSizing;
4530 use crate::halt::refusal_channel;
4531 use crate::response::run;
4532
4533 /// A zero-entry ring stands in for the locked-memory limit: both
4534 /// fail `io_uring_setup`. The stage reports the error and returns
4535 /// without running — `run` returning at all is the proof, since a
4536 /// running stage only stops on shutdown, which is never set.
4537 #[test]
4538 fn a_ring_that_cannot_be_created_is_reported_and_the_stage_returns() {
4539 let (_producer, mut consumers) =
4540 DisruptorBuilder::<OutputSlot<CounterReport, CounterQuery>>::new(64)
4541 .add_consumer()
4542 .build(WaitStrategy::SpinThenYield);
4543 let consumer = consumers.pop().expect("one consumer was requested");
4544 let (_control_tx, control_rx) = mpsc::channel();
4545 let refusals = refusal_channel(Arc::new(CachePadded::new(AtomicU64::new(0)))).1;
4546 let (ready_tx, ready_rx) = mpsc::sync_channel(1);
4547 let mut config = config(
4548 DurableWireSeqCursor::detached(WireSeq::new(0)),
4549 Arc::new(FenceState::new(0)),
4550 refusals,
4551 None,
4552 );
4553 config.ring_sizing = RingSizing::unchecked(0, 32);
4554 config.ready = Some(ready_tx);
4555
4556 let started = run::<Counter>(consumer, control_rx, config, &AtomicBool::new(false));
4557 assert!(!started, "the stage reports that it never ran");
4558
4559 let err = ready_rx
4560 .recv()
4561 .expect("the stage reports")
4562 .expect_err("a zero-entry ring cannot be created");
4563 let msg = err.to_string();
4564 assert!(msg.contains("response"), "{msg}");
4565 assert!(msg.contains("io_uring"), "{msg}");
4566 }
4567 }
4568}