Skip to main content

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::collections::{HashMap, HashSet};
12use std::os::unix::io::RawFd;
13use std::sync::Arc;
14use std::sync::atomic::{AtomicBool, Ordering};
15use std::sync::mpsc;
16use std::time::{Duration, Instant};
17
18use io_uring::{IoUring, opcode, types};
19use tracing::{debug, error};
20
21use melin_pipeline::ring;
22
23use crate::durability_policy::{CursorView, DurabilityMode, EvalStatus, Policy};
24use crate::replication::ReplicationMetrics;
25use melin_app::Application;
26use melin_app::amortized_timer::AmortizedTimer;
27use melin_transport_core::pipeline::{OutputPayload, OutputSlot, StageUtilization};
28#[cfg(feature = "latency-trace")]
29use melin_transport_core::trace;
30use melin_transport_core::{DurableWireSeqCursor, WireSeq};
31
32use melin_wire_protocol::control::TransportResponse;
33use melin_wire_protocol::control_codec;
34
35/// Maximum number of output slots consumed per batch.
36const MAX_BATCH: usize = 1024;
37
38/// Maximum encoded response size. PositionSnapshot is the largest variant
39/// at up to 330 bytes (length(4) + tag(1) + account(4) + count(1) +
40/// 16*(currency(4)+free(8)+reserved(8))). 512 bytes covers all variants.
41const MAX_RESPONSE_BUF: usize = 512;
42
43/// io_uring submission queue depth for sends. Must be ≥ max concurrent
44/// connections to avoid SQ overflow when all connections are dirty.
45/// Power of 2 for io_uring alignment. 4096 supports 1024+ client
46/// benchmarks where all connections flush simultaneously.
47const RING_SIZE: u32 = 4096;
48
49/// Maximum accumulated send buffer per connection (64 KiB). If a client
50/// falls behind and the buffer exceeds this, the connection is dropped.
51/// 64 KiB holds ~500 response frames — well beyond any reasonable lag.
52const MAX_SEND_BUF: usize = 64 * 1024;
53
54pub use crate::ControlEvent;
55
56/// Encoder type alias: response encoder bound to the application's
57/// `Report` / `QueryResponse` types. Hides the long
58/// `dyn ResponseEncoder<Report = ..., Query = ...>` at call sites.
59pub type ResponseEncoderArc<A> = Arc<
60    dyn melin_app::encoder::ResponseEncoder<
61            Report = <A as Application>::Report,
62            Query = <A as Application>::QueryResponse,
63        >,
64>;
65
66/// Configuration and shared state for the response stage.
67pub struct Response<A: Application> {
68    /// Highest wire seq durably persisted on the primary's journal.
69    /// In the same sequence space as `OutputSlot.wire_seq` and the
70    /// replica metrics (`metrics.in_memory_sequence` /
71    /// `metrics.acked_sequence`), so the durability gate can compare
72    /// these values numerically and the comparison is meaningful
73    /// regardless of `starting_sequence` (fresh vs recovered primary).
74    /// Typed [`DurableWireSeqCursor`] so the gate cannot be wired to a
75    /// ring-space counter — the pre-v14 bug class. Updated by the
76    /// journal stage after every fsync batch via `set_last_seq_publisher`.
77    pub journal_persisted_wire_seq: DurableWireSeqCursor,
78    /// Operator-selected durability mode, published through a shared
79    /// [`AtomicU8`] so the admin `DURABILITY` command can swap it at
80    /// runtime without restarting the node. The response stage reads
81    /// this once per gate iteration with a relaxed load (cheaper than a
82    /// `Mutex` or refcounted `Arc<Policy>` snapshot) and rebuilds its
83    /// local [`Policy`] when the byte changes. See
84    /// [`crate::durability_policy::DurabilityMode::as_u8`] for the
85    /// encoding.
86    pub durability_mode: Arc<std::sync::atomic::AtomicU8>,
87    /// Per-slot replica cursors. `None` for standalone deployments
88    /// (no replication wiring) — the policy then evaluates against the
89    /// primary alone.
90    pub replication_metrics: Option<Arc<ReplicationMetrics>>,
91    /// Per-slot replica active flags. Only "true" slots are included in
92    /// the cursor view fed to `Policy::evaluate`, so disconnected slots
93    /// don't pollute the view with stale zero cursors. When the
94    /// resulting view is too small to satisfy a clause, the policy
95    /// reports degraded and the gate stalls.
96    /// Mirrors `replication_metrics` — `None` in standalone.
97    pub replica_active: Option<[Arc<AtomicBool>; 2]>,
98    pub heartbeat_interval: Option<Duration>,
99    pub busy_spin: bool,
100    pub utilization: Arc<StageUtilization>,
101    /// Wire encoder for application-shaped payloads. Constructed
102    /// once at boot (`Arc::new(ExchangeResponseEncoder)`) and shared
103    /// with the DPDK response stage.
104    pub encoder: ResponseEncoderArc<A>,
105    /// Node fencing state. When latched (a higher epoch was observed), the
106    /// stage exits *without* the best-effort flush — in-flight responses
107    /// for orders on a superseded epoch must not be acknowledged. Fencing
108    /// co-sets `shutdown`, so the latch is only consulted on the shutdown
109    /// path (zero steady-state cost). See `crate::fence`.
110    pub fence_state: Arc<melin_transport_core::fence::FenceState>,
111}
112
113/// Per-connection state for batched io_uring sends.
114struct ConnectionEntry {
115    fd: RawFd,
116    /// Owns the write half of the socket to keep the fd alive.
117    _owner: Box<dyn Send>,
118    /// Accumulates encoded response frames between flushes.
119    /// The full wire frame (length prefix + payload) is appended here.
120    /// Vec's internal data pointer is heap-stable, so io_uring SEND SQEs
121    /// referencing `as_ptr()` remain valid even if the HashMap relocates
122    /// this struct — as long as we don't reallocate the Vec during in-flight sends.
123    send_buf: Vec<u8>,
124    /// Last time data was sent to this connection. Used for heartbeat scheduling.
125    last_send: Instant,
126}
127
128/// Run the io_uring response stage loop. Blocks the calling thread until shutdown.
129///
130/// Consumes from the output SPSC, waits for durability confirmation, and
131/// sends responses via io_uring SEND.
132///
133/// Durability gating: every gate iteration reads the journal cursor
134/// (primary persisted) plus per-slot replica cursors (in-memory and
135/// persisted) from `replication_metrics` and feeds them through the
136/// configured [`Policy`]. See [`evaluate_durability`].
137pub fn run<A: Application>(
138    mut consumer: ring::Consumer<OutputSlot<A::Report, A::QueryResponse>>,
139    control_rx: mpsc::Receiver<ControlEvent>,
140    config: Response<A>,
141    shutdown: &AtomicBool,
142) {
143    let Response {
144        journal_persisted_wire_seq,
145        durability_mode,
146        replication_metrics,
147        replica_active,
148        heartbeat_interval,
149        busy_spin,
150        utilization,
151        encoder,
152        fence_state,
153    } = config;
154    // Resolve the starting mode from the shared atomic and derive the
155    // local Policy. The atomic is the single source of truth across the
156    // process lifetime; the response thread keeps a thread-local copy
157    // for cheap per-iteration use and rebuilds it when an admin
158    // `DURABILITY` command swaps the atomic. Initialise as Hybrid (the
159    // default mode) if the atomic ever holds a corrupted byte — better
160    // than panicking on a degraded process and matches the default
161    // operators see at boot.
162    let mut active_mode =
163        DurabilityMode::from_u8(durability_mode.load(std::sync::atomic::Ordering::Relaxed))
164            .unwrap_or_else(|| {
165                tracing::error!(
166                    "durability_mode atomic held a corrupted byte at startup; defaulting to hybrid"
167                );
168                DurabilityMode::Hybrid
169            });
170    let mut policy = active_mode.to_policy();
171    let mut ring =
172        IoUring::new(RING_SIZE).expect("failed to create io_uring instance for response stage");
173
174    // Connection table: maps connection IDs to their state.
175    // HashMap for O(1) lookup. Pre-sized for a reasonable number of concurrent clients.
176    let mut connections: HashMap<u64, ConnectionEntry> = HashMap::with_capacity(256);
177
178    let mut batch = [OutputSlot::<A::Report, A::QueryResponse>::default(); MAX_BATCH];
179    let mut encode_buf = [0u8; MAX_RESPONSE_BUF];
180
181    // Cached durability position to avoid atomic reads on every slot.
182    // Initialised below from the policy's startup evaluation; updated
183    // via `evaluate_durability` on every gate iteration.
184    let mut cached_durable_pos: u64;
185
186    // Degradation logger. Tracks transitions, suppresses sub-second
187    // flap noise, and drives the `/healthz` `policy_degraded` gauge.
188    // See `DegradationLogger` for the full state machine. Initialised
189    // below from the policy's startup evaluation so an unsatisfiable
190    // policy (e.g. a primary that just lost both replicas while
191    // running `hybrid` or `durably-replicated`) is visible immediately
192    // on `/healthz` and in the journal.
193    let startup_now = Instant::now();
194    let mut last_policy_check = startup_now;
195    /// Re-emit interval for the "still degraded" reminder.
196    const DEGRADED_LOG_INTERVAL: Duration = Duration::from_secs(5);
197    /// Cadence at which the idle path re-evaluates the policy. Bounds
198    /// the lag between a connection-state change and the `/healthz`
199    /// gauge / warn-log reflecting it. Cheap (a handful of atomic
200    /// loads + the policy evaluator) at this rate.
201    const POLICY_CHECK_INTERVAL: Duration = Duration::from_secs(1);
202    /// Cadence at which the gate-wait spin folds elapsed time into the
203    /// degraded-duration counter while the durability gate is stalled.
204    /// Tighter than the idle cadence — it bounds the boundary error when
205    /// a degradation begins or flips mid-wedge, which matters most for
206    /// short stalls. The accrual tick is gated by this period, but the
207    /// clock read behind it is gated by the `AmortizedTimer` mask, so the
208    /// effective resolution is `max(this, the mask's clock-read cadence)`.
209    /// The mask reads the clock ~every 6.5 ms at this spin's rate
210    /// (`AmortizedTimer::CHECK_MASK` is `2^16`), finer than the 10 ms
211    /// here, so this cadence is the binding one and is realized in full.
212    const GATE_ACCRUAL_INTERVAL: Duration = Duration::from_millis(10);
213
214    // Initial evaluation so the cached durable position and the
215    // `/healthz` gauge reflect the cluster's startup shape before
216    // the first batch arrives.
217    let mut degraded_logger;
218    {
219        let journal_pos = journal_persisted_wire_seq.load();
220        let metrics_ref = replication_metrics.as_deref();
221        let active_ref = replica_active.as_ref();
222        let status = evaluate_durability(&policy, journal_pos, metrics_ref, active_ref);
223        cached_durable_pos = status.durable_pos;
224        utilization
225            .policy_degraded
226            .store(status.degraded, Ordering::Relaxed);
227        degraded_logger = if status.degraded {
228            DegradationLogger::new_starting_degraded(startup_now, &policy)
229        } else {
230            DegradationLogger::new(startup_now)
231        };
232    }
233
234    // Stage histograms registered with the global registry — see
235    // `melin_transport_core::trace`. The four breakdown stages
236    // (journal-wait, replica-wait, encode, egress) feed the bench's
237    // tick-to-trade decomposition; spsc/dispatch/server-e2e are kept
238    // alongside as overall sanity checks.
239    #[cfg(feature = "latency-trace")]
240    let mut spsc_rec =
241        trace::register_stage("response: SPSC wakeup (matching publish → response consume)");
242    #[cfg(feature = "latency-trace")]
243    let mut dispatch_rec = trace::register_stage("response: dispatch (consume → socket write)");
244    #[cfg(feature = "latency-trace")]
245    let mut server_e2e_rec = trace::register_stage("server e2e (reader recv → response flush)");
246    // Tick-to-trade breakdown: per-slot wait observed for each
247    // durability path (recorded only when the gate actually held us
248    // up — cache-hit paths skip to avoid inflating the metric with
249    // crossings that happened before we noticed). Encode is wall-time
250    // around `encode_transport_response`. Egress wraps a `flush_sends`
251    // call (one sample per io_uring flush, batching many slots).
252    // Gated on `tick-to-trade`, not `latency-trace`, because these
253    // stages roughly double the hot-path mutex traffic vs the lighter
254    // 4-stage mode.
255    #[cfg(feature = "tick-to-trade")]
256    let mut journal_wait_rec =
257        trace::register_stage("response: journal-wait (match_complete → journal cursor crossed)");
258    #[cfg(feature = "tick-to-trade")]
259    let mut replica_wait_rec = trace::register_stage(
260        "response: replica-wait (match_complete → replication cursor crossed)",
261    );
262    #[cfg(feature = "tick-to-trade")]
263    let mut encode_rec = trace::register_stage("response: encode (per-kind wire encoding)");
264    #[cfg(feature = "tick-to-trade")]
265    let mut egress_rec = trace::register_stage("response: egress (flush_sends elapsed)");
266
267    // Track connections with buffered (unflushed) writes across batches.
268    let mut dirty_connections: HashSet<u64> = HashSet::new();
269
270    // Connections to remove after flush (send errors).
271    let mut to_remove: Vec<u64> = Vec::new();
272
273    // Pre-allocated CQE collection buffer. Must collect CQEs before
274    // processing because the CQ borrow must end before mutating connections.
275    // Pre-sized to RING_SIZE to avoid per-iteration heap allocation.
276    let mut cqes: Vec<(u64, i32)> = Vec::with_capacity(RING_SIZE as usize);
277
278    // Pre-encode the heartbeat response frame once. Full wire frame
279    // (length prefix + tag) for direct append to send_buf.
280    let heartbeat_wire_frame = {
281        let mut buf = [0u8; 8];
282        let written =
283            control_codec::encode_transport_response(&TransportResponse::Heartbeat, &mut buf)
284                .expect("heartbeat encodes");
285        buf[..written].to_vec()
286    };
287
288    // Coarse timestamp for heartbeat scan — avoids Instant::now() on every spin.
289    let mut last_heartbeat_scan = Instant::now();
290
291    // Adaptive spin: spin first (fast wakeup), yield after threshold.
292    let mut idle_spins: u32 = 0;
293
294    let mut busy_count: u64 = 0;
295    let mut idle_count: u64 = 0;
296
297    // Paces accrual ticks inside the durability gate-wait spin so the
298    // degraded-duration counter keeps advancing during a hard stall.
299    // Declared once at function scope (not per gate entry) so the normal
300    // gated path — entered briefly whenever durability lags by a few µs —
301    // pays no extra `Instant::now()`; the amortized mask only reads the
302    // clock once per ~1 M cumulative spin iterations.
303    let mut gate_accrual_timer = AmortizedTimer::new();
304
305    loop {
306        // Observe runtime mode swaps from the admin `DURABILITY`
307        // command. Relaxed load (single writer is the admin handler,
308        // single reader is this thread). When the byte changes,
309        // rebuild the local Policy and reset the cached durable
310        // position so the next gate evaluation starts from a clean
311        // slate under the new shape; log the transition for the audit
312        // trail. An unknown byte is treated as memory corruption: we
313        // log and keep the prior mode rather than silently downgrading.
314        let observed_byte = durability_mode.load(Ordering::Relaxed);
315        if observed_byte != active_mode.as_u8() {
316            match DurabilityMode::from_u8(observed_byte) {
317                Some(next) => {
318                    tracing::info!(
319                        prev = active_mode.as_str(),
320                        next = next.as_str(),
321                        "durability mode swapped at runtime"
322                    );
323                    active_mode = next;
324                    policy = active_mode.to_policy();
325                    // The fresh policy may evaluate degraded/undegraded
326                    // differently against the same cluster shape; let
327                    // the next gate evaluation re-derive.
328                    cached_durable_pos = 0;
329                    // Re-seed the degradation logger so a transition
330                    // out of (or into) degraded under the new policy
331                    // surfaces immediately rather than waiting for the
332                    // sustained-state hold to roll over. Flushes accrual
333                    // first so pre-swap degraded time isn't dropped.
334                    degraded_logger.reseed(&utilization, Instant::now());
335                }
336                None => {
337                    tracing::error!(
338                        byte = observed_byte,
339                        "durability_mode atomic held a corrupted byte; retaining prior mode"
340                    );
341                }
342            }
343        }
344
345        if shutdown.load(Ordering::Relaxed) {
346            // Fence: a superseded ex-primary must not acknowledge any
347            // further in-flight work — skip the best-effort flush so
348            // responses buffered for orders on the old epoch are dropped
349            // (the client sees a connection reset and reconciles on
350            // reconnect). Checked only here, not per iteration: fencing
351            // always co-sets `shutdown` (`FenceState::fence_if_superseded`
352            // owns that invariant), so this branch is the first one a
353            // fenced node reaches and the steady-state loop pays nothing.
354            let flush = !fence_state.is_fenced();
355            // Best-effort flush before shutdown.
356            if flush && !dirty_connections.is_empty() {
357                flush_sends(
358                    &mut ring,
359                    &mut connections,
360                    &dirty_connections,
361                    &mut to_remove,
362                    &mut cqes,
363                );
364                dirty_connections.clear();
365            }
366            utilization.busy.store(busy_count, Ordering::Relaxed);
367            utilization.idle.store(idle_count, Ordering::Relaxed);
368            #[cfg(feature = "pipeline-stats")]
369            print_utilization("response", busy_count, idle_count);
370            return;
371        }
372
373        // Poll control channel (non-blocking) for connect/disconnect.
374        while let Ok(event) = control_rx.try_recv() {
375            match event {
376                ControlEvent::Connected {
377                    connection_id,
378                    fd,
379                    writer,
380                } => {
381                    // The writer keeps the fd alive — store it as the owner.
382                    let owner: Box<dyn Send> = Box::new(writer);
383                    connections.insert(
384                        connection_id,
385                        ConnectionEntry {
386                            fd,
387                            _owner: owner,
388                            send_buf: Vec::with_capacity(4096),
389                            last_send: Instant::now(),
390                        },
391                    );
392                }
393                ControlEvent::Disconnected { connection_id } => {
394                    connections.remove(&connection_id);
395                    dirty_connections.remove(&connection_id);
396                }
397            }
398        }
399
400        // Consume output slots from matching stage.
401        let count = consumer.consume_batch(&mut batch, MAX_BATCH);
402        if count == 0 {
403            // SPSC is empty — flush all dirty connections via io_uring.
404            // This is the response-data egress path; heartbeat flushes
405            // below aren't sampled because they're admin traffic, not
406            // on the client RTT path.
407            if !dirty_connections.is_empty() {
408                #[cfg(feature = "tick-to-trade")]
409                let egress_start = trace::mono_trace_ns();
410                flush_sends(
411                    &mut ring,
412                    &mut connections,
413                    &dirty_connections,
414                    &mut to_remove,
415                    &mut cqes,
416                );
417                #[cfg(feature = "tick-to-trade")]
418                egress_rec.record_elapsed(egress_start, trace::mono_trace_ns());
419                for conn_id in to_remove.drain(..) {
420                    connections.remove(&conn_id);
421                }
422                dirty_connections.clear();
423            }
424
425            // Send heartbeats to idle connections. Only checked during
426            // idle periods (SPSC empty) to avoid overhead on the hot path.
427            if let Some(interval) = heartbeat_interval {
428                let now = Instant::now();
429                // Coarse gate: only scan at most once per second.
430                if now.duration_since(last_heartbeat_scan) >= Duration::from_secs(1) {
431                    last_heartbeat_scan = now;
432                    for (&conn_id, entry) in connections.iter_mut() {
433                        if now.duration_since(entry.last_send) >= interval {
434                            entry.send_buf.extend_from_slice(&heartbeat_wire_frame);
435                            dirty_connections.insert(conn_id);
436                            entry.last_send = now;
437                        }
438                    }
439                    // Flush the heartbeat sends immediately.
440                    if !dirty_connections.is_empty() {
441                        flush_sends(
442                            &mut ring,
443                            &mut connections,
444                            &dirty_connections,
445                            &mut to_remove,
446                            &mut cqes,
447                        );
448                        for conn_id in to_remove.drain(..) {
449                            connections.remove(&conn_id);
450                        }
451                        dirty_connections.clear();
452                    }
453                }
454            }
455
456            // Re-evaluate the durability policy on a slow timer so the
457            // `policy_degraded` flag and the periodic warn track the
458            // cluster's real state even on idle / quiet venues. The
459            // gate-open block also calls `update_degraded_state` after
460            // each consumed batch; this is the equivalent for the
461            // no-batch path.
462            {
463                let now_ts = Instant::now();
464                if now_ts.duration_since(last_policy_check) >= POLICY_CHECK_INTERVAL {
465                    last_policy_check = now_ts;
466                    let journal_pos = journal_persisted_wire_seq.load();
467                    let metrics_ref = replication_metrics.as_deref();
468                    let active_ref = replica_active.as_ref();
469                    let status = evaluate_durability(&policy, journal_pos, metrics_ref, active_ref);
470                    degraded_logger.tick(
471                        &policy,
472                        &utilization,
473                        status.degraded,
474                        now_ts,
475                        DEGRADED_LOG_INTERVAL,
476                    );
477                    // Cache the position so the next batch's gate sees a
478                    // fresh value rather than spinning from a stale cache.
479                    cached_durable_pos = status.durable_pos;
480                }
481            }
482
483            idle_count += 1;
484            if idle_count.is_multiple_of(1024) {
485                utilization.busy.store(busy_count, Ordering::Relaxed);
486                utilization.idle.store(idle_count, Ordering::Relaxed);
487            }
488            if busy_spin || idle_spins < 1000 {
489                idle_spins = idle_spins.wrapping_add(1);
490                std::hint::spin_loop();
491            } else {
492                std::thread::yield_now();
493            }
494            continue;
495        }
496        idle_spins = 0;
497        busy_count += 1;
498
499        #[cfg(feature = "latency-trace")]
500        let consume_ts = trace::mono_trace_ns();
501
502        // Wait for durability confirmation before sending responses.
503        //
504        // Each iteration: read the primary journal cursor + per-slot
505        // replica cursors (both in-memory and persisted), build a
506        // `CursorView`, and evaluate the configured policy. Spin until
507        // the durable position catches up to the batch's max input_seq.
508        //
509        // Per-slot journal-wait / replica-wait tracker. See
510        // `GateCrossTracker` for the rationale (only records cursors
511        // that were actually on the critical path). Attribution uses
512        // `repl_min` = min of connected-replica persisted cursors so
513        // operators see "which subsystem to optimize" the same way as
514        // before the policy refactor.
515        #[cfg(feature = "tick-to-trade")]
516        let mut gate_tracker;
517        {
518            // Gate on `wire_seq`, not `input_seq`. `input_seq` is in
519            // local-consumer space (the matching cursor on the input
520            // ring, starts at 0 in this process) while replica metrics
521            // and the primary's `journal_persisted_wire_seq` live in
522            // wire-seq space (allocated by the journal stage starting
523            // at `starting_sequence`). A `needed` derived from
524            // `input_seq` and compared against wire-seq cursors only
525            // works when `starting_sequence == 1`; a recovered primary
526            // (or any process whose journal already has prior content
527            // pushing `starting_sequence` above 1) would silently open
528            // the gate ahead of the replica's actual replicated state.
529            //
530            // Every cursor in the policy view (`journal_persisted_wire_seq`,
531            // `metrics.in_memory_sequence`, `metrics.acked_sequence`)
532            // carries "highest wire seq known to be in that state on
533            // node X". A batch's `needed` is therefore the *exact*
534            // wire seq the gate must see — not `+1` — for the latest
535            // event in the batch to be considered durable. The legacy
536            // `+1` was load-bearing only because `input_seq` was off
537            // by `starting_sequence - 1` from wire seq; with the
538            // wire-seq stamp it would over-shoot by one event and
539            // make the gate stall an extra round-trip per response.
540            let needed = batch[..count]
541                .iter()
542                .map(|s| s.wire_seq)
543                .max()
544                .expect("non-empty batch");
545            #[cfg(feature = "tick-to-trade")]
546            {
547                gate_tracker = GateCrossTracker::new(needed);
548            }
549            // Durability-gate carve-out for halt-state output. Slots
550            // tagged `durability_bypass = true` at emission carry no
551            // engine state worth replicating before delivery — see
552            // `OutputSlot::durability_bypass` for the correctness
553            // argument. When every slot in the batch carries the flag
554            // the gate is skipped entirely, so clients receive the halt
555            // reason immediately rather than blocking on a structurally
556            // unsatisfiable policy (e.g. `Hybrid` with all replicas
557            // disconnected, which would otherwise stall the gate until
558            // peers return). If even one normal slot is present, gate
559            // the whole batch as usual — the bypass slots ride along
560            // behind the gated one, which is safe (no ordering
561            // inversion vs. a strict-gate world).
562            let needs_gate = batch[..count].iter().any(|s| !s.durability_bypass);
563            if needs_gate && cached_durable_pos < needed {
564                loop {
565                    // Inside the gate-wait spin loop, also observe a
566                    // mode swap. Without this, a batch whose gate
567                    // becomes structurally unsatisfiable (e.g. all
568                    // replicas die while a non-bypass slot is in
569                    // flight under `Hybrid`) would wedge the response
570                    // stage forever, even if an operator sends the
571                    // remediating `DURABILITY local` — the outer loop
572                    // observation never gets a chance to run. The
573                    // relaxed load is ~1 cycle on x86; cheaper than
574                    // the `spin_loop` hint below.
575                    let observed_byte = durability_mode.load(Ordering::Relaxed);
576                    if observed_byte != active_mode.as_u8()
577                        && let Some(next) = DurabilityMode::from_u8(observed_byte)
578                    {
579                        tracing::info!(
580                            prev = active_mode.as_str(),
581                            next = next.as_str(),
582                            "durability mode swapped during gate wait"
583                        );
584                        active_mode = next;
585                        policy = active_mode.to_policy();
586                        // Flush accrual before re-seeding so the wedged-
587                        // degraded interval up to the swap isn't dropped.
588                        degraded_logger.reseed(&utilization, Instant::now());
589                    }
590
591                    let journal_pos = journal_persisted_wire_seq.load();
592                    let metrics_ref = replication_metrics.as_deref();
593                    let active_ref = replica_active.as_ref();
594                    let repl_min = connected_persisted_min(metrics_ref, active_ref);
595
596                    #[cfg(feature = "tick-to-trade")]
597                    gate_tracker.observe(journal_pos.get(), repl_min, trace::mono_trace_ns());
598
599                    let status = evaluate_durability(&policy, journal_pos, metrics_ref, active_ref);
600                    cached_durable_pos = status.durable_pos;
601                    utilization
602                        .policy_degraded
603                        .store(status.degraded, Ordering::Relaxed);
604
605                    // Accrue degraded time while wedged. The post-gate
606                    // tick attributes the whole wait to a single state, so
607                    // without this a healthy→degraded flip during the
608                    // wedge would be mis-charged. `spinning = true`: this
609                    // loop always spins (never yields), so the clock read
610                    // behind the tick is mask-gated, landing only every
611                    // ~65 k iterations (`CHECK_MASK = 2^16`) regardless of
612                    // the period below.
613                    if gate_accrual_timer
614                        .tick(GATE_ACCRUAL_INTERVAL, true)
615                        .is_some()
616                    {
617                        degraded_logger.tick(
618                            &policy,
619                            &utilization,
620                            status.degraded,
621                            Instant::now(),
622                            DEGRADED_LOG_INTERVAL,
623                        );
624                    }
625
626                    if cached_durable_pos >= needed {
627                        // Attribution: which subsystem was slowest at
628                        // the moment the gate opened. Relaxed is fine —
629                        // health reads are infrequent.
630                        if journal_pos.get() <= repl_min {
631                            utilization.gate_journal.fetch_add(1, Ordering::Relaxed);
632                        } else {
633                            utilization.gate_replication.fetch_add(1, Ordering::Relaxed);
634                        }
635                        break;
636                    }
637                    std::hint::spin_loop();
638                }
639            }
640        }
641
642        let batch_now = Instant::now();
643
644        // Log degradation transitions / re-emit the reminder. Same
645        // logger the idle path uses; transitions are gated on a
646        // sustained-state hold so sub-second flap doesn't spam.
647        let degraded_now = utilization.policy_degraded.load(Ordering::Relaxed);
648        degraded_logger.tick(
649            &policy,
650            &utilization,
651            degraded_now,
652            batch_now,
653            DEGRADED_LOG_INTERVAL,
654        );
655        // Bump the idle-path's check timestamp so we don't double-
656        // tick the logger when traffic stops.
657        last_policy_check = batch_now;
658
659        for slot in &batch[..count] {
660            #[cfg(feature = "latency-trace")]
661            spsc_rec.record_elapsed(slot.match_complete_ts, consume_ts);
662
663            // Per-slot durability-gate breakdown. Recorded only when
664            // the gate actually held us up (the tracker captured a
665            // cross). Note: the cross timestamp is for the *batch's*
666            // `needed` — for slots earlier in the batch, the cursor
667            // may have crossed their individual `input_seq+1` earlier,
668            // so this systematically overestimates wait for non-last
669            // slots by up to the batch's matching span. Acceptable
670            // noise for the operator-facing breakdown; documented in
671            // `docs/benchmarking.md`.
672            #[cfg(feature = "tick-to-trade")]
673            if let Some(ts) = gate_tracker.journal_crossed() {
674                journal_wait_rec.record_elapsed(slot.match_complete_ts, ts);
675            }
676            #[cfg(feature = "tick-to-trade")]
677            if let Some(ts) = gate_tracker.replica_crossed() {
678                replica_wait_rec.record_elapsed(slot.match_complete_ts, ts);
679            }
680
681            // Each slot expands to at most two wire frames: the
682            // application payload (Report / Query / EngineError) and
683            // an optional trailing `BatchEnd` when
684            // `is_last_in_request` is set. Application-shaped
685            // payloads go through the encoder; transport-shaped
686            // frames (EngineError, BatchEnd) are encoded by the
687            // runtime directly.
688            if let Some(entry) = connections.get_mut(&slot.connection_id) {
689                // Frame 1: application payload (if any). BatchEnd
690                // payloads carry no body — the terminator below
691                // handles them via `is_last_in_request`.
692                let payload_result: Option<Result<usize, &'static str>> = match slot.payload {
693                    OutputPayload::Report(ref report) => {
694                        Some(encoder.encode_report(report, &mut encode_buf))
695                    }
696                    OutputPayload::QueryResponse(ref q) => {
697                        Some(encoder.encode_query(q, &mut encode_buf))
698                    }
699                    OutputPayload::EngineError => Some(
700                        control_codec::encode_transport_response(
701                            &TransportResponse::EngineError,
702                            &mut encode_buf,
703                        )
704                        .map_err(|_| "encode error"),
705                    ),
706                    OutputPayload::BatchEnd => None,
707                };
708
709                let payload_handled = if let Some(result) = payload_result {
710                    #[cfg(feature = "tick-to-trade")]
711                    let encode_start = trace::mono_trace_ns();
712                    let outcome = append_frame(
713                        result,
714                        slot.connection_id,
715                        entry,
716                        &encode_buf,
717                        batch_now,
718                        &mut dirty_connections,
719                        &mut to_remove,
720                    );
721                    #[cfg(feature = "tick-to-trade")]
722                    encode_rec.record_elapsed(encode_start, trace::mono_trace_ns());
723                    outcome
724                } else {
725                    AppendOutcome::Continue
726                };
727
728                // Frame 2: BatchEnd terminator. Skipped if the payload
729                // append dropped the connection.
730                if matches!(payload_handled, AppendOutcome::Continue) && slot.is_last_in_request {
731                    let result = control_codec::encode_transport_response(
732                        &TransportResponse::BatchEnd,
733                        &mut encode_buf,
734                    )
735                    .map_err(|_| "encode error");
736                    let outcome = append_frame(
737                        result,
738                        slot.connection_id,
739                        entry,
740                        &encode_buf,
741                        batch_now,
742                        &mut dirty_connections,
743                        &mut to_remove,
744                    );
745                    // Record server-side end-to-end: reader recv ->
746                    // response flush. Only the BatchEnd frame carries
747                    // this measurement; tracked here after the append
748                    // so a dropped connection doesn't skew the metric.
749                    #[cfg(feature = "latency-trace")]
750                    if matches!(outcome, AppendOutcome::Continue) {
751                        server_e2e_rec.record_elapsed(slot.recv_ts, trace::mono_trace_ns());
752                    }
753                    let _ = outcome;
754                }
755            }
756        }
757
758        // Remove connections that exceeded the send buffer limit.
759        for conn_id in to_remove.drain(..) {
760            connections.remove(&conn_id);
761            dirty_connections.remove(&conn_id);
762        }
763
764        #[cfg(feature = "latency-trace")]
765        dispatch_rec.record_elapsed(consume_ts, trace::mono_trace_ns());
766    }
767}
768
769/// Submit io_uring SEND SQEs for all dirty connections and wait for completions.
770///
771/// Outcome of a single per-frame append. `Continue` means the
772/// caller may proceed to the next frame for this slot;
773/// `ConnectionDropped` means the connection's send buffer overflowed
774/// or the encode failed, and the connection has been queued for
775/// removal — no further frames should be appended for this slot.
776#[derive(Clone, Copy)]
777enum AppendOutcome {
778    Continue,
779    ConnectionDropped,
780}
781
782/// Copy an encoded frame into the connection's send buffer with
783/// overflow checking. Splits the responsibilities the inline encode
784/// loop used to have: the caller passes in the encode result (so it
785/// can come from the `ResponseEncoder` trait for application
786/// payloads, or `encode_transport_response` for transport-shaped
787/// frames), and this helper handles size accounting + dirty
788/// tracking uniformly.
789#[allow(clippy::too_many_arguments)]
790fn append_frame(
791    result: Result<usize, &'static str>,
792    connection_id: u64,
793    entry: &mut ConnectionEntry,
794    encode_buf: &[u8],
795    batch_now: Instant,
796    dirty_connections: &mut HashSet<u64>,
797    to_remove: &mut Vec<u64>,
798) -> AppendOutcome {
799    let written = match result {
800        Ok(n) => n,
801        Err(reason) => {
802            tracing::error!(connection_id, reason, "encode error");
803            return AppendOutcome::Continue;
804        }
805    };
806
807    // Drop slow clients whose send buffer has grown too large. This
808    // prevents unbounded memory growth from a single laggy connection
809    // causing allocator pressure and tail latency spikes.
810    if entry.send_buf.len() + written > MAX_SEND_BUF {
811        debug!(
812            connection_id,
813            send_buf_len = entry.send_buf.len(),
814            "send buffer exceeded limit, dropping connection"
815        );
816        to_remove.push(connection_id);
817        return AppendOutcome::ConnectionDropped;
818    }
819
820    // Append the full wire frame to the connection's send buffer.
821    // The encoder writes [length(4) | payload], which is the complete
822    // wire format — no extra framing needed.
823    entry.send_buf.extend_from_slice(&encode_buf[..written]);
824    entry.last_send = batch_now;
825    dirty_connections.insert(connection_id);
826    AppendOutcome::Continue
827}
828
829/// Each dirty connection's accumulated send buffer is sent in a single SEND
830/// operation. Partial sends are retried until all bytes are delivered.
831/// Failed connections are collected in `to_remove` for the caller to clean up.
832fn flush_sends(
833    ring: &mut IoUring,
834    connections: &mut HashMap<u64, ConnectionEntry>,
835    dirty: &HashSet<u64>,
836    to_remove: &mut Vec<u64>,
837    cqes: &mut Vec<(u64, i32)>,
838) {
839    // Submit SEND SQEs for all dirty connections.
840    let mut pending: usize = 0;
841    for &conn_id in dirty {
842        if let Some(entry) = connections.get(&conn_id) {
843            if entry.send_buf.is_empty() {
844                continue;
845            }
846            let sqe = opcode::Send::new(
847                types::Fd(entry.fd),
848                entry.send_buf.as_ptr(),
849                entry.send_buf.len() as u32,
850            )
851            .build()
852            .user_data(conn_id);
853
854            unsafe {
855                ring.submission()
856                    .push(&sqe)
857                    .expect("io_uring SQ full — increase RING_SIZE");
858            }
859            pending += 1;
860        }
861    }
862
863    if pending == 0 {
864        return;
865    }
866
867    // Submit and wait for all completions.
868    if let Err(e) = ring.submit_and_wait(pending) {
869        error!(error = %e, "io_uring submit_and_wait failed in response stage");
870        return;
871    }
872
873    // Drain completions into pre-allocated buffer. Must collect to
874    // release CQ borrow before mutating connections.
875    cqes.clear();
876    cqes.extend(ring.completion().map(|cqe| (cqe.user_data(), cqe.result())));
877
878    for &(conn_id, result) in cqes.iter() {
879        if result < 0 {
880            debug!(
881                connection_id = conn_id,
882                error = result,
883                "send error, dropping connection"
884            );
885            to_remove.push(conn_id);
886            continue;
887        }
888
889        let sent = result as usize;
890        if let Some(entry) = connections.get_mut(&conn_id) {
891            if sent >= entry.send_buf.len() {
892                entry.send_buf.clear();
893            } else {
894                // Partial send — drain sent bytes, retry remainder.
895                // Rare for small response frames over TCP/UDS but must
896                // be handled for correctness (e.g., send buffer pressure).
897                entry.send_buf.drain(..sent);
898                retry_send(ring, entry, conn_id, to_remove);
899            }
900        }
901    }
902}
903
904/// Retry sending remaining bytes after a partial send. Loops until the
905/// entire buffer is delivered or an error occurs.
906fn retry_send(
907    ring: &mut IoUring,
908    entry: &mut ConnectionEntry,
909    conn_id: u64,
910    to_remove: &mut Vec<u64>,
911) {
912    while !entry.send_buf.is_empty() {
913        let sqe = opcode::Send::new(
914            types::Fd(entry.fd),
915            entry.send_buf.as_ptr(),
916            entry.send_buf.len() as u32,
917        )
918        .build()
919        .user_data(conn_id);
920
921        unsafe {
922            ring.submission()
923                .push(&sqe)
924                .expect("io_uring SQ full during send retry");
925        }
926
927        if let Err(e) = ring.submit_and_wait(1) {
928            debug!(connection_id = conn_id, error = %e, "send retry failed");
929            to_remove.push(conn_id);
930            return;
931        }
932
933        if let Some(cqe) = ring.completion().next() {
934            let result = cqe.result();
935            if result <= 0 {
936                debug!(
937                    connection_id = conn_id,
938                    error = result,
939                    "send retry error, dropping connection"
940                );
941                to_remove.push(conn_id);
942                return;
943            }
944            let sent = result as usize;
945            if sent >= entry.send_buf.len() {
946                entry.send_buf.clear();
947            } else {
948                entry.send_buf.drain(..sent);
949            }
950        }
951    }
952}
953
954/// Evaluate the durability policy against the live cursor state.
955///
956/// Builds a `CursorView` containing the primary plus every *currently
957/// connected* replica slot and returns the highest sequence at which
958/// the policy is satisfied. The primary's in-memory cursor is modeled
959/// as `u64::MAX` because the response stage only gates events that have
960/// already been processed by the matching engine — those are trivially
961/// in-memory on the primary by construction.
962///
963/// Disconnected slots are *omitted from the view* rather than included
964/// with zero cursors. The view's `len()` reflects how many nodes are
965/// actually available; if it's too small to satisfy a clause, the
966/// policy reports degraded and the gate stalls.
967#[inline]
968pub(crate) fn evaluate_durability(
969    policy: &Policy,
970    journal_pos: WireSeq,
971    metrics: Option<&ReplicationMetrics>,
972    replica_active: Option<&[Arc<AtomicBool>; 2]>,
973) -> EvalStatus {
974    // Primary + up to 2 replica slots = 3 nodes max. The policy view is
975    // raw `u64`, all wire-seq space: `journal_pos` leaves the type system
976    // here, alongside the replica metrics gauges (the `Ack` frame's
977    // wire-seq fields verbatim).
978    let mut nodes: [[u64; 2]; 3] = [[0, 0]; 3];
979    nodes[0] = [u64::MAX, journal_pos.get()];
980    let mut len = 1;
981    if let (Some(m), Some(active)) = (metrics, replica_active) {
982        for (i, slot_active) in active.iter().enumerate() {
983            // Skip inactive slots up-front.
984            if !slot_active.load(Ordering::Acquire) {
985                continue;
986            }
987            let in_mem = m.in_memory_sequence[i].load(Ordering::Acquire);
988            let persisted = m.acked_sequence[i].load(Ordering::Acquire);
989            nodes[len] = [in_mem, persisted];
990            len += 1;
991        }
992    }
993    policy.evaluate_with_status(&CursorView::new(&nodes[..len]))
994}
995
996/// Hold-time before a state transition is committed to the log.
997/// Suppresses log spam when a replica flaps faster than this — only
998/// transitions that hold for at least this long emit warn/info
999/// entries. The `/healthz` gauge updates immediately regardless,
1000/// so dashboards and alerts still see real-time state.
1001const DEGRADED_FLAP_HOLD: Duration = Duration::from_secs(1);
1002
1003/// Tracks degradation state across calls and emits warn/info logs
1004/// with sustained-state gating + a periodic heartbeat re-emit.
1005///
1006/// The hot path calls [`Self::tick`] every gate iteration / idle
1007/// poll with the current `degraded` value and the wall clock. The
1008/// logger handles:
1009///
1010/// - Updating the `policy_degraded` health gauge immediately.
1011/// - Suppressing log lines for transitions that don't hold for at
1012///   least [`DEGRADED_FLAP_HOLD`] — a replica flapping at sub-second
1013///   cadence produces no log noise, only a quietly-updating gauge.
1014/// - Emitting a warn at the moment a sustained degraded state
1015///   crosses the hold threshold, plus a periodic re-emit every
1016///   `heartbeat_interval` while it persists.
1017/// - Emitting an info when a sustained healthy state crosses the
1018///   hold threshold (the cluster is back to its target shape and
1019///   stayed there long enough that we trust the recovery).
1020pub(crate) struct DegradationLogger {
1021    /// Last value passed to `tick`; what we'd log about if it stayed
1022    /// at this value past the hold threshold.
1023    pending_state: bool,
1024    /// When `pending_state` first appeared. Reset on every flip.
1025    pending_since: Instant,
1026    /// Whether the current pending state has been logged yet. Only
1027    /// the *first* log per sustained streak crosses; subsequent
1028    /// re-emits while degraded are heartbeat warns.
1029    pending_logged: bool,
1030    /// When the last warn fired. Drives the periodic re-emit while
1031    /// degraded.
1032    last_log: Option<Instant>,
1033    /// Wall clock of the previous accrual. The interval since this
1034    /// instant is attributed to the state observed then (`pending_state`)
1035    /// and accumulated into the `policy_degraded_nanos` counter. Advanced
1036    /// by [`Self::accrue`] — reached on every `tick` (post-gate, idle, and
1037    /// the gate-wait pacing tick) and on `reseed`.
1038    last_tick: Instant,
1039}
1040
1041impl DegradationLogger {
1042    pub(crate) fn new(now: Instant) -> Self {
1043        Self {
1044            pending_state: false,
1045            pending_since: now,
1046            pending_logged: true, // healthy is the assumed initial state; nothing to log
1047            last_log: None,
1048            last_tick: now,
1049        }
1050    }
1051
1052    /// Use when the policy is known to start in a degraded state
1053    /// (e.g. a primary in `hybrid` mode with no replica yet
1054    /// connected). Logs a startup warn immediately and treats the
1055    /// state as already-logged so the next tick doesn't re-emit.
1056    pub(crate) fn new_starting_degraded(now: Instant, policy: &Policy) -> Self {
1057        tracing::warn!(
1058            policy = %policy,
1059            "durability policy starts in degraded mode — fewer connected nodes than the target count"
1060        );
1061        Self {
1062            pending_state: true,
1063            pending_since: now,
1064            pending_logged: true,
1065            last_log: Some(now),
1066            last_tick: now,
1067        }
1068    }
1069
1070    /// Charge the interval `[last_tick, now]` to the degraded-duration
1071    /// counter when `prev_degraded` (the state observed at the previous
1072    /// tick) was degraded, then advance `last_tick`. Drives the
1073    /// `_seconds_total` counter so `rate()` reflects time-in-degraded
1074    /// continuously, even mid-incident, rather than only stepping on
1075    /// recovery. Shared by [`Self::tick`] and [`Self::reseed`] so accrual
1076    /// is never skipped on a logger lifecycle boundary.
1077    #[inline]
1078    fn accrue(&mut self, utilization: &StageUtilization, prev_degraded: bool, now: Instant) {
1079        if prev_degraded {
1080            // `duration_since` saturates to zero when `now < last_tick`;
1081            // `now` is always >= `last_tick` here (single-thread monotonic
1082            // clock), matching the plain `duration_since` used elsewhere
1083            // in this file.
1084            let elapsed = now.duration_since(self.last_tick);
1085            // `as_nanos()` is u128; one inter-tick interval is sub-second
1086            // to a few seconds, far below the u64 nanos ceiling (~584
1087            // years), so the cast can't truncate. See the field doc on
1088            // `StageUtilization::policy_degraded_nanos`.
1089            utilization
1090                .policy_degraded_nanos
1091                .fetch_add(elapsed.as_nanos() as u64, Ordering::Relaxed);
1092        }
1093        self.last_tick = now;
1094    }
1095
1096    /// Flush in-flight degraded accrual up to `now`, then reset to a
1097    /// fresh healthy-start logger. Called on a runtime durability-mode
1098    /// swap, which is a logger lifecycle boundary: without flushing
1099    /// first, the pre-swap degraded interval — on the gate-wait path the
1100    /// entire wedge — would be silently dropped. The new policy's actual
1101    /// degraded state is re-derived by the next `tick`, so the brief
1102    /// swap-to-next-tick window is attributed healthy; that residual is
1103    /// bounded by one tick interval, the counter's inherent granularity.
1104    pub(crate) fn reseed(&mut self, utilization: &StageUtilization, now: Instant) {
1105        let prev_state = self.pending_state;
1106        self.accrue(utilization, prev_state, now);
1107        *self = Self::new(now);
1108    }
1109
1110    /// Update the gauge + emit transition/heartbeat logs as needed.
1111    /// Cheap on the hot path: one atomic store, a few branches, one
1112    /// `Instant::duration_since`.
1113    pub(crate) fn tick(
1114        &mut self,
1115        policy: &Policy,
1116        utilization: &StageUtilization,
1117        degraded_now: bool,
1118        now: Instant,
1119        heartbeat_interval: Duration,
1120    ) {
1121        // Charge the just-elapsed interval to the state observed at the
1122        // *previous* tick. Snapshot it up front, before the flap-hold
1123        // bookkeeping below mutates `pending_state`, so accrual stays
1124        // correct even if that block is later reordered.
1125        let prev_state = self.pending_state;
1126        self.accrue(utilization, prev_state, now);
1127
1128        utilization
1129            .policy_degraded
1130            .store(degraded_now, Ordering::Relaxed);
1131
1132        if degraded_now != self.pending_state {
1133            // State changed — start a new hold window. Don't log
1134            // until / unless this new state stays long enough.
1135            self.pending_state = degraded_now;
1136            self.pending_since = now;
1137            self.pending_logged = false;
1138            return;
1139        }
1140
1141        // State held. If we haven't yet logged this streak's onset,
1142        // and it's been pending for at least the flap-hold time,
1143        // emit the transition message and mark logged.
1144        if !self.pending_logged && now.duration_since(self.pending_since) >= DEGRADED_FLAP_HOLD {
1145            if degraded_now {
1146                tracing::warn!(
1147                    policy = %policy,
1148                    "durability policy operating in degraded mode — fewer connected nodes than the target count, gate clamped to surviving cluster"
1149                );
1150            } else {
1151                tracing::info!(
1152                    policy = %policy,
1153                    "durability policy returned to target shape"
1154                );
1155            }
1156            self.pending_logged = true;
1157            self.last_log = Some(now);
1158            return;
1159        }
1160
1161        // Heartbeat re-emit while a degraded state persists.
1162        if degraded_now
1163            && self.pending_logged
1164            && self
1165                .last_log
1166                .is_none_or(|t| now.duration_since(t) >= heartbeat_interval)
1167        {
1168            tracing::warn!(
1169                policy = %policy,
1170                "durability policy still degraded — fewer connected nodes than the target count"
1171            );
1172            self.last_log = Some(now);
1173        }
1174    }
1175}
1176
1177/// Minimum persisted cursor across currently-connected replica slots.
1178/// Used for gate-bottleneck attribution and the journal-wait /
1179/// replica-wait histograms — *not* for durability decisions, which go
1180/// through [`evaluate_durability`].
1181///
1182/// Returns `u64::MAX` when no replica is connected, which makes
1183/// attribution always credit the journal — correct, because in
1184/// standalone mode the journal is the only path.
1185#[inline]
1186pub(crate) fn connected_persisted_min(
1187    metrics: Option<&ReplicationMetrics>,
1188    replica_active: Option<&[Arc<AtomicBool>; 2]>,
1189) -> u64 {
1190    let (Some(m), Some(active)) = (metrics, replica_active) else {
1191        return u64::MAX;
1192    };
1193    let mut min = u64::MAX;
1194    for (i, slot_active) in active.iter().enumerate() {
1195        if !slot_active.load(Ordering::Acquire) {
1196            continue;
1197        }
1198        let v = m.acked_sequence[i].load(Ordering::Acquire);
1199        if v < min {
1200            min = v;
1201        }
1202    }
1203    min
1204}
1205
1206/// Tracks per-cursor "first observed transition from below to >= needed"
1207/// inside the durability gate loop, to drive the journal-wait /
1208/// replica-wait histograms in the bench's tick-to-trade decomposition.
1209///
1210/// A sample is recorded only for cursors that were strictly below
1211/// `needed` at the loop's first observation. Cursors already past at
1212/// entry were not on the critical path for this batch, so attributing
1213/// "wait time" to them would inflate the metric with cursor-poll
1214/// observation timestamps that have nothing to do with how long the
1215/// stage actually held us up.
1216///
1217/// `now_ns` is taken as a parameter rather than read internally so
1218/// tests can supply deterministic timestamps. The caller's hot path
1219/// reads `trace::mono_trace_ns()` once per gate iteration and feeds it in.
1220#[cfg(feature = "tick-to-trade")]
1221pub(crate) struct GateCrossTracker {
1222    needed: u64,
1223    journal_crossed_ts: Option<trace::MonoTraceInstant>,
1224    replica_crossed_ts: Option<trace::MonoTraceInstant>,
1225    journal_was_below: bool,
1226    replica_was_below: bool,
1227    first: bool,
1228}
1229
1230#[cfg(feature = "tick-to-trade")]
1231impl GateCrossTracker {
1232    pub(crate) fn new(needed: u64) -> Self {
1233        Self {
1234            needed,
1235            journal_crossed_ts: None,
1236            replica_crossed_ts: None,
1237            journal_was_below: false,
1238            replica_was_below: false,
1239            first: true,
1240        }
1241    }
1242
1243    pub(crate) fn observe(
1244        &mut self,
1245        journal_pos: u64,
1246        repl_min: u64,
1247        now_ns: trace::MonoTraceInstant,
1248    ) {
1249        if self.first {
1250            self.journal_was_below = journal_pos < self.needed;
1251            self.replica_was_below = repl_min < self.needed;
1252            self.first = false;
1253        }
1254        if self.journal_was_below && self.journal_crossed_ts.is_none() && journal_pos >= self.needed
1255        {
1256            self.journal_crossed_ts = Some(now_ns);
1257        }
1258        if self.replica_was_below && self.replica_crossed_ts.is_none() && repl_min >= self.needed {
1259            self.replica_crossed_ts = Some(now_ns);
1260        }
1261    }
1262
1263    pub(crate) fn journal_crossed(&self) -> Option<trace::MonoTraceInstant> {
1264        self.journal_crossed_ts
1265    }
1266
1267    pub(crate) fn replica_crossed(&self) -> Option<trace::MonoTraceInstant> {
1268        self.replica_crossed_ts
1269    }
1270}
1271
1272/// Print busy/idle utilization for a pipeline stage on shutdown.
1273#[cfg(feature = "pipeline-stats")]
1274fn print_utilization(stage: &str, busy: u64, idle: u64) {
1275    let total = busy + idle;
1276    if total == 0 {
1277        tracing::info!(stage, "no iterations recorded");
1278        return;
1279    }
1280    let pct = (busy as f64 / total as f64) * 100.0;
1281    tracing::info!(
1282        stage,
1283        pct_busy = format_args!("{pct:.2}%"),
1284        busy,
1285        idle,
1286        total,
1287        "pipeline utilization",
1288    );
1289}
1290
1291#[cfg(test)]
1292mod tests {
1293    #[cfg(feature = "tick-to-trade")]
1294    use super::GateCrossTracker;
1295    use super::{DegradationLogger, WireSeq, connected_persisted_min, evaluate_durability};
1296    use crate::durability_policy::{Clause, Level, Policy};
1297    use crate::replication::ReplicationMetrics;
1298
1299    /// Build a [`Policy`] from a mini DSL: one or more
1300    /// `"<level>>=<count>"` clauses joined with `&&`. Test-only
1301    /// ergonomics — production builds policies via
1302    /// [`DurabilityMode::to_policy`].
1303    fn parse(s: &str) -> Result<Policy, String> {
1304        let mut clauses = Vec::new();
1305        for raw in s.split("&&") {
1306            let token = raw.trim();
1307            let (lvl, rhs) = token
1308                .split_once(">=")
1309                .ok_or_else(|| format!("clause `{token}` missing `>=`"))?;
1310            let level = match lvl.trim() {
1311                "persisted" => Level::Persisted,
1312                "in_memory" => Level::InMemory,
1313                other => return Err(format!("unknown level `{other}`")),
1314            };
1315            let count: u8 = rhs.trim().parse().map_err(|e| format!("bad count: {e}"))?;
1316            clauses.push(Clause { count, level });
1317        }
1318        Policy::new(clauses).map_err(|e| e.to_string())
1319    }
1320    use melin_transport_core::pipeline::StageUtilization;
1321    use std::sync::Arc;
1322    use std::sync::atomic::{AtomicBool, Ordering};
1323    use std::time::{Duration, Instant};
1324
1325    /// Build a `ReplicationMetrics` with both slots populated. Tests
1326    /// that need to simulate a disconnected slot use [`flags`] to mark
1327    /// it inactive — its cursors are then ignored regardless of value.
1328    fn metrics(slot0: (u64, u64), slot1: (u64, u64)) -> Arc<ReplicationMetrics> {
1329        let m = Arc::new(ReplicationMetrics::default());
1330        m.in_memory_sequence[0].store(slot0.0, Ordering::Relaxed);
1331        m.acked_sequence[0].store(slot0.1, Ordering::Relaxed);
1332        m.in_memory_sequence[1].store(slot1.0, Ordering::Relaxed);
1333        m.acked_sequence[1].store(slot1.1, Ordering::Relaxed);
1334        m
1335    }
1336
1337    /// Build a `[active; 2]` flags array.
1338    fn flags(slot0_active: bool, slot1_active: bool) -> [Arc<AtomicBool>; 2] {
1339        [
1340            Arc::new(AtomicBool::new(slot0_active)),
1341            Arc::new(AtomicBool::new(slot1_active)),
1342        ]
1343    }
1344
1345    /// Both replicas active — the common healthy-cluster case.
1346    fn both_active() -> [Arc<AtomicBool>; 2] {
1347        flags(true, true)
1348    }
1349
1350    // --- Standalone (no replicas wired) ---
1351
1352    #[test]
1353    fn standalone_persisted_one_gates_on_journal() {
1354        // No metrics → only the primary is in the view. `persisted>=1`
1355        // is satisfied by the primary alone at journal_pos.
1356        let p = parse("persisted>=1").unwrap();
1357        assert_eq!(
1358            evaluate_durability(&p, WireSeq::new(500), None, None).durable_pos,
1359            500
1360        );
1361    }
1362
1363    #[test]
1364    fn standalone_strict_persisted_two_never_opens() {
1365        // `persisted>=2` on a standalone primary stays at 0: the
1366        // operator asked for two copies and there is only one. The
1367        // policy surfaces as degraded so the operator sees the gate
1368        // is stalled because the cluster can't meet the policy.
1369        let p = parse("persisted>=2").unwrap();
1370        let r = evaluate_durability(&p, WireSeq::new(500), None, None);
1371        assert_eq!(r.durable_pos, 0);
1372        assert!(
1373            r.degraded,
1374            "policy structurally unsatisfiable on this shape → degraded",
1375        );
1376    }
1377
1378    // --- 2 replicas connected ---
1379
1380    #[test]
1381    fn quorum_both_replicas_ahead_of_journal() {
1382        // Both replicas persisted past journal. `persisted>=2` returns
1383        // the 2nd-largest persisted across {primary, slot0, slot1}.
1384        let p = parse("persisted>=2").unwrap();
1385        let m = metrics((100, 100), (120, 120));
1386        let a = both_active();
1387        assert_eq!(
1388            evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
1389            100
1390        );
1391    }
1392
1393    #[test]
1394    fn quorum_journal_ahead_of_both_replicas() {
1395        // Journal at 500, replicas at 100/120. 2nd-largest persisted = 120.
1396        let p = parse("persisted>=2").unwrap();
1397        let m = metrics((100, 100), (120, 120));
1398        let a = both_active();
1399        assert_eq!(
1400            evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a)).durable_pos,
1401            120
1402        );
1403    }
1404
1405    #[test]
1406    fn quorum_journal_between_slow_and_fast_replica() {
1407        // {primary=150, slot0_persisted=50, slot1_persisted=200}.
1408        // 2nd-largest = 150 (primary itself).
1409        let p = parse("persisted>=2").unwrap();
1410        let m = metrics((50, 50), (200, 200));
1411        let a = both_active();
1412        assert_eq!(
1413            evaluate_durability(&p, WireSeq::new(150), Some(&m), Some(&a)).durable_pos,
1414            150
1415        );
1416    }
1417
1418    // --- Single replica connected ---
1419
1420    #[test]
1421    fn single_replica_strict_persisted_two_requires_both_survivors() {
1422        // Slot 0 connected, slot 1 disconnected. View = {primary, slot0}.
1423        // Strict `persisted>=2`: 2nd-largest of the 2-row view =
1424        // min(primary, slot0). Strictly stronger than legacy auto-
1425        // degrade-to-1-node in the same shape.
1426        let p = parse("persisted>=2").unwrap();
1427        let m = metrics((100, 100), (999, 999)); // slot 1 cursors ignored
1428        let a = flags(true, false);
1429        assert_eq!(
1430            evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
1431            50
1432        );
1433        assert_eq!(
1434            evaluate_durability(&p, WireSeq::new(200), Some(&m), Some(&a)).durable_pos,
1435            100
1436        );
1437    }
1438
1439    #[test]
1440    fn single_replica_persisted_two_requires_both_survivors() {
1441        // 2-node view (primary + surviving replica). `persisted>=2` is
1442        // satisfiable; the gate opens at the slower of the two and the
1443        // policy is not degraded.
1444        let p = parse("persisted>=2").unwrap();
1445        let m = metrics((100, 100), (999, 999));
1446        let a = flags(true, false);
1447        let r = evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a));
1448        assert_eq!(r.durable_pos, 50);
1449        assert!(!r.degraded);
1450    }
1451
1452    #[test]
1453    fn both_replicas_disconnected_strict_stalls() {
1454        // View has only the primary. Strict `persisted>=2` cannot be
1455        // satisfied — operator opted out of degrade.
1456        let p = parse("persisted>=2").unwrap();
1457        let m = metrics((999, 999), (999, 999));
1458        let a = flags(false, false);
1459        assert_eq!(
1460            evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a)).durable_pos,
1461            0
1462        );
1463    }
1464
1465    #[test]
1466    fn both_replicas_disconnected_strict_stalls_and_flags_degraded() {
1467        // With `persisted>=2` and both replicas down, the cursor view
1468        // collapses to {primary}: the clause's count (=2) exceeds the
1469        // view size, so the gate stays at 0 and the policy flags
1470        // degraded. Note the matching stage's separate halt at
1471        // `replicas_connected==0` rejects new orders before they reach
1472        // the gate; this verifies the gate semantics in isolation.
1473        let p = parse("persisted>=2").unwrap();
1474        let m = metrics((999, 999), (999, 999));
1475        let a = flags(false, false);
1476        let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
1477        assert_eq!(r.durable_pos, 0);
1478        assert!(r.degraded);
1479    }
1480
1481    // --- Mixed-level policies ---
1482
1483    #[test]
1484    fn persisted_one_and_in_memory_two() {
1485        // "Leader persists, plus one other node has it in memory" —
1486        // the cheap-but-non-zero durability target. Slot 0 has it in
1487        // memory, slot 1 disconnected.
1488        let p = parse("persisted>=1 && in_memory>=2").unwrap();
1489        // primary persisted=50, slot0 in_mem=80 / persisted=20.
1490        // persisted>=1: max(50, 20, 0) = 50.
1491        // in_memory>=2: primary in_mem=u64::MAX (always), slot0_eff=max(80, 20)=80,
1492        //               slot1=0. 2nd-largest = 80.
1493        // min(50, 80) = 50.
1494        let m = metrics((80, 20), (999, 999));
1495        let a = flags(true, false);
1496        assert_eq!(
1497            evaluate_durability(&p, WireSeq::new(50), Some(&m), Some(&a)).durable_pos,
1498            50
1499        );
1500    }
1501
1502    // --- Edge: journal at 0 ---
1503
1504    #[test]
1505    fn journal_at_zero_with_replicas_persisted_one() {
1506        // Journal hasn't fsynced anything; both replicas have. With
1507        // `persisted>=1` the gate opens at the fastest replica.
1508        let p = parse("persisted>=1").unwrap();
1509        let m = metrics((100, 100), (200, 200));
1510        let a = both_active();
1511        assert_eq!(
1512            evaluate_durability(&p, WireSeq::new(0), Some(&m), Some(&a)).durable_pos,
1513            200
1514        );
1515    }
1516
1517    // --- connected_persisted_min — used for gate-bottleneck attribution ---
1518
1519    #[test]
1520    fn attribution_min_skips_disconnected_slots() {
1521        // Slot 1 disconnected via active flag.
1522        let m = metrics((150, 100), (999, 999));
1523        let a = flags(true, false);
1524        assert_eq!(connected_persisted_min(Some(&m), Some(&a)), 100);
1525    }
1526
1527    #[test]
1528    fn attribution_min_returns_max_when_standalone() {
1529        // No metrics wired → u64::MAX, which makes attribution always
1530        // credit the journal. Correct for a standalone deployment.
1531        assert_eq!(connected_persisted_min(None, None), u64::MAX);
1532    }
1533
1534    /// Fresh-cluster catch-up: a replica that handshakes at sequence
1535    /// 0 (the legitimate genesis case, not a stale-flag race) must be
1536    /// included in the cursor view with its zero cursors so the policy
1537    /// behaves the same way it would for a 1-replica deployment that
1538    /// has just produced its first batch. The disconnect-race
1539    /// mitigations (B1 seed-on-connect + B2 reorder) keep this from
1540    /// being conflated with the stale-flag-paired-with-zero-cursor
1541    /// case under normal cluster lifecycles.
1542    #[test]
1543    fn fresh_cluster_zero_cursors_included_in_view() {
1544        let p = parse("persisted>=2").unwrap();
1545        // Both replicas just handshook at seq 0, primary also at 0
1546        // (fresh cluster, no events yet). View = 3 nodes; the clause's
1547        // count (=2) is met by the view size, so the policy is not
1548        // degraded and the gate sits at the 2nd-largest persisted = 0.
1549        let m = metrics((0, 0), (0, 0));
1550        let a = both_active();
1551        let r = evaluate_durability(&p, WireSeq::new(0), Some(&m), Some(&a));
1552        assert_eq!(r.durable_pos, 0);
1553        assert!(
1554            !r.degraded,
1555            "all 3 nodes present, view meets clause target — should not flag degraded"
1556        );
1557    }
1558
1559    #[test]
1560    fn attribution_min_takes_smaller_when_both_connected() {
1561        let m = metrics((150, 100), (180, 80));
1562        let a = both_active();
1563        assert_eq!(connected_persisted_min(Some(&m), Some(&a)), 80);
1564    }
1565
1566    // -- Race-window regression tests --
1567    //
1568    // The replication senders fix two memory-ordering issues at the
1569    // active-flag transition points:
1570    //
1571    //   B1 (`a84540a`): seed `metrics.{acked,in_memory}_sequence[i]`
1572    //   to `handshake.last_sequence` BEFORE setting active_flag=true
1573    //   on reconnect. Without this, the gate would observe (active=
1574    //   true, cursor=0) for ~1 RTT after a replica catch-up completed,
1575    //   freezing the gate on a degrade-friendly clause.
1576    //
1577    //   B2 (`8888732`): zero `metrics.{acked,in_memory}_sequence[i]`
1578    //   BEFORE setting active_flag=false on disconnect. Without this,
1579    //   a weak-memory reader could observe (active=true, cursor=0)
1580    //   for one iteration during the disconnect window.
1581    //
1582    // Both fixes are in the senders, but the gate's *behaviour* under
1583    // the race-window inputs is tested here. The intent is to lock in
1584    // the invariant: even under a hypothetical (active=true,cursor=0)
1585    // observation, the gate must not produce a spuriously-open answer
1586    // that would cause a client to be told "your event is durable"
1587    // when it isn't. Stalling-briefly is safe; opening-spuriously is
1588    // not.
1589
1590    #[test]
1591    fn race_b1_post_seed_gate_doesnt_freeze_on_reconnect() {
1592        // Post-B1-fix state: replica reconnected, cursors seeded to
1593        // `handshake.last_sequence` (480) before active flipped to
1594        // true. Primary kept moving and is at 500. The gate's view
1595        // is now [primary=500, slot=480]; the durable position dips
1596        // from 500 (primary alone, degraded) to 480 (both nodes).
1597        //
1598        // The dip is correct, not a bug: once a 2nd node is
1599        // connected, durability is bounded by the slower of the two.
1600        // Events 481-500 were already served as durable on primary
1601        // alone — they aren't unsent. New responses for seq>500 wait
1602        // until slot acks; we just don't freeze at 0.
1603        let p = parse("persisted>=2").unwrap();
1604        let m = metrics((480, 480), (999, 999));
1605        let a = flags(true, false);
1606        let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
1607        assert_eq!(
1608            r.durable_pos, 480,
1609            "post-seed reconnect should produce a coherent gate position equal to the slower node, not freeze at 0"
1610        );
1611    }
1612
1613    #[test]
1614    fn race_b1_pre_seed_freeze_is_what_the_fix_avoids() {
1615        // Pre-B1-fix state: cursors at 0, active=true. The gate sees
1616        // [primary=500, slot=[0,0]] and 2nd-largest persisted = 0.
1617        // The gate WOULD freeze at 0. This test documents the bug
1618        // the seeding fix is designed to avoid; the senders ensure
1619        // this state is never observed in production.
1620        let p = parse("persisted>=2").unwrap();
1621        let m = metrics((0, 0), (999, 999));
1622        let a = flags(true, false);
1623        let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
1624        assert_eq!(
1625            r.durable_pos, 0,
1626            "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"
1627        );
1628    }
1629
1630    #[test]
1631    fn race_b2_disconnect_window_doesnt_open_gate_spuriously() {
1632        // Simulates the B2 race window: a weak-memory reader observes
1633        // (active=true, cursor=0) for one iteration during the
1634        // disconnect transition. The slot legitimately has cursor=0
1635        // because the disconnect handler just zeroed the metrics.
1636        //
1637        // Critical invariant: the gate must NOT produce a higher
1638        // durable_pos than it would with the slot correctly excluded.
1639        // Specifically: with primary at 500, slot stale-zero-included,
1640        // the gate must not "see" the primary alone and open at 500
1641        // — that would let a client be told a seq is durable when
1642        // only the primary has it under a `persisted>=2` policy that
1643        // demands 2 nodes.
1644        let p = parse("persisted>=2").unwrap();
1645        let m = metrics((0, 0), (999, 999));
1646        let a = flags(true, false);
1647        let r = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a));
1648        // 2nd-largest persisted across {primary=500, slot=0} = 0.
1649        // Gate stalls. ✓
1650        assert_eq!(r.durable_pos, 0);
1651
1652        // Post-disconnect (active=false): view shrinks to {primary}.
1653        // `persisted>=2` is structurally unsatisfiable on a 1-node
1654        // view, so the gate stays at 0 AND surfaces degraded. The
1655        // matching stage's `replicas_connected==0` halt is what stops
1656        // accepting new orders; the gate side's job is just to keep
1657        // the existing in-flight orders stalled and the alert lit.
1658        let a_disconnected = flags(false, false);
1659        let r_after = evaluate_durability(&p, WireSeq::new(500), Some(&m), Some(&a_disconnected));
1660        assert_eq!(r_after.durable_pos, 0);
1661        assert!(
1662            r_after.degraded,
1663            "post-disconnect view of size 1 cannot meet persisted>=2 → degraded"
1664        );
1665    }
1666
1667    #[test]
1668    fn race_invariant_zero_cursor_never_opens_gate_above_slower_node() {
1669        // Property under both B1 and B2 race windows: for any slot
1670        // observed at cursor=0 with active=true, the gate cannot
1671        // produce a durable_pos that exceeds what an honest 2-node
1672        // evaluation would give. Spot-check a handful of primary
1673        // positions to lock the invariant.
1674        let p = parse("persisted>=2").unwrap();
1675        let m = metrics((0, 0), (999, 999));
1676        let a = flags(true, false);
1677        for primary_pos in [0, 1, 100, 500, 1_000_000_000_u64] {
1678            let r = evaluate_durability(&p, WireSeq::new(primary_pos), Some(&m), Some(&a));
1679            // 2nd-largest of {primary_pos, 0} = 0 for any primary > 0.
1680            // For primary_pos = 0, also 0. So always 0.
1681            assert_eq!(
1682                r.durable_pos, 0,
1683                "race-window observation must not open the gate above 0 for any primary position (got {} for primary_pos={primary_pos})",
1684                r.durable_pos
1685            );
1686        }
1687    }
1688
1689    // ------------------------------------------------------------------
1690    // GateCrossTracker — per-cursor "first transition from below to
1691    // crossed" inside the gate loop, used by the journal-wait /
1692    // replica-wait histograms.
1693    // ------------------------------------------------------------------
1694
1695    #[cfg(feature = "tick-to-trade")]
1696    #[test]
1697    fn gate_cross_tracker_records_journal_when_strictly_below() {
1698        // Journal starts at 5 (< 10), repl_min already at 100.
1699        // Journal crosses on the second observation. Replica was already
1700        // past at entry, so no replica sample.
1701        let mut t = GateCrossTracker::new(10);
1702        t.observe(5, 100, 1_000);
1703        t.observe(15, 100, 2_000);
1704        assert_eq!(t.journal_crossed(), Some(2_000));
1705        assert_eq!(t.replica_crossed(), None);
1706    }
1707
1708    #[cfg(feature = "tick-to-trade")]
1709    #[test]
1710    fn gate_cross_tracker_records_replica_when_strictly_below() {
1711        // Mirror image: journal already past, replica below at entry.
1712        let mut t = GateCrossTracker::new(10);
1713        t.observe(50, 5, 1_000);
1714        t.observe(50, 12, 2_000);
1715        assert_eq!(t.journal_crossed(), None);
1716        assert_eq!(t.replica_crossed(), Some(2_000));
1717    }
1718
1719    #[cfg(feature = "tick-to-trade")]
1720    #[test]
1721    fn gate_cross_tracker_records_both_when_both_below() {
1722        // Both below at entry, both cross independently.
1723        let mut t = GateCrossTracker::new(100);
1724        t.observe(50, 60, 1_000); // both below
1725        t.observe(105, 60, 2_000); // journal crosses
1726        t.observe(105, 110, 3_000); // replica crosses
1727        assert_eq!(t.journal_crossed(), Some(2_000));
1728        assert_eq!(t.replica_crossed(), Some(3_000));
1729    }
1730
1731    #[cfg(feature = "tick-to-trade")]
1732    #[test]
1733    fn gate_cross_tracker_skips_cursor_already_past_at_entry() {
1734        // Both cursors already >= needed at first observation —
1735        // neither was on the critical path. No samples.
1736        let mut t = GateCrossTracker::new(10);
1737        t.observe(50, 100, 1_000);
1738        // Even later observations don't backfill: was_below is sticky.
1739        t.observe(60, 110, 2_000);
1740        assert_eq!(t.journal_crossed(), None);
1741        assert_eq!(t.replica_crossed(), None);
1742    }
1743
1744    #[cfg(feature = "tick-to-trade")]
1745    #[test]
1746    fn gate_cross_tracker_first_observation_only_for_cross_decision() {
1747        // A cursor that goes back below `needed` after first iteration
1748        // (impossible in practice — cursors are monotonic — but we
1749        // verify the first-iteration snapshot is what gates the
1750        // sample). Journal: 50 < 10 false → was_below=false → no sample.
1751        let mut t = GateCrossTracker::new(10);
1752        t.observe(50, 5, 1_000); // journal already past, replica below
1753        t.observe(20, 12, 2_000); // both >= needed now
1754        // Journal: was_below=false at entry → still no sample.
1755        assert_eq!(t.journal_crossed(), None);
1756        // Replica: was_below=true at entry, crosses on iter 2 → sample.
1757        assert_eq!(t.replica_crossed(), Some(2_000));
1758    }
1759
1760    #[cfg(feature = "tick-to-trade")]
1761    #[test]
1762    fn gate_cross_tracker_holds_first_cross_only() {
1763        // Once a cross is recorded, later observations don't
1764        // overwrite — the metric is "when did it first cross", not
1765        // "when was it last below".
1766        let mut t = GateCrossTracker::new(10);
1767        t.observe(5, 100, 1_000);
1768        t.observe(15, 100, 2_000); // first cross
1769        t.observe(25, 100, 3_000); // would otherwise re-record
1770        assert_eq!(t.journal_crossed(), Some(2_000));
1771    }
1772
1773    // -- DegradationLogger flap-suppression --
1774    //
1775    // The logger gates transition logs on a sustained-state hold so a
1776    // replica flapping at sub-second cadence doesn't spam the journal.
1777    // These tests don't observe the logs themselves (tracing is
1778    // process-global and brittle to capture in unit tests); they
1779    // assert the underlying state machine via the `policy_degraded`
1780    // gauge, which the logger updates on every tick regardless of
1781    // log emission.
1782
1783    fn logger_test_policy() -> crate::durability_policy::Policy {
1784        parse("persisted>=2").unwrap()
1785    }
1786
1787    /// Tick the logger N times at `step` intervals, alternating
1788    /// `degraded` per call. Returns the gauge value after the last
1789    /// tick — useful for asserting that flap cycles don't leak the
1790    /// AtomicBool into a wrong terminal state.
1791    fn drive_logger(
1792        logger: &mut DegradationLogger,
1793        utilization: &StageUtilization,
1794        policy: &crate::durability_policy::Policy,
1795        start: Instant,
1796        states: &[bool],
1797        step: Duration,
1798    ) -> bool {
1799        for (i, &state) in states.iter().enumerate() {
1800            let now = start + step.checked_mul(i as u32).unwrap_or(Duration::ZERO);
1801            logger.tick(policy, utilization, state, now, Duration::from_secs(5));
1802        }
1803        utilization.policy_degraded.load(Ordering::Relaxed)
1804    }
1805
1806    #[test]
1807    fn logger_gauge_tracks_state_immediately() {
1808        // The /healthz gauge reflects the *latest* state on every
1809        // tick — this is what dashboards / alerts read. Sustained-
1810        // state gating only affects the warn/info log emission.
1811        let p = logger_test_policy();
1812        let utilization = StageUtilization::new();
1813        let now = Instant::now();
1814        let mut logger = DegradationLogger::new(now);
1815
1816        logger.tick(&p, &utilization, true, now, Duration::from_secs(5));
1817        assert!(utilization.policy_degraded.load(Ordering::Relaxed));
1818
1819        logger.tick(
1820            &p,
1821            &utilization,
1822            false,
1823            now + Duration::from_millis(50),
1824            Duration::from_secs(5),
1825        );
1826        assert!(!utilization.policy_degraded.load(Ordering::Relaxed));
1827    }
1828
1829    #[test]
1830    fn logger_starting_degraded_marks_initial_state_logged() {
1831        // `new_starting_degraded` emits the startup warn and treats
1832        // the state as already-logged so the next tick at the same
1833        // cluster shape doesn't re-emit instantly. The gauge starts
1834        // at 1.
1835        let p = logger_test_policy();
1836        let utilization = StageUtilization::new();
1837        let now = Instant::now();
1838        let mut logger = DegradationLogger::new_starting_degraded(now, &p);
1839        // The logger doesn't write the gauge from the constructor —
1840        // first tick does. Tick at the same state to settle the
1841        // gauge. No new log line should fire (state hasn't changed).
1842        logger.tick(
1843            &p,
1844            &utilization,
1845            true,
1846            now + Duration::from_millis(10),
1847            Duration::from_secs(5),
1848        );
1849        assert!(utilization.policy_degraded.load(Ordering::Relaxed));
1850    }
1851
1852    #[test]
1853    fn logger_accumulates_degraded_seconds_only_while_degraded() {
1854        // The `policy_degraded_nanos` counter must advance by exactly
1855        // the wall-clock time spent in the degraded state and stay flat
1856        // while healthy. Each tick attributes the interval since the
1857        // previous tick to the state observed at that previous tick.
1858        let p = logger_test_policy();
1859        let utilization = StageUtilization::new();
1860        let start = Instant::now();
1861        let mut logger = DegradationLogger::new(start);
1862        let sec = Duration::from_secs(1);
1863
1864        // t0: healthy -> degraded. The zero-length interval before the
1865        // transition is attributed to the healthy start: no accrual.
1866        logger.tick(&p, &utilization, true, start, Duration::from_secs(5));
1867        assert_eq!(utilization.policy_degraded_nanos.load(Ordering::Relaxed), 0);
1868
1869        // t0..t1 spent degraded -> +1s.
1870        logger.tick(&p, &utilization, true, start + sec, Duration::from_secs(5));
1871        // t1..t2 still degraded, then flips healthy at the tick -> +1s.
1872        logger.tick(
1873            &p,
1874            &utilization,
1875            false,
1876            start + 2 * sec,
1877            Duration::from_secs(5),
1878        );
1879        assert_eq!(
1880            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1881            2 * sec.as_nanos() as u64
1882        );
1883
1884        // t2..t3 spent healthy -> counter holds flat.
1885        logger.tick(
1886            &p,
1887            &utilization,
1888            false,
1889            start + 3 * sec,
1890            Duration::from_secs(5),
1891        );
1892        assert_eq!(
1893            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1894            2 * sec.as_nanos() as u64
1895        );
1896    }
1897
1898    #[test]
1899    fn logger_starting_degraded_accrues_from_construction() {
1900        // A primary that boots already-degraded (e.g. `hybrid` with no
1901        // replica yet) must accrue from construction, not from the first
1902        // observed transition — `new_starting_degraded` seeds the
1903        // degraded state so the first tick's interval counts.
1904        let p = logger_test_policy();
1905        let utilization = StageUtilization::new();
1906        let start = Instant::now();
1907        let mut logger = DegradationLogger::new_starting_degraded(start, &p);
1908
1909        logger.tick(
1910            &p,
1911            &utilization,
1912            true,
1913            start + Duration::from_secs(1),
1914            Duration::from_secs(5),
1915        );
1916        assert_eq!(
1917            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1918            Duration::from_secs(1).as_nanos() as u64
1919        );
1920    }
1921
1922    #[test]
1923    fn logger_reseed_flushes_in_flight_degraded_accrual() {
1924        // A runtime mode swap re-seeds the logger. On the gate-wait path
1925        // the swap can land after many seconds of wedged-degraded time
1926        // with no intervening tick, so `reseed` must flush that interval
1927        // before resetting — otherwise the whole wedge is silently lost,
1928        // which is exactly the incident the metric exists to measure.
1929        let p = logger_test_policy();
1930        let utilization = StageUtilization::new();
1931        let start = Instant::now();
1932        let sec = Duration::from_secs(1);
1933
1934        let mut logger = DegradationLogger::new_starting_degraded(start, &p);
1935        logger.tick(&p, &utilization, true, start, Duration::from_secs(5));
1936        assert_eq!(utilization.policy_degraded_nanos.load(Ordering::Relaxed), 0);
1937
1938        // 30s wedged-degraded with no tick (frozen spin), then swap.
1939        logger.reseed(&utilization, start + 30 * sec);
1940        assert_eq!(
1941            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1942            30 * sec.as_nanos() as u64
1943        );
1944
1945        // Post-reseed the logger is healthy-start; a healthy interval
1946        // does not accrue, and `last_tick` was rebased to the swap so
1947        // the next interval isn't double-counted.
1948        logger.tick(
1949            &p,
1950            &utilization,
1951            false,
1952            start + 31 * sec,
1953            Duration::from_secs(5),
1954        );
1955        assert_eq!(
1956            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1957            30 * sec.as_nanos() as u64
1958        );
1959    }
1960
1961    #[test]
1962    fn logger_starting_degraded_then_first_tick_healthy_counts_construction_interval() {
1963        // `new_starting_degraded` seeds the degraded state, so the
1964        // construction→first-tick interval is attributed degraded even
1965        // when the first observed state is already healthy (the cluster
1966        // recovered before the first tick). Locks this intentional edge.
1967        let p = logger_test_policy();
1968        let utilization = StageUtilization::new();
1969        let start = Instant::now();
1970        let mut logger = DegradationLogger::new_starting_degraded(start, &p);
1971
1972        logger.tick(
1973            &p,
1974            &utilization,
1975            false,
1976            start + Duration::from_secs(2),
1977            Duration::from_secs(5),
1978        );
1979        assert_eq!(
1980            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
1981            Duration::from_secs(2).as_nanos() as u64
1982        );
1983    }
1984
1985    #[test]
1986    fn logger_counter_matches_total_degraded_time_across_flaps() {
1987        // The cumulative counter must equal exactly the wall time spent
1988        // in degraded states across a flap sequence — the guarantee
1989        // `rate(...degraded_seconds_total)` dashboards depend on.
1990        let p = logger_test_policy();
1991        let utilization = StageUtilization::new();
1992        let start = Instant::now();
1993        let step = Duration::from_millis(500);
1994        let mut logger = DegradationLogger::new(start);
1995
1996        // State observed at tick i (fired at start + i*step). The state
1997        // set at tick i holds over [tick i, tick i+1], so degraded wall
1998        // time = the spans where the *prior* tick's state was true:
1999        // [t1,t2], [t2,t3], [t4,t5] = 3 * step.
2000        let states = [false, true, true, false, true, false];
2001        for (i, &s) in states.iter().enumerate() {
2002            logger.tick(
2003                &p,
2004                &utilization,
2005                s,
2006                start + step * i as u32,
2007                Duration::from_secs(5),
2008            );
2009        }
2010
2011        assert_eq!(
2012            utilization.policy_degraded_nanos.load(Ordering::Relaxed),
2013            (3 * step).as_nanos() as u64
2014        );
2015    }
2016
2017    #[test]
2018    fn logger_handles_rapid_flap_without_panic() {
2019        // Drive the logger through 100 alternating flips at 100ms
2020        // each (faster than the 1s flap-hold). The state machine
2021        // must remain coherent — no panics, gauge tracks final
2022        // state, and `pending_logged` doesn't get stuck.
2023        let p = logger_test_policy();
2024        let utilization = StageUtilization::new();
2025        let now = Instant::now();
2026        let mut logger = DegradationLogger::new(now);
2027        let states: Vec<bool> = (0..100u32).map(|i| i.is_multiple_of(2)).collect();
2028        let final_state = drive_logger(
2029            &mut logger,
2030            &utilization,
2031            &p,
2032            now,
2033            &states,
2034            Duration::from_millis(100),
2035        );
2036        // 100 states starting at i=0 → final state is i=99 → odd → false.
2037        assert!(!final_state);
2038    }
2039
2040    #[test]
2041    fn logger_sustained_degraded_eventually_settles() {
2042        // After a sustained-true state, the logger should be in the
2043        // "logged the onset" mode. Drive 5 ticks of degraded=true at
2044        // 500ms intervals — total 2s, well past the 1s flap-hold.
2045        // Last tick should leave gauge=1 and the heartbeat re-emit
2046        // window primed (last_log set).
2047        let p = logger_test_policy();
2048        let utilization = StageUtilization::new();
2049        let now = Instant::now();
2050        let mut logger = DegradationLogger::new(now);
2051        let final_state = drive_logger(
2052            &mut logger,
2053            &utilization,
2054            &p,
2055            now,
2056            &[true; 5],
2057            Duration::from_millis(500),
2058        );
2059        assert!(final_state);
2060    }
2061
2062    #[test]
2063    fn logger_recovery_to_healthy_settles_gauge() {
2064        // Sustained degraded → sustained healthy. Gauge should end at 0.
2065        let p = logger_test_policy();
2066        let utilization = StageUtilization::new();
2067        let now = Instant::now();
2068        let mut logger = DegradationLogger::new_starting_degraded(now, &p);
2069        let mut states = vec![true; 5]; // 2.5s degraded
2070        states.extend(vec![false; 5]); // 2.5s healthy
2071        let final_state = drive_logger(
2072            &mut logger,
2073            &utilization,
2074            &p,
2075            now,
2076            &states,
2077            Duration::from_millis(500),
2078        );
2079        assert!(!final_state);
2080    }
2081}