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