Skip to main content

khive_db/
checkpoint.rs

1//! Periodic WAL checkpoint task for the connection pool.
2//!
3//! Issues `PRAGMA wal_checkpoint(PASSIVE)` on every tick — including when the
4//! WAL page count exceeds the high-water mark. Ordinary ticks stay
5//! PASSIVE-only and non-blocking; a rare, separately-gated escalation may
6//! additionally run `PRAGMA wal_checkpoint(TRUNCATE)` under the same writer
7//! guard with a shortened busy timeout — see the ADR-091 Plank 2 doc below
8//! for the escalation's own gating.
9//!
10//! Non-contending design: `checkpoint_once` uses `try_writer_nowait` (zero-wait
11//! `try_lock`) so a tick is skipped immediately when any writer holds the mutex,
12//! rather than blocking for up to `checkout_timeout`. The checkpoint task must
13//! never stall active write traffic — a skipped tick is always preferable.
14//!
15//! Why TRUNCATE is excluded from *every ordinary* tick: TRUNCATE inherits
16//! RESTART semantics — it waits for active readers to release their WAL
17//! snapshots and invokes the busy handler before acquiring the exclusive lock
18//! needed to reset the WAL file. With PoolConfig's 30 s busy_timeout, blindly
19//! running it every tick could sit inside SQLite holding the sole writer
20//! connection for up to 30 s, stalling all normal write traffic. PASSIVE never
21//! waits for readers; it checkpoints as many frames as currently possible and
22//! returns promptly. When WAL pressure is sustained (high_water_pages
23//! exceeded), the task emits a WARNING; once WAL pressure reaches the much
24//! higher `truncate_high_water_pages` mark, the rare Plank 2 escalation below
25//! may additionally attempt a bounded, rate-limited TRUNCATE under a
26//! deliberately shortened busy timeout — replacing what used to be a purely
27//! operator-scheduled manual step.
28//!
29//! Threshold-crossing WARN semantics: both the `warn_pages` and `high_water_pages`
30//! warnings fire at most once per below→above crossing. Skipped ticks (writer
31//! busy) leave the crossing state unchanged so that a skip cannot spuriously
32//! re-arm the rate limit while WAL pressure is still elevated. The ADR-091
33//! Plank 0 open-transaction-registry WARNs (oldest-entry escalation and the
34//! high-water snapshot enumeration) ride the SAME crossing gates — they are
35//! not independently rate-limited, so they never repeat on consecutive ticks
36//! that remain above a threshold. Only the per-tick `debug!` trace of the
37//! oldest open entry fires unconditionally.
38//!
39//! ADR-091 Plank 2: rare TRUNCATE escalation. The periodic tick above stays
40//! PASSIVE-only and non-blocking; on top of it, `checkpoint_once` also
41//! evaluates a much rarer escalation to `PRAGMA wal_checkpoint(TRUNCATE)`
42//! once the WAL has grown past `truncate_high_water_pages` and at least
43//! `truncate_min_interval` has elapsed since the last TRUNCATE *attempt*
44//! (not the last successful reclaim). This is a **single writer checkout per
45//! tick**: PASSIVE and any due TRUNCATE both run under the one guard
46//! `checkpoint_once` already holds — there is never a second concurrent
47//! checkout for TRUNCATE. If the writer mutex is busy, both PASSIVE and any
48//! due TRUNCATE are skipped for that tick, and `last_truncate_attempt` is
49//! left untouched so the next tick where the writer is free is immediately
50//! eligible rather than waiting out the full interval again.
51//! `last_truncate_attempt` only advances on a tick that actually attempted
52//! TRUNCATE (writer held, threshold crossed, interval elapsed) — never on a
53//! skip for any reason (writer busy, below threshold, interval not yet up).
54//! TRUNCATE runs under a temporarily shortened `busy_timeout`
55//! (`truncate_busy_timeout`), restored on the writer connection immediately
56//! after the attempt, win or lose. No transaction is ever killed or aborted
57//! here — the tx_registry is only read for diagnostics (Plank 1 owns
58//! enforcement).
59
60use std::sync::atomic::{AtomicU64, Ordering};
61use std::sync::Arc;
62use std::time::{Duration, Instant};
63
64use crate::pool::{ConnectionPool, WriterGuard};
65
66// ── metrics read-surface (load/perf harness) ─────────────────────────────
67//
68// Process-wide gauges mirroring the fallback-counter pattern in
69// `khive-mcp/src/daemon.rs` (`FALLBACK_*` statics + their `pub(crate)`
70// accessors): the checkpoint task is a single fire-and-forget
71// `tokio::spawn` with no handle retained anywhere the daemon's
72// connection-accept loop can reach, so these are plain module-scoped
73// atomics rather than a struct threaded through every `checkpoint_once`/
74// `maybe_truncate`/`note_truncate_outcome` call site (and, transitively,
75// every existing test call site). Read-only surface: nothing here is ever
76// reset outside `#[cfg(test)]`, and nothing reachable over the daemon wire
77// can reset them either (see `khive_runtime::daemon::DaemonRequestFrame::
78// metrics_only`).
79
80/// Last-observed WAL page count (`query_wal_pages`'s return value on its
81/// most recent call, from either `checkpoint_once` or `maybe_truncate`).
82/// `u64::MAX` is the "never observed" sentinel — no checkpoint tick has run
83/// yet in this process — distinct from a genuine zero-page WAL.
84static LAST_WAL_PAGES: AtomicU64 = AtomicU64::new(u64::MAX);
85
86/// Count of TRUNCATE attempts (`maybe_truncate`'s pragma actually invoked,
87/// win or lose) across this process's lifetime.
88static TRUNCATE_ATTEMPTS: AtomicU64 = AtomicU64::new(0);
89
90/// Current consecutive-failure count, mirrored from the caller-owned
91/// `TruncateState::consecutive_failures` field into a process-readable
92/// gauge every time `note_truncate_outcome` runs.
93static TRUNCATE_CONSECUTIVE_FAILURES: AtomicU64 = AtomicU64::new(0);
94
95/// Count of checkpoint ticks skipped because the writer mutex was already
96/// held (ADR-091 checkpoint-pressure telemetry), across this process's
97/// lifetime. Never reset outside `#[cfg(test)]`.
98static CHECKPOINT_SKIPPED_TICKS: AtomicU64 = AtomicU64::new(0);
99
100/// Current run-length of consecutive skipped ticks. Reset to 0 the next time
101/// a tick is actually observed (writer free), so a sustained skip streak is
102/// visible even between two successful observations.
103static CHECKPOINT_CONSECUTIVE_SKIPS: AtomicU64 = AtomicU64::new(0);
104
105/// WAL page count as of the most recent *observed* tick, snapshotted at the
106/// moment a skip occurs. `u64::MAX` is the "no skip has recorded a snapshot
107/// yet" sentinel, mirroring `LAST_WAL_PAGES`.
108static CHECKPOINT_LAST_SKIP_WAL_PAGES: AtomicU64 = AtomicU64::new(u64::MAX);
109
110/// Last-observed WAL page count, if any checkpoint tick has run yet in this
111/// process. Read surface for the daemon-frame metrics snapshot.
112pub fn last_observed_wal_pages() -> Option<u64> {
113    match LAST_WAL_PAGES.load(Ordering::Relaxed) {
114        u64::MAX => None,
115        pages => Some(pages),
116    }
117}
118
119/// Total WAL TRUNCATE attempts made in this process's lifetime.
120pub fn truncate_attempts() -> u64 {
121    TRUNCATE_ATTEMPTS.load(Ordering::Relaxed)
122}
123
124/// Current consecutive TRUNCATE-attempt failure count.
125pub fn truncate_consecutive_failures() -> u64 {
126    TRUNCATE_CONSECUTIVE_FAILURES.load(Ordering::Relaxed)
127}
128
129/// Total checkpoint ticks skipped (writer busy) in this process's lifetime.
130pub fn checkpoint_skipped_ticks() -> u64 {
131    CHECKPOINT_SKIPPED_TICKS.load(Ordering::Relaxed)
132}
133
134/// Current consecutive-skip run length; 0 once the next tick is observed.
135pub fn checkpoint_consecutive_skips() -> u64 {
136    CHECKPOINT_CONSECUTIVE_SKIPS.load(Ordering::Relaxed)
137}
138
139/// WAL page count last known at the time of the most recent skip, if any
140/// skip has occurred yet in this process.
141pub fn checkpoint_last_skip_wal_pages() -> Option<u64> {
142    match CHECKPOINT_LAST_SKIP_WAL_PAGES.load(Ordering::Relaxed) {
143        u64::MAX => None,
144        pages => Some(pages),
145    }
146}
147
148/// A tick's writer checkout was skipped (mutex busy): bump the lifetime and
149/// consecutive-skip counters and snapshot the last-known WAL pressure so an
150/// operator can see how bad the WAL was heading into the skip streak.
151fn note_checkpoint_skipped() {
152    CHECKPOINT_SKIPPED_TICKS.fetch_add(1, Ordering::Relaxed);
153    CHECKPOINT_CONSECUTIVE_SKIPS.fetch_add(1, Ordering::Relaxed);
154    if let Some(pages) = last_observed_wal_pages() {
155        CHECKPOINT_LAST_SKIP_WAL_PAGES.store(pages, Ordering::Relaxed);
156    }
157}
158
159/// A tick was actually observed (writer free): close out any prior skip
160/// streak. `_wal_pages` is accepted for call-site symmetry with
161/// `note_checkpoint_skipped` and to leave room for a future observed-side
162/// gauge without changing this function's signature again.
163fn note_checkpoint_observed(_wal_pages: u64) {
164    CHECKPOINT_CONSECUTIVE_SKIPS.store(0, Ordering::Relaxed);
165}
166
167/// Reset the checkpoint-pressure atomics between tests. Process-wide gauges
168/// are otherwise shared across every test in this binary; tests that assert
169/// on them must reset first and run under a shared `#[serial(...)]` group.
170#[cfg(test)]
171pub(crate) fn reset_checkpoint_metrics_for_tests() {
172    CHECKPOINT_SKIPPED_TICKS.store(0, Ordering::Relaxed);
173    CHECKPOINT_CONSECUTIVE_SKIPS.store(0, Ordering::Relaxed);
174    CHECKPOINT_LAST_SKIP_WAL_PAGES.store(u64::MAX, Ordering::Relaxed);
175}
176
177/// Outcome of a single checkpoint attempt.
178///
179/// `Skipped` is returned when the writer mutex is already held (the tick is a
180/// no-op). `Observed` carries the WAL page count read during the tick. The
181/// distinction matters for threshold-crossing WARN rate-limiting: a skipped tick
182/// must leave the above/below state unchanged so that a busy tick cannot
183/// spuriously re-arm the rate limit while WAL pressure is still elevated.
184#[derive(Debug, Clone, Copy, PartialEq, Eq)]
185pub enum CheckpointTick {
186    /// The writer mutex was busy; no checkpoint was issued this tick.
187    Skipped,
188    /// A checkpoint was issued; the value is the observed WAL page count.
189    Observed(u64),
190}
191
192/// Default number of consecutive above-`warn_pages` observed ticks required
193/// to escalate from the INFO to the WARN rung of the ADR-091 severity ladder.
194pub const DEFAULT_WARN_SUSTAINED_CYCLES: u8 = 3;
195
196/// Configuration for the WAL checkpoint background task.
197///
198/// All fields default to conservative production values. Override via the
199/// environment variables documented on each field.
200#[derive(Clone, Debug)]
201pub struct CheckpointConfig {
202    /// How often to run a passive checkpoint when there is no active write.
203    ///
204    /// Overridable via `KHIVE_CHECKPOINT_INTERVAL_MS` (milliseconds).
205    /// Default: 500 ms.
206    pub interval: Duration,
207
208    /// WAL page count above which a warning is logged.
209    ///
210    /// Overridable via `KHIVE_WAL_WARN_PAGES`.
211    /// Default: 2000 pages (~8 MB at 4 KiB page size).
212    pub warn_pages: u64,
213
214    /// Number of consecutive observed ticks with `wal_pages >= warn_pages`
215    /// required before the ADR-091 severity ladder escalates from INFO
216    /// (first crossing) to WARN (sustained pressure). Edge-triggered once
217    /// per elevation episode — see [`CheckpointSeverityState`].
218    ///
219    /// Overridable via `KHIVE_WAL_WARN_SUSTAINED_CYCLES`.
220    /// Default: 3 cycles.
221    pub warn_sustained_cycles: u8,
222
223    /// WAL page count above which a high-pressure WARNING is logged.
224    ///
225    /// The periodic task always runs PASSIVE regardless; this threshold signals
226    /// that a long-lived reader may be pinning an old WAL snapshot that PASSIVE
227    /// cannot reclaim. An operator can then schedule a blocking TRUNCATE at a
228    /// safe moment outside normal write traffic.
229    ///
230    /// Overridable via `KHIVE_WAL_HIGH_WATER_PAGES`.
231    /// Default: 6000 pages (~24 MB at 4 KiB page size).
232    pub high_water_pages: u64,
233
234    /// WAL page count above which a TRUNCATE escalation attempt is armed
235    /// (ADR-091 Plank 2).
236    ///
237    /// This is a separate, much higher threshold than `high_water_pages`:
238    /// crossing it does not itself attempt TRUNCATE — it only arms the
239    /// attempt, which additionally requires `truncate_min_interval` to have
240    /// elapsed since the last attempt.
241    ///
242    /// Overridable via `KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES`.
243    /// Default: 20000 pages.
244    pub truncate_high_water_pages: u64,
245
246    /// Minimum spacing between TRUNCATE *attempts* (not successes).
247    ///
248    /// A skipped tick (writer busy, below threshold, or interval not yet
249    /// elapsed) never advances the "last attempt" clock, so the next tick
250    /// where the writer is free and the threshold is still crossed is
251    /// immediately eligible rather than waiting out the full interval again.
252    ///
253    /// Overridable via `KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS`.
254    /// Default: 300 seconds (5 minutes).
255    pub truncate_min_interval: Duration,
256
257    /// Temporary `busy_timeout` used only for the duration of a TRUNCATE
258    /// attempt, restored to the pool's configured busy timeout immediately
259    /// after the attempt completes (win or lose).
260    ///
261    /// Overridable via `KHIVE_WAL_TRUNCATE_BUSY_MS`.
262    /// Default: 2000 ms.
263    pub truncate_busy_timeout: Duration,
264}
265
266impl Default for CheckpointConfig {
267    fn default() -> Self {
268        Self {
269            interval: Duration::from_millis(500),
270            warn_pages: 2000,
271            warn_sustained_cycles: DEFAULT_WARN_SUSTAINED_CYCLES,
272            high_water_pages: 6000,
273            truncate_high_water_pages: 20_000,
274            truncate_min_interval: Duration::from_secs(300),
275            truncate_busy_timeout: Duration::from_millis(2000),
276        }
277    }
278}
279
280impl CheckpointConfig {
281    /// Build a `CheckpointConfig` from the environment.
282    ///
283    /// Unset or unparseable variables fall back to the compiled-in defaults.
284    pub fn from_env() -> Self {
285        let mut cfg = Self::default();
286
287        if let Ok(ms) = std::env::var("KHIVE_CHECKPOINT_INTERVAL_MS") {
288            if let Ok(v) = ms.parse::<u64>() {
289                if v > 0 {
290                    cfg.interval = Duration::from_millis(v);
291                }
292            }
293        }
294
295        if let Ok(v) = std::env::var("KHIVE_WAL_WARN_PAGES") {
296            if let Ok(n) = v.parse::<u64>() {
297                if n > 0 {
298                    cfg.warn_pages = n;
299                }
300            }
301        }
302
303        if let Ok(v) = std::env::var("KHIVE_WAL_WARN_SUSTAINED_CYCLES") {
304            if let Ok(n) = v.parse::<u8>() {
305                if n > 0 {
306                    cfg.warn_sustained_cycles = n;
307                }
308            }
309        }
310
311        if let Ok(v) = std::env::var("KHIVE_WAL_HIGH_WATER_PAGES") {
312            if let Ok(n) = v.parse::<u64>() {
313                if n > 0 {
314                    cfg.high_water_pages = n;
315                }
316            }
317        }
318
319        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES") {
320            if let Ok(n) = v.parse::<u64>() {
321                if n > 0 {
322                    cfg.truncate_high_water_pages = n;
323                }
324            }
325        }
326
327        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS") {
328            if let Ok(n) = v.parse::<u64>() {
329                if n > 0 {
330                    cfg.truncate_min_interval = Duration::from_secs(n);
331                }
332            }
333        }
334
335        if let Ok(v) = std::env::var("KHIVE_WAL_TRUNCATE_BUSY_MS") {
336            if let Ok(n) = v.parse::<u64>() {
337                if n > 0 {
338                    cfg.truncate_busy_timeout = Duration::from_millis(n);
339                }
340            }
341        }
342
343        cfg
344    }
345}
346
347/// Mutable escalation state carried across ticks by the caller (ADR-091 Plank 2).
348///
349/// Kept separate from [`CheckpointConfig`] because it is *state*, not
350/// configuration: `last_attempt` and `consecutive_failures` mutate every tick,
351/// while `CheckpointConfig` is parsed once and held immutable for the life of
352/// the task.
353#[derive(Debug, Default)]
354pub struct TruncateState {
355    /// When the last TRUNCATE *attempt* ran (armed + writer held), regardless
356    /// of whether it succeeded in reclaiming pages. `None` means no attempt
357    /// has ever run, so the first armed tick is immediately eligible.
358    last_attempt: Option<Instant>,
359    /// Count of consecutive TRUNCATE attempts that failed to bring `wal_pages`
360    /// back below `warn_pages`. Resets to 0 the first time an attempt clears
361    /// `warn_pages`; used to fire a one-shot escalated WARN at exactly 3
362    /// consecutive failures (does not repeat every subsequent attempt).
363    consecutive_failures: u32,
364}
365
366/// ADR-091 graduated severity rung for sustained WAL pressure.
367///
368/// `Alarm` is never produced by [`CheckpointSeverityState::observe_wal_pages`]
369/// — it labels the existing TRUNCATE-escalation tier (`maybe_truncate`),
370/// which is gated on its own threshold/interval state, not on this ladder.
371/// It exists here so callers and tests can name all three rungs uniformly.
372#[derive(Debug, Clone, Copy, PartialEq, Eq)]
373pub enum CheckpointSeverityRung {
374    /// First observed tick crossing `warn_pages` after a below-warn tick.
375    Info,
376    /// `warn_sustained_cycles` consecutive observed ticks at/above
377    /// `warn_pages`; edge-triggered once per elevation episode.
378    Warn,
379    /// The TRUNCATE-escalation tier (`checkpoint_high_water_pages` and
380    /// above); never emitted by `observe_wal_pages`.
381    Alarm,
382}
383
384/// ADR-091 severity ladder state, carried across ticks by the caller
385/// alongside [`TruncateState`]. Pure state machine: no I/O, no logging —
386/// callers turn the returned emissions into `tracing` calls.
387#[derive(Debug, Default, Clone)]
388pub struct CheckpointSeverityState {
389    /// Whether the previous observed tick was at/above `warn_pages`. Drives
390    /// the below→above edge that fires INFO.
391    was_above_warn: bool,
392    /// Run-length of consecutive observed ticks at/above `warn_pages` in the
393    /// current elevation episode. Resets to 0 on any below-warn tick.
394    consecutive_above_warn: u8,
395    /// Whether WARN has already fired for the current elevation episode, so
396    /// sustained pressure logs WARN once per episode, not once per tick past
397    /// the threshold.
398    warn_emitted_for_episode: bool,
399}
400
401/// One severity-ladder emission produced by a single
402/// [`CheckpointSeverityState::observe_wal_pages`] call.
403#[derive(Debug, Clone, Copy, PartialEq, Eq)]
404pub struct CheckpointSeverityEmission {
405    /// Which rung this emission represents (`Info` or `Warn`; see
406    /// [`CheckpointSeverityRung::Alarm`] doc for why `Alarm` never appears
407    /// here).
408    pub rung: CheckpointSeverityRung,
409    /// The WAL page count observed on the tick that produced this emission.
410    pub wal_pages: u64,
411    /// The `warn_pages` threshold in effect for this tick.
412    pub threshold_pages: u64,
413    /// Consecutive above-warn cycle count as of this tick (1 on the INFO
414    /// edge, `warn_sustained_cycles` on the WARN edge).
415    pub consecutive_cycles: u8,
416}
417
418impl CheckpointSeverityState {
419    /// Advance the severity ladder by one observed tick and return every
420    /// rung crossed on this tick (zero, one, or two emissions: a fresh
421    /// elevation episode can produce INFO and, if `warn_sustained_cycles`
422    /// is 1, WARN on the very same tick).
423    ///
424    /// A below-warn tick resets both the consecutive-cycle counter and the
425    /// per-episode WARN latch, re-arming INFO/WARN for a later episode.
426    /// Skipped ticks must not be passed here at all — the caller only calls
427    /// this on `CheckpointTick::Observed`, matching the existing
428    /// threshold-crossing WARN's skip-leaves-state-unchanged rule.
429    pub fn observe_wal_pages(
430        &mut self,
431        wal_pages: u64,
432        config: &CheckpointConfig,
433    ) -> Vec<CheckpointSeverityEmission> {
434        let mut emissions = Vec::new();
435        let above_warn = wal_pages >= config.warn_pages;
436
437        if above_warn {
438            self.consecutive_above_warn = self.consecutive_above_warn.saturating_add(1);
439
440            if !self.was_above_warn {
441                emissions.push(CheckpointSeverityEmission {
442                    rung: CheckpointSeverityRung::Info,
443                    wal_pages,
444                    threshold_pages: config.warn_pages,
445                    consecutive_cycles: self.consecutive_above_warn,
446                });
447            }
448
449            if !self.warn_emitted_for_episode
450                && self.consecutive_above_warn >= config.warn_sustained_cycles
451            {
452                emissions.push(CheckpointSeverityEmission {
453                    rung: CheckpointSeverityRung::Warn,
454                    wal_pages,
455                    threshold_pages: config.warn_pages,
456                    consecutive_cycles: self.consecutive_above_warn,
457                });
458                self.warn_emitted_for_episode = true;
459            }
460        } else {
461            self.consecutive_above_warn = 0;
462            self.warn_emitted_for_episode = false;
463        }
464
465        self.was_above_warn = above_warn;
466        emissions
467    }
468}
469
470/// Run the WAL checkpoint background task.
471///
472/// This is a long-running async task that should be spawned with
473/// `tokio::spawn`. It loops until `shutdown_rx` observes a change (or its
474/// sender is dropped), at which point it exits on its next `select!` wakeup.
475/// Callers should hold the paired `tokio::sync::watch::Sender` for the
476/// daemon's run scope and send on it as part of the shutdown sequence.
477///
478/// An earlier version of this task used `Arc::strong_count(&pool) <= 1` as
479/// its exit condition instead of an explicit signal. That check is
480/// unreachable whenever a sibling owner holds its own clone of `pool` for
481/// the task's lifetime — which the production boot path does: `event_store`
482/// (`Option<Arc<dyn EventStore>>`), when `Some`, is a `SqlEventStore` that
483/// retains its own `Arc::clone` of the same pool, so the task always
484/// observed `strong_count == 2` and never exited via that mechanism
485/// (issue #774). The explicit watch channel does not depend on how many
486/// other owners exist.
487///
488/// The task issues `PRAGMA wal_checkpoint(PASSIVE)` on every tick — ordinary
489/// ticks stay PASSIVE-only and non-blocking; see the module-level doc for the
490/// rare Plank 2 TRUNCATE escalation `checkpoint_once` may additionally run
491/// under the same writer guard when WAL pressure is sustained past
492/// `truncate_high_water_pages`. A WARNING is emitted once on threshold
493/// crossing (wal_pages transitions from below a threshold to at/above) rather
494/// than on every tick, preventing log spam when a long-lived reader pins a
495/// WAL snapshot.
496///
497/// Skipped ticks (writer mutex busy) leave both crossing-state flags unchanged
498/// so that a skip cannot spuriously re-arm the rate limit while WAL pressure is
499/// still elevated.
500///
501/// Uses `try_writer_nowait` (zero-wait try-lock) so a busy writer causes the
502/// current tick to be skipped rather than stalling write traffic.
503///
504/// `event_store` (ADR-094): when `Some`, this task appends a best-effort
505/// `CheckpointOutcomeRecorded` lifecycle event on every tick where WAL
506/// pressure is at/above `warn_pages`, plus exactly one drain row on the tick
507/// that observes pressure fall back below `warn_pages` after an elevated
508/// episode — never on every ordinary below-warn tick. `namespace` is
509/// stamped on those rows. `None` makes event emission a pure no-op, exactly
510/// like an unconfigured audit sink elsewhere in the runtime.
511pub async fn run_checkpoint_task(
512    pool: Arc<ConnectionPool>,
513    config: CheckpointConfig,
514    event_store: Option<Arc<dyn khive_storage::EventStore>>,
515    namespace: String,
516    mut shutdown_rx: tokio::sync::watch::Receiver<()>,
517) {
518    let mut interval = tokio::time::interval(config.interval);
519    interval.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip);
520    let mut severity_state = CheckpointSeverityState::default();
521    let mut was_above_high_water = false;
522    let mut truncate_state = TruncateState::default();
523    // Independent of `severity_state` (which owns the WARN-episode ladder
524    // internally): this tracks only the "was the previous observed tick
525    // elevated" edge the ADR-094 event emission needs, so the event path
526    // never has to reach into the severity state machine's private fields.
527    let mut event_was_elevated = false;
528
529    loop {
530        // A closed sender (the daemon returning without an explicit send)
531        // makes `changed()` resolve with `Err` immediately, which `select!`
532        // treats as ready — so shutdown is observed either way, not just on
533        // an explicit send.
534        tokio::select! {
535            _ = interval.tick() => {}
536            _ = shutdown_rx.changed() => break,
537        }
538
539        let tick = checkpoint_once(&pool, &config, &mut truncate_state);
540        // Skipped ticks leave crossing state unchanged — a busy tick must not
541        // re-arm the rate limit while WAL pressure is still elevated.
542        let wal_pages = match tick {
543            CheckpointTick::Skipped => continue,
544            CheckpointTick::Observed(n) => n,
545        };
546
547        let above_warn = wal_pages >= config.warn_pages;
548        let above_high_water = wal_pages >= config.high_water_pages;
549        let above_truncate_high_water = wal_pages >= config.truncate_high_water_pages;
550
551        // Per-tick debug for the oldest open entry always fires (cheap, single
552        // `oldest()` lookup); the two `warn!`-level registry logs below are
553        // gated on the SAME crossing state as the WAL-threshold WARNs above,
554        // so sustained pressure logs once per crossing, not once per tick.
555        log_tx_registry_oldest_debug(wal_pages);
556
557        // ADR-091 severity ladder: INFO on the first below→above crossing,
558        // WARN once `warn_sustained_cycles` consecutive ticks stay elevated.
559        // The oldest-entry registry WARN rides the same INFO edge the old
560        // binary crossing_warn used to gate on.
561        for emission in severity_state.observe_wal_pages(wal_pages, &config) {
562            match emission.rung {
563                CheckpointSeverityRung::Info => {
564                    log_tx_registry_oldest_warn(wal_pages);
565                    tracing::info!(
566                        wal_pages = emission.wal_pages,
567                        warn_threshold = emission.threshold_pages,
568                        "WAL page count crossed warn threshold"
569                    );
570                }
571                CheckpointSeverityRung::Warn => {
572                    tracing::warn!(
573                        wal_pages = emission.wal_pages,
574                        warn_threshold = emission.threshold_pages,
575                        consecutive_cycles = emission.consecutive_cycles,
576                        "WAL page count failed to drain below warn threshold"
577                    );
578                }
579                CheckpointSeverityRung::Alarm => {
580                    // Never produced by `observe_wal_pages`; see its doc.
581                }
582            }
583        }
584
585        let high_water_crossed = crossing_warn(above_high_water, &mut was_above_high_water);
586        if high_water_crossed {
587            log_tx_registry_snapshot_warn(wal_pages);
588            tracing::warn!(
589                wal_pages,
590                high_water = config.high_water_pages,
591                "WAL high-water mark exceeded; sustained WAL pressure — \
592                 a long-lived reader may be pinning an old snapshot that PASSIVE cannot reclaim"
593            );
594        }
595
596        // ADR-094: emit every elevated tick, plus exactly one drain row on
597        // the tick that observes the episode end — never on every ordinary
598        // below-warn tick.
599        if checkpoint_outcome_should_emit(above_warn, event_was_elevated) {
600            let payload = khive_storage::CheckpointOutcomeRecordedPayload {
601                wal_pages,
602                warn_pages: config.warn_pages,
603                high_water_pages: config.high_water_pages,
604                truncate_high_water_pages: config.truncate_high_water_pages,
605                above_warn,
606                above_high_water,
607                above_truncate_high_water,
608            };
609            append_checkpoint_lifecycle_event(
610                event_store.as_ref(),
611                &namespace,
612                khive_types::EventKind::CheckpointOutcomeRecorded,
613                payload,
614            )
615            .await;
616        }
617        event_was_elevated = above_warn;
618    }
619}
620
621/// Whether a `CheckpointOutcomeRecorded` event should be emitted for this
622/// tick: every elevated (`above_warn`) tick, plus exactly one drain row on
623/// the first tick that observes a return to below-warn after an elevated
624/// episode (`was_elevated`). An ordinary below-warn tick following another
625/// below-warn tick emits nothing.
626fn checkpoint_outcome_should_emit(above_warn: bool, was_elevated: bool) -> bool {
627    above_warn || was_elevated
628}
629
630/// Append one ADR-094 lifecycle event on behalf of the checkpoint task.
631///
632/// Best-effort: `event_store == None` is a no-op, and an append failure is
633/// logged and swallowed. No lifecycle-append error may ever interrupt or
634/// slow down checkpoint/TRUNCATE work — the checkpoint task's correctness
635/// does not depend on this succeeding.
636async fn append_checkpoint_lifecycle_event<P: serde::Serialize>(
637    store: Option<&Arc<dyn khive_storage::EventStore>>,
638    namespace: &str,
639    kind: khive_types::EventKind,
640    payload: P,
641) {
642    let Some(store) = store else {
643        return;
644    };
645    let payload_value = match serde_json::to_value(&payload) {
646        Ok(v) => v,
647        Err(e) => {
648            tracing::warn!(
649                error = %e,
650                event_kind = %kind.name(),
651                "failed to serialize checkpoint lifecycle event payload"
652            );
653            return;
654        }
655    };
656    let event = khive_storage::Event::new(
657        namespace,
658        "checkpoint.lifecycle",
659        kind,
660        khive_types::SubstrateKind::Event,
661        "daemon:checkpoint_task",
662    )
663    .with_payload(payload_value);
664    if let Err(err) = store.append_event(event).await {
665        tracing::warn!(
666            error = %err,
667            event_kind = %kind.name(),
668            "checkpoint lifecycle event append failed"
669        );
670    }
671}
672
673/// ADR-091 Plank 0: log the oldest open transaction registry entry alongside
674/// the WAL frame count at `debug!`, on EVERY tick regardless of threshold
675/// state. This is the low-volume per-tick trace; the WARN-level escalations
676/// live in [`log_tx_registry_oldest_warn`] and
677/// [`log_tx_registry_snapshot_warn`], both of which are gated on threshold
678/// *crossing* by the caller (`run_checkpoint_task`) so they fire once per
679/// crossing rather than once per tick. Observe only: this never enforces or
680/// force-closes anything.
681fn log_tx_registry_oldest_debug(wal_pages: u64) {
682    if let Some((age, label)) = khive_storage::tx_registry::oldest() {
683        tracing::debug!(
684            wal_pages,
685            oldest_tx_age_secs = age.as_secs_f64(),
686            oldest_tx_label = label.as_deref().unwrap_or("<unlabeled>"),
687            "WAL checkpoint tick: oldest open transaction registry entry"
688        );
689    }
690}
691
692/// ADR-091 Plank 0: escalate the oldest open registry entry to `warn!`.
693///
694/// Callers MUST gate this on a below→above `warn_pages` crossing (via
695/// `crossing_warn`) — it is not rate-limited internally, so calling it every
696/// tick would reproduce the log-spam bug this rewrite fixes.
697fn log_tx_registry_oldest_warn(wal_pages: u64) {
698    if let Some((age, label)) = khive_storage::tx_registry::oldest() {
699        tracing::warn!(
700            wal_pages,
701            oldest_tx_age_secs = age.as_secs_f64(),
702            oldest_tx_label = label.as_deref().unwrap_or("<unlabeled>"),
703            "WAL checkpoint tick: oldest open transaction registry entry"
704        );
705    }
706}
707
708/// ADR-091 Plank 0: enumerate every open registry entry at `warn!` — the
709/// "which caller is holding the pin" answer this ADR's static reading could
710/// not produce.
711///
712/// Callers MUST gate this on a below→above `high_water_pages` crossing (via
713/// `crossing_warn`) — it is not rate-limited internally, so calling it every
714/// tick would repeat the full snapshot enumeration every tick under
715/// sustained pressure.
716fn log_tx_registry_snapshot_warn(wal_pages: u64) {
717    for (age, label) in khive_storage::tx_registry::snapshot() {
718        tracing::warn!(
719            wal_pages,
720            tx_age_secs = age.as_secs_f64(),
721            tx_label = label.as_deref().unwrap_or("<unlabeled>"),
722            "WAL high-water: open transaction registry entry"
723        );
724    }
725}
726
727/// Issue one checkpoint cycle against the writer connection.
728///
729/// Returns [`CheckpointTick::Skipped`] when the writer mutex is already held
730/// (the tick is a no-op) and [`CheckpointTick::Observed`] with the WAL page
731/// count otherwise. All checkpoint errors are logged at warn level and treated
732/// as non-fatal; the next tick retries.
733///
734/// Uses `try_writer_nowait` so that a busy active writer causes this tick to
735/// be skipped immediately rather than stalling for up to `checkout_timeout`.
736/// The caller (`run_checkpoint_task`) owns all threshold-crossing WARN logging
737/// so that warnings fire at most once per crossing, not every tick.
738///
739/// ADR-091 Plank 2: after the PASSIVE pass, this is also the single point
740/// that may escalate to TRUNCATE (`maybe_truncate`) — under the SAME writer
741/// guard acquired above, never a second checkout. A busy writer (`Skipped`)
742/// short-circuits before either PASSIVE or TRUNCATE run.
743pub fn checkpoint_once(
744    pool: &ConnectionPool,
745    config: &CheckpointConfig,
746    truncate_state: &mut TruncateState,
747) -> CheckpointTick {
748    let writer = match pool.try_writer_nowait() {
749        Ok(w) => w,
750        Err(_) => {
751            note_checkpoint_skipped();
752            return CheckpointTick::Skipped;
753        }
754    };
755
756    let wal_pages = query_wal_pages(writer.conn());
757
758    if let Err(e) = writer
759        .conn()
760        .execute_batch("PRAGMA wal_checkpoint(PASSIVE)")
761    {
762        tracing::warn!(error = %e, "WAL checkpoint failed");
763    } else {
764        tracing::debug!(wal_pages, "WAL checkpoint issued");
765    }
766
767    maybe_truncate(pool, &writer, config, wal_pages, truncate_state);
768
769    CheckpointTick::Observed(wal_pages)
770}
771
772/// ADR-091 Plank 2: evaluate and, if due, attempt a TRUNCATE escalation.
773///
774/// Runs under the writer guard the caller already holds — never performs its
775/// own checkout. Returns immediately (a no-op) unless BOTH:
776/// - `wal_pages >= config.truncate_high_water_pages`, and
777/// - no prior attempt (`truncate_state.last_attempt.is_none()`) OR at least
778///   `config.truncate_min_interval` has elapsed since the last attempt.
779///
780/// `truncate_state.last_attempt` is stamped ONLY immediately before the
781/// TRUNCATE pragma itself runs (writer held, threshold crossed, interval
782/// elapsed, AND the temporary busy_timeout override successfully applied) —
783/// every earlier return (below threshold, interval not elapsed, or the
784/// busy_timeout override failing to apply) is a skip, not an attempt, and
785/// never touches it, matching the ADR's "skip must not stamp" requirement.
786///
787/// The oldest-pinning-transaction snapshot is logged (reusing Plank 0's
788/// `tx_registry`) before the attempt, so an operator can see what is
789/// (potentially) pinning the WAL even if the attempt goes on to succeed.
790/// `busy_timeout` is temporarily lowered to `config.truncate_busy_timeout` for
791/// the PRAGMA call and restored to the pool's configured value immediately
792/// after, regardless of outcome. No transaction is ever killed here — this is
793/// read-only diagnostics plus the TRUNCATE pragma itself; enforcement is
794/// Plank 1's job, not this one's.
795fn maybe_truncate(
796    pool: &ConnectionPool,
797    writer: &WriterGuard<'_>,
798    config: &CheckpointConfig,
799    wal_pages_before: u64,
800    truncate_state: &mut TruncateState,
801) {
802    if wal_pages_before < config.truncate_high_water_pages {
803        return;
804    }
805
806    if let Some(last) = truncate_state.last_attempt {
807        if last.elapsed() < config.truncate_min_interval {
808            return;
809        }
810    }
811
812    // Which caller (if any) is pinning the WAL — logged before the attempt so
813    // it is available even if the attempt itself succeeds.
814    log_tx_registry_snapshot_warn(wal_pages_before);
815
816    let conn = writer.conn();
817    let original_busy_timeout = pool.config().busy_timeout;
818
819    if let Err(e) = conn.busy_timeout(config.truncate_busy_timeout) {
820        // Setup failed before the TRUNCATE pragma ever ran — this is a skip,
821        // not an attempt. `last_attempt` must NOT advance here (ADR-091
822        // §377-382): stamping now would suppress the next eligible attempt
823        // for the full `truncate_min_interval` on a path that never touched
824        // the WAL at all.
825        tracing::warn!(error = %e, "failed to lower busy_timeout for TRUNCATE attempt; skipping");
826        return;
827    }
828
829    // Only now is this a genuine attempt: the writer is held, the threshold
830    // and interval gates passed, and the busy_timeout override is in effect
831    // immediately before the TRUNCATE pragma itself.
832    truncate_state.last_attempt = Some(Instant::now());
833
834    let start = Instant::now();
835    let outcome = conn.execute_batch("PRAGMA wal_checkpoint(TRUNCATE)");
836    let elapsed = start.elapsed();
837
838    // Restore the pool's configured busy_timeout immediately after the
839    // attempt, win or lose, before any other logging or bookkeeping.
840    if let Err(e) = conn.busy_timeout(original_busy_timeout) {
841        tracing::warn!(error = %e, "failed to restore busy_timeout after TRUNCATE attempt");
842    }
843
844    match outcome {
845        Ok(()) => {
846            let wal_pages_after = query_wal_pages(conn);
847            tracing::info!(
848                wal_pages_before,
849                wal_pages_after,
850                elapsed_ms = elapsed.as_millis() as u64,
851                "WAL TRUNCATE checkpoint attempted"
852            );
853
854            let made_progress = wal_pages_after < wal_pages_before;
855            if !made_progress {
856                tracing::warn!(
857                    wal_pages_before,
858                    wal_pages_after,
859                    "WAL TRUNCATE attempt made no progress; \
860                     a long-lived reader may still be pinning the WAL snapshot"
861                );
862                log_tx_registry_snapshot_warn(wal_pages_after);
863            }
864
865            note_truncate_outcome(config, wal_pages_after, truncate_state);
866        }
867        Err(e) => {
868            tracing::warn!(error = %e, wal_pages_before, "WAL TRUNCATE attempt failed");
869            log_tx_registry_snapshot_warn(wal_pages_before);
870            note_truncate_outcome(config, wal_pages_before, truncate_state);
871        }
872    }
873}
874
875/// ADR-091 Plank 2: track consecutive TRUNCATE attempts that fail to bring
876/// `wal_pages` back below `warn_pages`, firing a one-shot escalated WARN at
877/// exactly the third consecutive failure (does not repeat every attempt
878/// thereafter — mirrors the crossing-WARN debounce used elsewhere in this
879/// module). A single attempt that clears `warn_pages` resets the counter.
880fn note_truncate_outcome(
881    config: &CheckpointConfig,
882    wal_pages_after: u64,
883    state: &mut TruncateState,
884) {
885    // Metrics read-surface (load/perf harness): this function runs exactly
886    // once per genuine TRUNCATE attempt (both the `Ok` and `Err` outcome
887    // arms in `maybe_truncate` call it once each), so incrementing here
888    // counts total attempts without a separate call site.
889    TRUNCATE_ATTEMPTS.fetch_add(1, Ordering::Relaxed);
890
891    if wal_pages_after >= config.warn_pages {
892        state.consecutive_failures = state.consecutive_failures.saturating_add(1);
893        if state.consecutive_failures == 3 {
894            tracing::warn!(
895                wal_pages_after,
896                warn_threshold = config.warn_pages,
897                "WAL TRUNCATE has failed to clear WAL pressure for 3 consecutive attempts"
898            );
899        }
900    } else {
901        state.consecutive_failures = 0;
902    }
903
904    TRUNCATE_CONSECUTIVE_FAILURES.store(state.consecutive_failures as u64, Ordering::Relaxed);
905}
906
907/// Evaluate whether a threshold-crossing WARN should fire and advance the
908/// crossing-state flag.
909///
910/// Returns `true` on a false→true transition in `now_above` (first observed
911/// above-threshold tick after a below-threshold tick), `false` on any other
912/// tick. The `was_above` flag is updated in-place to track state across calls.
913/// Used by `run_checkpoint_task` for both the `warn_pages` band and the
914/// `high_water_pages` threshold.
915fn crossing_warn(now_above: bool, was_above: &mut bool) -> bool {
916    let fire = now_above && !*was_above;
917    *was_above = now_above;
918    fire
919}
920
921/// Query the current WAL frame count via `PRAGMA wal_checkpoint`.
922///
923/// The pragma returns a 3-column row `(busy, log, checkpointed)`, where `log`
924/// (column index 1) is the number of frames currently in the WAL file — the
925/// backlog the high-water threshold keys off. (Column 2 is `checkpointed`, the
926/// frames moved *by this call*, which is not the WAL size.) The no-arg pragma
927/// also performs a PASSIVE checkpoint as a side effect; the subsequent explicit
928/// `PRAGMA wal_checkpoint(PASSIVE)` in `checkpoint_once` is a deliberate second
929/// pass that can checkpoint any frames written between the two calls.
930///
931/// Returns 0 on any error (e.g. in-memory DB where WAL is not active, which
932/// reports `log = -1`).
933fn query_wal_pages(conn: &rusqlite::Connection) -> u64 {
934    let pages = conn
935        .query_row("PRAGMA wal_checkpoint", [], |row| row.get::<_, i64>(1))
936        .unwrap_or(0)
937        .max(0) as u64;
938    // Metrics read-surface (load/perf harness): mirror every observation into
939    // the process-wide gauge, regardless of which caller (`checkpoint_once`
940    // or `maybe_truncate`) triggered it.
941    LAST_WAL_PAGES.store(pages, Ordering::Relaxed);
942    note_checkpoint_observed(pages);
943    pages
944}
945
946#[cfg(test)]
947mod tests {
948    use super::*;
949    use crate::pool::PoolConfig;
950    use serial_test::serial;
951    use tracing::field::{Field, Visit};
952
953    #[derive(Clone, Debug, Default)]
954    struct CapturedEvent {
955        message: Option<String>,
956        oldest_tx_label: Option<String>,
957        tx_label: Option<String>,
958    }
959
960    #[derive(Default)]
961    struct CapturedEventVisitor(CapturedEvent);
962
963    impl Visit for CapturedEventVisitor {
964        fn record_str(&mut self, field: &Field, value: &str) {
965            match field.name() {
966                "message" => self.0.message = Some(value.to_string()),
967                "oldest_tx_label" => self.0.oldest_tx_label = Some(value.to_string()),
968                "tx_label" => self.0.tx_label = Some(value.to_string()),
969                _ => {}
970            }
971        }
972
973        fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
974            let formatted = format!("{value:?}");
975            let cleaned = formatted
976                .trim_start_matches('"')
977                .trim_end_matches('"')
978                .to_string();
979            match field.name() {
980                "message" => self.0.message = Some(cleaned),
981                "oldest_tx_label" => self.0.oldest_tx_label = Some(cleaned),
982                "tx_label" => self.0.tx_label = Some(cleaned),
983                _ => {}
984            }
985        }
986    }
987
988    /// Minimal `tracing::Subscriber` that captures events into a thread-local
989    /// vec, installed as the thread-local default for the duration of one
990    /// test closure via `tracing::subscriber::with_default`. Mirrors the
991    /// capture subscriber in `khive-runtime/src/pack.rs`'s gate-dispatch tests.
992    struct CaptureSubscriber {
993        events: std::sync::Arc<std::sync::Mutex<Vec<CapturedEvent>>>,
994    }
995
996    impl tracing::Subscriber for CaptureSubscriber {
997        fn enabled(&self, _: &tracing::Metadata<'_>) -> bool {
998            true
999        }
1000        fn new_span(&self, _: &tracing::span::Attributes<'_>) -> tracing::span::Id {
1001            tracing::span::Id::from_u64(1)
1002        }
1003        fn record(&self, _: &tracing::span::Id, _: &tracing::span::Record<'_>) {}
1004        fn record_follows_from(&self, _: &tracing::span::Id, _: &tracing::span::Id) {}
1005        fn event(&self, event: &tracing::Event<'_>) {
1006            let mut visitor = CapturedEventVisitor::default();
1007            event.record(&mut visitor);
1008            self.events.lock().unwrap().push(visitor.0);
1009        }
1010        fn enter(&self, _: &tracing::span::Id) {}
1011        fn exit(&self, _: &tracing::span::Id) {}
1012    }
1013
1014    /// ADR-091 Plank 0: `log_tx_registry_oldest_debug` emits a debug-level log
1015    /// naming the oldest open registry entry's label, on every call.
1016    ///
1017    /// `#[serial(tx_registry)]`: the registry is a process-wide singleton
1018    /// shared across every test in this binary — see `pool.rs`'s and
1019    /// `sql_bridge.rs`'s registry tests, which share this same serial group
1020    /// (round-1 fix: these three were previously unserialized and could
1021    /// race, corrupting each other's `oldest()`/`snapshot()` reads).
1022    ///
1023    /// This test does NOT hardcode "checkpoint_tick_test" as the expected
1024    /// label: production write paths elsewhere in this same test binary
1025    /// (vectors/graph/text stores) also register short-lived registry
1026    /// entries while their own tests run, and `serial(tx_registry)` only
1027    /// serializes against the OTHER tests in that same group, not against
1028    /// every write path in the crate. Instead it samples `oldest()` itself
1029    /// immediately before invoking the function under test and asserts the
1030    /// logged label matches whatever the registry considers oldest at that
1031    /// instant — deterministic regardless of unrelated concurrent registry
1032    /// churn, while still verifying `log_tx_registry_oldest_debug` correctly
1033    /// surfaces the registry's own `oldest()` answer.
1034    #[test]
1035    #[serial(tx_registry)]
1036    fn log_tx_registry_oldest_debug_reports_oldest_open_entry() {
1037        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1038        let subscriber = CaptureSubscriber {
1039            events: std::sync::Arc::clone(&buffer),
1040        };
1041
1042        let _handle =
1043            khive_storage::tx_registry::register(Some("checkpoint_tick_test".to_string()));
1044
1045        let expected_label = khive_storage::tx_registry::oldest()
1046            .and_then(|(_, label)| label)
1047            .unwrap_or_else(|| "<unlabeled>".to_string());
1048
1049        tracing::subscriber::with_default(subscriber, || {
1050            log_tx_registry_oldest_debug(100);
1051        });
1052
1053        let events = buffer.lock().unwrap();
1054        assert!(
1055            events.iter().any(|e| {
1056                e.message.as_deref()
1057                    == Some("WAL checkpoint tick: oldest open transaction registry entry")
1058                    && e.oldest_tx_label.as_deref() == Some(expected_label.as_str())
1059            }),
1060            "expected a log line naming the open registry entry's label, got: {events:?}"
1061        );
1062    }
1063
1064    /// ADR-091 Plank 0 (round-1 fix): the oldest-entry WARN and the
1065    /// high-water snapshot-enumeration WARN are gated by `crossing_warn` at
1066    /// the call site (mirroring the WAL-threshold WARNs), so driving two
1067    /// consecutive above-threshold ticks through that same gate must produce
1068    /// exactly one of each — never a repeat on the second tick.
1069    #[test]
1070    #[serial(tx_registry)]
1071    fn registry_warns_fire_on_crossing_and_do_not_repeat() {
1072        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1073        let subscriber = CaptureSubscriber {
1074            events: std::sync::Arc::clone(&buffer),
1075        };
1076
1077        let _handle =
1078            khive_storage::tx_registry::register(Some("registry_warn_crossing_test".to_string()));
1079
1080        let mut was_above_warn = false;
1081        let mut was_above_high_water = false;
1082
1083        tracing::subscriber::with_default(subscriber, || {
1084            // Tick 1: below→above crossing for both bands — both WARNs fire.
1085            if crossing_warn(true, &mut was_above_warn) {
1086                log_tx_registry_oldest_warn(6000);
1087            }
1088            if crossing_warn(true, &mut was_above_high_water) {
1089                log_tx_registry_snapshot_warn(6000);
1090            }
1091
1092            // Tick 2: still above both thresholds — neither must repeat.
1093            if crossing_warn(true, &mut was_above_warn) {
1094                log_tx_registry_oldest_warn(6000);
1095            }
1096            if crossing_warn(true, &mut was_above_high_water) {
1097                log_tx_registry_snapshot_warn(6000);
1098            }
1099        });
1100
1101        let events = buffer.lock().unwrap();
1102
1103        // `tracing::subscriber::with_default` scopes capture to THIS thread for
1104        // the duration of the closure, so `events` contains only the two
1105        // `log_tx_registry_oldest_warn` calls made above — no concurrent test's
1106        // log calls land in this buffer. This lets the crossing/no-repeat
1107        // assertion match on message text alone: unlike the "names MY label"
1108        // assertion in the sibling test above, WHICH label `oldest()` reports
1109        // is irrelevant here (a concurrent write path elsewhere in the binary
1110        // may transiently be the registry's genuine oldest entry) — only the
1111        // fire-once-per-crossing COUNT is under test.
1112        let oldest_warn_count = events
1113            .iter()
1114            .filter(|e| {
1115                e.message.as_deref()
1116                    == Some("WAL checkpoint tick: oldest open transaction registry entry")
1117            })
1118            .count();
1119        assert_eq!(
1120            oldest_warn_count, 1,
1121            "oldest-entry WARN must fire exactly once across two above-threshold ticks, got: {events:?}"
1122        );
1123
1124        let snapshot_warn_count = events
1125            .iter()
1126            .filter(|e| {
1127                e.message.as_deref() == Some("WAL high-water: open transaction registry entry")
1128                    && e.tx_label.as_deref() == Some("registry_warn_crossing_test")
1129            })
1130            .count();
1131        assert_eq!(
1132            snapshot_warn_count, 1,
1133            "high-water snapshot WARN must fire exactly once across two above-threshold ticks, got: {events:?}"
1134        );
1135    }
1136
1137    fn file_pool(path: &std::path::Path) -> Arc<ConnectionPool> {
1138        let cfg = PoolConfig {
1139            path: Some(path.to_path_buf()),
1140            ..PoolConfig::default()
1141        };
1142        Arc::new(ConnectionPool::new(cfg).expect("pool open"))
1143    }
1144
1145    // `checkpoint_once` -> `query_wal_pages` writes the process-wide
1146    // `LAST_WAL_PAGES` gauge and resets `CHECKPOINT_CONSECUTIVE_SKIPS`
1147    // (see the reset-discipline comment on `reset_checkpoint_metrics_for_tests`
1148    // above) — this must join the `checkpoint_skip_metrics` group so it can
1149    // never interleave with a test asserting on those same gauges.
1150    #[test]
1151    #[serial(checkpoint_skip_metrics)]
1152    fn checkpoint_once_succeeds_on_file_backed_pool() {
1153        let dir = tempfile::tempdir().unwrap();
1154        let path = dir.path().join("wal_test.db");
1155        let pool = file_pool(&path);
1156
1157        // Create a table so the DB is not completely empty.
1158        {
1159            let writer = pool.try_writer().unwrap();
1160            writer
1161                .conn()
1162                .execute_batch("CREATE TABLE IF NOT EXISTS t (x INTEGER);")
1163                .unwrap();
1164            writer
1165                .conn()
1166                .execute_batch("INSERT INTO t VALUES (1);")
1167                .unwrap();
1168        }
1169
1170        checkpoint_once(
1171            &pool,
1172            &CheckpointConfig::default(),
1173            &mut TruncateState::default(),
1174        );
1175    }
1176
1177    #[test]
1178    #[serial(checkpoint_skip_metrics)]
1179    fn checkpoint_once_is_noop_on_in_memory_pool() {
1180        // In-memory databases do not use WAL; checkpoint_once must not panic.
1181        let cfg = PoolConfig {
1182            path: None,
1183            ..PoolConfig::default()
1184        };
1185        let pool = Arc::new(ConnectionPool::new(cfg).expect("in-memory pool"));
1186        checkpoint_once(
1187            &pool,
1188            &CheckpointConfig::default(),
1189            &mut TruncateState::default(),
1190        );
1191    }
1192
1193    #[tokio::test]
1194    #[serial(checkpoint_skip_metrics)]
1195    async fn checkpoint_task_exits_on_shutdown_signal() {
1196        let dir = tempfile::tempdir().unwrap();
1197        let path = dir.path().join("wal_task_shutdown.db");
1198        let pool = file_pool(&path);
1199
1200        // Use a very short interval so the task ticks quickly in the test.
1201        let cfg = CheckpointConfig {
1202            interval: Duration::from_millis(10),
1203            ..Default::default()
1204        };
1205
1206        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
1207        let handle = tokio::spawn(run_checkpoint_task(
1208            pool,
1209            cfg,
1210            None,
1211            "local".to_string(),
1212            shutdown_rx,
1213        ));
1214
1215        shutdown_tx.send(()).expect("send shutdown signal");
1216
1217        tokio::time::timeout(Duration::from_secs(1), handle)
1218            .await
1219            .expect("checkpoint task should exit within 1s")
1220            .expect("checkpoint task panicked");
1221    }
1222
1223    /// Regression for issue #774: on the production boot path, the daemon
1224    /// passes `run_checkpoint_task` both `pool` directly and an
1225    /// `event_store` that internally retains its own `Arc::clone` of the
1226    /// same pool (`SqlEventStore::new_scoped`). A strong-count-based exit
1227    /// condition can never fire in that shape, because the task always
1228    /// observes at least two live clones — its own `pool` argument plus the
1229    /// one buried in `event_store`. This test reproduces that exact
1230    /// ownership shape (a real `SqlEventStore` holding a sibling clone) and
1231    /// asserts the task still exits promptly via the watch-channel signal,
1232    /// proving the fix does not depend on `Arc::strong_count` at all.
1233    #[tokio::test]
1234    #[serial(checkpoint_skip_metrics)]
1235    async fn checkpoint_task_exits_via_shutdown_signal_with_live_event_store_pool_clone() {
1236        let dir = tempfile::tempdir().unwrap();
1237        let path = dir.path().join("wal_task_event_store.db");
1238        let pool = file_pool(&path);
1239
1240        let cfg = CheckpointConfig {
1241            interval: Duration::from_millis(10),
1242            ..Default::default()
1243        };
1244
1245        let event_store: Arc<dyn khive_storage::EventStore> =
1246            Arc::new(crate::stores::event::SqlEventStore::new_scoped(
1247                Arc::clone(&pool),
1248                true,
1249                "local".to_string(),
1250            ));
1251        // A second, independent sibling clone of `pool` outlives this test
1252        // function's own binding — mirrors `StorageBackend` retaining
1253        // `self.pool` alongside the `SqlEventStore` it hands to the
1254        // checkpoint task in production.
1255        let sibling_pool_clone = Arc::clone(&pool);
1256
1257        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
1258        let handle = tokio::spawn(run_checkpoint_task(
1259            pool,
1260            cfg,
1261            Some(event_store),
1262            "local".to_string(),
1263            shutdown_rx,
1264        ));
1265
1266        // Confirm strong_count is well above 1 — the old check would spin
1267        // forever here — before proving the new signal-based exit works
1268        // regardless.
1269        assert!(
1270            Arc::strong_count(&sibling_pool_clone) > 1,
1271            "test setup must reproduce the multi-owner shape the bug depends on"
1272        );
1273
1274        shutdown_tx.send(()).expect("send shutdown signal");
1275
1276        tokio::time::timeout(Duration::from_secs(1), handle)
1277            .await
1278            .expect(
1279                "checkpoint task should exit within 1s via the watch signal, \
1280                 even with a live sibling Arc<ConnectionPool> clone held by \
1281                 the event store",
1282            )
1283            .expect("checkpoint task panicked");
1284    }
1285
1286    #[test]
1287    #[serial]
1288    fn checkpoint_config_env_override() {
1289        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "250");
1290        std::env::set_var("KHIVE_WAL_WARN_PAGES", "1500");
1291        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "8000");
1292        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "12000");
1293        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "60");
1294        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "500");
1295
1296        let cfg = CheckpointConfig::from_env();
1297
1298        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1299        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1300        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1301        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1302        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1303        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1304
1305        assert_eq!(cfg.interval, Duration::from_millis(250));
1306        assert_eq!(cfg.warn_pages, 1500);
1307        assert_eq!(cfg.high_water_pages, 8000);
1308        assert_eq!(cfg.truncate_high_water_pages, 12000);
1309        assert_eq!(cfg.truncate_min_interval, Duration::from_secs(60));
1310        assert_eq!(cfg.truncate_busy_timeout, Duration::from_millis(500));
1311    }
1312
1313    #[test]
1314    #[serial]
1315    fn checkpoint_config_defaults_on_invalid_env() {
1316        let default = CheckpointConfig::default();
1317
1318        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "not_a_number");
1319        std::env::set_var("KHIVE_WAL_WARN_PAGES", "");
1320        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "0");
1321        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "not_a_number");
1322        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "");
1323        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "0");
1324
1325        let cfg = CheckpointConfig::from_env();
1326
1327        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1328        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1329        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1330        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1331        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1332        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1333
1334        assert_eq!(cfg.interval, default.interval);
1335        assert_eq!(cfg.warn_pages, default.warn_pages);
1336        assert_eq!(cfg.high_water_pages, default.high_water_pages);
1337        assert_eq!(
1338            cfg.truncate_high_water_pages,
1339            default.truncate_high_water_pages
1340        );
1341        assert_eq!(cfg.truncate_min_interval, default.truncate_min_interval);
1342        assert_eq!(cfg.truncate_busy_timeout, default.truncate_busy_timeout);
1343    }
1344
1345    /// Regression: a high-water tick must NOT block behind an active read transaction.
1346    ///
1347    /// Isomorphism guarantee: this test FAILS if `checkpoint_once` regresses to
1348    /// `PRAGMA wal_checkpoint(TRUNCATE)`. Confirmed by reasoning: TRUNCATE inherits
1349    /// RESTART semantics and will invoke the busy handler (sleeping up to
1350    /// `busy_timeout`) while waiting for the open reader snapshot to release.
1351    /// With `busy_timeout = 2000ms` a TRUNCATE regression causes the call to take
1352    /// ~2000ms, blowing the <500ms assertion. PASSIVE returns in <1ms even with an
1353    /// open reader, because PASSIVE never waits for readers.
1354    ///
1355    /// Why `busy_timeout = 2000ms` and threshold `< 500ms`: the original 200ms
1356    /// busy_timeout / 50ms threshold was too tight for contended CI runners where
1357    /// PASSIVE legitimately takes 50-200ms under parallel-test load. Raising the
1358    /// busy_timeout to 2000ms keeps the PASSIVE path well below 500ms while a
1359    /// TRUNCATE regression blocks for ~2000ms — a 4x safety margin on both sides.
1360    #[test]
1361    #[serial(checkpoint_skip_metrics)]
1362    fn checkpoint_high_water_does_not_block_behind_reader() {
1363        let dir = tempfile::tempdir().unwrap();
1364        let path = dir.path().join("high_water_test.db");
1365
1366        // busy_timeout = 2000ms: a TRUNCATE regression blocks ~2s (clearly caught by
1367        // the <500ms assertion below), but PASSIVE returns well within 500ms even on
1368        // a heavily loaded CI runner. 4x margin on both sides vs. the old 200ms/50ms.
1369        let pool = Arc::new(
1370            ConnectionPool::new(PoolConfig {
1371                path: Some(path.clone()),
1372                busy_timeout: Duration::from_millis(2000),
1373                ..PoolConfig::default()
1374            })
1375            .expect("pool open"),
1376        );
1377
1378        // Write data so the WAL has frames to checkpoint.
1379        {
1380            let writer = pool.try_writer().unwrap();
1381            writer
1382                .conn()
1383                .execute_batch(
1384                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1385                )
1386                .unwrap();
1387        }
1388
1389        // Open a reader and start a real read transaction so it holds a WAL
1390        // snapshot. An idle connection (no BEGIN) does NOT pin frames and would
1391        // not cause TRUNCATE to wait — the transaction is required for isomorphism.
1392        let reader = pool.reader().expect("reader");
1393        reader
1394            .execute_batch("BEGIN DEFERRED; SELECT * FROM t;")
1395            .expect("begin read tx");
1396
1397        // Write another row AFTER the snapshot is established. These new WAL
1398        // frames are now pinned by the open reader snapshot — TRUNCATE cannot
1399        // reclaim them without waiting; PASSIVE skips them and returns immediately.
1400        {
1401            let writer = pool.try_writer().unwrap();
1402            writer
1403                .conn()
1404                .execute_batch("INSERT INTO t VALUES (2);")
1405                .unwrap();
1406        }
1407
1408        let start = std::time::Instant::now();
1409        checkpoint_once(
1410            &pool,
1411            &CheckpointConfig::default(),
1412            &mut TruncateState::default(),
1413        );
1414        let elapsed = start.elapsed();
1415
1416        // Commit and release the read snapshot only after checkpoint_once returns.
1417        reader.execute_batch("COMMIT;").ok();
1418        drop(reader);
1419
1420        // PASSIVE returns in <1ms even with an open reader snapshot.
1421        // A TRUNCATE regression would block ~busy_timeout (2000ms) and fail here.
1422        // 500ms threshold is generous for CI jitter while staying well below 2000ms.
1423        assert!(
1424            elapsed < std::time::Duration::from_millis(500),
1425            "checkpoint_once with active reader snapshot took {:?}; \
1426             expected <500ms (PASSIVE must not block on readers; \
1427             a TRUNCATE regression would block ~2000ms)",
1428            elapsed
1429        );
1430    }
1431
1432    #[test]
1433    #[serial]
1434    fn checkpoint_config_rejects_zero_for_all_fields() {
1435        let default = CheckpointConfig::default();
1436        std::env::set_var("KHIVE_CHECKPOINT_INTERVAL_MS", "0");
1437        std::env::set_var("KHIVE_WAL_WARN_PAGES", "0");
1438        std::env::set_var("KHIVE_WAL_HIGH_WATER_PAGES", "0");
1439        std::env::set_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES", "0");
1440        std::env::set_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS", "0");
1441        std::env::set_var("KHIVE_WAL_TRUNCATE_BUSY_MS", "0");
1442
1443        let cfg = CheckpointConfig::from_env();
1444
1445        std::env::remove_var("KHIVE_CHECKPOINT_INTERVAL_MS");
1446        std::env::remove_var("KHIVE_WAL_WARN_PAGES");
1447        std::env::remove_var("KHIVE_WAL_HIGH_WATER_PAGES");
1448        std::env::remove_var("KHIVE_WAL_TRUNCATE_HIGH_WATER_PAGES");
1449        std::env::remove_var("KHIVE_WAL_TRUNCATE_MIN_INTERVAL_SECS");
1450        std::env::remove_var("KHIVE_WAL_TRUNCATE_BUSY_MS");
1451
1452        assert_eq!(
1453            cfg.interval, default.interval,
1454            "zero interval must fall back to default"
1455        );
1456        assert_eq!(
1457            cfg.warn_pages, default.warn_pages,
1458            "zero warn_pages must fall back to default"
1459        );
1460        assert_eq!(
1461            cfg.high_water_pages, default.high_water_pages,
1462            "zero high_water_pages must fall back to default"
1463        );
1464        assert_eq!(
1465            cfg.truncate_high_water_pages, default.truncate_high_water_pages,
1466            "zero truncate_high_water_pages must fall back to default"
1467        );
1468        assert_eq!(
1469            cfg.truncate_min_interval, default.truncate_min_interval,
1470            "zero truncate_min_interval must fall back to default"
1471        );
1472        assert_eq!(
1473            cfg.truncate_busy_timeout, default.truncate_busy_timeout,
1474            "zero truncate_busy_timeout must fall back to default"
1475        );
1476    }
1477
1478    /// Regression (Finding 1): a Skipped tick must NOT reset was_above_high_water.
1479    ///
1480    /// Before the fix, `checkpoint_once` returned `0` on both a genuinely-empty
1481    /// WAL and a writer-busy skip. The task treated `0` as an observed page count
1482    /// and reset `was_above_high_water`, re-arming the rate limit on every busy
1483    /// tick. With the fix, `CheckpointTick::Skipped` leaves crossing state
1484    /// unchanged.
1485    ///
1486    /// This test drives `crossing_warn` directly (the pure function that owns the
1487    /// decision) rather than going through the async task, which would require a
1488    /// logging harness.
1489    #[test]
1490    fn skipped_tick_does_not_reset_high_water_crossing_state() {
1491        let mut was_above = false;
1492
1493        // First observed tick: above threshold — fires WARN, sets was_above=true.
1494        assert!(
1495            crossing_warn(true, &mut was_above),
1496            "should fire on first crossing"
1497        );
1498        assert!(was_above);
1499
1500        // Simulate several skipped ticks: crossing state must remain true.
1501        // (In the task, Skipped causes `continue` so crossing_warn is never called.)
1502        // We verify by calling crossing_warn with the SAME above=true value, which
1503        // is what Observed(high_count) would produce — but a Skipped tick skips
1504        // the call entirely, so was_above stays as-is. Test the invariant directly:
1505        // if we leave was_above unchanged (no call at all), was_above remains true.
1506        assert!(was_above, "was_above must stay true across skipped ticks");
1507
1508        // Another observed tick still above threshold — must NOT re-fire.
1509        let fired = crossing_warn(true, &mut was_above);
1510        assert!(!fired, "WARN must not re-fire while still above threshold");
1511
1512        // Observed tick below threshold — resets was_above.
1513        let fired = crossing_warn(false, &mut was_above);
1514        assert!(!fired);
1515        assert!(!was_above);
1516
1517        // Next observed tick above threshold — fires again (legitimate new crossing).
1518        let fired = crossing_warn(true, &mut was_above);
1519        assert!(fired, "WARN must fire again on a new below→above crossing");
1520    }
1521
1522    /// Regression (Finding 2): warn_pages WARN fires once on crossing, not every tick.
1523    ///
1524    /// Before the fix, the WARN was emitted inside `checkpoint_once` on every tick
1525    /// while WAL sat in the warn band — log spam under sustained moderate pressure.
1526    /// With the fix, `crossing_warn` gates the WARN on the first in-band tick only;
1527    /// subsequent ticks while still in the band return false.
1528    #[test]
1529    fn warn_pages_fires_once_on_crossing_not_every_tick() {
1530        let mut was_above_warn = false;
1531
1532        // Simulate three consecutive ticks with WAL in the warn band.
1533        let fired_1 = crossing_warn(true, &mut was_above_warn);
1534        let fired_2 = crossing_warn(true, &mut was_above_warn);
1535        let fired_3 = crossing_warn(true, &mut was_above_warn);
1536
1537        assert!(fired_1, "WARN must fire on the first in-band tick");
1538        assert!(
1539            !fired_2,
1540            "WARN must not fire on the second consecutive in-band tick"
1541        );
1542        assert!(
1543            !fired_3,
1544            "WARN must not fire on the third consecutive in-band tick"
1545        );
1546
1547        // Drop below warn band — resets state.
1548        crossing_warn(false, &mut was_above_warn);
1549        assert!(!was_above_warn);
1550
1551        // Re-enter warn band — fires again.
1552        let fired_reentry = crossing_warn(true, &mut was_above_warn);
1553        assert!(
1554            fired_reentry,
1555            "WARN must fire again on re-entry into warn band"
1556        );
1557    }
1558
1559    // ADR-091 Plank 2: TRUNCATE escalation state machine tests.
1560
1561    /// Trigger threshold: once `wal_pages` (as observed by `checkpoint_once`) is
1562    /// at/above `truncate_high_water_pages` and no prior attempt has run, the
1563    /// escalation fires and stamps `last_attempt`.
1564    #[test]
1565    #[serial(tx_registry, checkpoint_skip_metrics)]
1566    fn truncate_attempts_when_high_water_crossed_with_no_prior_attempt() {
1567        let dir = tempfile::tempdir().unwrap();
1568        let path = dir.path().join("truncate_trigger.db");
1569        let pool = file_pool(&path);
1570
1571        {
1572            let writer = pool.try_writer().unwrap();
1573            writer
1574                .conn()
1575                .execute_batch(
1576                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1577                )
1578                .unwrap();
1579        }
1580
1581        let config = CheckpointConfig {
1582            // Force the escalation to arm regardless of the tiny WAL this test
1583            // actually produces — isolates the trigger-threshold behavior from
1584            // needing to stuff 20,000 real WAL pages.
1585            truncate_high_water_pages: 0,
1586            truncate_min_interval: Duration::from_secs(300),
1587            ..CheckpointConfig::default()
1588        };
1589        let mut state = TruncateState::default();
1590
1591        assert!(
1592            state.last_attempt.is_none(),
1593            "precondition: no attempt has run yet"
1594        );
1595
1596        let tick = checkpoint_once(&pool, &config, &mut state);
1597        assert!(matches!(tick, CheckpointTick::Observed(_)));
1598        assert!(
1599            state.last_attempt.is_some(),
1600            "an attempt must be stamped once the high-water threshold is crossed"
1601        );
1602    }
1603
1604    /// Below-threshold skip: `wal_pages < truncate_high_water_pages` must never
1605    /// stamp `last_attempt` — only an actual attempt advances it.
1606    #[test]
1607    #[serial(tx_registry, checkpoint_skip_metrics)]
1608    fn truncate_does_not_attempt_below_high_water() {
1609        let dir = tempfile::tempdir().unwrap();
1610        let path = dir.path().join("truncate_below_threshold.db");
1611        let pool = file_pool(&path);
1612
1613        {
1614            let writer = pool.try_writer().unwrap();
1615            writer
1616                .conn()
1617                .execute_batch(
1618                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1619                )
1620                .unwrap();
1621        }
1622
1623        // Effectively unreachable threshold for this test's tiny WAL.
1624        let config = CheckpointConfig {
1625            truncate_high_water_pages: u64::MAX,
1626            ..CheckpointConfig::default()
1627        };
1628        let mut state = TruncateState::default();
1629
1630        checkpoint_once(&pool, &config, &mut state);
1631
1632        assert!(
1633            state.last_attempt.is_none(),
1634            "a below-threshold tick must never stamp last_attempt"
1635        );
1636    }
1637
1638    /// Min-interval skip: once an attempt has run, a subsequent tick that is
1639    /// still above threshold but within `truncate_min_interval` must skip
1640    /// without re-stamping `last_attempt` (the timestamp must not move).
1641    #[test]
1642    #[serial(tx_registry, checkpoint_skip_metrics)]
1643    fn truncate_min_interval_skip_does_not_restamp_last_attempt() {
1644        let dir = tempfile::tempdir().unwrap();
1645        let path = dir.path().join("truncate_min_interval.db");
1646        let pool = file_pool(&path);
1647
1648        {
1649            let writer = pool.try_writer().unwrap();
1650            writer
1651                .conn()
1652                .execute_batch(
1653                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1654                )
1655                .unwrap();
1656        }
1657
1658        let config = CheckpointConfig {
1659            truncate_high_water_pages: 0,
1660            truncate_min_interval: Duration::from_secs(300),
1661            ..CheckpointConfig::default()
1662        };
1663        let mut state = TruncateState::default();
1664
1665        checkpoint_once(&pool, &config, &mut state);
1666        let first_attempt = state.last_attempt.expect("first tick must attempt");
1667
1668        // Second tick, immediately after: still above threshold, but the
1669        // min-interval has clearly not elapsed — must skip and leave
1670        // last_attempt exactly as it was.
1671        checkpoint_once(&pool, &config, &mut state);
1672        let second_attempt = state.last_attempt.expect("attempt timestamp must persist");
1673
1674        assert_eq!(
1675            first_attempt, second_attempt,
1676            "a tick within truncate_min_interval must not re-stamp last_attempt"
1677        );
1678    }
1679
1680    /// Busy fallback: when the writer mutex is already held, `checkpoint_once`
1681    /// must return `Skipped` and never touch the TRUNCATE state at all — both
1682    /// PASSIVE and any due TRUNCATE are skipped together (one writer checkout
1683    /// per tick). Also asserts #646 checkpoint-pressure telemetry: a skipped
1684    /// tick must bump the skipped/consecutive-skip counters and snapshot the
1685    /// last-known WAL pressure.
1686    #[test]
1687    #[serial(tx_registry, checkpoint_skip_metrics)]
1688    fn busy_writer_skips_both_passive_and_truncate() {
1689        reset_checkpoint_metrics_for_tests();
1690
1691        let dir = tempfile::tempdir().unwrap();
1692        let path = dir.path().join("truncate_busy_skip.db");
1693        let pool = file_pool(&path);
1694
1695        {
1696            let writer = pool.try_writer().unwrap();
1697            writer
1698                .conn()
1699                .execute_batch(
1700                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1701                )
1702                .unwrap();
1703        }
1704
1705        // An observed tick first, so the skip below has a last-known WAL
1706        // pressure snapshot to carry forward.
1707        let mut warmup_state = TruncateState::default();
1708        let warmup_tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut warmup_state);
1709        let observed_pages = match warmup_tick {
1710            CheckpointTick::Observed(n) => n,
1711            CheckpointTick::Skipped => panic!("warmup tick must observe, not skip"),
1712        };
1713        assert_eq!(
1714            checkpoint_consecutive_skips(),
1715            0,
1716            "an observed tick must not itself count as a skip"
1717        );
1718
1719        // Hold the writer mutex for the duration of the checkpoint_once call so
1720        // try_writer_nowait() fails, exactly like a concurrent write in progress.
1721        let _held = pool.try_writer().unwrap();
1722
1723        let config = CheckpointConfig {
1724            truncate_high_water_pages: 0,
1725            ..CheckpointConfig::default()
1726        };
1727        let mut state = TruncateState::default();
1728
1729        let tick = checkpoint_once(&pool, &config, &mut state);
1730
1731        assert_eq!(
1732            tick,
1733            CheckpointTick::Skipped,
1734            "a busy writer must skip the tick entirely"
1735        );
1736        assert!(
1737            state.last_attempt.is_none(),
1738            "a skipped tick (writer busy) must never stamp last_attempt, \
1739             even with a threshold that would otherwise arm immediately"
1740        );
1741
1742        assert_eq!(
1743            checkpoint_skipped_ticks(),
1744            1,
1745            "one skipped tick must bump the lifetime skipped-tick counter"
1746        );
1747        assert_eq!(
1748            checkpoint_consecutive_skips(),
1749            1,
1750            "one skipped tick must bump the consecutive-skip run length"
1751        );
1752        assert_eq!(
1753            checkpoint_last_skip_wal_pages(),
1754            Some(observed_pages),
1755            "the skip must snapshot the last-observed WAL pressure"
1756        );
1757    }
1758
1759    /// Observation branch: a checkpoint tick that is actually observed (writer
1760    /// free) must close out a prior skip streak, resetting the
1761    /// consecutive-skip counter to 0 without touching the lifetime total.
1762    #[test]
1763    #[serial(tx_registry, checkpoint_skip_metrics)]
1764    fn observed_tick_resets_consecutive_skips_but_not_lifetime_total() {
1765        reset_checkpoint_metrics_for_tests();
1766
1767        let dir = tempfile::tempdir().unwrap();
1768        let path = dir.path().join("skip_then_observe.db");
1769        let pool = file_pool(&path);
1770
1771        {
1772            let writer = pool.try_writer().unwrap();
1773            writer
1774                .conn()
1775                .execute_batch(
1776                    "CREATE TABLE IF NOT EXISTS t (x INTEGER); INSERT INTO t VALUES (1);",
1777                )
1778                .unwrap();
1779        }
1780
1781        // Two consecutive skipped ticks.
1782        {
1783            let _held = pool.try_writer().unwrap();
1784            let mut state = TruncateState::default();
1785            for _ in 0..2 {
1786                let tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut state);
1787                assert_eq!(tick, CheckpointTick::Skipped);
1788            }
1789        }
1790        assert_eq!(checkpoint_skipped_ticks(), 2);
1791        assert_eq!(checkpoint_consecutive_skips(), 2);
1792
1793        // Now the writer is free: an observed tick must reset the streak.
1794        let mut state = TruncateState::default();
1795        let tick = checkpoint_once(&pool, &CheckpointConfig::default(), &mut state);
1796        assert!(matches!(tick, CheckpointTick::Observed(_)));
1797
1798        assert_eq!(
1799            checkpoint_skipped_ticks(),
1800            2,
1801            "an observed tick must not change the lifetime skipped-tick total"
1802        );
1803        assert_eq!(
1804            checkpoint_consecutive_skips(),
1805            0,
1806            "an observed tick must reset the consecutive-skip run length"
1807        );
1808    }
1809
1810    /// Edge-triggered escalation WARN: `note_truncate_outcome` fires exactly
1811    /// once, on the third consecutive attempt that fails to clear
1812    /// `warn_pages`, and does not repeat on a fourth consecutive failure. A
1813    /// single attempt that clears `warn_pages` resets the counter.
1814    #[test]
1815    fn note_truncate_outcome_warns_once_at_third_consecutive_failure() {
1816        let buffer = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
1817        let subscriber = CaptureSubscriber {
1818            events: std::sync::Arc::clone(&buffer),
1819        };
1820
1821        let config = CheckpointConfig {
1822            warn_pages: 2000,
1823            ..CheckpointConfig::default()
1824        };
1825        let mut state = TruncateState::default();
1826
1827        tracing::subscriber::with_default(subscriber, || {
1828            // Three consecutive attempts that fail to clear warn_pages.
1829            note_truncate_outcome(&config, 5000, &mut state);
1830            note_truncate_outcome(&config, 5000, &mut state);
1831            note_truncate_outcome(&config, 5000, &mut state);
1832            // A fourth consecutive failure must not re-fire the escalation.
1833            note_truncate_outcome(&config, 5000, &mut state);
1834        });
1835
1836        assert_eq!(state.consecutive_failures, 4);
1837
1838        let events = buffer.lock().unwrap();
1839        let escalation_count = events
1840            .iter()
1841            .filter(|e| {
1842                e.message.as_deref()
1843                    == Some(
1844                        "WAL TRUNCATE has failed to clear WAL pressure for 3 consecutive attempts",
1845                    )
1846            })
1847            .count();
1848        assert_eq!(
1849            escalation_count, 1,
1850            "escalation WARN must fire exactly once at the 3rd consecutive failure, got: {events:?}"
1851        );
1852
1853        // A clearing attempt resets the counter.
1854        note_truncate_outcome(&config, 100, &mut state);
1855        assert_eq!(
1856            state.consecutive_failures, 0,
1857            "an attempt that clears warn_pages must reset the consecutive-failure counter"
1858        );
1859    }
1860
1861    // ADR-091 #617: graduated severity ladder state-machine tests.
1862
1863    fn severity_test_config() -> CheckpointConfig {
1864        CheckpointConfig {
1865            warn_pages: 100,
1866            warn_sustained_cycles: 3,
1867            ..CheckpointConfig::default()
1868        }
1869    }
1870
1871    /// INFO rung: a below→above crossing emits exactly one INFO and no WARN
1872    /// (default `warn_sustained_cycles = 3`, only one above-warn tick here).
1873    #[test]
1874    fn severity_ladder_info_on_first_crossing_no_warn() {
1875        let config = severity_test_config();
1876        let mut state = CheckpointSeverityState::default();
1877
1878        let below = state.observe_wal_pages(10, &config);
1879        assert!(below.is_empty(), "below-warn tick must emit nothing");
1880
1881        let above = state.observe_wal_pages(150, &config);
1882        assert_eq!(
1883            above,
1884            vec![CheckpointSeverityEmission {
1885                rung: CheckpointSeverityRung::Info,
1886                wal_pages: 150,
1887                threshold_pages: 100,
1888                consecutive_cycles: 1,
1889            }],
1890            "first below->above crossing must emit exactly one INFO and no WARN"
1891        );
1892    }
1893
1894    /// WARN rung: `warn_sustained_cycles` (3) consecutive above-warn ticks
1895    /// emit WARN exactly on the third tick, not before and not repeated after.
1896    #[test]
1897    fn severity_ladder_warn_on_third_consecutive_cycle() {
1898        let config = severity_test_config();
1899        let mut state = CheckpointSeverityState::default();
1900
1901        let tick1 = state.observe_wal_pages(150, &config);
1902        assert_eq!(tick1.len(), 1);
1903        assert_eq!(tick1[0].rung, CheckpointSeverityRung::Info);
1904
1905        let tick2 = state.observe_wal_pages(150, &config);
1906        assert!(
1907            tick2.is_empty(),
1908            "second consecutive above-warn tick must emit nothing yet"
1909        );
1910
1911        let tick3 = state.observe_wal_pages(150, &config);
1912        assert_eq!(
1913            tick3,
1914            vec![CheckpointSeverityEmission {
1915                rung: CheckpointSeverityRung::Warn,
1916                wal_pages: 150,
1917                threshold_pages: 100,
1918                consecutive_cycles: 3,
1919            }],
1920            "WARN must fire exactly on the third consecutive above-warn tick"
1921        );
1922
1923        let tick4 = state.observe_wal_pages(150, &config);
1924        assert!(
1925            tick4.is_empty(),
1926            "WARN must not repeat on a fourth consecutive above-warn tick"
1927        );
1928    }
1929
1930    /// Re-arm: after a WARN episode drains below warn_pages, a fresh episode
1931    /// of `warn_sustained_cycles` above-warn ticks must WARN again.
1932    #[test]
1933    fn severity_ladder_rearms_warn_after_drain() {
1934        let config = severity_test_config();
1935        let mut state = CheckpointSeverityState::default();
1936
1937        // First episode reaches WARN.
1938        for _ in 0..3 {
1939            state.observe_wal_pages(150, &config);
1940        }
1941        assert!(state.warn_emitted_for_episode);
1942
1943        // Drain below warn_pages: resets the episode.
1944        let drain = state.observe_wal_pages(10, &config);
1945        assert!(drain.is_empty(), "a draining tick must emit nothing");
1946
1947        // Second episode: INFO on first tick, no WARN until the third again.
1948        let reentry = state.observe_wal_pages(150, &config);
1949        assert_eq!(reentry.len(), 1);
1950        assert_eq!(reentry[0].rung, CheckpointSeverityRung::Info);
1951
1952        let mid = state.observe_wal_pages(150, &config);
1953        assert!(mid.is_empty());
1954
1955        let second_warn = state.observe_wal_pages(150, &config);
1956        assert_eq!(
1957            second_warn,
1958            vec![CheckpointSeverityEmission {
1959                rung: CheckpointSeverityRung::Warn,
1960                wal_pages: 150,
1961                threshold_pages: 100,
1962                consecutive_cycles: 3,
1963            }],
1964            "a fresh elevation episode after a drain must WARN again"
1965        );
1966    }
1967
1968    /// False-positive guard: three isolated single-tick crossings, each
1969    /// followed by a drain, must never reach WARN — only INFO fires each time.
1970    #[test]
1971    fn severity_ladder_isolated_crossings_never_warn() {
1972        let config = severity_test_config();
1973        let mut state = CheckpointSeverityState::default();
1974
1975        for _ in 0..3 {
1976            let crossing = state.observe_wal_pages(150, &config);
1977            assert_eq!(
1978                crossing.len(),
1979                1,
1980                "each isolated crossing must emit exactly one INFO"
1981            );
1982            assert_eq!(crossing[0].rung, CheckpointSeverityRung::Info);
1983
1984            let drain = state.observe_wal_pages(10, &config);
1985            assert!(drain.is_empty(), "the drain tick must emit nothing");
1986        }
1987
1988        assert!(
1989            !state.warn_emitted_for_episode,
1990            "isolated single-tick crossings must never accumulate into a WARN"
1991        );
1992    }
1993
1994    /// ALARM rung: the existing TRUNCATE-attempt gate is the ADR-091 ALARM
1995    /// tier. `observe_wal_pages` never produces it; this test documents and
1996    /// locks in that boundary so a future change can't silently reroute
1997    /// ALARM through the INFO/WARN ladder.
1998    #[test]
1999    fn severity_ladder_never_emits_alarm() {
2000        let config = CheckpointConfig {
2001            warn_pages: 100,
2002            warn_sustained_cycles: 1,
2003            ..CheckpointConfig::default()
2004        };
2005        let mut state = CheckpointSeverityState::default();
2006
2007        for wal_pages in [150, 200, 250, u64::MAX] {
2008            let emissions = state.observe_wal_pages(wal_pages, &config);
2009            assert!(
2010                emissions
2011                    .iter()
2012                    .all(|e| e.rung != CheckpointSeverityRung::Alarm),
2013                "observe_wal_pages must never emit the ALARM rung, got: {emissions:?}"
2014            );
2015        }
2016    }
2017
2018    /// `KHIVE_WAL_WARN_SUSTAINED_CYCLES` overrides the default and rejects 0.
2019    #[test]
2020    #[serial]
2021    fn checkpoint_config_warn_sustained_cycles_env_override() {
2022        let default = CheckpointConfig::default();
2023        assert_eq!(default.warn_sustained_cycles, DEFAULT_WARN_SUSTAINED_CYCLES);
2024
2025        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "5");
2026        let cfg = CheckpointConfig::from_env();
2027        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2028        assert_eq!(cfg.warn_sustained_cycles, 5);
2029
2030        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "0");
2031        let cfg_zero = CheckpointConfig::from_env();
2032        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2033        assert_eq!(
2034            cfg_zero.warn_sustained_cycles, DEFAULT_WARN_SUSTAINED_CYCLES,
2035            "zero must fall back to the default"
2036        );
2037
2038        std::env::set_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES", "not_a_number");
2039        let cfg_invalid = CheckpointConfig::from_env();
2040        std::env::remove_var("KHIVE_WAL_WARN_SUSTAINED_CYCLES");
2041        assert_eq!(
2042            cfg_invalid.warn_sustained_cycles,
2043            DEFAULT_WARN_SUSTAINED_CYCLES
2044        );
2045    }
2046
2047    // ADR-094: `CheckpointOutcomeRecorded` lifecycle event tests.
2048
2049    #[derive(Default)]
2050    struct FakeEventStore {
2051        events: std::sync::Mutex<Vec<khive_storage::Event>>,
2052    }
2053
2054    #[async_trait::async_trait]
2055    impl khive_storage::EventStore for FakeEventStore {
2056        async fn append_event(
2057            &self,
2058            event: khive_storage::Event,
2059        ) -> khive_storage::StorageResult<()> {
2060            self.events.lock().unwrap().push(event);
2061            Ok(())
2062        }
2063
2064        async fn append_events(
2065            &self,
2066            events: Vec<khive_storage::Event>,
2067        ) -> khive_storage::StorageResult<khive_storage::BatchWriteSummary> {
2068            let count = events.len() as u64;
2069            self.events.lock().unwrap().extend(events);
2070            Ok(khive_storage::BatchWriteSummary {
2071                attempted: count,
2072                affected: count,
2073                failed: 0,
2074                first_error: String::new(),
2075            })
2076        }
2077
2078        async fn get_event(
2079            &self,
2080            id: uuid::Uuid,
2081        ) -> khive_storage::StorageResult<Option<khive_storage::Event>> {
2082            Ok(self
2083                .events
2084                .lock()
2085                .unwrap()
2086                .iter()
2087                .find(|e| e.id == id)
2088                .cloned())
2089        }
2090
2091        async fn query_events(
2092            &self,
2093            _filter: khive_storage::EventFilter,
2094            _page: khive_storage::PageRequest,
2095        ) -> khive_storage::StorageResult<khive_storage::Page<khive_storage::Event>> {
2096            unimplemented!("not exercised by the checkpoint lifecycle-event tests")
2097        }
2098
2099        async fn count_events(
2100            &self,
2101            _filter: khive_storage::EventFilter,
2102        ) -> khive_storage::StorageResult<u64> {
2103            Ok(self.events.lock().unwrap().len() as u64)
2104        }
2105    }
2106
2107    /// Pure decision-table coverage for every input combination
2108    /// `checkpoint_outcome_should_emit` can see: a first elevated tick, a
2109    /// sustained elevated tick, the single drain row, and the ordinary
2110    /// healthy tick that must emit nothing.
2111    #[test]
2112    fn checkpoint_outcome_should_emit_covers_all_transitions() {
2113        assert!(
2114            checkpoint_outcome_should_emit(true, false),
2115            "first elevated tick must emit"
2116        );
2117        assert!(
2118            checkpoint_outcome_should_emit(true, true),
2119            "sustained elevated tick must emit"
2120        );
2121        assert!(
2122            checkpoint_outcome_should_emit(false, true),
2123            "the single drain row (elevated -> healthy) must emit"
2124        );
2125        assert!(
2126            !checkpoint_outcome_should_emit(false, false),
2127            "an ordinary below-warn tick must not emit"
2128        );
2129    }
2130
2131    #[tokio::test]
2132    #[serial(checkpoint_skip_metrics)]
2133    async fn checkpoint_task_emits_outcome_events_while_elevated_and_stops_after_drain() {
2134        let dir = tempfile::tempdir().unwrap();
2135        let path = dir.path().join("outcome_emit.db");
2136        let pool = file_pool(&path);
2137
2138        // warn_pages: 0 means any observed WAL page count (even 0) is
2139        // "elevated" for the duration this config is active.
2140        let cfg = CheckpointConfig {
2141            interval: Duration::from_millis(10),
2142            warn_pages: 0,
2143            ..CheckpointConfig::default()
2144        };
2145        let store = Arc::new(FakeEventStore::default());
2146        let store_dyn: Arc<dyn khive_storage::EventStore> = store.clone();
2147
2148        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2149        let handle = tokio::spawn(run_checkpoint_task(
2150            pool,
2151            cfg,
2152            Some(store_dyn),
2153            "local".to_string(),
2154            shutdown_rx,
2155        ));
2156
2157        tokio::time::sleep(Duration::from_millis(60)).await;
2158        shutdown_tx.send(()).expect("send shutdown signal");
2159        tokio::time::timeout(Duration::from_secs(1), handle)
2160            .await
2161            .expect("checkpoint task should exit within 1s")
2162            .expect("checkpoint task panicked");
2163
2164        let events = store.events.lock().unwrap();
2165        assert!(
2166            !events.is_empty(),
2167            "an always-elevated config must append at least one CheckpointOutcomeRecorded event"
2168        );
2169        assert!(
2170            events
2171                .iter()
2172                .all(|e| e.kind == khive_types::EventKind::CheckpointOutcomeRecorded),
2173            "every appended event must be CheckpointOutcomeRecorded, got: {events:?}"
2174        );
2175        assert!(
2176            events.iter().all(|e| e.namespace == "local"),
2177            "events must be stamped with the namespace passed to run_checkpoint_task"
2178        );
2179    }
2180
2181    #[tokio::test]
2182    #[serial(checkpoint_skip_metrics)]
2183    async fn checkpoint_task_emits_nothing_while_healthy() {
2184        let dir = tempfile::tempdir().unwrap();
2185        let path = dir.path().join("outcome_no_emit.db");
2186        let pool = file_pool(&path);
2187
2188        // An unreachable warn_pages threshold for this test's tiny WAL: every
2189        // tick stays below warn, so no event should ever be appended.
2190        let cfg = CheckpointConfig {
2191            interval: Duration::from_millis(10),
2192            warn_pages: u64::MAX,
2193            ..CheckpointConfig::default()
2194        };
2195        let store = Arc::new(FakeEventStore::default());
2196        let store_dyn: Arc<dyn khive_storage::EventStore> = store.clone();
2197
2198        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2199        let handle = tokio::spawn(run_checkpoint_task(
2200            pool,
2201            cfg,
2202            Some(store_dyn),
2203            "local".to_string(),
2204            shutdown_rx,
2205        ));
2206
2207        tokio::time::sleep(Duration::from_millis(60)).await;
2208        shutdown_tx.send(()).expect("send shutdown signal");
2209        tokio::time::timeout(Duration::from_secs(1), handle)
2210            .await
2211            .expect("checkpoint task should exit within 1s")
2212            .expect("checkpoint task panicked");
2213
2214        assert!(
2215            store.events.lock().unwrap().is_empty(),
2216            "a config that never crosses warn_pages must never append a lifecycle event"
2217        );
2218    }
2219
2220    #[tokio::test]
2221    #[serial(checkpoint_skip_metrics)]
2222    async fn checkpoint_task_with_no_event_store_does_not_panic() {
2223        let dir = tempfile::tempdir().unwrap();
2224        let path = dir.path().join("outcome_none_store.db");
2225        let pool = file_pool(&path);
2226
2227        let cfg = CheckpointConfig {
2228            interval: Duration::from_millis(10),
2229            warn_pages: 0,
2230            ..CheckpointConfig::default()
2231        };
2232
2233        let (shutdown_tx, shutdown_rx) = tokio::sync::watch::channel(());
2234        let handle = tokio::spawn(run_checkpoint_task(
2235            pool,
2236            cfg,
2237            None,
2238            "local".to_string(),
2239            shutdown_rx,
2240        ));
2241
2242        tokio::time::sleep(Duration::from_millis(40)).await;
2243        shutdown_tx.send(()).expect("send shutdown signal");
2244        tokio::time::timeout(Duration::from_secs(1), handle)
2245            .await
2246            .expect("checkpoint task should exit within 1s")
2247            .expect("checkpoint task panicked");
2248    }
2249}