Skip to main content

khive_db/
checkpoint.rs

1//! Periodic WAL checkpoint task for the connection pool (ADR-091).
2//!
3//! Issues `PRAGMA wal_checkpoint(PASSIVE)` on every tick — non-blocking, never
4//! waits for readers. A rare, separately-gated escalation may additionally run
5//! `PRAGMA wal_checkpoint(TRUNCATE)` once WAL pressure crosses
6//! `truncate_high_water_pages` and `truncate_min_interval` has elapsed since
7//! the last attempt (Plank 2); both run under the single writer checkout
8//! `checkpoint_once` holds for that tick. `checkpoint_once` uses
9//! `try_writer_nowait` (zero-wait `try_lock`) so a tick is skipped immediately
10//! when the writer mutex is held, rather than blocking — a skipped tick is
11//! always preferable to stalling write traffic.
12//!
13//! `warn_pages` / `high_water_pages` WARNs fire at most once per below→above
14//! crossing; a skipped tick leaves crossing state unchanged. An age-based
15//! background sweep (Plank 1) additionally checks the oldest span in
16//! `khive_storage::tx_registry` against `tx_warn_secs`/`tx_max_age_secs` on
17//! every tick (Skipped or Observed) and escalates to `warn!`/`error!` on each
18//! below→above crossing — visibility only, nothing here force-closes a stale
19//! span.
20//!
21//! See crates/khive-db/docs/api/checkpoint.md#module-overview-adr-091-planks-012
22//! for full ADR-091 Plank 0/1/2 design rationale (why TRUNCATE is excluded
23//! from ordinary ticks, the single-writer-checkout invariant, and why Plank 1
24//! is a sweep rather than the ADR's originally-described per-statement guard).
25
26use std::sync::atomic::{AtomicU64, Ordering};
27use std::sync::Arc;
28use std::time::{Duration, Instant};
29
30use crate::pool::{ConnectionPool, WriterGuard};
31
32// ── metrics read-surface (load/perf harness) ─────────────────────────────
33// Read-only process-wide gauges (never reset outside #[cfg(test)]). See
34// crates/khive-db/docs/api/checkpoint.md#metrics-read-surface-loadperf-harness
35
36/// Last-observed WAL page count (`query_wal_pages`'s return value on its
37/// most recent call, from either `checkpoint_once` or `maybe_truncate`).
38/// `u64::MAX` is the "never observed" sentinel — no checkpoint tick has run
39/// yet in this process — distinct from a genuine zero-page WAL.
40static LAST_WAL_PAGES: AtomicU64 = AtomicU64::new(u64::MAX);
41
42/// Count of TRUNCATE attempts (`maybe_truncate`'s pragma actually invoked,
43/// win or lose) across this process's lifetime.
44static TRUNCATE_ATTEMPTS: AtomicU64 = AtomicU64::new(0);
45
46/// Current consecutive-failure count, mirrored from the caller-owned
47/// `TruncateState::consecutive_failures` field into a process-readable
48/// gauge every time `note_truncate_outcome` runs.
49static TRUNCATE_CONSECUTIVE_FAILURES: AtomicU64 = AtomicU64::new(0);
50
51/// Count of checkpoint ticks skipped because the writer mutex was already
52/// held (ADR-091 checkpoint-pressure telemetry), across this process's
53/// lifetime. Never reset outside `#[cfg(test)]`.
54static CHECKPOINT_SKIPPED_TICKS: AtomicU64 = AtomicU64::new(0);
55
56/// Current run-length of consecutive skipped ticks. Reset to 0 the next time
57/// a tick is actually observed (writer free), so a sustained skip streak is
58/// visible even between two successful observations.
59static CHECKPOINT_CONSECUTIVE_SKIPS: AtomicU64 = AtomicU64::new(0);
60
61/// WAL page count as of the most recent *observed* tick, snapshotted at the
62/// moment a skip occurs. `u64::MAX` is the "no skip has recorded a snapshot
63/// yet" sentinel, mirroring `LAST_WAL_PAGES`.
64static CHECKPOINT_LAST_SKIP_WAL_PAGES: AtomicU64 = AtomicU64::new(u64::MAX);
65
66/// Last-observed WAL page count, if any checkpoint tick has run yet in this
67/// process. Read surface for the daemon-frame metrics snapshot.
68pub fn last_observed_wal_pages() -> Option<u64> {
69    match LAST_WAL_PAGES.load(Ordering::Relaxed) {
70        u64::MAX => None,
71        pages => Some(pages),
72    }
73}
74
75/// Total WAL TRUNCATE attempts made in this process's lifetime.
76pub fn truncate_attempts() -> u64 {
77    TRUNCATE_ATTEMPTS.load(Ordering::Relaxed)
78}
79
80/// Current consecutive TRUNCATE-attempt failure count.
81pub fn truncate_consecutive_failures() -> u64 {
82    TRUNCATE_CONSECUTIVE_FAILURES.load(Ordering::Relaxed)
83}
84
85/// Total checkpoint ticks skipped (writer busy) in this process's lifetime.
86pub fn checkpoint_skipped_ticks() -> u64 {
87    CHECKPOINT_SKIPPED_TICKS.load(Ordering::Relaxed)
88}
89
90/// Current consecutive-skip run length; 0 once the next tick is observed.
91pub fn checkpoint_consecutive_skips() -> u64 {
92    CHECKPOINT_CONSECUTIVE_SKIPS.load(Ordering::Relaxed)
93}
94
95/// WAL page count last known at the time of the most recent skip, if any
96/// skip has occurred yet in this process.
97pub fn checkpoint_last_skip_wal_pages() -> Option<u64> {
98    match CHECKPOINT_LAST_SKIP_WAL_PAGES.load(Ordering::Relaxed) {
99        u64::MAX => None,
100        pages => Some(pages),
101    }
102}
103
104/// A tick's writer checkout was skipped (mutex busy): bump the lifetime and
105/// consecutive-skip counters and snapshot the last-known WAL pressure so an
106/// operator can see how bad the WAL was heading into the skip streak.
107fn note_checkpoint_skipped() {
108    CHECKPOINT_SKIPPED_TICKS.fetch_add(1, Ordering::Relaxed);
109    CHECKPOINT_CONSECUTIVE_SKIPS.fetch_add(1, Ordering::Relaxed);
110    if let Some(pages) = last_observed_wal_pages() {
111        CHECKPOINT_LAST_SKIP_WAL_PAGES.store(pages, Ordering::Relaxed);
112    }
113}
114
115/// A tick was actually observed (writer free): close out any prior skip
116/// streak. `_wal_pages` is accepted for call-site symmetry with
117/// `note_checkpoint_skipped` and to leave room for a future observed-side
118/// gauge without changing this function's signature again.
119fn note_checkpoint_observed(_wal_pages: u64) {
120    CHECKPOINT_CONSECUTIVE_SKIPS.store(0, Ordering::Relaxed);
121}
122
123/// Reset the checkpoint-pressure atomics between tests. Process-wide gauges
124/// are otherwise shared across every test in this binary; tests that assert
125/// on them must reset first and run under a shared `#[serial(...)]` group.
126#[cfg(test)]
127pub(crate) fn reset_checkpoint_metrics_for_tests() {
128    CHECKPOINT_SKIPPED_TICKS.store(0, Ordering::Relaxed);
129    CHECKPOINT_CONSECUTIVE_SKIPS.store(0, Ordering::Relaxed);
130    CHECKPOINT_LAST_SKIP_WAL_PAGES.store(u64::MAX, Ordering::Relaxed);
131}
132
133/// Outcome of a single checkpoint attempt.
134///
135/// `Skipped` is returned when the writer mutex is already held (the tick is a
136/// no-op). `Observed` carries the WAL page count read during the tick. The
137/// distinction matters for threshold-crossing WARN rate-limiting: a skipped tick
138/// must leave the above/below state unchanged so that a busy tick cannot
139/// spuriously re-arm the rate limit while WAL pressure is still elevated.
140#[derive(Debug, Clone, Copy, PartialEq, Eq)]
141pub enum CheckpointTick {
142    /// The writer mutex was busy; no checkpoint was issued this tick.
143    Skipped,
144    /// A checkpoint was issued; the value is the observed WAL page count.
145    Observed(u64),
146}
147
148/// Default number of consecutive above-`warn_pages` observed ticks required
149/// to escalate from the INFO to the WARN rung of the ADR-091 severity ladder.
150pub const DEFAULT_WARN_SUSTAINED_CYCLES: u8 = 3;
151
152/// Configuration for the WAL checkpoint background task.
153///
154/// All fields default to conservative production values. Override via the
155/// environment variables documented on each field.
156#[derive(Clone, Debug)]
157pub struct CheckpointConfig {
158    /// How often to run a passive checkpoint when there is no active write.
159    ///
160    /// Overridable via `KHIVE_CHECKPOINT_INTERVAL_MS` (milliseconds).
161    /// Default: 500 ms.
162    pub interval: Duration,
163
164    /// WAL page count above which a warning is logged.
165    ///
166    /// Overridable via `KHIVE_WAL_WARN_PAGES`.
167    /// Default: 2000 pages (~8 MB at 4 KiB page size).
168    pub warn_pages: u64,
169
170    /// Number of consecutive observed ticks with `wal_pages >= warn_pages`
171    /// required before the ADR-091 severity ladder escalates from INFO
172    /// (first crossing) to WARN (sustained pressure). Edge-triggered once
173    /// per elevation episode — see [`CheckpointSeverityState`].
174    ///
175    /// Overridable via `KHIVE_WAL_WARN_SUSTAINED_CYCLES`.
176    /// Default: 3 cycles.
177    pub warn_sustained_cycles: u8,
178
179    /// WAL page count above which a high-pressure WARNING is logged.
180    ///
181    /// The periodic task always runs PASSIVE regardless; this threshold signals
182    /// that a long-lived reader may be pinning an old WAL snapshot that PASSIVE
183    /// cannot reclaim. An operator can then schedule a blocking TRUNCATE at a
184    /// safe moment outside normal write traffic.
185    ///
186    /// Overridable via `KHIVE_WAL_HIGH_WATER_PAGES`.
187    /// Default: 6000 pages (~24 MB at 4 KiB page size).
188    pub high_water_pages: u64,
189
190    /// WAL page count above which a TRUNCATE escalation attempt is armed
191    /// (ADR-091 Plank 2).
192    ///
193    /// This is a separate, much higher threshold than `high_water_pages`:
194    /// crossing it does not itself attempt TRUNCATE — it only arms the
195    /// attempt, which additionally requires `truncate_min_interval` to have
196    /// elapsed since the last attempt.
197    ///
198    /// Overridable via `KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES`.
199    /// Default: 20000 pages.
200    pub truncate_high_water_pages: u64,
201
202    /// Minimum spacing between TRUNCATE *attempts* (not successes).
203    ///
204    /// A skipped tick (writer busy, below threshold, or interval not yet
205    /// elapsed) never advances the "last attempt" clock, so the next tick
206    /// where the writer is free and the threshold is still crossed is
207    /// immediately eligible rather than waiting out the full interval again.
208    ///
209    /// Overridable via `KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS`.
210    /// Default: 300 seconds (5 minutes).
211    pub truncate_min_interval: Duration,
212
213    /// Temporary `busy_timeout` used only for the duration of a TRUNCATE
214    /// attempt, restored to the pool's configured busy timeout immediately
215    /// after the attempt completes (win or lose).
216    ///
217    /// Overridable via `KHIVE_WAL_TRUNCATE_BUSY_MS`.
218    /// Default: 2000 ms.
219    pub truncate_busy_timeout: Duration,
220
221    /// ADR-091 Plank 1 soft cap: age past which the oldest entry in the
222    /// shared open-transaction registry is surfaced at `tracing::warn!` on
223    /// every tick (Skipped or Observed), independent of WAL page pressure.
224    /// See `crates/khive-db/docs/api/checkpoint.md` for the Plank 1 rationale.
225    ///
226    /// Overridable via `KHIVE_TX_WARN_SECS`.
227    /// Default: 30 seconds.
228    pub tx_warn_secs: Duration,
229
230    /// ADR-091 Plank 1 hard cap: age past which the same sweep escalates the
231    /// oldest registry entry to `tracing::error!`. This is visibility only —
232    /// nothing here can force-close a stale span; see
233    /// `crates/khive-db/docs/design.md` for why.
234    ///
235    /// Overridable via `KHIVE_TX_MAX_AGE_SECS`.
236    /// Default: 120 seconds.
237    pub tx_max_age_secs: Duration,
238}
239
240impl Default for CheckpointConfig {
241    fn default() -> Self {
242        Self {
243            interval: Duration::from_millis(500),
244            warn_pages: 2000,
245            warn_sustained_cycles: DEFAULT_WARN_SUSTAINED_CYCLES,
246            high_water_pages: 6000,
247            truncate_high_water_pages: 20_000,
248            truncate_min_interval: Duration::from_secs(300),
249            truncate_busy_timeout: Duration::from_millis(2000),
250            tx_warn_secs: Duration::from_secs(30),
251            tx_max_age_secs: Duration::from_secs(120),
252        }
253    }
254}
255
256impl CheckpointConfig {
257    /// Build a `CheckpointConfig` from the environment.
258    ///
259    /// Unset or unparseable variables fall back to the compiled-in defaults.
260    pub fn from_env() -> Self {
261        let mut cfg = Self::default();
262
263        if let Ok(ms) = std::env::var("KHIVE_CHECKPOINT_INTERVAL_MS") {
264            if let Ok(v) = ms.parse::<u64>() {
265                if v > 0 {
266                    cfg.interval = Duration::from_millis(v);
267                }
268            }
269        }
270
271        if let Ok(v) = std::env::var("KHIVE_WAL_WARN_PAGES") {
272            if let Ok(n) = v.parse::<u64>() {
273                if n > 0 {
274                    cfg.warn_pages = n;
275                }
276            }
277        }
278
279        if let Ok(v) = std::env::var("KHIVE_WAL_WARN_SUSTAINED_CYCLES") {
280            if let Ok(n) = v.parse::<u8>() {
281                if n > 0 {
282                    cfg.warn_sustained_cycles = n;
283                }
284            }
285        }
286
287        if let Ok(v) = std::env::var("KHIVE_WAL_HIGH_WATER_PAGES") {
288            if let Ok(n) = v.parse::<u64>() {
289                if n > 0 {
290                    cfg.high_water_pages = n;
291                }
292            }
293        }
294
295        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES") {
296            if let Ok(n) = v.parse::<u64>() {
297                if n > 0 {
298                    cfg.truncate_high_water_pages = n;
299                }
300            }
301        }
302
303        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS") {
304            if let Ok(n) = v.parse::<u64>() {
305                if n > 0 {
306                    cfg.truncate_min_interval = Duration::from_secs(n);
307                }
308            }
309        }
310
311        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_BUSY_MS") {
312            if let Ok(n) = v.parse::<u64>() {
313                if n > 0 {
314                    cfg.truncate_busy_timeout = Duration::from_millis(n);
315                }
316            }
317        }
318
319        if let Ok(v) = std::env::var("KHIVE_TX_WARN_SECS") {
320            if let Ok(n) = v.parse::<u64>() {
321                if n > 0 {
322                    cfg.tx_warn_secs = Duration::from_secs(n);
323                }
324            }
325        }
326
327        if let Ok(v) = std::env::var("KHIVE_TX_MAX_AGE_SECS") {
328            if let Ok(n) = v.parse::<u64>() {
329                if n > 0 {
330                    cfg.tx_max_age_secs = Duration::from_secs(n);
331                }
332            }
333        }
334
335        // The severity ladder assumes tx_warn_secs < tx_max_age_secs (Warn
336        // fires before Stale as an entry ages). A reversed or equal pair —
337        // whether from one misconfigured var or the interaction of both —
338        // would invert or collapse that ordering (e.g. WARN_SECS=120,
339        // MAX_AGE_SECS=30 emits Stale at 30s and never reaches the Warn
340        // crossing until 120s), so both are rejected together rather than
341        // silently honored. Resetting both to their defaults (rather than
342        // just clamping one) avoids guessing which of the two the operator
343        // actually meant to change.
344        if cfg.tx_warn_secs >= cfg.tx_max_age_secs {
345            let default = Self::default();
346            tracing::warn!(
347                configured_tx_warn_secs = cfg.tx_warn_secs.as_secs_f64(),
348                configured_tx_max_age_secs = cfg.tx_max_age_secs.as_secs_f64(),
349                fallback_tx_warn_secs = default.tx_warn_secs.as_secs_f64(),
350                fallback_tx_max_age_secs = default.tx_max_age_secs.as_secs_f64(),
351                "KHIVE_TX_WARN_SECS must be strictly less than KHIVE_TX_MAX_AGE_SECS; \
352                 both transaction-age thresholds were rejected and reset to their defaults"
353            );
354            cfg.tx_warn_secs = default.tx_warn_secs;
355            cfg.tx_max_age_secs = default.tx_max_age_secs;
356        }
357
358        cfg
359    }
360}
361
362/// Mutable escalation state carried across ticks by the caller (ADR-091 Plank 2).
363///
364/// Kept separate from [`CheckpointConfig`] because it is *state*, not
365/// configuration: `last_attempt` and `consecutive_failures` mutate every tick,
366/// while `CheckpointConfig` is parsed once and held immutable for the life of
367/// the task.
368#[derive(Debug, Default)]
369pub struct TruncateState {
370    /// When the last TRUNCATE *attempt* ran (armed + writer held), regardless
371    /// of whether it succeeded in reclaiming pages. `None` means no attempt
372    /// has ever run, so the first armed tick is immediately eligible.
373    last_attempt: Option<Instant>,
374    /// Count of consecutive TRUNCATE attempts that failed to bring `wal_pages`
375    /// back below `warn_pages`. Resets to 0 the first time an attempt clears
376    /// `warn_pages`; used to fire a one-shot escalated WARN at exactly 3
377    /// consecutive failures (does not repeat every subsequent attempt).
378    consecutive_failures: u32,
379}
380
381/// ADR-091 graduated severity rung for sustained WAL pressure.
382///
383/// `Alarm` is never produced by [`CheckpointSeverityState::observe_wal_pages`]
384/// — it labels the existing TRUNCATE-escalation tier (`maybe_truncate`),
385/// which is gated on its own threshold/interval state, not on this ladder.
386/// It exists here so callers and tests can name all three rungs uniformly.
387#[derive(Debug, Clone, Copy, PartialEq, Eq)]
388pub enum CheckpointSeverityRung {
389    /// First observed tick crossing `warn_pages` after a below-warn tick.
390    Info,
391    /// `warn_sustained_cycles` consecutive observed ticks at/above
392    /// `warn_pages`; edge-triggered once per elevation episode.
393    Warn,
394    /// The TRUNCATE-escalation tier (`checkpoint_high_water_pages` and
395    /// above); never emitted by `observe_wal_pages`.
396    Alarm,
397}
398
399/// ADR-091 severity ladder state, carried across ticks by the caller
400/// alongside [`TruncateState`]. Pure state machine: no I/O, no logging —
401/// callers turn the returned emissions into `tracing` calls.
402#[derive(Debug, Default, Clone)]
403pub struct CheckpointSeverityState {
404    /// Whether the previous observed tick was at/above `warn_pages`. Drives
405    /// the below→above edge that fires INFO.
406    was_above_warn: bool,
407    /// Run-length of consecutive observed ticks at/above `warn_pages` in the
408    /// current elevation episode. Resets to 0 on any below-warn tick.
409    consecutive_above_warn: u8,
410    /// Whether WARN has already fired for the current elevation episode, so
411    /// sustained pressure logs WARN once per episode, not once per tick past
412    /// the threshold.
413    warn_emitted_for_episode: bool,
414}
415
416/// One severity-ladder emission produced by a single
417/// [`CheckpointSeverityState::observe_wal_pages`] call.
418#[derive(Debug, Clone, Copy, PartialEq, Eq)]
419pub struct CheckpointSeverityEmission {
420    /// Which rung this emission represents (`Info` or `Warn`; see
421    /// [`CheckpointSeverityRung::Alarm`] doc for why `Alarm` never appears
422    /// here).
423    pub rung: CheckpointSeverityRung,
424    /// The WAL page count observed on the tick that produced this emission.
425    pub wal_pages: u64,
426    /// The `warn_pages` threshold in effect for this tick.
427    pub threshold_pages: u64,
428    /// Consecutive above-warn cycle count as of this tick (1 on the INFO
429    /// edge, `warn_sustained_cycles` on the WARN edge).
430    pub consecutive_cycles: u8,
431}
432
433impl CheckpointSeverityState {
434    /// Advance the severity ladder by one observed tick and return every
435    /// rung crossed on this tick (zero, one, or two emissions: a fresh
436    /// elevation episode can produce INFO and, if `warn_sustained_cycles`
437    /// is 1, WARN on the very same tick).
438    ///
439    /// A below-warn tick resets both the consecutive-cycle counter and the
440    /// per-episode WARN latch, re-arming INFO/WARN for a later episode.
441    /// Skipped ticks must not be passed here at all — the caller only calls
442    /// this on `CheckpointTick::Observed`, matching the existing
443    /// threshold-crossing WARN's skip-leaves-state-unchanged rule.
444    pub fn observe_wal_pages(
445        &mut self,
446        wal_pages: u64,
447        config: &CheckpointConfig,
448    ) -> Vec<CheckpointSeverityEmission> {
449        let mut emissions = Vec::new();
450        let above_warn = wal_pages >= config.warn_pages;
451
452        if above_warn {
453            self.consecutive_above_warn = self.consecutive_above_warn.saturating_add(1);
454
455            if !self.was_above_warn {
456                emissions.push(CheckpointSeverityEmission {
457                    rung: CheckpointSeverityRung::Info,
458                    wal_pages,
459                    threshold_pages: config.warn_pages,
460                    consecutive_cycles: self.consecutive_above_warn,
461                });
462            }
463
464            if !self.warn_emitted_for_episode
465                && self.consecutive_above_warn >= config.warn_sustained_cycles
466            {
467                emissions.push(CheckpointSeverityEmission {
468                    rung: CheckpointSeverityRung::Warn,
469                    wal_pages,
470                    threshold_pages: config.warn_pages,
471                    consecutive_cycles: self.consecutive_above_warn,
472                });
473                self.warn_emitted_for_episode = true;
474            }
475        } else {
476            self.consecutive_above_warn = 0;
477            self.warn_emitted_for_episode = false;
478        }
479
480        self.was_above_warn = above_warn;
481        emissions
482    }
483}
484
485/// ADR-091 Plank 1 rung for the open-transaction registry's background age
486/// sweep: independent of the WAL-pressure ladder above, keyed purely off how
487/// long the registry's oldest entry has been open.
488#[derive(Debug, Clone, Copy, PartialEq, Eq)]
489pub enum TxAgeRung {
490    /// The oldest registry entry's age crossed `tx_warn_secs`.
491    Warn,
492    /// The oldest registry entry's age crossed `tx_max_age_secs` — the ADR's
493    /// "cooperative stale-op guard" cap. No in-process mechanism force-closes
494    /// it (see [`CheckpointConfig::tx_max_age_secs`]); this rung is the
495    /// sweep's strongest available signal.
496    Stale,
497}
498
499/// One emission produced by a single [`TxAgeSweepState::observe`] call.
500#[derive(Debug, Clone, PartialEq, Eq)]
501pub struct TxAgeEmission {
502    pub rung: TxAgeRung,
503    pub age: Duration,
504    pub label: Option<String>,
505}
506
507/// ADR-091 Plank 1 background-sweep state, carried across ticks by the
508/// caller alongside [`CheckpointSeverityState`] and [`TruncateState`]. Pure
509/// state machine: no I/O, no logging — callers turn the returned emissions
510/// into `tracing` calls, mirroring [`CheckpointSeverityState`]'s shape.
511///
512/// Keyed off `khive_storage::tx_registry::oldest()` — the single oldest
513/// entry across every registered span, regardless of which call site created
514/// it. Deliberately a different signal from the WAL-pressure ladder: a span
515/// can go stale under low WAL pressure, or vice versa. See
516/// `crates/khive-db/docs/api/checkpoint.md` for the full rationale.
517#[derive(Debug, Default, Clone)]
518pub struct TxAgeSweepState {
519    /// Whether the previous observed tick's oldest entry was at/above
520    /// `tx_warn_secs`. Drives the below→above edge that fires `Warn`.
521    was_above_warn: bool,
522    /// Whether the previous observed tick's oldest entry was at/above
523    /// `tx_max_age_secs`. Drives the below→above edge that fires `Stale`.
524    was_above_max_age: bool,
525    /// Identity of the entry the previous observed tick reported as oldest,
526    /// or `None` if the registry was empty. Tracked separately from the two
527    /// latches above so a change in *which span* is oldest can be detected
528    /// even when both latches are already `true` (see [`Self::observe`]).
529    tracked_id: Option<khive_storage::tx_registry::TxId>,
530}
531
532impl TxAgeSweepState {
533    /// Advance by one observed tick given the registry's current oldest
534    /// entry (identity, age, label), or `None` if empty. Returns zero, one,
535    /// or two emissions — an entry already stale the first time it's seen
536    /// under a given identity crosses both rungs on the same tick.
537    ///
538    /// A below-threshold (or absent) oldest entry resets both latches. A
539    /// change in the oldest entry's [`TxId`](khive_storage::tx_registry::TxId)
540    /// also force-resets both latches before re-evaluating age, so a
541    /// departed span's latched state cannot suppress the crossing for an
542    /// already-stale successor. See `crates/khive-db/docs/api/checkpoint.md`
543    /// for why identity tracking is required here, not just the age check.
544    pub fn observe(
545        &mut self,
546        oldest: Option<(khive_storage::tx_registry::TxId, Duration, Option<String>)>,
547        config: &CheckpointConfig,
548    ) -> Vec<TxAgeEmission> {
549        let mut emissions = Vec::new();
550
551        let Some((id, age, label)) = oldest else {
552            self.was_above_warn = false;
553            self.was_above_max_age = false;
554            self.tracked_id = None;
555            return emissions;
556        };
557
558        if self.tracked_id != Some(id) {
559            self.was_above_warn = false;
560            self.was_above_max_age = false;
561        }
562        self.tracked_id = Some(id);
563
564        let above_warn = age >= config.tx_warn_secs;
565        let above_max_age = age >= config.tx_max_age_secs;
566
567        if above_warn && !self.was_above_warn {
568            emissions.push(TxAgeEmission {
569                rung: TxAgeRung::Warn,
570                age,
571                label: label.clone(),
572            });
573        }
574        if above_max_age && !self.was_above_max_age {
575            emissions.push(TxAgeEmission {
576                rung: TxAgeRung::Stale,
577                age,
578                label,
579            });
580        }
581
582        self.was_above_warn = above_warn;
583        self.was_above_max_age = above_max_age;
584        emissions
585    }
586}
587
588/// ADR-091 Plank 1: turn a [`TxAgeEmission`] into the appropriate `tracing`
589/// call. Extracted from `run_checkpoint_task` so tests can drive the same
590/// logging path `CaptureSubscriber`-style without spinning up the async task
591/// (mirrors [`log_tx_registry_oldest_warn`]/[`log_tx_registry_snapshot_warn`]).
592fn log_tx_age_emission(emission: &TxAgeEmission) {
593    let label = emission.label.as_deref().unwrap_or("<unlabeled>");
594    match emission.rung {
595        TxAgeRung::Warn => {
596            tracing::warn!(
597                tx_age_secs = emission.age.as_secs_f64(),
598                tx_label = label,
599                "ADR-091 Plank 1: open transaction registry entry exceeded soft-cap age"
600            );
601        }
602        TxAgeRung::Stale => {
603            tracing::error!(
604                tx_age_secs = emission.age.as_secs_f64(),
605                tx_label = label,
606                "ADR-091 Plank 1: open transaction registry entry exceeded the cooperative \
607                 stale-op cap; no in-process mechanism can force-close it — investigate the \
608                 labeled caller directly"
609            );
610        }
611    }
612}
613
614/// Run the WAL checkpoint background task.
615///
616/// Long-running async task — spawn with `tokio::spawn`. Loops until
617/// `shutdown_rx` observes a change (or its sender is dropped). Callers MUST
618/// hold the paired `tokio::sync::watch::Sender` for the daemon's run scope
619/// and send on it to shut down — do NOT rely on `pool`'s `Arc` refcount
620/// reaching zero; a sibling owner (e.g. `event_store`) holding its own clone
621/// makes that check unreachable (issue #774).
622///
623/// Issues `PRAGMA wal_checkpoint(PASSIVE)` every tick via `try_writer_nowait`
624/// (zero-wait try-lock): a busy writer skips the tick rather than stalling
625/// write traffic. A WARNING fires once per below→above threshold crossing,
626/// not every tick.
627///
628/// `event_store` (ADR-094): when `Some`, appends a best-effort
629/// `CheckpointOutcomeRecorded` event on every at/above-`warn_pages` tick,
630/// plus one drain row when pressure falls back below `warn_pages`. `None` is
631/// a no-op. See `crates/khive-db/docs/api/checkpoint.md` for the full
632/// shutdown-mechanism and event-emission design history.
633pub async fn run_checkpoint_task(
634    pool: Arc<ConnectionPool>,
635    config: CheckpointConfig,
636    event_store: Option<Arc<dyn khive_storage::EventStore>>,
637    namespace: String,
638    mut shutdown_rx: tokio::sync::watch::Receiver<()>,
639) {
640    let mut interval = tokio::time::interval(config.interval);
641    interval.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip);
642    let mut severity_state = CheckpointSeverityState::default();
643    let mut tx_age_state = TxAgeSweepState::default();
644    let mut was_above_high_water = false;
645    let mut truncate_state = TruncateState::default();
646    // Independent of `severity_state` (which owns the WARN-episode ladder
647    // internally): this tracks only the "was the previous observed tick
648    // elevated" edge the ADR-094 event emission needs, so the event path
649    // never has to reach into the severity state machine's private fields.
650    let mut event_was_elevated = false;
651
652    loop {
653        // A closed sender (the daemon returning without an explicit send)
654        // makes `changed()` resolve with `Err` immediately, which `select!`
655        // treats as ready — so shutdown is observed either way, not just on
656        // an explicit send.
657        tokio::select! {
658            _ = interval.tick() => {}
659            _ = shutdown_rx.changed() => break,
660        }
661
662        let tick = checkpoint_once(&pool, &config, &mut truncate_state);
663
664        // ADR-091 Plank 1: age-based sweep over the registry's oldest entry
665        // MUST run on every tick, including a Skipped one — deliberately
666        // BEFORE the Skipped early-continue below. A registered
667        // `WriterGuard::transaction` span (`pool.rs`) holds the writer mutex
668        // for its entire registered lifetime, so exactly the long-running
669        // transaction this sweep exists to name is the one that makes an
670        // ordinary checkpoint tick observe `Skipped` — gating the sweep on
671        // `Observed` would silence it for precisely that scenario, defeating
672        // the WAL-independent diagnostic the ADR specifies. Independent of
673        // WAL page pressure by the same design: a registered span can go
674        // stale (KHIVE_TX_WARN_SECS / KHIVE_TX_MAX_AGE_SECS) while
675        // wal_pages sits well under warn_pages, or isn't sampled at all this
676        // tick. Edge-triggered per rung, same debounce idiom as the severity
677        // ladder below, so a sustained stale span logs once per rung rather
678        // than once per tick.
679        for emission in tx_age_state.observe(khive_storage::tx_registry::oldest(), &config) {
680            log_tx_age_emission(&emission);
681        }
682
683        // Skipped ticks leave crossing state unchanged — a busy tick must not
684        // re-arm the rate limit while WAL pressure is still elevated.
685        let wal_pages = match tick {
686            CheckpointTick::Skipped => continue,
687            CheckpointTick::Observed(n) => n,
688        };
689
690        let above_warn = wal_pages >= config.warn_pages;
691        let above_high_water = wal_pages >= config.high_water_pages;
692        let above_truncate_high_water = wal_pages >= config.truncate_high_water_pages;
693
694        // Per-tick debug for the oldest open entry always fires (cheap, single
695        // `oldest()` lookup); the two `warn!`-level registry logs below are
696        // gated on the SAME crossing state as the WAL-threshold WARNs above,
697        // so sustained pressure logs once per crossing, not once per tick.
698        log_tx_registry_oldest_debug(wal_pages);
699
700        // ADR-091 severity ladder: INFO on the first below→above crossing,
701        // WARN once `warn_sustained_cycles` consecutive ticks stay elevated.
702        // The oldest-entry registry WARN rides the same INFO edge the old
703        // binary crossing_warn used to gate on.
704        for emission in severity_state.observe_wal_pages(wal_pages, &config) {
705            match emission.rung {
706                CheckpointSeverityRung::Info => {
707                    log_tx_registry_oldest_warn(wal_pages);
708                    tracing::info!(
709                        wal_pages = emission.wal_pages,
710                        warn_threshold = emission.threshold_pages,
711                        "WAL page count crossed warn threshold"
712                    );
713                }
714                CheckpointSeverityRung::Warn => {
715                    tracing::warn!(
716                        wal_pages = emission.wal_pages,
717                        warn_threshold = emission.threshold_pages,
718                        consecutive_cycles = emission.consecutive_cycles,
719                        "WAL page count failed to drain below warn threshold"
720                    );
721                }
722                CheckpointSeverityRung::Alarm => {
723                    // Never produced by `observe_wal_pages`; see its doc.
724                }
725            }
726        }
727
728        let high_water_crossed = crossing_warn(above_high_water, &mut was_above_high_water);
729        if high_water_crossed {
730            log_tx_registry_snapshot_warn(wal_pages);
731            tracing::warn!(
732                wal_pages,
733                high_water = config.high_water_pages,
734                "WAL high-water mark exceeded; sustained WAL pressure — \
735                 a long-lived reader may be pinning an old snapshot that PASSIVE cannot reclaim"
736            );
737        }
738
739        // ADR-094: emit every elevated tick, plus exactly one drain row on
740        // the tick that observes the episode end — never on every ordinary
741        // below-warn tick.
742        if checkpoint_outcome_should_emit(above_warn, event_was_elevated) {
743            let payload = khive_storage::CheckpointOutcomeRecordedPayload {
744                wal_pages,
745                warn_pages: config.warn_pages,
746                high_water_pages: config.high_water_pages,
747                truncate_high_water_pages: config.truncate_high_water_pages,
748                above_warn,
749                above_high_water,
750                above_truncate_high_water,
751            };
752            append_checkpoint_lifecycle_event(
753                event_store.as_ref(),
754                &namespace,
755                khive_types::EventKind::CheckpointOutcomeRecorded,
756                payload,
757            )
758            .await;
759        }
760        event_was_elevated = above_warn;
761    }
762}
763
764/// Whether a `CheckpointOutcomeRecorded` event should be emitted for this
765/// tick: every elevated (`above_warn`) tick, plus exactly one drain row on
766/// the first tick that observes a return to below-warn after an elevated
767/// episode (`was_elevated`). An ordinary below-warn tick following another
768/// below-warn tick emits nothing.
769fn checkpoint_outcome_should_emit(above_warn: bool, was_elevated: bool) -> bool {
770    above_warn || was_elevated
771}
772
773/// Append one ADR-094 lifecycle event on behalf of the checkpoint task.
774///
775/// Best-effort: `event_store == None` is a no-op, and an append failure is
776/// logged and swallowed. No lifecycle-append error may ever interrupt or
777/// slow down checkpoint/TRUNCATE work — the checkpoint task's correctness
778/// does not depend on this succeeding.
779async fn append_checkpoint_lifecycle_event<P: serde::Serialize>(
780    store: Option<&Arc<dyn khive_storage::EventStore>>,
781    namespace: &str,
782    kind: khive_types::EventKind,
783    payload: P,
784) {
785    let Some(store) = store else {
786        return;
787    };
788    let payload_value = match serde_json::to_value(&payload) {
789        Ok(v) => v,
790        Err(e) => {
791            tracing::warn!(
792                error = %e,
793                event_kind = %kind.name(),
794                "failed to serialize checkpoint lifecycle event payload"
795            );
796            return;
797        }
798    };
799    let event = khive_storage::Event::new(
800        namespace,
801        "checkpoint.lifecycle",
802        kind,
803        khive_types::SubstrateKind::Event,
804        "daemon:checkpoint_task",
805    )
806    .with_payload(payload_value);
807    if let Err(err) = store.append_event(event).await {
808        tracing::warn!(
809            error = %err,
810            event_kind = %kind.name(),
811            "checkpoint lifecycle event append failed"
812        );
813    }
814}
815
816/// ADR-091 Plank 0: log the oldest open transaction registry entry alongside
817/// the WAL frame count at `debug!`, on EVERY tick regardless of threshold
818/// state. This is the low-volume per-tick trace; the WARN-level escalations
819/// live in [`log_tx_registry_oldest_warn`] and
820/// debug-level, unconditional per-tick trace. See
821/// crates/khive-db/docs/api/checkpoint.md#private-tx-registry-logging-helpers-plank-0
822fn log_tx_registry_oldest_debug(wal_pages: u64) {
823    if let Some((_id, age, label)) = khive_storage::tx_registry::oldest() {
824        tracing::debug!(
825            wal_pages,
826            oldest_tx_age_secs = age.as_secs_f64(),
827            oldest_tx_label = label.as_deref().unwrap_or("<unlabeled>"),
828            "WAL checkpoint tick: oldest open transaction registry entry"
829        );
830    }
831}
832
833/// Escalates the oldest open registry entry to `warn!`. NOT internally
834/// rate-limited — caller MUST gate on a below→above `warn_pages` crossing
835/// (`crossing_warn`) or every tick reproduces the log-spam bug this fixes.
836fn log_tx_registry_oldest_warn(wal_pages: u64) {
837    if let Some((_id, age, label)) = khive_storage::tx_registry::oldest() {
838        tracing::warn!(
839            wal_pages,
840            oldest_tx_age_secs = age.as_secs_f64(),
841            oldest_tx_label = label.as_deref().unwrap_or("<unlabeled>"),
842            "WAL checkpoint tick: oldest open transaction registry entry"
843        );
844    }
845}
846
847/// Enumerates every open registry entry at `warn!`. NOT internally
848/// rate-limited — caller MUST gate on a below→above `high_water_pages`
849/// crossing (`crossing_warn`) or every tick repeats the full enumeration.
850fn log_tx_registry_snapshot_warn(wal_pages: u64) {
851    for (age, label) in khive_storage::tx_registry::snapshot() {
852        tracing::warn!(
853            wal_pages,
854            tx_age_secs = age.as_secs_f64(),
855            tx_label = label.as_deref().unwrap_or("<unlabeled>"),
856            "WAL high-water: open transaction registry entry"
857        );
858    }
859}
860
861/// Issue one checkpoint cycle against the writer connection.
862///
863/// Returns [`CheckpointTick::Skipped`] when the writer mutex is already held
864/// (the tick is a no-op) and [`CheckpointTick::Observed`] with the WAL page
865/// count otherwise. All checkpoint errors are logged at warn level and treated
866/// as non-fatal; the next tick retries.
867///
868/// Uses `try_writer_nowait` so that a busy active writer causes this tick to
869/// be skipped immediately rather than stalling for up to `checkout_timeout`.
870/// The caller (`run_checkpoint_task`) owns all threshold-crossing WARN logging
871/// so that warnings fire at most once per crossing, not every tick.
872///
873/// ADR-091 Plank 2: after the PASSIVE pass, this is also the single point
874/// that may escalate to TRUNCATE (`maybe_truncate`) — under the SAME writer
875/// guard acquired above, never a second checkout. A busy writer (`Skipped`)
876/// short-circuits before either PASSIVE or TRUNCATE run.
877pub fn checkpoint_once(
878    pool: &ConnectionPool,
879    config: &CheckpointConfig,
880    truncate_state: &mut TruncateState,
881) -> CheckpointTick {
882    let writer = match pool.try_writer_nowait() {
883        Ok(w) => w,
884        Err(_) => {
885            note_checkpoint_skipped();
886            return CheckpointTick::Skipped;
887        }
888    };
889
890    let wal_pages = query_wal_pages(writer.conn());
891
892    if let Err(e) = writer
893        .conn()
894        .execute_batch("PRAGMA wal_checkpoint(PASSIVE)")
895    {
896        tracing::warn!(error = %e, "WAL checkpoint failed");
897    } else {
898        tracing::debug!(wal_pages, "WAL checkpoint issued");
899    }
900
901    maybe_truncate(pool, &writer, config, wal_pages, truncate_state);
902
903    CheckpointTick::Observed(wal_pages)
904}
905
906/// Evaluate and, if due, attempt a TRUNCATE escalation under the writer
907/// guard the caller already holds (never its own checkout). `last_attempt`
908/// is stamped ONLY on an actual attempt, never on a skip. See
909/// crates/khive-db/docs/api/checkpoint.md#maybe_truncate--truncate-attempt-gating-plank-2
910fn maybe_truncate(
911    pool: &ConnectionPool,
912    writer: &WriterGuard<'_>,
913    config: &CheckpointConfig,
914    wal_pages_before: u64,
915    truncate_state: &mut TruncateState,
916) {
917    if wal_pages_before < config.truncate_high_water_pages {
918        return;
919    }
920
921    if let Some(last) = truncate_state.last_attempt {
922        if last.elapsed() < config.truncate_min_interval {
923            return;
924        }
925    }
926
927    // Which caller (if any) is pinning the WAL — logged before the attempt so
928    // it is available even if the attempt itself succeeds.
929    log_tx_registry_snapshot_warn(wal_pages_before);
930
931    let conn = writer.conn();
932    let original_busy_timeout = pool.config().busy_timeout;
933
934    if let Err(e) = conn.busy_timeout(config.truncate_busy_timeout) {
935        // Setup failed before the TRUNCATE pragma ever ran — this is a skip,
936        // not an attempt. `last_attempt` must NOT advance here (ADR-091
937        // §377-382): stamping now would suppress the next eligible attempt
938        // for the full `truncate_min_interval` on a path that never touched
939        // the WAL at all.
940        tracing::warn!(error = %e, "failed to lower busy_timeout for TRUNCATE attempt; skipping");
941        return;
942    }
943
944    // Only now is this a genuine attempt: the writer is held, the threshold
945    // and interval gates passed, and the busy_timeout override is in effect
946    // immediately before the TRUNCATE pragma itself.
947    truncate_state.last_attempt = Some(Instant::now());
948
949    let start = Instant::now();
950    let outcome = conn.execute_batch("PRAGMA wal_checkpoint(TRUNCATE)");
951    let elapsed = start.elapsed();
952
953    // Restore the pool's configured busy_timeout immediately after the
954    // attempt, win or lose, before any other logging or bookkeeping.
955    if let Err(e) = conn.busy_timeout(original_busy_timeout) {
956        tracing::warn!(error = %e, "failed to restore busy_timeout after TRUNCATE attempt");
957    }
958
959    match outcome {
960        Ok(()) => {
961            let wal_pages_after = query_wal_pages(conn);
962            tracing::info!(
963                wal_pages_before,
964                wal_pages_after,
965                elapsed_ms = elapsed.as_millis() as u64,
966                "WAL TRUNCATE checkpoint attempted"
967            );
968
969            let made_progress = wal_pages_after < wal_pages_before;
970            if !made_progress {
971                tracing::warn!(
972                    wal_pages_before,
973                    wal_pages_after,
974                    "WAL TRUNCATE attempt made no progress; \
975                     a long-lived reader may still be pinning the WAL snapshot"
976                );
977                log_tx_registry_snapshot_warn(wal_pages_after);
978            }
979
980            note_truncate_outcome(config, wal_pages_after, truncate_state);
981        }
982        Err(e) => {
983            tracing::warn!(error = %e, wal_pages_before, "WAL TRUNCATE attempt failed");
984            log_tx_registry_snapshot_warn(wal_pages_before);
985            note_truncate_outcome(config, wal_pages_before, truncate_state);
986        }
987    }
988}
989
990/// ADR-091 Plank 2: track consecutive TRUNCATE attempts that fail to bring
991/// `wal_pages` back below `warn_pages`, firing a one-shot escalated WARN at
992/// exactly the third consecutive failure (does not repeat every attempt
993/// thereafter — mirrors the crossing-WARN debounce used elsewhere in this
994/// module). A single attempt that clears `warn_pages` resets the counter.
995fn note_truncate_outcome(
996    config: &CheckpointConfig,
997    wal_pages_after: u64,
998    state: &mut TruncateState,
999) {
1000    // Metrics read-surface (load/perf harness): this function runs exactly
1001    // once per genuine TRUNCATE attempt (both the `Ok` and `Err` outcome
1002    // arms in `maybe_truncate` call it once each), so incrementing here
1003    // counts total attempts without a separate call site.
1004    TRUNCATE_ATTEMPTS.fetch_add(1, Ordering::Relaxed);
1005
1006    if wal_pages_after >= config.warn_pages {
1007        state.consecutive_failures = state.consecutive_failures.saturating_add(1);
1008        if state.consecutive_failures == 3 {
1009            tracing::warn!(
1010                wal_pages_after,
1011                warn_threshold = config.warn_pages,
1012                "WAL TRUNCATE has failed to clear WAL pressure for 3 consecutive attempts"
1013            );
1014        }
1015    } else {
1016        state.consecutive_failures = 0;
1017    }
1018
1019    TRUNCATE_CONSECUTIVE_FAILURES.store(state.consecutive_failures as u64, Ordering::Relaxed);
1020}
1021
1022/// Evaluate whether a threshold-crossing WARN should fire and advance the
1023/// crossing-state flag.
1024///
1025/// Returns `true` on a false→true transition in `now_above` (first observed
1026/// above-threshold tick after a below-threshold tick), `false` on any other
1027/// tick. The `was_above` flag is updated in-place to track state across calls.
1028/// Used by `run_checkpoint_task` for both the `warn_pages` band and the
1029/// `high_water_pages` threshold.
1030fn crossing_warn(now_above: bool, was_above: &mut bool) -> bool {
1031    let fire = now_above && !*was_above;
1032    *was_above = now_above;
1033    fire
1034}
1035
1036/// Query the current WAL frame count via `PRAGMA wal_checkpoint`.
1037///
1038/// The pragma returns a 3-column row `(busy, log, checkpointed)`, where `log`
1039/// (column index 1) is the number of frames currently in the WAL file — the
1040/// backlog the high-water threshold keys off. (Column 2 is `checkpointed`, the
1041/// frames moved *by this call*, which is not the WAL size.) The no-arg pragma
1042/// also performs a PASSIVE checkpoint as a side effect; the subsequent explicit
1043/// `PRAGMA wal_checkpoint(PASSIVE)` in `checkpoint_once` is a deliberate second
1044/// pass that can checkpoint any frames written between the two calls.
1045///
1046/// Returns 0 on any error (e.g. in-memory DB where WAL is not active, which
1047/// reports `log = -1`).
1048fn query_wal_pages(conn: &rusqlite::Connection) -> u64 {
1049    let pages = conn
1050        .query_row("PRAGMA wal_checkpoint", [], |row| row.get::<_, i64>(1))
1051        .unwrap_or(0)
1052        .max(0) as u64;
1053    // Metrics read-surface (load/perf harness): mirror every observation into
1054    // the process-wide gauge, regardless of which caller (`checkpoint_once`
1055    // or `maybe_truncate`) triggered it.
1056    LAST_WAL_PAGES.store(pages, Ordering::Relaxed);
1057    note_checkpoint_observed(pages);
1058    pages
1059}
1060
1061#[cfg(test)]
1062mod tests {
1063    use super::*;
1064    use crate::pool::PoolConfig;
1065    use serial_test::serial;
1066    use tracing::field::{Field, Visit};
1067
1068    #[derive(Clone, Debug, Default)]
1069    struct CapturedEvent {
1070        message: Option<String>,
1071        oldest_tx_label: Option<String>,
1072        tx_label: Option<String>,
1073    }
1074
1075    #[derive(Default)]
1076    struct CapturedEventVisitor(CapturedEvent);
1077
1078    impl Visit for CapturedEventVisitor {
1079        fn record_str(&mut self, field: &Field, value: &str) {
1080            match field.name() {
1081                "message" => self.0.message = Some(value.to_string()),
1082                "oldest_tx_label" => self.0.oldest_tx_label = Some(value.to_string()),
1083                "tx_label" => self.0.tx_label = Some(value.to_string()),
1084                _ => {}
1085            }
1086        }
1087
1088        fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
1089            let formatted = format!("{value:?}");
1090            let cleaned = formatted
1091                .trim_start_matches('"')
1092                .trim_end_matches('"')
1093                .to_string();
1094            match field.name() {
1095                "message" => self.0.message = Some(cleaned),
1096                "oldest_tx_label" => self.0.oldest_tx_label = Some(cleaned),
1097                "tx_label" => self.0.tx_label = Some(cleaned),
1098                _ => {}
1099            }
1100        }
1101    }
1102
1103    /// Minimal `tracing::Subscriber` that captures events into a thread-local
1104    /// vec, installed as the thread-local default for the duration of one
1105    /// test closure via `tracing::subscriber::with_default`. Mirrors the
1106    /// capture subscriber in `khive-runtime/src/pack.rs`'s gate-dispatch tests.
1107    struct CaptureSubscriber {
1108        events: std::sync::Arc<std::sync::Mutex<Vec<CapturedEvent>>>,
1109    }
1110
1111    impl tracing::Subscriber for CaptureSubscriber {
1112        fn enabled(&self, _: &tracing::Metadata<'_>) -> bool {
1113            true
1114        }
1115        fn new_span(&self, _: &tracing::span::Attributes<'_>) -> tracing::span::Id {
1116            tracing::span::Id::from_u64(1)
1117        }
1118        fn record(&self, _: &tracing::span::Id, _: &tracing::span::Record<'_>) {}
1119        fn record_follows_from(&self, _: &tracing::span::Id, _: &tracing::span::Id) {}
1120        fn event(&self, event: &tracing::Event<'_>) {
1121            let mut visitor = CapturedEventVisitor::default();
1122            event.record(&mut visitor);
1123            self.events.lock().unwrap().push(visitor.0);
1124        }
1125        fn enter(&self, _: &tracing::span::Id) {}
1126        fn exit(&self, _: &tracing::span::Id) {}
1127    }
1128
1129    /// `log_tx_registry_oldest_debug` names the oldest open registry entry.
1130    /// See crates/khive-db/docs/api/checkpoint.md#log_tx_registry_oldest_debug_reports_oldest_open_entry
1131    #[test]
1132    #[serial(tx_registry)]
1133    fn log_tx_registry_oldest_debug_reports_oldest_open_entry() {
1134        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1135        let subscriber = CaptureSubscriber {
1136            events: std::sync::Arc::clone(&buffer),
1137        };
1138
1139        let _handle =
1140            khive_storage::tx_registry::register(Some("checkpoint_tick_test".to_string()));
1141
1142        let expected_label = khive_storage::tx_registry::oldest()
1143            .and_then(|(_, _, label)| label)
1144            .unwrap_or_else(|| "<unlabeled>".to_string());
1145
1146        tracing::subscriber::with_default(subscriber, || {
1147            log_tx_registry_oldest_debug(100);
1148        });
1149
1150        let events = buffer.lock().unwrap();
1151        assert!(
1152            events.iter().any(|e| {
1153                e.message.as_deref()
1154                    == Some("WAL checkpoint tick: oldest open transaction registry entry")
1155                    && e.oldest_tx_label.as_deref() == Some(expected_label.as_str())
1156            }),
1157            "expected a log line naming the open registry entry's label, got: {events:?}"
1158        );
1159    }
1160
1161    /// ADR-091 Plank 0: the oldest-entry WARN and the
1162    /// high-water snapshot-enumeration WARN are gated by `crossing_warn` at
1163    /// the call site (mirroring the WAL-threshold WARNs), so driving two
1164    /// consecutive above-threshold ticks through that same gate must produce
1165    /// exactly one of each — never a repeat on the second tick.
1166    #[test]
1167    #[serial(tx_registry)]
1168    fn registry_warns_fire_on_crossing_and_do_not_repeat() {
1169        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1170        let subscriber = CaptureSubscriber {
1171            events: std::sync::Arc::clone(&buffer),
1172        };
1173
1174        let _handle =
1175            khive_storage::tx_registry::register(Some("registry_warn_crossing_test".to_string()));
1176
1177        let mut was_above_warn = false;
1178        let mut was_above_high_water = false;
1179
1180        tracing::subscriber::with_default(subscriber, || {
1181            // Tick 1: below→above crossing for both bands — both WARNs fire.
1182            if crossing_warn(true, &mut was_above_warn) {
1183                log_tx_registry_oldest_warn(6000);
1184            }
1185            if crossing_warn(true, &mut was_above_high_water) {
1186                log_tx_registry_snapshot_warn(6000);
1187            }
1188
1189            // Tick 2: still above both thresholds — neither must repeat.
1190            if crossing_warn(true, &mut was_above_warn) {
1191                log_tx_registry_oldest_warn(6000);
1192            }
1193            if crossing_warn(true, &mut was_above_high_water) {
1194                log_tx_registry_snapshot_warn(6000);
1195            }
1196        });
1197
1198        let events = buffer.lock().unwrap();
1199
1200        // `tracing::subscriber::with_default` scopes capture to THIS thread for
1201        // the duration of the closure, so `events` contains only the two
1202        // `log_tx_registry_oldest_warn` calls made above — no concurrent test's
1203        // log calls land in this buffer. This lets the crossing/no-repeat
1204        // assertion match on message text alone: unlike the "names MY label"
1205        // assertion in the sibling test above, WHICH label `oldest()` reports
1206        // is irrelevant here (a concurrent write path elsewhere in the binary
1207        // may transiently be the registry's genuine oldest entry) — only the
1208        // fire-once-per-crossing COUNT is under test.
1209        let oldest_warn_count = events
1210            .iter()
1211            .filter(|e| {
1212                e.message.as_deref()
1213                    == Some("WAL checkpoint tick: oldest open transaction registry entry")
1214            })
1215            .count();
1216        assert_eq!(
1217            oldest_warn_count, 1,
1218            "oldest-entry WARN must fire exactly once across two above-threshold ticks, got: {events:?}"
1219        );
1220
1221        let snapshot_warn_count = events
1222            .iter()
1223            .filter(|e| {
1224                e.message.as_deref() == Some("WAL high-water: open transaction registry entry")
1225                    && e.tx_label.as_deref() == Some("registry_warn_crossing_test")
1226            })
1227            .count();
1228        assert_eq!(
1229            snapshot_warn_count, 1,
1230            "high-water snapshot WARN must fire exactly once across two above-threshold ticks, got: {events:?}"
1231        );
1232    }
1233
1234    /// ADR-091 Plank 1: `log_tx_age_emission` emits the correct message text
1235    /// and carries the entry's label, for both the `Warn` and `Stale` rungs.
1236    #[test]
1237    fn log_tx_age_emission_carries_label_for_both_rungs() {
1238        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1239        let subscriber = CaptureSubscriber {
1240            events: std::sync::Arc::clone(&buffer),
1241        };
1242
1243        tracing::subscriber::with_default(subscriber, || {
1244            log_tx_age_emission(&TxAgeEmission {
1245                rung: TxAgeRung::Warn,
1246                age: Duration::from_secs(45),
1247                label: Some("plank1_warn_test".to_string()),
1248            });
1249            log_tx_age_emission(&TxAgeEmission {
1250                rung: TxAgeRung::Stale,
1251                age: Duration::from_secs(150),
1252                label: Some("plank1_stale_test".to_string()),
1253            });
1254        });
1255
1256        let events = buffer.lock().unwrap();
1257        assert!(
1258            events.iter().any(|e| {
1259                e.message.as_deref()
1260                    == Some(
1261                        "ADR-091 Plank 1: open transaction registry entry exceeded soft-cap age",
1262                    )
1263                    && e.tx_label.as_deref() == Some("plank1_warn_test")
1264            }),
1265            "expected a Warn-rung log line naming the entry, got: {events:?}"
1266        );
1267        assert!(
1268            events.iter().any(|e| {
1269                e.message.as_deref().is_some_and(|m| {
1270                    m.starts_with(
1271                        "ADR-091 Plank 1: open transaction registry entry exceeded the cooperative",
1272                    )
1273                }) && e.tx_label.as_deref() == Some("plank1_stale_test")
1274            }),
1275            "expected a Stale-rung log line naming the entry, got: {events:?}"
1276        );
1277    }
1278
1279    fn file_pool(path: &std::path::Path) -> Arc<ConnectionPool> {
1280        let cfg = PoolConfig {
1281            path: Some(path.to_path_buf()),
1282            ..PoolConfig::default()
1283        };
1284        Arc::new(ConnectionPool::new(cfg).expect("pool open"))
1285    }
1286
1287    // `checkpoint_once` -> `query_wal_pages` writes the process-wide
1288    // `LAST_WAL_PAGES` gauge and resets `CHECKPOINT_CONSECUTIVE_SKIPS`
1289    // (see the reset-discipline comment on `reset_checkpoint_metrics_for_tests`
1290    // above) — this must join the `checkpoint_skip_metrics` group so it can
1291    // never interleave with a test asserting on those same gauges.
1292    #[test]
1293    #[serial(checkpoint_skip_metrics)]
1294    fn checkpoint_once_succeeds_on_file_backed_pool() {
1295        let dir = tempfile::tempdir().unwrap();
1296        let path = dir.path().join("wal_test.db");
1297        let pool = file_pool(&path);
1298
1299        // Create a table so the DB is not completely empty.
1300        {
1301            let writer = pool.try_writer().unwrap();
1302            writer
1303                .conn()
1304                .execute_batch("CREATE TABLE IF NOT EXISTS t (x INTEGER);")
1305                .unwrap();
1306            writer
1307                .conn()
1308                .execute_batch("INSERT INTO t VALUES (1);")
1309                .unwrap();
1310        }
1311
1312        checkpoint_once(
1313            &pool,
1314            &CheckpointConfig::default(),
1315            &mut TruncateState::default(),
1316        );
1317    }
1318
1319    #[test]
1320    #[serial(checkpoint_skip_metrics)]
1321    fn checkpoint_once_is_noop_on_in_memory_pool() {
1322        // In-memory databases do not use WAL; checkpoint_once must not panic.
1323        let cfg = PoolConfig {
1324            path: None,
1325            ..PoolConfig::default()
1326        };
1327        let pool = Arc::new(ConnectionPool::new(cfg).expect("in-memory pool"));
1328        checkpoint_once(
1329            &pool,
1330            &CheckpointConfig::default(),
1331            &mut TruncateState::default(),
1332        );
1333    }
1334
1335    #[tokio::test]
1336    #[serial(checkpoint_skip_metrics)]
1337    async fn checkpoint_task_exits_on_shutdown_signal() {
1338        let dir = tempfile::tempdir().unwrap();
1339        let path = dir.path().join("wal_task_shutdown.db");
1340        let pool = file_pool(&path);
1341
1342        // Use a very short interval so the task ticks quickly in the test.
1343        let cfg = CheckpointConfig {
1344            interval: Duration::from_millis(10),
1345            ..Default::default()
1346        };
1347
1348        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
1349        let handle = tokio::spawn(run_checkpoint_task(
1350            pool,
1351            cfg,
1352            None,
1353            "local".to_string(),
1354            shutdown_rx,
1355        ));
1356
1357        shutdown_tx.send(()).expect("send shutdown signal");
1358
1359        tokio::time::timeout(Duration::from_secs(1), handle)
1360            .await
1361            .expect("checkpoint task should exit within 1s")
1362            .expect("checkpoint task panicked");
1363    }
1364
1365    /// Regression #774: exits via watch-signal even with a live event_store
1366    /// pool clone (rules out a strong-count-based exit condition). See
1367    /// crates/khive-db/docs/api/checkpoint.md#checkpoint_task_exits_via_shutdown_signal_with_live_event_store_pool_clone
1368    #[tokio::test]
1369    #[serial(checkpoint_skip_metrics)]
1370    async fn checkpoint_task_exits_via_shutdown_signal_with_live_event_store_pool_clone() {
1371        let dir = tempfile::tempdir().unwrap();
1372        let path = dir.path().join("wal_task_event_store.db");
1373        let pool = file_pool(&path);
1374
1375        let cfg = CheckpointConfig {
1376            interval: Duration::from_millis(10),
1377            ..Default::default()
1378        };
1379
1380        let event_store: Arc<dyn khive_storage::EventStore> =
1381            Arc::new(crate::stores::event::SqlEventStore::new_scoped(
1382                Arc::clone(&pool),
1383                true,
1384                "local".to_string(),
1385            ));
1386        // A second, independent sibling clone of `pool` outlives this test
1387        // function's own binding — mirrors `StorageBackend` retaining
1388        // `self.pool` alongside the `SqlEventStore` it hands to the
1389        // checkpoint task in production.
1390        let sibling_pool_clone = Arc::clone(&pool);
1391
1392        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
1393        let handle = tokio::spawn(run_checkpoint_task(
1394            pool,
1395            cfg,
1396            Some(event_store),
1397            "local".to_string(),
1398            shutdown_rx,
1399        ));
1400
1401        // Confirm strong_count is well above 1 — the old check would spin
1402        // forever here — before proving the new signal-based exit works
1403        // regardless.
1404        assert!(
1405            Arc::strong_count(&sibling_pool_clone) > 1,
1406            "test setup must reproduce the multi-owner shape the bug depends on"
1407        );
1408
1409        shutdown_tx.send(()).expect("send shutdown signal");
1410
1411        tokio::time::timeout(Duration::from_secs(1), handle)
1412            .await
1413            .expect(
1414                "checkpoint task should exit within 1s via the watch signal, \
1415                 even with a live sibling Arc<ConnectionPool> clone held by \
1416                 the event store",
1417            )
1418            .expect("checkpoint task panicked");
1419    }
1420
1421    #[test]
1422    #[serial]
1423    fn checkpoint_config_env_override() {
1424        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "250");
1425        std::env::set_var("KHIVE_WAL_WARN_PAGES", "1500");
1426        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "8000");
1427        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "12000");
1428        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "60");
1429        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "500");
1430        std::env::set_var("KHIVE_TX_WARN_SECS", "15");
1431        std::env::set_var("KHIVE_TX_MAX_AGE_SECS", "90");
1432
1433        let cfg = CheckpointConfig::from_env();
1434
1435        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1436        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1437        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1438        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1439        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1440        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1441        std::env::remove_var("KHIVE_TX_WARN_SECS");
1442        std::env::remove_var("KHIVE_TX_MAX_AGE_SECS");
1443
1444        assert_eq!(cfg.interval, Duration::from_millis(250));
1445        assert_eq!(cfg.warn_pages, 1500);
1446        assert_eq!(cfg.high_water_pages, 8000);
1447        assert_eq!(cfg.truncate_high_water_pages, 12000);
1448        assert_eq!(cfg.truncate_min_interval, Duration::from_secs(60));
1449        assert_eq!(cfg.truncate_busy_timeout, Duration::from_millis(500));
1450        assert_eq!(cfg.tx_warn_secs, Duration::from_secs(15));
1451        assert_eq!(cfg.tx_max_age_secs, Duration::from_secs(90));
1452    }
1453
1454    #[test]
1455    #[serial]
1456    fn checkpoint_config_defaults_on_invalid_env() {
1457        let default = CheckpointConfig::default();
1458
1459        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "not_a_number");
1460        std::env::set_var("KHIVE_WAL_WARN_PAGES", "");
1461        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "0");
1462        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "not_a_number");
1463        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "");
1464        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "0");
1465        std::env::set_var("KHIVE_TX_WARN_SECS", "not_a_number");
1466        std::env::set_var("KHIVE_TX_MAX_AGE_SECS", "0");
1467
1468        let cfg = CheckpointConfig::from_env();
1469
1470        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1471        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1472        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1473        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1474        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1475        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1476        std::env::remove_var("KHIVE_TX_WARN_SECS");
1477        std::env::remove_var("KHIVE_TX_MAX_AGE_SECS");
1478
1479        assert_eq!(cfg.interval, default.interval);
1480        assert_eq!(cfg.warn_pages, default.warn_pages);
1481        assert_eq!(cfg.high_water_pages, default.high_water_pages);
1482        assert_eq!(
1483            cfg.truncate_high_water_pages,
1484            default.truncate_high_water_pages
1485        );
1486        assert_eq!(cfg.truncate_min_interval, default.truncate_min_interval);
1487        assert_eq!(cfg.truncate_busy_timeout, default.truncate_busy_timeout);
1488        assert_eq!(cfg.tx_warn_secs, default.tx_warn_secs);
1489        assert_eq!(cfg.tx_max_age_secs, default.tx_max_age_secs);
1490    }
1491
1492    /// Regression: a high-water tick must NOT block behind an active read
1493    /// transaction (isomorphism guarantee — fails if `checkpoint_once`
1494    /// regresses to TRUNCATE). See
1495    /// crates/khive-db/docs/api/checkpoint.md#checkpoint_high_water_does_not_block_behind_reader
1496    #[test]
1497    #[serial(checkpoint_skip_metrics)]
1498    fn checkpoint_high_water_does_not_block_behind_reader() {
1499        let dir = tempfile::tempdir().unwrap();
1500        let path = dir.path().join("high_water_test.db");
1501
1502        // busy_timeout = 2000ms: a TRUNCATE regression blocks ~2s (clearly caught by
1503        // the <500ms assertion below), but PASSIVE returns well within 500ms even on
1504        // a heavily loaded CI runner. 4x margin on both sides vs. the old 200ms/50ms.
1505        let pool = Arc::new(
1506            ConnectionPool::new(PoolConfig {
1507                path: Some(path.clone()),
1508                busy_timeout: Duration::from_millis(2000),
1509                ..PoolConfig::default()
1510            })
1511            .expect("pool open"),
1512        );
1513
1514        // Write data so the WAL has frames to checkpoint.
1515        {
1516            let writer = pool.try_writer().unwrap();
1517            writer
1518                .conn()
1519                .execute_batch(
1520                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1521                )
1522                .unwrap();
1523        }
1524
1525        // Open a reader and start a real read transaction so it holds a WAL
1526        // snapshot. An idle connection (no BEGIN) does NOT pin frames and would
1527        // not cause TRUNCATE to wait — the transaction is required for isomorphism.
1528        let reader = pool.reader().expect("reader");
1529        reader
1530            .execute_batch("BEGIN DEFERRED; SELECT * FROM t;")
1531            .expect("begin read tx");
1532
1533        // Write another row AFTER the snapshot is established. These new WAL
1534        // frames are now pinned by the open reader snapshot — TRUNCATE cannot
1535        // reclaim them without waiting; PASSIVE skips them and returns immediately.
1536        {
1537            let writer = pool.try_writer().unwrap();
1538            writer
1539                .conn()
1540                .execute_batch("INSERT INTO t VALUES (2);")
1541                .unwrap();
1542        }
1543
1544        let start = std::time::Instant::now();
1545        checkpoint_once(
1546            &pool,
1547            &CheckpointConfig::default(),
1548            &mut TruncateState::default(),
1549        );
1550        let elapsed = start.elapsed();
1551
1552        // Commit and release the read snapshot only after checkpoint_once returns.
1553        reader.execute_batch("COMMIT;").ok();
1554        drop(reader);
1555
1556        // PASSIVE returns in <1ms even with an open reader snapshot.
1557        // A TRUNCATE regression would block ~busy_timeout (2000ms) and fail here.
1558        // 500ms threshold is generous for CI jitter while staying well below 2000ms.
1559        assert!(
1560            elapsed < std::time::Duration::from_millis(500),
1561            "checkpoint_once with active reader snapshot took {:?}; \
1562             expected <500ms (PASSIVE must not block on readers; \
1563             a TRUNCATE regression would block ~2000ms)",
1564            elapsed
1565        );
1566    }
1567
1568    #[test]
1569    #[serial]
1570    fn checkpoint_config_rejects_zero_for_all_fields() {
1571        let default = CheckpointConfig::default();
1572        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "0");
1573        std::env::set_var("KHIVE_WAL_WARN_PAGES", "0");
1574        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "0");
1575        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "0");
1576        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "0");
1577        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "0");
1578        std::env::set_var("KHIVE_TX_WARN_SECS", "0");
1579        std::env::set_var("KHIVE_TX_MAX_AGE_SECS", "0");
1580
1581        let cfg = CheckpointConfig::from_env();
1582
1583        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1584        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1585        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1586        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1587        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1588        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1589        std::env::remove_var("KHIVE_TX_WARN_SECS");
1590        std::env::remove_var("KHIVE_TX_MAX_AGE_SECS");
1591
1592        assert_eq!(
1593            cfg.interval, default.interval,
1594            "zero interval must fall back to default"
1595        );
1596        assert_eq!(
1597            cfg.warn_pages, default.warn_pages,
1598            "zero warn_pages must fall back to default"
1599        );
1600        assert_eq!(
1601            cfg.high_water_pages, default.high_water_pages,
1602            "zero high_water_pages must fall back to default"
1603        );
1604        assert_eq!(
1605            cfg.truncate_high_water_pages, default.truncate_high_water_pages,
1606            "zero truncate_high_water_pages must fall back to default"
1607        );
1608        assert_eq!(
1609            cfg.truncate_min_interval, default.truncate_min_interval,
1610            "zero truncate_min_interval must fall back to default"
1611        );
1612        assert_eq!(
1613            cfg.truncate_busy_timeout, default.truncate_busy_timeout,
1614            "zero truncate_busy_timeout must fall back to default"
1615        );
1616        assert_eq!(
1617            cfg.tx_warn_secs, default.tx_warn_secs,
1618            "zero tx_warn_secs must fall back to default"
1619        );
1620        assert_eq!(
1621            cfg.tx_max_age_secs, default.tx_max_age_secs,
1622            "zero tx_max_age_secs must fall back to default"
1623        );
1624    }
1625
1626    /// Fix: a reversed threshold pair must not be honored independently. See
1627    /// crates/khive-db/docs/api/checkpoint.md#checkpoint_config_rejects_reversed_tx_thresholds
1628    #[test]
1629    #[serial]
1630    fn checkpoint_config_rejects_reversed_tx_thresholds() {
1631        let default = CheckpointConfig::default();
1632        std::env::set_var("KHIVE_TX_WARN_SECS", "120");
1633        std::env::set_var("KHIVE_TX_MAX_AGE_SECS", "30");
1634
1635        let cfg = CheckpointConfig::from_env();
1636
1637        std::env::remove_var("KHIVE_TX_WARN_SECS");
1638        std::env::remove_var("KHIVE_TX_MAX_AGE_SECS");
1639
1640        assert_eq!(
1641            cfg.tx_warn_secs, default.tx_warn_secs,
1642            "a reversed pair must fall back tx_warn_secs to its default, got: {:?}",
1643            cfg.tx_warn_secs
1644        );
1645        assert_eq!(
1646            cfg.tx_max_age_secs, default.tx_max_age_secs,
1647            "a reversed pair must fall back tx_max_age_secs to its default, got: {:?}",
1648            cfg.tx_max_age_secs
1649        );
1650    }
1651
1652    /// Degenerate equal-thresholds case; see
1653    /// crates/khive-db/docs/api/checkpoint.md#checkpoint_config_rejects_equal_tx_thresholds
1654    #[test]
1655    #[serial]
1656    fn checkpoint_config_rejects_equal_tx_thresholds() {
1657        let default = CheckpointConfig::default();
1658        std::env::set_var("KHIVE_TX_WARN_SECS", "60");
1659        std::env::set_var("KHIVE_TX_MAX_AGE_SECS", "60");
1660
1661        let cfg = CheckpointConfig::from_env();
1662
1663        std::env::remove_var("KHIVE_TX_WARN_SECS");
1664        std::env::remove_var("KHIVE_TX_MAX_AGE_SECS");
1665
1666        assert_eq!(
1667            cfg.tx_warn_secs, default.tx_warn_secs,
1668            "an equal pair must fall back tx_warn_secs to its default, got: {:?}",
1669            cfg.tx_warn_secs
1670        );
1671        assert_eq!(
1672            cfg.tx_max_age_secs, default.tx_max_age_secs,
1673            "an equal pair must fall back tx_max_age_secs to its default, got: {:?}",
1674            cfg.tx_max_age_secs
1675        );
1676    }
1677
1678    /// Regression: a Skipped tick must NOT reset `was_above_high_water`. See
1679    /// crates/khive-db/docs/api/checkpoint.md#skipped_tick_does_not_reset_high_water_crossing_state
1680    #[test]
1681    fn skipped_tick_does_not_reset_high_water_crossing_state() {
1682        let mut was_above = false;
1683
1684        // First observed tick: above threshold — fires WARN, sets was_above=true.
1685        assert!(
1686            crossing_warn(true, &mut was_above),
1687            "should fire on first crossing"
1688        );
1689        assert!(was_above);
1690
1691        // Simulate several skipped ticks: crossing state must remain true.
1692        // (In the task, Skipped causes `continue` so crossing_warn is never called.)
1693        // We verify by calling crossing_warn with the SAME above=true value, which
1694        // is what Observed(high_count) would produce — but a Skipped tick skips
1695        // the call entirely, so was_above stays as-is. Test the invariant directly:
1696        // if we leave was_above unchanged (no call at all), was_above remains true.
1697        assert!(was_above, "was_above must stay true across skipped ticks");
1698
1699        // Another observed tick still above threshold — must NOT re-fire.
1700        let fired = crossing_warn(true, &mut was_above);
1701        assert!(!fired, "WARN must not re-fire while still above threshold");
1702
1703        // Observed tick below threshold — resets was_above.
1704        let fired = crossing_warn(false, &mut was_above);
1705        assert!(!fired);
1706        assert!(!was_above);
1707
1708        // Next observed tick above threshold — fires again (legitimate new crossing).
1709        let fired = crossing_warn(true, &mut was_above);
1710        assert!(fired, "WARN must fire again on a new below→above crossing");
1711    }
1712
1713    /// Regression: warn_pages WARN fires once on crossing, not every tick.
1714    ///
1715    /// Before the fix, the WARN was emitted inside `checkpoint_once` on every tick
1716    /// while WAL sat in the warn band — log spam under sustained moderate pressure.
1717    /// With the fix, `crossing_warn` gates the WARN on the first in-band tick only;
1718    /// subsequent ticks while still in the band return false.
1719    #[test]
1720    fn warn_pages_fires_once_on_crossing_not_every_tick() {
1721        let mut was_above_warn = false;
1722
1723        // Simulate three consecutive ticks with WAL in the warn band.
1724        let fired_1 = crossing_warn(true, &mut was_above_warn);
1725        let fired_2 = crossing_warn(true, &mut was_above_warn);
1726        let fired_3 = crossing_warn(true, &mut was_above_warn);
1727
1728        assert!(fired_1, "WARN must fire on the first in-band tick");
1729        assert!(
1730            !fired_2,
1731            "WARN must not fire on the second consecutive in-band tick"
1732        );
1733        assert!(
1734            !fired_3,
1735            "WARN must not fire on the third consecutive in-band tick"
1736        );
1737
1738        // Drop below warn band — resets state.
1739        crossing_warn(false, &mut was_above_warn);
1740        assert!(!was_above_warn);
1741
1742        // Re-enter warn band — fires again.
1743        let fired_reentry = crossing_warn(true, &mut was_above_warn);
1744        assert!(
1745            fired_reentry,
1746            "WARN must fire again on re-entry into warn band"
1747        );
1748    }
1749
1750    // ADR-091 Plank 2: TRUNCATE escalation state machine tests.
1751
1752    /// Trigger threshold: once `wal_pages` (as observed by `checkpoint_once`) is
1753    /// at/above `truncate_high_water_pages` and no prior attempt has run, the
1754    /// escalation fires and stamps `last_attempt`.
1755    #[test]
1756    #[serial(tx_registry, checkpoint_skip_metrics)]
1757    fn truncate_attempts_when_high_water_crossed_with_no_prior_attempt() {
1758        let dir = tempfile::tempdir().unwrap();
1759        let path = dir.path().join("truncate_trigger.db");
1760        let pool = file_pool(&path);
1761
1762        {
1763            let writer = pool.try_writer().unwrap();
1764            writer
1765                .conn()
1766                .execute_batch(
1767                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1768                )
1769                .unwrap();
1770        }
1771
1772        let config = CheckpointConfig {
1773            // Force the escalation to arm regardless of the tiny WAL this test
1774            // actually produces — isolates the trigger-threshold behavior from
1775            // needing to stuff 20,000 real WAL pages.
1776            truncate_high_water_pages: 0,
1777            truncate_min_interval: Duration::from_secs(300),
1778            ..CheckpointConfig::default()
1779        };
1780        let mut state = TruncateState::default();
1781
1782        assert!(
1783            state.last_attempt.is_none(),
1784            "precondition: no attempt has run yet"
1785        );
1786
1787        let tick = checkpoint_once(&pool, &config, &mut state);
1788        assert!(matches!(tick, CheckpointTick::Observed(_)));
1789        assert!(
1790            state.last_attempt.is_some(),
1791            "an attempt must be stamped once the high-water threshold is crossed"
1792        );
1793    }
1794
1795    /// Below-threshold skip: `wal_pages < truncate_high_water_pages` must never
1796    /// stamp `last_attempt` — only an actual attempt advances it.
1797    #[test]
1798    #[serial(tx_registry, checkpoint_skip_metrics)]
1799    fn truncate_does_not_attempt_below_high_water() {
1800        let dir = tempfile::tempdir().unwrap();
1801        let path = dir.path().join("truncate_below_threshold.db");
1802        let pool = file_pool(&path);
1803
1804        {
1805            let writer = pool.try_writer().unwrap();
1806            writer
1807                .conn()
1808                .execute_batch(
1809                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1810                )
1811                .unwrap();
1812        }
1813
1814        // Effectively unreachable threshold for this test's tiny WAL.
1815        let config = CheckpointConfig {
1816            truncate_high_water_pages: u64::MAX,
1817            ..CheckpointConfig::default()
1818        };
1819        let mut state = TruncateState::default();
1820
1821        checkpoint_once(&pool, &config, &mut state);
1822
1823        assert!(
1824            state.last_attempt.is_none(),
1825            "a below-threshold tick must never stamp last_attempt"
1826        );
1827    }
1828
1829    /// Min-interval skip: once an attempt has run, a subsequent tick that is
1830    /// still above threshold but within `truncate_min_interval` must skip
1831    /// without re-stamping `last_attempt` (the timestamp must not move).
1832    #[test]
1833    #[serial(tx_registry, checkpoint_skip_metrics)]
1834    fn truncate_min_interval_skip_does_not_restamp_last_attempt() {
1835        let dir = tempfile::tempdir().unwrap();
1836        let path = dir.path().join("truncate_min_interval.db");
1837        let pool = file_pool(&path);
1838
1839        {
1840            let writer = pool.try_writer().unwrap();
1841            writer
1842                .conn()
1843                .execute_batch(
1844                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1845                )
1846                .unwrap();
1847        }
1848
1849        let config = CheckpointConfig {
1850            truncate_high_water_pages: 0,
1851            truncate_min_interval: Duration::from_secs(300),
1852            ..CheckpointConfig::default()
1853        };
1854        let mut state = TruncateState::default();
1855
1856        checkpoint_once(&pool, &config, &mut state);
1857        let first_attempt = state.last_attempt.expect("first tick must attempt");
1858
1859        // Second tick, immediately after: still above threshold, but the
1860        // min-interval has clearly not elapsed — must skip and leave
1861        // last_attempt exactly as it was.
1862        checkpoint_once(&pool, &config, &mut state);
1863        let second_attempt = state.last_attempt.expect("attempt timestamp must persist");
1864
1865        assert_eq!(
1866            first_attempt, second_attempt,
1867            "a tick within truncate_min_interval must not re-stamp last_attempt"
1868        );
1869    }
1870
1871    /// Busy fallback: when the writer mutex is already held, `checkpoint_once`
1872    /// must return `Skipped` and never touch the TRUNCATE state at all — both
1873    /// PASSIVE and any due TRUNCATE are skipped together (one writer checkout
1874    /// per tick). Also asserts #646 checkpoint-pressure telemetry: a skipped
1875    /// tick must bump the skipped/consecutive-skip counters and snapshot the
1876    /// last-known WAL pressure.
1877    #[test]
1878    #[serial(tx_registry, checkpoint_skip_metrics)]
1879    fn busy_writer_skips_both_passive_and_truncate() {
1880        reset_checkpoint_metrics_for_tests();
1881
1882        let dir = tempfile::tempdir().unwrap();
1883        let path = dir.path().join("truncate_busy_skip.db");
1884        let pool = file_pool(&path);
1885
1886        {
1887            let writer = pool.try_writer().unwrap();
1888            writer
1889                .conn()
1890                .execute_batch(
1891                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1892                )
1893                .unwrap();
1894        }
1895
1896        // An observed tick first, so the skip below has a last-known WAL
1897        // pressure snapshot to carry forward.
1898        let mut warmup_state = TruncateState::default();
1899        let warmup_tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut warmup_state);
1900        let observed_pages = match warmup_tick {
1901            CheckpointTick::Observed(n) => n,
1902            CheckpointTick::Skipped => panic!("warmup tick must observe, not skip"),
1903        };
1904        assert_eq!(
1905            checkpoint_consecutive_skips(),
1906            0,
1907            "an observed tick must not itself count as a skip"
1908        );
1909
1910        // Hold the writer mutex for the duration of the checkpoint_once call so
1911        // try_writer_nowait() fails, exactly like a concurrent write in progress.
1912        let _held = pool.try_writer().unwrap();
1913
1914        let config = CheckpointConfig {
1915            truncate_high_water_pages: 0,
1916            ..CheckpointConfig::default()
1917        };
1918        let mut state = TruncateState::default();
1919
1920        let tick = checkpoint_once(&pool, &config, &mut state);
1921
1922        assert_eq!(
1923            tick,
1924            CheckpointTick::Skipped,
1925            "a busy writer must skip the tick entirely"
1926        );
1927        assert!(
1928            state.last_attempt.is_none(),
1929            "a skipped tick (writer busy) must never stamp last_attempt, \
1930             even with a threshold that would otherwise arm immediately"
1931        );
1932
1933        assert_eq!(
1934            checkpoint_skipped_ticks(),
1935            1,
1936            "one skipped tick must bump the lifetime skipped-tick counter"
1937        );
1938        assert_eq!(
1939            checkpoint_consecutive_skips(),
1940            1,
1941            "one skipped tick must bump the consecutive-skip run length"
1942        );
1943        assert_eq!(
1944            checkpoint_last_skip_wal_pages(),
1945            Some(observed_pages),
1946            "the skip must snapshot the last-observed WAL pressure"
1947        );
1948    }
1949
1950    /// Regression guard for #845 (a recurrence of the #828 shared-statics
1951    /// race): every test in this module that calls `checkpoint_once` or
1952    /// `run_checkpoint_task` — both funnel through `query_wal_pages`, which
1953    /// writes the process-wide `LAST_WAL_PAGES` / `CHECKPOINT_*` atomics —
1954    /// must be tagged with a `#[serial(...)]` group that includes
1955    /// `checkpoint_skip_metrics`. Before #828, six such call sites carried no
1956    /// serial tag at all: cargo's default test thread pool ran them
1957    /// concurrently with `busy_writer_skips_both_passive_and_truncate`, and an
1958    /// untagged tick's `query_wal_pages` call clobbered the gauges between
1959    /// this test's warmup tick and its skip assertion (`left: Some(0), right:
1960    /// Some(3)` on CI — the two ticks never actually raced against each
1961    /// other, a third test's tick did). This scans the module's own source so
1962    /// a future test that calls either function without the tag fails this
1963    /// assertion instead of flaking on a loaded CI runner.
1964    #[test]
1965    fn all_checkpoint_metrics_callers_are_serial_tagged() {
1966        const SELF_SRC: &str = include_str!("checkpoint.rs");
1967        let lines: Vec<&str> = SELF_SRC.lines().collect();
1968
1969        let attr_starts: Vec<usize> = lines
1970            .iter()
1971            .enumerate()
1972            .filter(|(_, l)| {
1973                let t = l.trim();
1974                t == "#[test]" || t.starts_with("#[tokio::test")
1975            })
1976            .map(|(i, _)| i)
1977            .collect();
1978
1979        let mut offenders = Vec::new();
1980
1981        for (idx, &start) in attr_starts.iter().enumerate() {
1982            let end = attr_starts.get(idx + 1).copied().unwrap_or(lines.len());
1983            let span = &lines[start..end];
1984
1985            let touches_shared_metrics = span
1986                .iter()
1987                .any(|l| l.contains("checkpoint_once(") || l.contains("run_checkpoint_task("));
1988            if !touches_shared_metrics {
1989                continue;
1990            }
1991
1992            let has_group_tag = span
1993                .iter()
1994                .any(|l| l.contains("#[serial") && l.contains("checkpoint_skip_metrics"));
1995
1996            if !has_group_tag {
1997                let name = span
1998                    .iter()
1999                    .find_map(|l| {
2000                        let t = l.trim_start();
2001                        let t = t.strip_prefix("pub(crate) ").unwrap_or(t);
2002                        let t = t.strip_prefix("pub ").unwrap_or(t);
2003                        let t = t.strip_prefix("async ").unwrap_or(t);
2004                        t.strip_prefix("fn ")
2005                            .map(|rest| rest.split(['(', '<']).next().unwrap_or("").trim())
2006                    })
2007                    .unwrap_or("<unknown test>");
2008                offenders.push(name.to_string());
2009            }
2010        }
2011
2012        assert!(
2013            offenders.is_empty(),
2014            "these tests call checkpoint_once/run_checkpoint_task (which write the \
2015             process-wide LAST_WAL_PAGES/CHECKPOINT_* atomics via query_wal_pages) but \
2016             are not tagged #[serial(checkpoint_skip_metrics)] (or a group including it); \
2017             an untagged caller running concurrently on cargo's default test thread pool \
2018             can clobber those atomics mid-assertion in another test (the #828/#845 race): \
2019             {offenders:?}"
2020        );
2021    }
2022
2023    /// Observation branch: a checkpoint tick that is actually observed (writer
2024    /// free) must close out a prior skip streak, resetting the
2025    /// consecutive-skip counter to 0 without touching the lifetime total.
2026    #[test]
2027    #[serial(tx_registry, checkpoint_skip_metrics)]
2028    fn observed_tick_resets_consecutive_skips_but_not_lifetime_total() {
2029        reset_checkpoint_metrics_for_tests();
2030
2031        let dir = tempfile::tempdir().unwrap();
2032        let path = dir.path().join("skip_then_observe.db");
2033        let pool = file_pool(&path);
2034
2035        {
2036            let writer = pool.try_writer().unwrap();
2037            writer
2038                .conn()
2039                .execute_batch(
2040                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
2041                )
2042                .unwrap();
2043        }
2044
2045        // Two consecutive skipped ticks.
2046        {
2047            let _held = pool.try_writer().unwrap();
2048            let mut state = TruncateState::default();
2049            for _ in 0..2 {
2050                let tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut state);
2051                assert_eq!(tick, CheckpointTick::Skipped);
2052            }
2053        }
2054        assert_eq!(checkpoint_skipped_ticks(), 2);
2055        assert_eq!(checkpoint_consecutive_skips(), 2);
2056
2057        // Now the writer is free: an observed tick must reset the streak.
2058        let mut state = TruncateState::default();
2059        let tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut state);
2060        assert!(matches!(tick, CheckpointTick::Observed(_)));
2061
2062        assert_eq!(
2063            checkpoint_skipped_ticks(),
2064            2,
2065            "an observed tick must not change the lifetime skipped-tick total"
2066        );
2067        assert_eq!(
2068            checkpoint_consecutive_skips(),
2069            0,
2070            "an observed tick must reset the consecutive-skip run length"
2071        );
2072    }
2073
2074    /// Edge-triggered escalation WARN: `note_truncate_outcome` fires exactly
2075    /// once, on the third consecutive attempt that fails to clear
2076    /// `warn_pages`, and does not repeat on a fourth consecutive failure. A
2077    /// single attempt that clears `warn_pages` resets the counter.
2078    #[test]
2079    fn note_truncate_outcome_warns_once_at_third_consecutive_failure() {
2080        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
2081        let subscriber = CaptureSubscriber {
2082            events: std::sync::Arc::clone(&buffer),
2083        };
2084
2085        let config = CheckpointConfig {
2086            warn_pages: 2000,
2087            ..CheckpointConfig::default()
2088        };
2089        let mut state = TruncateState::default();
2090
2091        tracing::subscriber::with_default(subscriber, || {
2092            // Three consecutive attempts that fail to clear warn_pages.
2093            note_truncate_outcome(&config, 5000, &mut state);
2094            note_truncate_outcome(&config, 5000, &mut state);
2095            note_truncate_outcome(&config, 5000, &mut state);
2096            // A fourth consecutive failure must not re-fire the escalation.
2097            note_truncate_outcome(&config, 5000, &mut state);
2098        });
2099
2100        assert_eq!(state.consecutive_failures, 4);
2101
2102        let events = buffer.lock().unwrap();
2103        let escalation_count = events
2104            .iter()
2105            .filter(|e| {
2106                e.message.as_deref()
2107                    == Some(
2108                        "WAL TRUNCATE has failed to clear WAL pressure for 3 consecutive attempts",
2109                    )
2110            })
2111            .count();
2112        assert_eq!(
2113            escalation_count, 1,
2114            "escalation WARN must fire exactly once at the 3rd consecutive failure, got: {events:?}"
2115        );
2116
2117        // A clearing attempt resets the counter.
2118        note_truncate_outcome(&config, 100, &mut state);
2119        assert_eq!(
2120            state.consecutive_failures, 0,
2121            "an attempt that clears warn_pages must reset the consecutive-failure counter"
2122        );
2123    }
2124
2125    // ADR-091 #617: graduated severity ladder state-machine tests.
2126
2127    fn severity_test_config() -> CheckpointConfig {
2128        CheckpointConfig {
2129            warn_pages: 100,
2130            warn_sustained_cycles: 3,
2131            ..CheckpointConfig::default()
2132        }
2133    }
2134
2135    /// INFO rung: a below→above crossing emits exactly one INFO and no WARN
2136    /// (default `warn_sustained_cycles = 3`, only one above-warn tick here).
2137    #[test]
2138    fn severity_ladder_info_on_first_crossing_no_warn() {
2139        let config = severity_test_config();
2140        let mut state = CheckpointSeverityState::default();
2141
2142        let below = state.observe_wal_pages(10, &config);
2143        assert!(below.is_empty(), "below-warn tick must emit nothing");
2144
2145        let above = state.observe_wal_pages(150, &config);
2146        assert_eq!(
2147            above,
2148            vec![CheckpointSeverityEmission {
2149                rung: CheckpointSeverityRung::Info,
2150                wal_pages: 150,
2151                threshold_pages: 100,
2152                consecutive_cycles: 1,
2153            }],
2154            "first below->above crossing must emit exactly one INFO and no WARN"
2155        );
2156    }
2157
2158    /// WARN rung: `warn_sustained_cycles` (3) consecutive above-warn ticks
2159    /// emit WARN exactly on the third tick, not before and not repeated after.
2160    #[test]
2161    fn severity_ladder_warn_on_third_consecutive_cycle() {
2162        let config = severity_test_config();
2163        let mut state = CheckpointSeverityState::default();
2164
2165        let tick1 = state.observe_wal_pages(150, &config);
2166        assert_eq!(tick1.len(), 1);
2167        assert_eq!(tick1[0].rung, CheckpointSeverityRung::Info);
2168
2169        let tick2 = state.observe_wal_pages(150, &config);
2170        assert!(
2171            tick2.is_empty(),
2172            "second consecutive above-warn tick must emit nothing yet"
2173        );
2174
2175        let tick3 = state.observe_wal_pages(150, &config);
2176        assert_eq!(
2177            tick3,
2178            vec![CheckpointSeverityEmission {
2179                rung: CheckpointSeverityRung::Warn,
2180                wal_pages: 150,
2181                threshold_pages: 100,
2182                consecutive_cycles: 3,
2183            }],
2184            "WARN must fire exactly on the third consecutive above-warn tick"
2185        );
2186
2187        let tick4 = state.observe_wal_pages(150, &config);
2188        assert!(
2189            tick4.is_empty(),
2190            "WARN must not repeat on a fourth consecutive above-warn tick"
2191        );
2192    }
2193
2194    /// Re-arm: after a WARN episode drains below warn_pages, a fresh episode
2195    /// of `warn_sustained_cycles` above-warn ticks must WARN again.
2196    #[test]
2197    fn severity_ladder_rearms_warn_after_drain() {
2198        let config = severity_test_config();
2199        let mut state = CheckpointSeverityState::default();
2200
2201        // First episode reaches WARN.
2202        for _ in 0..3 {
2203            state.observe_wal_pages(150, &config);
2204        }
2205        assert!(state.warn_emitted_for_episode);
2206
2207        // Drain below warn_pages: resets the episode.
2208        let drain = state.observe_wal_pages(10, &config);
2209        assert!(drain.is_empty(), "a draining tick must emit nothing");
2210
2211        // Second episode: INFO on first tick, no WARN until the third again.
2212        let reentry = state.observe_wal_pages(150, &config);
2213        assert_eq!(reentry.len(), 1);
2214        assert_eq!(reentry[0].rung, CheckpointSeverityRung::Info);
2215
2216        let mid = state.observe_wal_pages(150, &config);
2217        assert!(mid.is_empty());
2218
2219        let second_warn = state.observe_wal_pages(150, &config);
2220        assert_eq!(
2221            second_warn,
2222            vec![CheckpointSeverityEmission {
2223                rung: CheckpointSeverityRung::Warn,
2224                wal_pages: 150,
2225                threshold_pages: 100,
2226                consecutive_cycles: 3,
2227            }],
2228            "a fresh elevation episode after a drain must WARN again"
2229        );
2230    }
2231
2232    /// False-positive guard: three isolated single-tick crossings, each
2233    /// followed by a drain, must never reach WARN — only INFO fires each time.
2234    #[test]
2235    fn severity_ladder_isolated_crossings_never_warn() {
2236        let config = severity_test_config();
2237        let mut state = CheckpointSeverityState::default();
2238
2239        for _ in 0..3 {
2240            let crossing = state.observe_wal_pages(150, &config);
2241            assert_eq!(
2242                crossing.len(),
2243                1,
2244                "each isolated crossing must emit exactly one INFO"
2245            );
2246            assert_eq!(crossing[0].rung, CheckpointSeverityRung::Info);
2247
2248            let drain = state.observe_wal_pages(10, &config);
2249            assert!(drain.is_empty(), "the drain tick must emit nothing");
2250        }
2251
2252        assert!(
2253            !state.warn_emitted_for_episode,
2254            "isolated single-tick crossings must never accumulate into a WARN"
2255        );
2256    }
2257
2258    /// ALARM rung: the existing TRUNCATE-attempt gate is the ADR-091 ALARM
2259    /// tier. `observe_wal_pages` never produces it; this test documents and
2260    /// locks in that boundary so a future change can't silently reroute
2261    /// ALARM through the INFO/WARN ladder.
2262    #[test]
2263    fn severity_ladder_never_emits_alarm() {
2264        let config = CheckpointConfig {
2265            warn_pages: 100,
2266            warn_sustained_cycles: 1,
2267            ..CheckpointConfig::default()
2268        };
2269        let mut state = CheckpointSeverityState::default();
2270
2271        for wal_pages in [150, 200, 250, u64::MAX] {
2272            let emissions = state.observe_wal_pages(wal_pages, &config);
2273            assert!(
2274                emissions
2275                    .iter()
2276                    .all(|e| e.rung != CheckpointSeverityRung::Alarm),
2277                "observe_wal_pages must never emit the ALARM rung, got: {emissions:?}"
2278            );
2279        }
2280    }
2281
2282    // ADR-091 Plank 1: `TxAgeSweepState` background-sweep state-machine tests.
2283    // Pure unit tests mirroring the severity-ladder tests above — no I/O.
2284
2285    fn tx_age_test_config() -> CheckpointConfig {
2286        CheckpointConfig {
2287            tx_warn_secs: Duration::from_secs(30),
2288            tx_max_age_secs: Duration::from_secs(120),
2289            ..CheckpointConfig::default()
2290        }
2291    }
2292
2293    /// Synthetic identity for `TxAgeSweepState::observe`'s pure unit tests
2294    /// below, which exercise identity-change detection without paying for a
2295    /// real `tx_registry::register` call. `TxId`'s wrapped value is public
2296    /// exactly to support this (see its doc comment in `khive-storage`).
2297    fn tx_id(n: u64) -> khive_storage::tx_registry::TxId {
2298        khive_storage::tx_registry::TxId(n)
2299    }
2300
2301    /// No open entry: nothing fires, and any prior latch state clears.
2302    #[test]
2303    fn tx_age_sweep_empty_registry_emits_nothing() {
2304        let config = tx_age_test_config();
2305        let mut state = TxAgeSweepState::default();
2306
2307        let emissions = state.observe(None, &config);
2308        assert!(emissions.is_empty(), "no open entry must emit nothing");
2309    }
2310
2311    /// A fresh entry (age below both thresholds) emits nothing.
2312    #[test]
2313    fn tx_age_sweep_fresh_entry_emits_nothing() {
2314        let config = tx_age_test_config();
2315        let mut state = TxAgeSweepState::default();
2316
2317        let emissions = state.observe(
2318            Some((
2319                tx_id(1),
2320                Duration::from_secs(5),
2321                Some("fresh_span".to_string()),
2322            )),
2323            &config,
2324        );
2325        assert!(emissions.is_empty(), "a fresh entry must emit nothing");
2326    }
2327
2328    /// Below→above crossing of `tx_warn_secs` fires exactly one `Warn`
2329    /// emission carrying the entry's label; it must not repeat on a second
2330    /// tick that is still above `tx_warn_secs` but below `tx_max_age_secs`.
2331    #[test]
2332    fn tx_age_sweep_warn_fires_once_on_crossing() {
2333        let config = tx_age_test_config();
2334        let mut state = TxAgeSweepState::default();
2335
2336        let tick1 = state.observe(
2337            Some((
2338                tx_id(1),
2339                Duration::from_secs(45),
2340                Some("stale_span".to_string()),
2341            )),
2342            &config,
2343        );
2344        assert_eq!(
2345            tick1,
2346            vec![TxAgeEmission {
2347                rung: TxAgeRung::Warn,
2348                age: Duration::from_secs(45),
2349                label: Some("stale_span".to_string()),
2350            }],
2351            "crossing tx_warn_secs must emit exactly one Warn"
2352        );
2353
2354        let tick2 = state.observe(
2355            Some((
2356                tx_id(1),
2357                Duration::from_secs(50),
2358                Some("stale_span".to_string()),
2359            )),
2360            &config,
2361        );
2362        assert!(
2363            tick2.is_empty(),
2364            "Warn must not repeat while the entry stays in the warn band"
2365        );
2366    }
2367
2368    /// Crossing `tx_max_age_secs` fires `Stale`; a further tick still above
2369    /// the cap must not repeat it.
2370    #[test]
2371    fn tx_age_sweep_stale_fires_once_on_crossing() {
2372        let config = tx_age_test_config();
2373        let mut state = TxAgeSweepState::default();
2374
2375        // Drive through the warn crossing first, matching real elapsed-time
2376        // progression (an entry ages through the warn band before the max).
2377        state.observe(
2378            Some((
2379                tx_id(1),
2380                Duration::from_secs(45),
2381                Some("stuck_writer_task_tx".to_string()),
2382            )),
2383            &config,
2384        );
2385
2386        let tick = state.observe(
2387            Some((
2388                tx_id(1),
2389                Duration::from_secs(130),
2390                Some("stuck_writer_task_tx".to_string()),
2391            )),
2392            &config,
2393        );
2394        assert_eq!(
2395            tick,
2396            vec![TxAgeEmission {
2397                rung: TxAgeRung::Stale,
2398                age: Duration::from_secs(130),
2399                label: Some("stuck_writer_task_tx".to_string()),
2400            }],
2401            "crossing tx_max_age_secs must emit exactly one Stale"
2402        );
2403
2404        let tick_repeat = state.observe(
2405            Some((
2406                tx_id(1),
2407                Duration::from_secs(200),
2408                Some("stuck_writer_task_tx".to_string()),
2409            )),
2410            &config,
2411        );
2412        assert!(
2413            tick_repeat.is_empty(),
2414            "Stale must not repeat while the entry stays above tx_max_age_secs"
2415        );
2416    }
2417
2418    /// An entry already stale the first time the sweep observes it (e.g.
2419    /// right after process start with a pre-existing registry entry) crosses
2420    /// both rungs on the same tick.
2421    #[test]
2422    fn tx_age_sweep_already_stale_entry_emits_both_rungs_same_tick() {
2423        let config = tx_age_test_config();
2424        let mut state = TxAgeSweepState::default();
2425
2426        let tick = state.observe(
2427            Some((
2428                tx_id(1),
2429                Duration::from_secs(300),
2430                Some("ancient_tx".to_string()),
2431            )),
2432            &config,
2433        );
2434        assert_eq!(
2435            tick,
2436            vec![
2437                TxAgeEmission {
2438                    rung: TxAgeRung::Warn,
2439                    age: Duration::from_secs(300),
2440                    label: Some("ancient_tx".to_string()),
2441                },
2442                TxAgeEmission {
2443                    rung: TxAgeRung::Stale,
2444                    age: Duration::from_secs(300),
2445                    label: Some("ancient_tx".to_string()),
2446                },
2447            ],
2448            "an already-stale entry must cross both rungs on its first observed tick"
2449        );
2450    }
2451
2452    /// Re-arm: once the stale entry closes (registry reports a fresher
2453    /// oldest entry, or none at all), a future stale span must fire again.
2454    #[test]
2455    fn tx_age_sweep_rearms_after_entry_clears() {
2456        let config = tx_age_test_config();
2457        let mut state = TxAgeSweepState::default();
2458
2459        state.observe(
2460            Some((
2461                tx_id(1),
2462                Duration::from_secs(150),
2463                Some("first_span".to_string()),
2464            )),
2465            &config,
2466        );
2467
2468        // The stale span closed; nothing is open now.
2469        let cleared = state.observe(None, &config);
2470        assert!(cleared.is_empty(), "a clearing tick must emit nothing");
2471
2472        // A fresh entry (unrelated span) is now oldest — still below threshold.
2473        let fresh = state.observe(
2474            Some((
2475                tx_id(2),
2476                Duration::from_secs(2),
2477                Some("second_span".to_string()),
2478            )),
2479            &config,
2480        );
2481        assert!(fresh.is_empty(), "a fresh oldest entry must emit nothing");
2482
2483        // That second span goes stale in turn — must WARN again (re-armed).
2484        let rewarn = state.observe(
2485            Some((
2486                tx_id(2),
2487                Duration::from_secs(35),
2488                Some("second_span".to_string()),
2489            )),
2490            &config,
2491        );
2492        assert_eq!(
2493            rewarn,
2494            vec![TxAgeEmission {
2495                rung: TxAgeRung::Warn,
2496                age: Duration::from_secs(35),
2497                label: Some("second_span".to_string()),
2498            }],
2499            "a fresh stale episode after a clear must Warn again"
2500        );
2501    }
2502
2503    /// Fix: an already-stale entry replacing a stale one on the next tick,
2504    /// with no intervening clear, must still emit both rungs. See
2505    /// crates/khive-db/docs/api/checkpoint.md#tx_age_sweep_stale_replacement_without_intervening_clear_still_names_new_entry
2506    #[test]
2507    fn tx_age_sweep_stale_replacement_without_intervening_clear_still_names_new_entry() {
2508        let config = tx_age_test_config();
2509        let mut state = TxAgeSweepState::default();
2510
2511        let tick_a = state.observe(
2512            Some((
2513                tx_id(1),
2514                Duration::from_secs(300),
2515                Some("stale_entry_a".to_string()),
2516            )),
2517            &config,
2518        );
2519        assert_eq!(
2520            tick_a.len(),
2521            2,
2522            "entry A must cross both rungs on its first observed tick, got: {tick_a:?}"
2523        );
2524
2525        // B replaces A as the oldest entry on the VERY NEXT tick — already
2526        // stale itself, with no intervening None/below-threshold tick.
2527        let tick_b = state.observe(
2528            Some((
2529                tx_id(2),
2530                Duration::from_secs(400),
2531                Some("stale_entry_b".to_string()),
2532            )),
2533            &config,
2534        );
2535        assert_eq!(
2536            tick_b,
2537            vec![
2538                TxAgeEmission {
2539                    rung: TxAgeRung::Warn,
2540                    age: Duration::from_secs(400),
2541                    label: Some("stale_entry_b".to_string()),
2542                },
2543                TxAgeEmission {
2544                    rung: TxAgeRung::Stale,
2545                    age: Duration::from_secs(400),
2546                    label: Some("stale_entry_b".to_string()),
2547                },
2548            ],
2549            "a same-tick identity change to an already-stale successor must re-emit both \
2550             rungs naming the NEW entry, got: {tick_b:?}"
2551        );
2552    }
2553
2554    /// Closes the loop from env var to actual emitted rung. See
2555    /// crates/khive-db/docs/api/checkpoint.md#tx_age_sweep_uses_configured_thresholds_not_hardcoded_defaults
2556    #[test]
2557    fn tx_age_sweep_uses_configured_thresholds_not_hardcoded_defaults() {
2558        let config = CheckpointConfig {
2559            tx_warn_secs: Duration::from_millis(1),
2560            tx_max_age_secs: Duration::from_millis(2),
2561            ..CheckpointConfig::default()
2562        };
2563        let mut state = TxAgeSweepState::default();
2564
2565        let tick = state.observe(
2566            Some((
2567                tx_id(1),
2568                Duration::from_millis(5),
2569                Some("fast_cap_span".to_string()),
2570            )),
2571            &config,
2572        );
2573        assert_eq!(
2574            tick.len(),
2575            2,
2576            "a millisecond-scale cap must cross both rungs immediately, got: {tick:?}"
2577        );
2578    }
2579
2580    /// Integration-level regression for the incident this ADR fixes. See
2581    /// crates/khive-db/docs/api/checkpoint.md#tx_age_sweep_names_long_lived_reader_pinning_wal_past_high_water
2582    #[test]
2583    #[serial(tx_registry, checkpoint_skip_metrics)]
2584    fn tx_age_sweep_names_long_lived_reader_pinning_wal_past_high_water() {
2585        let dir = tempfile::tempdir().unwrap();
2586        let path = dir.path().join("tx_age_sweep_reader_pin.db");
2587        let pool = file_pool(&path);
2588
2589        {
2590            let writer = pool.try_writer().unwrap();
2591            writer
2592                .conn()
2593                .execute_batch(
2594                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
2595                )
2596                .unwrap();
2597        }
2598
2599        // Open a real read transaction so it holds a WAL snapshot (same
2600        // isomorphism as `checkpoint_high_water_does_not_block_behind_reader`),
2601        // AND register it in tx_registry — the telemetry a real long-lived
2602        // reader call site (e.g. `graph_traverse_read`) is expected to carry.
2603        let reader = pool.reader().expect("reader");
2604        reader
2605            .execute_batch("BEGIN DEFERRED; SELECT * FROM t;")
2606            .expect("begin read tx");
2607        let _tx_handle =
2608            khive_storage::tx_registry::register(Some("tx_age_sweep_reader_pin_test".to_string()));
2609
2610        // Drive writes past high_water_pages while the reader snapshot pins
2611        // the WAL tail — PASSIVE cannot reclaim these frames.
2612        let config = CheckpointConfig {
2613            high_water_pages: 1,
2614            tx_warn_secs: Duration::from_millis(1),
2615            tx_max_age_secs: Duration::from_millis(1),
2616            ..CheckpointConfig::default()
2617        };
2618        {
2619            let writer = pool.try_writer().unwrap();
2620            for i in 0..50 {
2621                writer
2622                    .conn()
2623                    .execute_batch(&format!("INSERT INTO t VALUES ({i});"))
2624                    .unwrap();
2625            }
2626        }
2627
2628        let tick = checkpoint_once(&pool, &config, &mut TruncateState::default());
2629        let wal_pages = match tick {
2630            CheckpointTick::Observed(n) => n,
2631            CheckpointTick::Skipped => panic!("writer must not be busy in this test"),
2632        };
2633        assert!(
2634            wal_pages >= config.high_water_pages,
2635            "test setup must actually drive wal_pages ({wal_pages}) past high_water_pages \
2636             ({}) for this regression to mean anything",
2637            config.high_water_pages
2638        );
2639
2640        // The Plank 1 sweep, given the SAME registry state, must name the
2641        // pinning reader at the Stale rung. The handle's age must exceed the
2642        // 1ms `tx_max_age_secs` cap deterministically: the inserts plus one
2643        // PASSIVE checkpoint above can complete in under a millisecond on a
2644        // warm page cache, so sleep past the cap instead of assuming
2645        // the elapsed work already crossed it.
2646        std::thread::sleep(Duration::from_millis(5));
2647        // `tx_registry` is a process-wide singleton shared by every test in
2648        // this binary (cargo runs `#[test]`s in parallel threads of the same
2649        // process): `#[serial(tx_registry)]` only excludes other tests that
2650        // carry the same key, not every production write path elsewhere in
2651        // the crate (e.g. `graph_upsert_edges`) that also calls `register()`
2652        // as ordinary telemetry. If one of those happens to still be open and
2653        // was registered before this test's own handle, raw `oldest()` would
2654        // return THAT entry instead of the fixture's reader — see #926. Look
2655        // up this test's own entry by its known label instead of trusting
2656        // global `oldest()`, so the assertion is immune to that noise.
2657        let our_entry = khive_storage::tx_registry::snapshot()
2658            .into_iter()
2659            .find(|(_, label)| label.as_deref() == Some("tx_age_sweep_reader_pin_test"))
2660            .expect("this test's own tx_registry entry must still be open");
2661        let mut tx_age_state = TxAgeSweepState::default();
2662        let emissions = tx_age_state.observe(Some((tx_id(1), our_entry.0, our_entry.1)), &config);
2663        assert!(
2664            emissions.iter().any(|e| e.rung == TxAgeRung::Stale
2665                && e.label.as_deref() == Some("tx_age_sweep_reader_pin_test")),
2666            "expected a Stale emission naming the pinning reader, got: {emissions:?}"
2667        );
2668
2669        reader.execute_batch("COMMIT;").ok();
2670        drop(reader);
2671        drop(_tx_handle);
2672    }
2673
2674    /// Regression #926: reproduces the exact tx_registry race directly. See
2675    /// crates/khive-db/docs/api/checkpoint.md#tx_age_sweep_own_entry_survives_concurrent_older_registration
2676    #[test]
2677    #[serial(tx_registry, checkpoint_skip_metrics)]
2678    fn tx_age_sweep_own_entry_survives_concurrent_older_registration() {
2679        let _decoy = khive_storage::tx_registry::register(Some("decoy_unrelated_span".to_string()));
2680        std::thread::sleep(Duration::from_millis(2));
2681        let _own = khive_storage::tx_registry::register(Some("this_test_own_span".to_string()));
2682        std::thread::sleep(Duration::from_millis(5));
2683
2684        // Confirm the race condition is actually reproduced: an entry older
2685        // than this test's own span must currently lead the process-wide
2686        // registry. Another concurrently running test may have registered an
2687        // entry before the decoy, so do not assume the decoy is globally
2688        // oldest; the required invariant is only that our span is not.
2689        let global_oldest = khive_storage::tx_registry::oldest().expect("registry not empty");
2690        assert_ne!(
2691            global_oldest.2.as_deref(),
2692            Some("this_test_own_span"),
2693            "test setup must reproduce the race: an older, unrelated entry must be \
2694             the current global oldest, got: {global_oldest:?}"
2695        );
2696
2697        let our_entry = khive_storage::tx_registry::snapshot()
2698            .into_iter()
2699            .find(|(_, label)| label.as_deref() == Some("this_test_own_span"))
2700            .expect("this test's own tx_registry entry must still be open");
2701
2702        let config = CheckpointConfig {
2703            tx_warn_secs: Duration::from_millis(1),
2704            tx_max_age_secs: Duration::from_millis(1),
2705            ..CheckpointConfig::default()
2706        };
2707        let mut state = TxAgeSweepState::default();
2708        let emissions = state.observe(Some((tx_id(2), our_entry.0, our_entry.1)), &config);
2709        assert!(
2710            emissions
2711                .iter()
2712                .any(|e| e.rung == TxAgeRung::Stale
2713                    && e.label.as_deref() == Some("this_test_own_span")),
2714            "expected a Stale emission naming this test's own span despite an older, \
2715             unrelated concurrent registration, got: {emissions:?}"
2716        );
2717    }
2718
2719    /// `KHIVE_WAL_WARN_SUSTAINED_CYCLES` overrides the default and rejects 0.
2720    #[test]
2721    #[serial]
2722    fn checkpoint_config_warn_sustained_cycles_env_override() {
2723        let default = CheckpointConfig::default();
2724        assert_eq!(default.warn_sustained_cycles, DEFAULT_WARN_SUSTAINED_CYCLES);
2725
2726        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "5");
2727        let cfg = CheckpointConfig::from_env();
2728        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2729        assert_eq!(cfg.warn_sustained_cycles, 5);
2730
2731        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "0");
2732        let cfg_zero = CheckpointConfig::from_env();
2733        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2734        assert_eq!(
2735            cfg_zero.warn_sustained_cycles, DEFAULT_WARN_SUSTAINED_CYCLES,
2736            "zero must fall back to the default"
2737        );
2738
2739        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "not_a_number");
2740        let cfg_invalid = CheckpointConfig::from_env();
2741        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2742        assert_eq!(
2743            cfg_invalid.warn_sustained_cycles,
2744            DEFAULT_WARN_SUSTAINED_CYCLES
2745        );
2746    }
2747
2748    // ADR-094: `CheckpointOutcomeRecorded` lifecycle event tests.
2749
2750    #[derive(Default)]
2751    struct FakeEventStore {
2752        events: std::sync::Mutex<Vec<khive_storage::Event>>,
2753    }
2754
2755    #[async_trait::async_trait]
2756    impl khive_storage::EventStore for FakeEventStore {
2757        async fn append_event(
2758            &self,
2759            event: khive_storage::Event,
2760        ) -> khive_storage::StorageResult<()> {
2761            self.events.lock().unwrap().push(event);
2762            Ok(())
2763        }
2764
2765        async fn append_events(
2766            &self,
2767            events: Vec<khive_storage::Event>,
2768        ) -> khive_storage::StorageResult<khive_storage::BatchWriteSummary> {
2769            let count = events.len() as u64;
2770            self.events.lock().unwrap().extend(events);
2771            Ok(khive_storage::BatchWriteSummary {
2772                attempted: count,
2773                affected: count,
2774                failed: 0,
2775                first_error: String::new(),
2776            })
2777        }
2778
2779        async fn get_event(
2780            &self,
2781            id: uuid::Uuid,
2782        ) -> khive_storage::StorageResult<Option<khive_storage::Event>> {
2783            Ok(self
2784                .events
2785                .lock()
2786                .unwrap()
2787                .iter()
2788                .find(|e| e.id == id)
2789                .cloned())
2790        }
2791
2792        async fn query_events(
2793            &self,
2794            _filter: khive_storage::EventFilter,
2795            _page: khive_storage::PageRequest,
2796        ) -> khive_storage::StorageResult<khive_storage::Page<khive_storage::Event>> {
2797            unimplemented!("not exercised by the checkpoint lifecycle-event tests")
2798        }
2799
2800        async fn count_events(
2801            &self,
2802            _filter: khive_storage::EventFilter,
2803        ) -> khive_storage::StorageResult<u64> {
2804            Ok(self.events.lock().unwrap().len() as u64)
2805        }
2806    }
2807
2808    /// Pure decision-table coverage for every input combination
2809    /// `checkpoint_outcome_should_emit` can see: a first elevated tick, a
2810    /// sustained elevated tick, the single drain row, and the ordinary
2811    /// healthy tick that must emit nothing.
2812    #[test]
2813    fn checkpoint_outcome_should_emit_covers_all_transitions() {
2814        assert!(
2815            checkpoint_outcome_should_emit(true, false),
2816            "first elevated tick must emit"
2817        );
2818        assert!(
2819            checkpoint_outcome_should_emit(true, true),
2820            "sustained elevated tick must emit"
2821        );
2822        assert!(
2823            checkpoint_outcome_should_emit(false, true),
2824            "the single drain row (elevated -> healthy) must emit"
2825        );
2826        assert!(
2827            !checkpoint_outcome_should_emit(false, false),
2828            "an ordinary below-warn tick must not emit"
2829        );
2830    }
2831
2832    #[tokio::test]
2833    #[serial(checkpoint_skip_metrics)]
2834    async fn checkpoint_task_emits_outcome_events_while_elevated_and_stops_after_drain() {
2835        let dir = tempfile::tempdir().unwrap();
2836        let path = dir.path().join("outcome_emit.db");
2837        let pool = file_pool(&path);
2838
2839        // warn_pages: 0 means any observed WAL page count (even 0) is
2840        // "elevated" for the duration this config is active.
2841        let cfg = CheckpointConfig {
2842            interval: Duration::from_millis(10),
2843            warn_pages: 0,
2844            ..CheckpointConfig::default()
2845        };
2846        let store = Arc::new(FakeEventStore::default());
2847        let store_dyn: Arc<dyn khive_storage::EventStore> = store.clone();
2848
2849        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2850        let handle = tokio::spawn(run_checkpoint_task(
2851            pool,
2852            cfg,
2853            Some(store_dyn),
2854            "local".to_string(),
2855            shutdown_rx,
2856        ));
2857
2858        tokio::time::sleep(Duration::from_millis(60)).await;
2859        shutdown_tx.send(()).expect("send shutdown signal");
2860        tokio::time::timeout(Duration::from_secs(1), handle)
2861            .await
2862            .expect("checkpoint task should exit within 1s")
2863            .expect("checkpoint task panicked");
2864
2865        let events = store.events.lock().unwrap();
2866        assert!(
2867            !events.is_empty(),
2868            "an always-elevated config must append at least one CheckpointOutcomeRecorded event"
2869        );
2870        assert!(
2871            events
2872                .iter()
2873                .all(|e| e.kind == khive_types::EventKind::CheckpointOutcomeRecorded),
2874            "every appended event must be CheckpointOutcomeRecorded, got: {events:?}"
2875        );
2876        assert!(
2877            events.iter().all(|e| e.namespace == "local"),
2878            "events must be stamped with the namespace passed to run_checkpoint_task"
2879        );
2880    }
2881
2882    #[tokio::test]
2883    #[serial(checkpoint_skip_metrics)]
2884    async fn checkpoint_task_emits_nothing_while_healthy() {
2885        let dir = tempfile::tempdir().unwrap();
2886        let path = dir.path().join("outcome_no_emit.db");
2887        let pool = file_pool(&path);
2888
2889        // An unreachable warn_pages threshold for this test's tiny WAL: every
2890        // tick stays below warn, so no event should ever be appended.
2891        let cfg = CheckpointConfig {
2892            interval: Duration::from_millis(10),
2893            warn_pages: u64::MAX,
2894            ..CheckpointConfig::default()
2895        };
2896        let store = Arc::new(FakeEventStore::default());
2897        let store_dyn: Arc<dyn khive_storage::EventStore> = store.clone();
2898
2899        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2900        let handle = tokio::spawn(run_checkpoint_task(
2901            pool,
2902            cfg,
2903            Some(store_dyn),
2904            "local".to_string(),
2905            shutdown_rx,
2906        ));
2907
2908        tokio::time::sleep(Duration::from_millis(60)).await;
2909        shutdown_tx.send(()).expect("send shutdown signal");
2910        tokio::time::timeout(Duration::from_secs(1), handle)
2911            .await
2912            .expect("checkpoint task should exit within 1s")
2913            .expect("checkpoint task panicked");
2914
2915        assert!(
2916            store.events.lock().unwrap().is_empty(),
2917            "a config that never crosses warn_pages must never append a lifecycle event"
2918        );
2919    }
2920
2921    #[tokio::test]
2922    #[serial(checkpoint_skip_metrics)]
2923    async fn checkpoint_task_with_no_event_store_does_not_panic() {
2924        let dir = tempfile::tempdir().unwrap();
2925        let path = dir.path().join("outcome_none_store.db");
2926        let pool = file_pool(&path);
2927
2928        let cfg = CheckpointConfig {
2929            interval: Duration::from_millis(10),
2930            warn_pages: 0,
2931            ..CheckpointConfig::default()
2932        };
2933
2934        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2935        let handle = tokio::spawn(run_checkpoint_task(
2936            pool,
2937            cfg,
2938            None,
2939            "local".to_string(),
2940            shutdown_rx,
2941        ));
2942
2943        tokio::time::sleep(Duration::from_millis(40)).await;
2944        shutdown_tx.send(()).expect("send shutdown signal");
2945        tokio::time::timeout(Duration::from_secs(1), handle)
2946            .await
2947            .expect("checkpoint task should exit within 1s")
2948            .expect("checkpoint task panicked");
2949    }
2950
2951    // Fix: task-level regressions
2952    // that actually spawn `run_checkpoint_task` and capture its `tracing`
2953    // output, so the wiring at the `tx_age_state.observe(...)` call site
2954    // itself is under test — the pure `TxAgeSweepState` unit tests above
2955    // stay green even if that call site is deleted; these do not. All three
2956    // share `#[serial(tx_registry, checkpoint_skip_metrics)]`: `tx_registry`
2957    // because they read the process-wide registry singleton (see the
2958    // `log_tx_registry_oldest_debug_reports_oldest_open_entry` doc comment
2959    // above for why other tests in this same binary can transiently touch
2960    // it too), `checkpoint_skip_metrics` because they spawn the real task
2961    // that updates the module's skip-tracking atomics.
2962
2963    /// (1) A stale labeled entry with a healthy WAL: the spawned task itself
2964    /// must sweep and escalate it to `Stale`, with WAL-pressure thresholds
2965    /// set unreachably high so only the age sweep — never the WAL-pressure
2966    /// ladder — could be responsible for the captured emission.
2967    #[tokio::test]
2968    #[serial(tx_registry, checkpoint_skip_metrics)]
2969    async fn checkpoint_task_sweeps_stale_registry_entry_while_wal_is_healthy() {
2970        let dir = tempfile::tempdir().unwrap();
2971        let path = dir.path().join("tx_age_sweep_task_healthy_wal.db");
2972        let pool = file_pool(&path);
2973
2974        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
2975        let subscriber = CaptureSubscriber {
2976            events: std::sync::Arc::clone(&buffer),
2977        };
2978        let _tracing_guard = tracing::subscriber::set_default(subscriber);
2979
2980        let _tx_handle = khive_storage::tx_registry::register(Some(
2981            "checkpoint_task_healthy_wal_sweep_test".to_string(),
2982        ));
2983
2984        let cfg = CheckpointConfig {
2985            interval: Duration::from_millis(10),
2986            warn_pages: u64::MAX,
2987            high_water_pages: u64::MAX,
2988            truncate_high_water_pages: u64::MAX,
2989            tx_warn_secs: Duration::from_millis(1),
2990            tx_max_age_secs: Duration::from_millis(1),
2991            ..CheckpointConfig::default()
2992        };
2993
2994        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2995        let handle = tokio::spawn(run_checkpoint_task(
2996            pool,
2997            cfg,
2998            None,
2999            "local".to_string(),
3000            shutdown_rx,
3001        ));
3002
3003        tokio::time::sleep(Duration::from_millis(60)).await;
3004        shutdown_tx.send(()).expect("send shutdown signal");
3005        tokio::time::timeout(Duration::from_secs(1), handle)
3006            .await
3007            .expect("checkpoint task should exit within 1s")
3008            .expect("checkpoint task panicked");
3009
3010        drop(_tx_handle);
3011
3012        let events = buffer.lock().unwrap();
3013        assert!(
3014            events.iter().any(|e| {
3015                e.tx_label.as_deref() == Some("checkpoint_task_healthy_wal_sweep_test")
3016                    && e.message
3017                        .as_deref()
3018                        .is_some_and(|m| m.contains("stale-op cap"))
3019            }),
3020            "expected the spawned task to sweep and escalate the stale registry entry \
3021             to Stale on its own, got: {events:?}"
3022        );
3023    }
3024
3025    /// (2) An empty registry must never produce a Plank 1 age emission from
3026    /// the real spawned task, mirroring the pure
3027    /// `tx_age_sweep_empty_registry_emits_nothing` unit test above.
3028    #[tokio::test]
3029    #[serial(tx_registry, checkpoint_skip_metrics)]
3030    async fn checkpoint_task_emits_no_age_alert_for_an_empty_registry() {
3031        let dir = tempfile::tempdir().unwrap();
3032        let path = dir.path().join("tx_age_sweep_task_empty_registry.db");
3033        let pool = file_pool(&path);
3034
3035        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
3036        let subscriber = CaptureSubscriber {
3037            events: std::sync::Arc::clone(&buffer),
3038        };
3039        let _tracing_guard = tracing::subscriber::set_default(subscriber);
3040
3041        let cfg = CheckpointConfig {
3042            interval: Duration::from_millis(10),
3043            tx_warn_secs: Duration::from_millis(1),
3044            tx_max_age_secs: Duration::from_millis(1),
3045            ..CheckpointConfig::default()
3046        };
3047
3048        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
3049        let handle = tokio::spawn(run_checkpoint_task(
3050            pool,
3051            cfg,
3052            None,
3053            "local".to_string(),
3054            shutdown_rx,
3055        ));
3056
3057        tokio::time::sleep(Duration::from_millis(40)).await;
3058        shutdown_tx.send(()).expect("send shutdown signal");
3059        tokio::time::timeout(Duration::from_secs(1), handle)
3060            .await
3061            .expect("checkpoint task should exit within 1s")
3062            .expect("checkpoint task panicked");
3063
3064        let events = buffer.lock().unwrap();
3065        assert!(
3066            events.iter().all(|e| e
3067                .message
3068                .as_deref()
3069                .is_none_or(|m| !m.contains("ADR-091 Plank 1"))),
3070            "an empty registry must never produce a Plank 1 age emission, got: {events:?}"
3071        );
3072    }
3073
3074    /// (3) High-finding regression: a writer-busy tick must NOT silence the
3075    /// age sweep. Holds the pool's writer mutex (via `pool.try_writer()`,
3076    /// never released for the task's entire run) across several checkpoint
3077    /// intervals alongside a stale registered entry, and asserts the age
3078    /// alert still fires even though `checkpoint_once` observes
3079    /// `CheckpointTick::Skipped` on every single tick. Before the fix, the
3080    /// sweep call sat after the `Skipped` early-continue and never ran here.
3081    #[tokio::test]
3082    #[serial(tx_registry, checkpoint_skip_metrics)]
3083    async fn checkpoint_task_sweeps_stale_entry_even_when_writer_is_busy_every_tick() {
3084        reset_checkpoint_metrics_for_tests();
3085
3086        let dir = tempfile::tempdir().unwrap();
3087        let path = dir.path().join("tx_age_sweep_task_writer_busy.db");
3088        let pool = file_pool(&path);
3089        {
3090            let writer = pool.try_writer().unwrap();
3091            writer
3092                .conn()
3093                .execute_batch("CREATE TABLE IF NOT EXISTS t (x INTEGER);")
3094                .unwrap();
3095        }
3096
3097        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
3098        let subscriber = CaptureSubscriber {
3099            events: std::sync::Arc::clone(&buffer),
3100        };
3101        let _tracing_guard = tracing::subscriber::set_default(subscriber);
3102
3103        let _tx_handle = khive_storage::tx_registry::register(Some(
3104            "checkpoint_task_writer_busy_sweep_test".to_string(),
3105        ));
3106
3107        // Held for the checkpoint task's entire run, acquired BEFORE spawn
3108        // (and with no `.await` in between) so the task cannot possibly
3109        // observe a free writer on any tick.
3110        let _writer_guard = pool.try_writer().expect("acquire writer for busy hold");
3111
3112        let cfg = CheckpointConfig {
3113            interval: Duration::from_millis(10),
3114            tx_warn_secs: Duration::from_millis(1),
3115            tx_max_age_secs: Duration::from_millis(1),
3116            ..CheckpointConfig::default()
3117        };
3118
3119        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
3120        let handle = tokio::spawn(run_checkpoint_task(
3121            Arc::clone(&pool),
3122            cfg,
3123            None,
3124            "local".to_string(),
3125            shutdown_rx,
3126        ));
3127
3128        // Several 10ms intervals, every one of them writer-busy.
3129        tokio::time::sleep(Duration::from_millis(60)).await;
3130
3131        assert!(
3132            checkpoint_skipped_ticks() > 0,
3133            "test setup must actually drive at least one Skipped tick for this \
3134             regression to mean anything"
3135        );
3136
3137        shutdown_tx.send(()).expect("send shutdown signal");
3138        tokio::time::timeout(Duration::from_secs(1), handle)
3139            .await
3140            .expect("checkpoint task should exit within 1s")
3141            .expect("checkpoint task panicked");
3142
3143        drop(_writer_guard);
3144        drop(_tx_handle);
3145
3146        let events = buffer.lock().unwrap();
3147        assert!(
3148            events.iter().any(|e| {
3149                e.tx_label.as_deref() == Some("checkpoint_task_writer_busy_sweep_test")
3150                    && e.message
3151                        .as_deref()
3152                        .is_some_and(|m| m.contains("stale-op cap"))
3153            }),
3154            "expected the age sweep to fire even though every tick's writer checkout \
3155             was skipped, got: {events:?}"
3156        );
3157    }
3158}