Skip to main content

macrame/
metrics.rs

1//! What the write actor knows about its own latency (T1.4, D-079).
2//!
3//! # Why this exists
4//!
5//! [`crate::CHUNK_BUDGET`] is 3 ms and the crate has, until now, had exactly one
6//! way to find out whether that bound holds: run `benches/budgets.rs` on a
7//! synthetic fixture. That is a statement about a laptop, not about a database
8//! in use. D-059 already established that the bound does **not** hold on a large
9//! file, by a factor of 15, and it took a benchmark rewrite to notice — because
10//! nothing in the running system was counting.
11//!
12//! Tier 1's other three items are all "make the tail bounded". None of them can
13//! be validated in the field without something that measures the tail, which is
14//! why this is a precondition for them rather than a nice-to-have.
15//!
16//! # What is recorded, and what is deliberately not
17//!
18//! Four things, all of them per **actor turn** — one command, start to finish:
19//!
20//! - **queue depth** on both channels, sampled *before* the turn begins;
21//! - **hold duration**, bucketed, per command kind;
22//! - **holds over budget**, counted separately per kind;
23//! - **the longest hold since open**, with the kind that caused it.
24//!
25//! The hold is the whole turn, not the `execute` call's SQL. That is the
26//! quantity the budget is about: the SQLite write lock is not preemptible, so an
27//! interactive assertion arriving mid-turn waits for the turn, whatever the turn
28//! spent its time on.
29//!
30//! There is no per-command timestamp trail and no sampling of individual slow
31//! commands. That would be a tracing problem, and `tracing` is already a
32//! dependency — spans belong there. This module answers one question ("is the
33//! bound holding, and if not, which kind breaks it") in fixed memory, with no
34//! allocation on the actor's path.
35//!
36//! # The feature gate
37//!
38//! Behind `metrics`, which has been a **default** feature since 0.12.11
39//! (D-154): a crate whose contract is a latency bound must not ship a default
40//! build that cannot report whether the bound is met. `--no-default-features`
41//! still removes it. With the feature off, [`ActorMetrics`] is a
42//! zero-sized type whose methods compile away and [`HoldTimer::start`] does not
43//! read the clock — so the actor loop has **one** shape either way. That
44//! matters more than the nanoseconds: a `#[cfg]` in the loop body is how the
45//! instrumented and uninstrumented paths drift until only one of them is the one
46//! that runs.
47
48use std::time::Duration;
49
50/// The command kinds the actor can spend a turn on.
51///
52/// One flat enum across both channels rather than one per channel. The question
53/// this exists to answer is "which command broke the budget", and a reader
54/// looking at a 400 ms hold does not first want to know which queue it came off.
55/// Priority is a property of scheduling; kind is a property of cost.
56///
57/// # `#[non_exhaustive]`, added while it was still free (0.12.8, W4.2)
58///
59/// Adding a variant here is a **breaking change** without this attribute,
60/// because a downstream `match` on `CommandKind` would stop compiling. That is
61/// not hypothetical for this enum: [`crate::metrics::CommandKind::Rehydrate`]
62/// did not exist until 0.12.9 precisely because adding it was a break, and
63/// rehydration reported as `Archive` for several releases as a result. The
64/// codebase has already paid this cost once, which is the argument for paying
65/// the attribute now rather than deciding it at 1.0 when the cost is permanent.
66///
67/// Callers must therefore include a `_ =>` arm. In exchange, this enum can grow
68/// a variant for a command kind that does not exist yet without a major version.
69#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
70#[repr(u8)]
71#[non_exhaustive]
72pub enum CommandKind {
73    AssertEdge,
74    RetireEdge,
75    UpsertConcept,
76    WriteBulkAtomic,
77    RebuildCurrent,
78    RegisterModel,
79    Shutdown,
80    BulkImportChunk,
81    WriteConceptsChunk,
82    WriteAnalyticsChunk,
83    UpsertEmbeddingChunk,
84    Archive,
85    RebuildFts,
86    /// One step of a chunked shadow rebuild (T1.2). Its own kind rather than
87    /// folded into `RebuildCurrent`, because the two have opposite latency
88    /// profiles and the whole point of the chunked path is that its turns are
89    /// short — averaging them together would hide exactly the improvement.
90    ShadowRebuild,
91    /// Refreshing the query planner's statistics (0.12.4, D-149).
92    ///
93    /// Its own kind rather than folded into `RebuildFts`, though both are
94    /// maintenance on derived state: this one is bounded by
95    /// `PRAGMA analysis_limit` and that one is bounded by the size of the
96    /// concept table, so averaging their holds together would describe neither.
97    Analyze,
98    /// Moving archived rows back into the hot file (0.12.9, W4.3, D-152).
99    ///
100    /// Its own kind at last. Through 0.12.8 this reported as
101    /// [`CommandKind::Archive`], on the stated ground that rehydration is the
102    /// archive path run backwards and shares its budget — true of the *budget*
103    /// and false of the *attribution*, which is what a metrics surface is for.
104    /// An operator reading a long `archive` hold could not tell whether the
105    /// database had archived anything at all, and the two move rows in opposite
106    /// directions.
107    ///
108    /// The real reason it stayed folded was that adding a variant was a
109    /// breaking change. `#[non_exhaustive]` (W4.2) is what removed that
110    /// obstacle, and this variant is the first thing it bought — which is also
111    /// the evidence that the attribute was worth adding rather than a
112    /// precaution against a hypothetical.
113    ///
114    /// **Appended at the end**, per [`CommandKind::index`]: the position of
115    /// every existing variant is a persisted contract in two languages.
116    Rehydrate,
117    /// An explicit `PRAGMA wal_checkpoint` (0.12.13, W5.2, D-156).
118    ///
119    /// Its own kind because it is the one actor turn that is **not** a
120    /// transaction: it moves frames from the WAL back into the main database
121    /// file, and its duration is a function of how much WAL has accumulated
122    /// rather than of anything the caller passed. Folding it into any existing
123    /// kind would make that kind's hold distribution bimodal for a reason no
124    /// dashboard could recover.
125    ///
126    /// **Appended at the end**, per [`CommandKind::index`].
127    Checkpoint,
128}
129
130impl CommandKind {
131    /// Every kind, in declaration order. Indexing into the per-kind arrays is by
132    /// position in this slice, so the two must not drift — which is why the
133    /// arrays are sized from `ALL.len()` rather than from a hand-written count.
134    pub const ALL: &'static [CommandKind] = &[
135        CommandKind::AssertEdge,
136        CommandKind::RetireEdge,
137        CommandKind::UpsertConcept,
138        CommandKind::WriteBulkAtomic,
139        CommandKind::RebuildCurrent,
140        CommandKind::RegisterModel,
141        CommandKind::Shutdown,
142        CommandKind::BulkImportChunk,
143        CommandKind::WriteConceptsChunk,
144        CommandKind::WriteAnalyticsChunk,
145        CommandKind::UpsertEmbeddingChunk,
146        CommandKind::Archive,
147        CommandKind::RebuildFts,
148        CommandKind::ShadowRebuild,
149        CommandKind::Analyze,
150        CommandKind::Rehydrate,
151        CommandKind::Checkpoint,
152    ];
153
154    pub const COUNT: usize = CommandKind::ALL.len();
155
156    /// This kind's slot in the per-kind arrays.
157    ///
158    /// # Declaration order is a persisted contract (0.12.8, W4.2)
159    ///
160    /// `self as usize` means the **order of the variants above** is the order of
161    /// every per-kind array in this module, and the compiler cannot catch a
162    /// change to it. Reordering the enum silently reassigns every counter to a
163    /// different command: the code compiles, the tests pass, and a histogram
164    /// read after the change attributes `archive`'s holds to `rebuild_fts`.
165    ///
166    /// **New variants go at the end**, always — including at the end of
167    /// [`CommandKind::ALL`], whose order is what `as_str()` and the Python
168    /// surface enumerate. This binds Python too: `BUCKET_BOUNDS_MICROS` is a
169    /// module constant there and `KindMetrics` is built by position, so a
170    /// reorder here relabels axes in a language the Rust compiler is not
171    /// looking at.
172    ///
173    /// `#[repr(u8)]` is on the enum for the same reason — it pins the
174    /// discriminants to the declaration order rather than leaving them to the
175    /// compiler — but it pins them to whatever the order *is*, so it does not
176    /// make a reorder safe. Only this rule does.
177    pub const fn index(self) -> usize {
178        self as usize
179    }
180
181    pub const fn as_str(self) -> &'static str {
182        match self {
183            CommandKind::AssertEdge => "assert_edge",
184            CommandKind::RetireEdge => "retire_edge",
185            CommandKind::UpsertConcept => "upsert_concept",
186            CommandKind::WriteBulkAtomic => "write_bulk_atomic",
187            CommandKind::RebuildCurrent => "rebuild_current",
188            CommandKind::RegisterModel => "register_model",
189            CommandKind::Shutdown => "shutdown",
190            CommandKind::BulkImportChunk => "bulk_import_chunk",
191            CommandKind::WriteConceptsChunk => "write_concepts_chunk",
192            CommandKind::WriteAnalyticsChunk => "write_analytics_chunk",
193            CommandKind::UpsertEmbeddingChunk => "upsert_embedding_chunk",
194            CommandKind::Archive => "archive",
195            CommandKind::RebuildFts => "rebuild_fts",
196            CommandKind::ShadowRebuild => "shadow_rebuild",
197            CommandKind::Analyze => "analyze",
198            CommandKind::Rehydrate => "rehydrate",
199            CommandKind::Checkpoint => "checkpoint",
200        }
201    }
202
203    /// Whether this kind is exempt from [`crate::CHUNK_BUDGET`] by contract.
204    ///
205    /// The exemptions are the table in `CHUNK_BUDGET`'s own rustdoc, and they
206    /// are carried here so a dashboard can separate "the budget is being
207    /// broken" from "the budget does not apply and never claimed to". Counting
208    /// an `archive` as a budget violation would make the violation count useless
209    /// on any database that archives.
210    ///
211    /// The two lists must agree, and since 0.12.9 they are tied together in
212    /// both directions by `the_budget_exemptions_and_their_documented_table_agree`
213    /// — the extra-row direction being the one worth having, since a table row
214    /// with no code behind it promises a caller an exemption the violation
215    /// counter is about to disagree with.
216    ///
217    /// [`CommandKind::ShadowRebuild`] is deliberately **not** exempt. Its fill
218    /// chunks are meant to fit the budget and its swap turn is not going to —
219    /// the swap rebuilds three indexes under the lock, which is the residual
220    /// cost T1.2 could not remove. Both facts are worth seeing, and exempting
221    /// the kind would hide the first to excuse the second.
222    ///
223    /// # `Rehydrate` is exempt, and splitting it out is what made that a
224    /// decision rather than an accident (0.12.9, W4.3, D-152)
225    ///
226    /// Until 0.12.8 rehydration reported as [`CommandKind::Archive`] and was
227    /// therefore exempt **by inheritance** — nobody had decided it, it fell out
228    /// of the borrowed kind. Giving it its own variant would have silently
229    /// flipped it to non-exempt, and since a rehydrate is one unchunked
230    /// transaction moving rows back across the file boundary, every single one
231    /// would have counted as a budget violation. The violation count would then
232    /// have become useless on any database that rehydrates, which is precisely
233    /// the failure the `Archive` exemption exists to prevent, arriving by the
234    /// back door of a change made for attribution.
235    ///
236    /// So it is exempt, on the merits and now on the record: rehydration is the
237    /// archive path run backwards and makes the same claim about its hold —
238    /// that it is bulk movement with no latency bound, and that the caller asked
239    /// for it explicitly.
240    ///
241    /// # [`CommandKind::Analyze`] is **not** exempt, and that is a decision
242    /// (0.12.25, D-168)
243    ///
244    /// It looks like it belongs here. `ANALYZE` is one indivisible statement —
245    /// there is no smaller unit to chunk into — and its cost is set by data
246    /// volume, so it cannot meet the budget on a populated ledger. Measured
247    /// (`examples/analyze_hold.rs`): **5.26 ms at 10,000 edges, 19.1 ms at
248    /// 40,000**, against 3 ms. Every call is a violation and always will be.
249    ///
250    /// It stays counted for two reasons.
251    ///
252    /// **The table has a `Bound` column, and this kind cannot fill it in.**
253    /// `Checkpoint`'s bound is frames accumulated since the last one;
254    /// `Archive`'s is the session's row count. The honest entry here would be
255    /// "the size of the table, damped 3–4× by `analysis_limit`", which is not a
256    /// bound but the absence of one. A row that cannot state its bound is this
257    /// table admitting the thing it exists to prevent.
258    ///
259    /// **And this kind is two callers wearing one name.** `Analyze` covers
260    /// [`crate::Database::optimize`] as well as [`crate::Database::analyze`],
261    /// and `close()` calls `optimize()` unconditionally. Exempting the kind
262    /// would silence the *automatic* path — every handle close on a large
263    /// ledger holding ~19 ms with nothing reporting it — which is exactly the
264    /// call nobody chose to make. That is [`CommandKind::Rehydrate`]'s lesson
265    /// above, arriving from the other direction: there, a shared kind granted
266    /// an exemption nobody had decided; here, a shared kind would launder one.
267    ///
268    /// **So the violation is expected, permanent, and must not be "fixed" by
269    /// lowering [`crate::schema::ddl::ANALYSIS_LIMIT`].** That would buy the
270    /// number by sampling too little to separate the two `source_id`-leading
271    /// indices, which is the entire purpose of having statistics
272    /// ([D-149](../docs/architecture/s13-decision-register.md#d-149)).
273    ///
274    /// Splitting the kind is scheduled as **W10.5, 0.14.0**; the exemption
275    /// question is answerable per-caller once it is split, and not before.
276    pub const fn exempt_from_budget(self) -> bool {
277        matches!(
278            self,
279            CommandKind::WriteBulkAtomic
280                | CommandKind::Archive
281                | CommandKind::RebuildCurrent
282                | CommandKind::Rehydrate
283                | CommandKind::Checkpoint
284        )
285    }
286}
287
288impl std::fmt::Display for CommandKind {
289    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
290        f.write_str(self.as_str())
291    }
292}
293
294/// Upper bounds of the hold-duration histogram, in microseconds.
295///
296/// `3_000` is [`crate::CHUNK_BUDGET`] exactly, so the bucket boundary and the
297/// bound are the same number and a reader does not have to interpolate to answer
298/// "what fraction of turns fit". The tail runs to 1 s because D-059's measured
299/// worst case was 45 ms and `rebuild_current` at 40K rows is 318 ms (D-077) —
300/// a range this has to cover without saturating.
301///
302/// Anything above the last bound lands in the overflow bucket, which is why
303/// [`KindSnapshot::buckets`] is one longer than this slice.
304pub const BUCKET_BOUNDS_MICROS: &[u64] = &[
305    100, 300, 1_000, 3_000, 10_000, 30_000, 100_000, 300_000, 1_000_000,
306];
307
308/// Number of histogram buckets, including the overflow bucket.
309pub const BUCKET_COUNT: usize = BUCKET_BOUNDS_MICROS.len() + 1;
310
311#[allow(dead_code)] // used by `imp` under `metrics`, and by the tests always
312fn bucket_of(micros: u64) -> usize {
313    // Linear scan over nine bounds. A binary search here would be slower in
314    // practice and this runs once per actor turn, against a turn measured in
315    // microseconds at best.
316    BUCKET_BOUNDS_MICROS
317        .iter()
318        .position(|&bound| micros <= bound)
319        .unwrap_or(BUCKET_BOUNDS_MICROS.len())
320}
321
322/// Times one actor turn.
323///
324/// # This clock is no longer optional (0.12.0, W1)
325///
326/// Until 0.11.0 the field was `#[cfg(feature = "metrics")]` and `elapsed()`
327/// returned `Duration::ZERO` in a default build: the reading existed only to
328/// feed [`ActorMetrics::record_hold`]'s histogram, so a build that did not keep
329/// the histogram had no reason to read a clock.
330///
331/// The chunk loop changed what the reading is *for*. A chunk's measured hold is
332/// now the input to the next chunk's size (`connection::next_chunk_size`, named
333/// in prose because it is private — D-144), which means it is a control signal
334/// in every build and not an observation in some of them. Left gated, `bulk_import` would have sized its chunks off
335/// `Duration::ZERO` — a value that reads as "comfortably under budget" — and
336/// grown every chunk to the ceiling, in exactly the builds nobody was measuring.
337///
338/// So the clock is unconditional and **only the histogram is still gated**:
339/// `record_hold` remains a no-op without the feature. What that costs is one
340/// `Instant::now()` pair per actor turn — tens of nanoseconds against a turn
341/// measured in microseconds at best, and the same reasoning §5.1.5 uses to
342/// decide that a channel hop is free beside a chunk.
343///
344/// It stays a type rather than a bare `Instant::now()` in the loop because the
345/// ordering guarantee in [`crate::connection`]'s `Turn` is attached to it.
346pub struct HoldTimer {
347    start: std::time::Instant,
348}
349
350impl HoldTimer {
351    #[inline]
352    pub fn start() -> Self {
353        Self {
354            start: std::time::Instant::now(),
355        }
356    }
357
358    #[inline]
359    pub fn elapsed(&self) -> Duration {
360        self.start.elapsed()
361    }
362}
363
364// ---------------------------------------------------------------------------
365// Instrumented implementation
366// ---------------------------------------------------------------------------
367
368#[cfg(feature = "metrics")]
369mod imp {
370    use super::{bucket_of, CommandKind, BUCKET_COUNT};
371    use std::sync::atomic::{AtomicU64, Ordering};
372    use std::time::Duration;
373
374    /// One kind's counters. All `Relaxed`: these are statistics, and ordering
375    /// them against each other would buy a consistency no reader needs and cost
376    /// fences on the write path.
377    #[derive(Debug, Default)]
378    struct Kind {
379        turns: AtomicU64,
380        total_micros: AtomicU64,
381        over_budget: AtomicU64,
382        /// This kind's own high-water mark, in µs.
383        ///
384        /// Not redundant with the global `longest`. That one names a single
385        /// command, so on any real database it names whichever kind is slowest
386        /// overall — and the question "did windowing shrink the archive's worst
387        /// hold" cannot be answered by a counter that a bulk import wins. No
388        /// packing needed here: the kind is the array index.
389        longest_micros: AtomicU64,
390        buckets: [AtomicU64; BUCKET_COUNT],
391    }
392
393    /// Live counters, shared between the actor and the handle.
394    ///
395    /// Fixed size, no allocation, no lock. The actor updates; anyone may read.
396    #[derive(Debug, Default)]
397    pub struct ActorMetrics {
398        kinds: [Kind; CommandKind::COUNT],
399        /// Packed `micros << 8 | kind`, so the longest hold and the kind that
400        /// caused it are read and written as **one** value. Two atomics would
401        /// let a reader see a duration from one turn beside a kind from
402        /// another — a rare wrong answer to exactly the question this field
403        /// exists to answer. 2^56 µs is over two thousand years.
404        ///
405        /// **The duration must occupy the high bits.** The update is a
406        /// `fetch_max` on the packed word, so whichever field is packed high is
407        /// the one being compared. The first version of this had the kind up
408        /// there, which made the "longest hold" the hold with the largest
409        /// *enum index* — a 3 ms `write_concepts_chunk` beat a 10 ms
410        /// `rebuild_current` because its variant is declared later. It was
411        /// `actor_metrics_tests` that caught it, not the unit tests, because
412        /// nothing in the arithmetic is wrong: the packing is only incorrect in
413        /// the presence of the atomic operation it exists to serve.
414        longest: AtomicU64,
415        /// Loop iterations, which is **not** the number of turns taken.
416        ///
417        /// The depth sample happens at the top of the loop, before `select!`
418        /// blocks — so an idle actor has already counted the iteration for a
419        /// command that has not arrived. That is right for depth (the sample is
420        /// "what was queued when I went looking") and wrong for turns, which is
421        /// why [`MetricsSnapshot::turns`] is the sum of the per-kind counters
422        /// instead. Conflating the two made `turns` permanently one too high and
423        /// disagree with its own breakdown.
424        depth_samples: AtomicU64,
425        high_depth_sum: AtomicU64,
426        high_depth_max: AtomicU64,
427        low_depth_sum: AtomicU64,
428        low_depth_max: AtomicU64,
429        /// Turns where the actor took high-priority work while low-priority
430        /// work was already queued (0.12.10, W4.4, D-153).
431        ///
432        /// The `biased` `select!` in `run_writer_actor` has **no floor**:
433        /// sustained high-priority traffic can hold the low tier off
434        /// indefinitely, and nothing has ever said whether that happens. This
435        /// is the numerator of that question — how often the choice went
436        /// against the low tier at all.
437        low_starved_turns: AtomicU64,
438        /// The current unbroken run of such turns. Reset to zero the moment
439        /// low-priority work is taken.
440        ///
441        /// Not exposed; it is the state [`Self::low_starved_run_max`] is a
442        /// high-water mark of. A live value would be read at an arbitrary point
443        /// in a run and mean nothing.
444        low_starved_run: AtomicU64,
445        /// The longest such run since open, which is the number that answers the
446        /// question.
447        ///
448        /// A large `low_starved_turns` on a busy database is unremarkable — it
449        /// says the high tier is being used, which is what the tier is for. A
450        /// large *run* says one specific low-priority command waited that many
451        /// turns, and it is the only one of the two that can distinguish
452        /// "prioritised" from "starved".
453        low_starved_run_max: AtomicU64,
454    }
455
456    const MICROS_SHIFT: u32 = 8;
457    const KIND_MASK: u64 = (1 << MICROS_SHIFT) - 1;
458
459    impl ActorMetrics {
460        pub fn new() -> Self {
461            Self::default()
462        }
463
464        /// Sample both queue depths. Called before the turn, not after: after
465        /// the turn the queue reflects what arrived *during* it, which is a
466        /// different and much less useful quantity.
467        #[inline]
468        pub fn record_turn(&self, high_depth: usize, low_depth: usize) {
469            self.depth_samples.fetch_add(1, Ordering::Relaxed);
470            for (sum, max, depth) in [
471                (
472                    &self.high_depth_sum,
473                    &self.high_depth_max,
474                    high_depth as u64,
475                ),
476                (&self.low_depth_sum, &self.low_depth_max, low_depth as u64),
477            ] {
478                sum.fetch_add(depth, Ordering::Relaxed);
479                max.fetch_max(depth, Ordering::Relaxed);
480            }
481        }
482
483        /// Record which tier the `select!` chose, and what was waiting.
484        ///
485        /// `low_queued` is the depth sampled *before* the `select!`, so it is
486        /// the backlog the turn found on arrival. By the time a high-priority
487        /// arm fires the low queue may have grown; using the pre-select reading
488        /// keeps this consistent with every other depth figure in this module
489        /// and makes the counter conservative — it never invents starvation
490        /// from work that arrived after the choice was made.
491        ///
492        /// A low-priority turn resets the run rather than decrementing it: the
493        /// question is "how many turns did one low-priority command wait", and
494        /// that is a run length, not a balance.
495        #[inline]
496        pub fn record_priority_choice(&self, took_high: bool, low_queued: usize) {
497            if took_high && low_queued > 0 {
498                self.low_starved_turns.fetch_add(1, Ordering::Relaxed);
499                let run = self.low_starved_run.fetch_add(1, Ordering::Relaxed) + 1;
500                self.low_starved_run_max.fetch_max(run, Ordering::Relaxed);
501            } else if !took_high {
502                self.low_starved_run.store(0, Ordering::Relaxed);
503            }
504        }
505
506        #[inline]
507        pub fn record_hold(&self, kind: CommandKind, held: Duration) {
508            let micros = held.as_micros().min(super::MICROS_CEILING as u128) as u64;
509            let k = &self.kinds[kind.index()];
510            k.turns.fetch_add(1, Ordering::Relaxed);
511            k.total_micros.fetch_add(micros, Ordering::Relaxed);
512            k.buckets[bucket_of(micros)].fetch_add(1, Ordering::Relaxed);
513            k.longest_micros.fetch_max(micros, Ordering::Relaxed);
514            if !kind.exempt_from_budget() && held > crate::CHUNK_BUDGET {
515                k.over_budget.fetch_add(1, Ordering::Relaxed);
516            }
517            self.longest.fetch_max(
518                (micros << MICROS_SHIFT) | kind.index() as u64,
519                Ordering::Relaxed,
520            );
521        }
522
523        /// A consistent-enough picture for a dashboard.
524        ///
525        /// Not a torn-read-free snapshot, and it does not pretend to be: the
526        /// actor keeps running while this walks the array, so two kinds may be
527        /// read one turn apart. Locking the actor to produce a report would make
528        /// the observer a source of the latency it is measuring.
529        pub fn snapshot(&self) -> super::MetricsSnapshot {
530            let samples = self.depth_samples.load(Ordering::Relaxed);
531            let mean = |sum: &AtomicU64| {
532                if samples == 0 {
533                    0.0
534                } else {
535                    sum.load(Ordering::Relaxed) as f64 / samples as f64
536                }
537            };
538
539            let packed = self.longest.load(Ordering::Relaxed);
540            let longest_micros = packed >> MICROS_SHIFT;
541            let longest = (longest_micros > 0)
542                .then(|| {
543                    let idx = (packed & KIND_MASK) as usize;
544                    CommandKind::ALL
545                        .get(idx)
546                        .map(|&kind| (kind, Duration::from_micros(longest_micros)))
547                })
548                .flatten();
549
550            let kinds: Vec<_> = CommandKind::ALL
551                .iter()
552                .map(|&kind| {
553                    let k = &self.kinds[kind.index()];
554                    let turns = k.turns.load(Ordering::Relaxed);
555                    let total = k.total_micros.load(Ordering::Relaxed);
556                    super::KindSnapshot {
557                        kind,
558                        turns,
559                        over_budget: k.over_budget.load(Ordering::Relaxed),
560                        mean: total
561                            .checked_div(turns)
562                            .map_or(Duration::ZERO, Duration::from_micros),
563                        longest: Duration::from_micros(k.longest_micros.load(Ordering::Relaxed)),
564                        buckets: std::array::from_fn(|i| k.buckets[i].load(Ordering::Relaxed)),
565                    }
566                })
567                .collect();
568
569            super::MetricsSnapshot {
570                // Summed, not counted separately — see `depth_samples`.
571                turns: kinds.iter().map(|k| k.turns).sum(),
572                depth_samples: samples,
573                high_depth_mean: mean(&self.high_depth_sum),
574                high_depth_max: self.high_depth_max.load(Ordering::Relaxed),
575                low_depth_mean: mean(&self.low_depth_sum),
576                low_depth_max: self.low_depth_max.load(Ordering::Relaxed),
577                low_starved_turns: self.low_starved_turns.load(Ordering::Relaxed),
578                low_starved_run_max: self.low_starved_run_max.load(Ordering::Relaxed),
579                longest,
580                kinds,
581            }
582        }
583    }
584}
585
586// ---------------------------------------------------------------------------
587// No-op implementation
588// ---------------------------------------------------------------------------
589
590#[cfg(not(feature = "metrics"))]
591mod imp {
592    use super::CommandKind;
593    use std::time::Duration;
594
595    /// The `metrics`-off shape: zero-sized, and every method is nothing.
596    #[derive(Debug, Default)]
597    pub struct ActorMetrics;
598
599    impl ActorMetrics {
600        pub fn new() -> Self {
601            Self
602        }
603        #[inline]
604        pub fn record_turn(&self, _high_depth: usize, _low_depth: usize) {}
605        #[inline]
606        pub fn record_priority_choice(&self, _took_high: bool, _low_queued: usize) {}
607        #[inline]
608        pub fn record_hold(&self, _kind: CommandKind, _held: Duration) {}
609    }
610}
611
612pub use imp::ActorMetrics;
613
614/// Saturation point for a recorded hold, in microseconds (~2,000 years).
615///
616/// Exists so the packed `longest` field cannot have a pathological duration
617/// overflow into the kind bits. A hold this long is not a measurement, it is a
618/// hang — and the counter should stay readable rather than start reporting the
619/// wrong command.
620///
621/// Kept out of the `metrics` cfg so the invariant test below runs in the default
622/// build too: the packing is a property of the layout, and a build that does not
623/// record is exactly the build where nobody would notice it break.
624#[allow(dead_code)]
625const MICROS_CEILING: u64 = (1u64 << 56) - 1;
626
627/// One command kind's holds, as of the moment [`ActorMetrics::snapshot`] read it.
628#[cfg(feature = "metrics")]
629#[derive(Debug, Clone, PartialEq, Eq)]
630#[non_exhaustive]
631pub struct KindSnapshot {
632    pub kind: CommandKind,
633    /// Turns spent on this kind.
634    pub turns: u64,
635    /// Turns that exceeded [`crate::CHUNK_BUDGET`]. Always 0 for the three
636    /// kinds [`CommandKind::exempt_from_budget`] names — see there for why.
637    pub over_budget: u64,
638    pub mean: Duration,
639    /// This kind's longest hold. Distinct from [`MetricsSnapshot::longest`],
640    /// which names one command across all kinds and so tends to be permanently
641    /// whichever kind is slowest overall.
642    pub longest: Duration,
643    /// Counts per [`BUCKET_BOUNDS_MICROS`], plus a final overflow bucket.
644    ///
645    /// Private behind [`Self::buckets`] since 0.12.8 (W4.2). A public array
646    /// field publishes `BUCKET_COUNT` as part of the type's shape, so adding a
647    /// bucket bound would break every caller that named the length — and the
648    /// bounds are exactly the thing a latency histogram is likely to want to
649    /// re-cut. The accessor returns a slice and the length becomes an
650    /// observation rather than a signature. Python already did it this way.
651    buckets: [u64; BUCKET_COUNT],
652}
653
654#[cfg(feature = "metrics")]
655impl KindSnapshot {
656    /// Counts per [`BUCKET_BOUNDS_MICROS`], plus a final overflow bucket.
657    ///
658    /// Pair it with `BUCKET_BOUNDS_MICROS` to label the axis rather than
659    /// hard-coding the bounds; the slice is one longer than that constant,
660    /// and the extra trailing element is the overflow bucket.
661    pub fn buckets(&self) -> &[u64] {
662        &self.buckets
663    }
664}
665
666/// What the actor has done since the database was opened.
667#[cfg(feature = "metrics")]
668#[derive(Debug, Clone, PartialEq)]
669#[non_exhaustive]
670pub struct MetricsSnapshot {
671    /// Commands executed, i.e. the sum of [`KindSnapshot::turns`]. The two agree
672    /// by construction rather than by coincidence.
673    pub turns: u64,
674    /// Loop iterations that took a queue-depth reading. Always at least
675    /// `turns + 1` on a live actor, because the reading is taken on the way in
676    /// to a `select!` that has not resolved yet. This is the denominator of the
677    /// two means below, and it is exposed so the difference is visible rather
678    /// than looking like drift.
679    pub depth_samples: u64,
680    pub high_depth_mean: f64,
681    pub high_depth_max: u64,
682    pub low_depth_mean: f64,
683    pub low_depth_max: u64,
684    /// The longest hold since open and what caused it. `None` before the first
685    /// turn, and — honestly — also when every turn so far took under a
686    /// microsecond, which on this path does not happen.
687    pub longest: Option<(CommandKind, Duration)>,
688    /// Turns spent on high-priority work while low-priority work was already
689    /// queued (0.12.10, W4.4, D-153).
690    ///
691    /// The actor's `select!` is `biased` and has **no floor**, so this is the
692    /// measurement of a bound the design has always had and never observed.
693    /// On its own it is not alarming: a busy database *should* prefer
694    /// interactive writes, and this counter rising is that working. Read it
695    /// beside [`Self::low_starved_run_max`], which is the number with teeth.
696    pub low_starved_turns: u64,
697    /// The longest unbroken run of the above — i.e. the most turns any single
698    /// low-priority command has waited (0.12.10, W4.4, D-153).
699    ///
700    /// This is the one that answers "can low-priority work be starved". A large
701    /// `low_starved_turns` spread over a long session says the tiers are doing
702    /// their job; a large *run* says one specific chunk, rebuild or archive sat
703    /// behind that many interactive writes in a row.
704    ///
705    /// **There is deliberately no forced-yield policy attached to this.**
706    /// Adding one now would be fixing a bound nobody has observed being hit,
707    /// and the counter exists precisely to find out whether it is. See D-153.
708    pub low_starved_run_max: u64,
709    pub kinds: Vec<KindSnapshot>,
710}
711
712#[cfg(feature = "metrics")]
713impl MetricsSnapshot {
714    /// Kinds that broke the budget, worst first. The one-line answer to "is the
715    /// 3 ms bound holding?".
716    pub fn budget_violations(&self) -> Vec<&KindSnapshot> {
717        let mut v: Vec<_> = self.kinds.iter().filter(|k| k.over_budget > 0).collect();
718        v.sort_by_key(|k| std::cmp::Reverse(k.over_budget));
719        v
720    }
721}
722
723#[cfg(test)]
724mod tests {
725    use super::*;
726
727    #[test]
728    fn every_kind_indexes_to_its_own_slot() {
729        for (i, &kind) in CommandKind::ALL.iter().enumerate() {
730            assert_eq!(kind.index(), i, "{kind} is out of order in ALL");
731        }
732        assert_eq!(CommandKind::COUNT, CommandKind::ALL.len());
733    }
734
735    /// The budget is a bucket boundary, not a value inside one — so "fits in the
736    /// budget" is a prefix sum and needs no interpolation.
737    #[test]
738    fn the_chunk_budget_is_exactly_a_bucket_boundary() {
739        let budget = crate::CHUNK_BUDGET.as_micros() as u64;
740        assert!(
741            BUCKET_BOUNDS_MICROS.contains(&budget),
742            "CHUNK_BUDGET is {budget} µs, which is not a bucket bound: \
743             {BUCKET_BOUNDS_MICROS:?}"
744        );
745        assert_eq!(bucket_of(budget), bucket_of(budget - 1));
746        assert_eq!(bucket_of(budget + 1), bucket_of(budget) + 1);
747    }
748
749    #[test]
750    fn the_overflow_bucket_catches_everything_past_the_last_bound() {
751        let last = *BUCKET_BOUNDS_MICROS.last().unwrap();
752        assert_eq!(bucket_of(last), BUCKET_BOUNDS_MICROS.len() - 1);
753        assert_eq!(bucket_of(last + 1), BUCKET_COUNT - 1);
754        assert_eq!(bucket_of(u64::MAX), BUCKET_COUNT - 1);
755    }
756
757    /// The packing is the reason `longest` is one atomic: duration high, kind
758    /// low, so a `fetch_max` on the word compares the duration.
759    #[test]
760    fn the_packing_leaves_room_for_both_fields() {
761        assert!(
762            (CommandKind::COUNT as u64) <= 0xFF,
763            "the kind index must fit in the low 8 bits"
764        );
765        // The ceiling must survive being shifted up by the kind's width.
766        assert_eq!(MICROS_CEILING.checked_shl(8), Some(MICROS_CEILING << 8));
767        assert_eq!((MICROS_CEILING << 8) >> 8, MICROS_CEILING);
768    }
769
770    #[cfg(feature = "metrics")]
771    #[test]
772    fn the_longest_hold_names_the_command_that_caused_it() {
773        let m = ActorMetrics::new();
774        m.record_hold(CommandKind::AssertEdge, Duration::from_micros(500));
775        m.record_hold(CommandKind::Archive, Duration::from_millis(40));
776        m.record_hold(CommandKind::UpsertConcept, Duration::from_micros(900));
777
778        let snap = m.snapshot();
779        assert_eq!(
780            snap.longest,
781            Some((CommandKind::Archive, Duration::from_millis(40)))
782        );
783    }
784
785    /// The regression the packing bug produced: a *short* hold of a
786    /// later-declared kind must not outrank a long hold of an earlier one.
787    ///
788    /// The test above does not catch it, because `Archive` happens to be both
789    /// the longest hold and a high enum index — which is exactly why the first
790    /// version of the packing shipped past it. Here the two orderings disagree.
791    #[cfg(feature = "metrics")]
792    #[test]
793    fn a_later_declared_kind_does_not_outrank_a_longer_hold() {
794        let long = CommandKind::AssertEdge; // index 0
795        let short = CommandKind::RebuildFts; // last index
796        assert!(short.index() > long.index(), "the fixture needs the gap");
797
798        let m = ActorMetrics::new();
799        m.record_hold(long, Duration::from_millis(40));
800        m.record_hold(short, Duration::from_micros(1));
801
802        assert_eq!(
803            m.snapshot().longest,
804            Some((long, Duration::from_millis(40))),
805            "the max is being taken over the kind index, not the duration"
806        );
807    }
808
809    /// The three contractual exemptions must not show up as violations, or the
810    /// violation count is noise on any database that archives.
811    #[cfg(feature = "metrics")]
812    #[test]
813    fn an_exempt_kind_over_budget_is_not_a_violation() {
814        let m = ActorMetrics::new();
815        m.record_hold(CommandKind::Archive, Duration::from_millis(40));
816        m.record_hold(CommandKind::AssertEdge, Duration::from_millis(40));
817
818        let snap = m.snapshot();
819        let violations = snap.budget_violations();
820        assert_eq!(violations.len(), 1);
821        assert_eq!(violations[0].kind, CommandKind::AssertEdge);
822        assert_eq!(violations[0].over_budget, 1);
823
824        // But the hold is still *recorded* — exempt means "not a violation",
825        // not "not measured". A 40 ms archive is exactly what T1.1 exists to
826        // shrink, and it cannot be shrunk if it is not counted.
827        let archive = snap
828            .kinds
829            .iter()
830            .find(|k| k.kind == CommandKind::Archive)
831            .unwrap();
832        assert_eq!(archive.turns, 1);
833        assert_eq!(archive.mean, Duration::from_millis(40));
834    }
835
836    #[cfg(feature = "metrics")]
837    #[test]
838    fn queue_depth_is_a_mean_and_a_high_water_mark() {
839        let m = ActorMetrics::new();
840        m.record_turn(0, 4);
841        m.record_turn(10, 0);
842
843        let snap = m.snapshot();
844        // No command ran, so `turns` is 0 while `depth_samples` is 2. The two
845        // counters are different facts and this is the case that shows it.
846        assert_eq!(snap.turns, 0);
847        assert_eq!(snap.depth_samples, 2);
848        assert_eq!(snap.high_depth_mean, 5.0);
849        assert_eq!(snap.high_depth_max, 10);
850        assert_eq!(snap.low_depth_mean, 2.0);
851        assert_eq!(snap.low_depth_max, 4);
852    }
853}