mongreldb_core/trace.rs
1//! Query path instrumentation (OPTIMIZATIONS.md Priority 0 / 16).
2//!
3//! MongrelDB has many physical paths a query can take: an O(1) metadata count,
4//! a zero-copy Arrow IPC shadow, a single-run lazy page cursor, a multi-run
5//! k-way merge cursor, an index-pushdown columnar gather, or a full row
6//! materialization. Correctness tests verify *results* but never reveal *which*
7//! path ran, so performance regressions are currently invisible until a
8//! benchmark accidentally trips one.
9//!
10//! [`QueryTrace`] makes those path decisions observable. It is a lightweight,
11//! opt-in record filled at decision points via a thread-local scope collector.
12//! The hot path (no capture active) pays only a single TLS load per record site
13//! and then returns immediately — there is no allocation, no lock, and no
14//! signature change to the hundreds of internal functions that serve queries.
15//!
16//! ## Usage
17//!
18//! The public `_traced` methods on [`crate::engine::Table`] (and
19//! `MongrelSession::run_sql_traced` in the query crate) wrap the corresponding
20//! query in [`QueryTrace::capture`] and return the result alongside the trace:
21//!
22//! ```no_run
23//! # use mongreldb_core::*;
24//! # let mut db: Table = unimplemented!();
25//! # let snap = db.snapshot();
26//! # let conditions = &[];
27//! # let proj = &[];
28//! let (cols, trace) = db.query_columns_native_traced(conditions, Some(proj), snap).unwrap();
29//! assert_eq!(trace.scan_mode, trace::ScanMode::NativePushdown);
30//! assert_eq!(trace.index_rebuild, trace::IndexRebuild::AlreadyComplete);
31//! ```
32//!
33//! ## Extensibility
34//!
35//! New fields can be added to [`QueryTrace`] freely — it is `#[derive(Default)]`,
36//! so existing callers and tests continue to compile. New recording sites are a
37//! single [`QueryTrace::record`] call at the decision point; no plumbing is
38//! required because the thread-local stack is the transport.
39
40use std::cell::RefCell;
41use std::fmt;
42
43thread_local! {
44 /// A stack of in-progress traces, supporting nested captures (an inner
45 /// `capture` gets its own fresh trace; the outer trace is unaffected).
46 static STACK: RefCell<Vec<QueryTrace>> = const { RefCell::new(Vec::new()) };
47}
48
49/// Which physical scan path served a query. Recorded by the SQL scan
50/// ([`crate::scan`]) and the native query entry points. Used in benchmarks and
51/// path-sensitive tests to assert that the expected path was taken.
52#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
53pub enum ScanMode {
54 /// The trace was never filled (no recording site ran). Indicates a path
55 /// that has not yet been instrumented.
56 #[default]
57 Unknown,
58 /// `COUNT(*)` / empty projection answered from the maintained `live_count`
59 /// metadata in O(1) — no run read, no index resolve.
60 CountMetadata,
61 /// `COUNT(*)` with a pushed `WHERE` answered from survivor set cardinality
62 /// via [`crate::engine::Table::count_conditions`] — index resolve only, no
63 /// column decode.
64 CountSurvivors,
65 /// Zero-copy Arrow IPC shadow read — no per-column decode at all (clean
66 /// single-run unfiltered table).
67 ArrowShadow,
68 /// Single-run lazy page cursor: fused predicate + page skip + late
69 /// materialization ([`crate::cursor::NativePageCursor`]).
70 NativePageCursor,
71 /// Multi-run k-way merge cursor ([`crate::cursor::MultiRunCursor`]).
72 MultiRunCursor,
73 /// Index pushdown fast path: survivors resolved then gathered column-wise
74 /// from a single reader ([`crate::engine::Table::query_columns_native`]
75 /// fast path — no cursor streaming, but no row materialization either).
76 NativePushdown,
77 /// Full materialization fallback: `visible_columns_native` or
78 /// `rows_for_rids` — rows go through the `Row { HashMap }` shape. This is
79 /// the path optimizations try to avoid.
80 Materialized,
81 /// §5.3 direct SQL dispatch: a simple single-table `SELECT` recognized from
82 /// the raw SQL (sqlparser AST) and served straight from the native column
83 /// cursor, bypassing DataFusion parse+plan+optimize entirely.
84 DirectDispatch,
85 /// DataFusion scan served by an external table module / virtual table
86 /// provider rather than a native MongrelDB storage table.
87 ExternalModule,
88}
89
90impl fmt::Display for ScanMode {
91 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
92 let s = match self {
93 ScanMode::Unknown => "unknown",
94 ScanMode::CountMetadata => "count-metadata",
95 ScanMode::CountSurvivors => "count-survivors",
96 ScanMode::ArrowShadow => "arrow-shadow",
97 ScanMode::NativePageCursor => "native-page-cursor",
98 ScanMode::MultiRunCursor => "multi-run-cursor",
99 ScanMode::NativePushdown => "native-pushdown",
100 ScanMode::Materialized => "materialized",
101 ScanMode::DirectDispatch => "direct-dispatch",
102 ScanMode::ExternalModule => "external-module",
103 };
104 f.write_str(s)
105 }
106}
107
108/// Which join execution path served a query (Priority 13: join diagnostics).
109/// `None` for non-join queries.
110#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
111pub enum JoinMode {
112 /// No join in the query (or the join path was never reached).
113 #[default]
114 None,
115 /// Native FK↔PK roaring-bitmap intersection — no hash-join materialization
116 /// ([`crate::engine::Table`] index resolve only).
117 FkBitmap,
118 /// Fell back to DataFusion's hash join (shape the native path can't serve).
119 DataFusionHash,
120}
121
122impl fmt::Display for JoinMode {
123 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
124 f.write_str(match self {
125 JoinMode::None => "none",
126 JoinMode::FkBitmap => "fk-bitmap",
127 JoinMode::DataFusionHash => "datafusion-hash",
128 })
129 }
130}
131
132/// Whether `ensure_indexes_complete` rebuilt indexes during this query. A
133/// rebuild is the user-facing stall case (Priority 10); this field exposes it.
134#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
135pub enum IndexRebuild {
136 /// No index rebuild happened (no query ran, or the table had no indexes).
137 #[default]
138 None,
139 /// Indexes were already complete; `ensure_indexes_complete` was a no-op.
140 AlreadyComplete,
141 /// Indexes were rebuilt from runs during this query (the stall case).
142 Rebuilt,
143}
144
145/// Records which engine path a query took. Filled at decision points via
146/// [`QueryTrace::record`]; collected via [`QueryTrace::capture`].
147///
148/// All fields are `#[derive(Default)]`, so adding a new field is non-breaking.
149/// Fields default to zero / `false` / `None` so a trace from an uninstrumented
150/// path still reads cleanly.
151#[derive(Debug, Default, Clone)]
152pub struct QueryTrace {
153 /// The physical scan path that served this query.
154 pub scan_mode: ScanMode,
155 /// Number of sorted runs in the table at query time. `1` = single-run fast
156 /// path eligible; `>1` = k-way merge; `0` = empty/memtable-only table.
157 pub run_count: usize,
158 /// Rows in the memtable overlay (unflushed puts/updates/deletes).
159 pub memtable_rows: usize,
160 /// Rows in the mutable-run tier overlay.
161 pub mutable_run_rows: usize,
162 /// Rows in the materialized overlay batch yielded by a cursor (memtable +
163 /// mutable-run combined, post-filter). Non-zero means the query paid
164 /// overlay materialization cost.
165 pub overlay_rows: usize,
166 /// How many conditions were translated to native pushdown (index-served).
167 pub conditions_pushed: usize,
168 /// How many conditions could not be pushed down (residual / fallback).
169 pub conditions_residual: usize,
170 /// Survivor row count after predicate resolution, if known without decoding
171 /// data columns (set for index-served and count paths).
172 pub survivor_count: Option<usize>,
173 /// Whether `ensure_indexes_complete` rebuilt indexes during this query.
174 pub index_rebuild: IndexRebuild,
175 /// Whether the fast clean-run row-id→position arithmetic was used (avoids
176 /// decoding + binary-searching the system row-id column).
177 pub fast_row_id_map: bool,
178 /// Whether a learned (PGM) range index served a `Range`/`RangeF64`
179 /// condition (in-memory, no column read).
180 pub learned_range_used: bool,
181 /// Whether the result cache returned a hit (no re-decode / re-resolve).
182 pub result_cache_hit: bool,
183 /// Whether persistent result-cache publication was skipped because the
184 /// background writer was unavailable (REM-D §8.5). The in-memory entry
185 /// was still cached; only the durable-tier write was skipped.
186 pub result_cache_persist_skipped: bool,
187 /// Why persistent publication was skipped (stable label from
188 /// `PersistenceDisabledReason::label`). `Some` only when
189 /// `result_cache_persist_skipped` is `true`.
190 pub result_cache_persist_skip_reason: Option<&'static str>,
191 /// Whether rows were materialized as `Row { HashMap }` (the slow path).
192 pub row_materialized: bool,
193 /// Number of pages decoded (lazily filled by cursors when capturing).
194 pub pages_decoded: usize,
195 /// Number of pages skipped by page-stat pruning or empty page plans.
196 pub pages_skipped: usize,
197 /// Which join path served the query (Priority 13). `None` for non-joins.
198 pub join_mode: JoinMode,
199 /// Logical-planning time in nanoseconds (Priority 8: parse + plan, separate
200 /// from execution). `0` on a result-cache hit (planning was skipped) or when
201 /// the plan came from the logical-plan cache.
202 pub planning_nanos: u64,
203 /// Authorization/RLS candidate-cache work for the query.
204 pub authorization_nanos: u64,
205 pub rls_cache_hit: bool,
206 pub rls_rows_evaluated: usize,
207 pub rls_policy_columns_decoded: usize,
208 pub authorization_retries: usize,
209 /// AI retrieval stage timings and bounded cardinalities.
210 pub hard_filter_nanos: u64,
211 /// ANN backend selected by the authoritative index schema.
212 pub ann_algorithm: Option<crate::schema::AnnAlgorithm>,
213 /// ANN representation selected by the authoritative index schema.
214 pub ann_quantization: Option<crate::schema::AnnQuantization>,
215 /// Concrete backend executing the ANN candidate search.
216 pub ann_backend: Option<&'static str>,
217 pub ann_candidate_nanos: u64,
218 pub ann_candidate_cap_hit: bool,
219 pub sparse_candidate_nanos: u64,
220 pub minhash_candidate_nanos: u64,
221 pub candidate_count: usize,
222 pub union_size: usize,
223 pub fusion_nanos: u64,
224 pub exact_vector_gather_nanos: u64,
225 pub exact_vector_score_nanos: u64,
226 pub exact_set_gather_nanos: u64,
227 pub exact_set_parse_nanos: u64,
228 pub exact_set_score_nanos: u64,
229 pub projection_nanos: u64,
230 pub projection_rows: usize,
231 pub projection_cells: usize,
232 pub work_consumed: usize,
233 pub total_nanos: u64,
234
235 // ---- TODO §1: point-lookup directory trace fields --------------------
236 /// Whether the `RunLookupDirectory` was consulted and produced a complete
237 /// candidate set for this get. `false` means the legacy range-scan fallback
238 /// ran (which is acceptable but not optimal).
239 pub directory_complete: bool,
240 /// Number of run locators the directory returned for the queried `RowId`.
241 pub directory_candidates: usize,
242 /// Number of runs rejected by the header-derived `run_row_id_ranges` filter.
243 pub run_range_rejects: usize,
244 /// Number of runs rejected by membership / predicate filters before open.
245 pub membership_filter_rejects: usize,
246 /// How many immutable run readers were actually opened.
247 pub run_readers_opened: usize,
248 /// Set when the lookup short-circuited because the best candidate was
249 /// provably newer than every remaining locator's upper bound.
250 pub early_stop: bool,
251 /// Point cache hits (replay of a recent in-process lookup result).
252 pub point_cache_hits: usize,
253
254 // ---- TODO §3: controlled-scan streaming trace fields ------------------
255 /// Total versions examined across all segments during the scan.
256 pub controlled_scan_versions_examined: usize,
257 /// Rows emitted by the scan (post-filter).
258 pub controlled_scan_rows_emitted: usize,
259 /// Number of times a segment cursor was refilled.
260 pub controlled_scan_source_refills: usize,
261 /// Peak number of buffered rows held by the streaming merge at any moment.
262 pub controlled_scan_peak_source_buffer_rows: usize,
263 /// Peak number of versions seen for any single `RowId` during the scan.
264 pub controlled_scan_peak_same_row_versions: usize,
265 /// Number of `ExecutionControl::checkpoint` calls issued during the scan.
266 pub controlled_scan_checkpoints: usize,
267 /// Wall-clock time to produce the first row, in microseconds.
268 pub controlled_scan_time_to_first_row_us: u64,
269 /// Time from `cancel` to the scan actually observing cancellation, in µs.
270 pub controlled_scan_cancel_latency_us: u64,
271 /// Wall-clock time spent constructing the controlled-scan sources, in µs.
272 pub controlled_scan_setup_time_us: u64,
273
274 // ---- TODO §5: HOT fallback trace fields ------------------------------
275 /// Whether a HOT lookup was attempted for this query.
276 pub hot_lookup_attempted: bool,
277 /// Whether the HOT lookup was a hit (no fallback).
278 pub hot_lookup_hit: bool,
279 /// Stable reason label when the HOT lookup fell back. `None` on hit.
280 pub hot_fallback_reason: Option<&'static str>,
281 /// Overlay versions examined during the fallback path.
282 pub hot_fallback_overlay_versions: usize,
283 /// Sorted runs considered during the fallback path.
284 pub hot_fallback_runs_considered: usize,
285 /// Sorted run readers actually opened during the fallback path.
286 pub hot_fallback_runs_opened: usize,
287 /// Pages decoded during the fallback path.
288 pub hot_fallback_pages_decoded: usize,
289 /// Rows materialized during the fallback path.
290 pub hot_fallback_rows_materialized: usize,
291 /// Wall-clock time spent on the HOT fast-path lookup, in nanoseconds.
292 pub hot_lookup_nanos: u64,
293 /// Wall-clock time spent on the fallback path, in nanoseconds.
294 pub hot_fallback_nanos: u64,
295
296 // ---- TODO §4: per-family retrieval trace fields ----------------------
297 /// Raw candidates produced by the index backend before dedup.
298 pub raw_candidates: usize,
299 /// Unique candidates after `(RowId)` dedup.
300 pub unique_candidates: usize,
301 /// Duplicate candidates dropped during dedup.
302 pub duplicate_candidates: usize,
303 /// Candidates rejected by `Snapshot::observes_row`.
304 pub visibility_rejected: usize,
305 /// Candidates rejected as tombstones.
306 pub tombstone_rejected: usize,
307 /// Candidates rejected by TTL.
308 pub ttl_rejected: usize,
309 /// Candidates rejected by authorization (RLS / allowed set).
310 pub authorization_rejected: usize,
311 /// Candidates rejected by hard filter.
312 pub hard_filter_rejected: usize,
313 /// Configured candidate cap for the retrieval.
314 pub candidate_cap: usize,
315 /// Whether the candidate cap was hit.
316 pub candidate_cap_hit: bool,
317 /// Final number of hits returned to the caller.
318 pub final_hits: usize,
319 /// Stable explanation when a top-k retrieval legally returns fewer than k.
320 pub underfill_reason: Option<&'static str>,
321}
322
323/// Reasons a HOT (`Hash-Organized Table`) PK lookup may fall back to the slower
324/// overlay + sorted-run path. Stable identifiers; the string literals are the
325/// stable wire/label form (see TODO §5.1).
326#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
327pub enum HotFallbackReason {
328 MissingMapping,
329 StaleRowId,
330 InvisibleAtSnapshot,
331 HistoricalSnapshot,
332 Tombstone,
333 TtlExpired,
334 PrimaryKeyMismatch,
335 IndexIncomplete,
336 CheckpointRejected,
337}
338
339impl HotFallbackReason {
340 pub fn as_str(self) -> &'static str {
341 match self {
342 HotFallbackReason::MissingMapping => "missing_mapping",
343 HotFallbackReason::StaleRowId => "stale_row_id",
344 HotFallbackReason::InvisibleAtSnapshot => "invisible_at_snapshot",
345 HotFallbackReason::HistoricalSnapshot => "historical_snapshot",
346 HotFallbackReason::Tombstone => "tombstone",
347 HotFallbackReason::TtlExpired => "ttl_expired",
348 HotFallbackReason::PrimaryKeyMismatch => "primary_key_mismatch",
349 HotFallbackReason::IndexIncomplete => "index_incomplete",
350 HotFallbackReason::CheckpointRejected => "checkpoint_rejected",
351 }
352 }
353}
354
355impl fmt::Display for HotFallbackReason {
356 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
357 f.write_str(self.as_str())
358 }
359}
360
361/// Diagnostic classification of a HOT (`Hash-Organized Table`) candidate row.
362///
363/// `Table::get` collapses several distinct failure modes into `None`
364/// (tombstone, TTL expiry, snapshot invisibility). To preserve observability
365/// across every HOT fallback path, [`Table::resolve_pk_with_hot_fallback`]
366/// inspects the candidate directly and tags the failure with one of these
367/// reasons before delegating to the PK equality scanner.
368///
369/// `PrimaryKeyMismatch` carries the mismatched bytes for diagnostics — the
370/// `materialized_pk` is the value read from the row's PK column and
371/// `requested` is the lookup key bytes (after HMAC tokenization). Neither is
372/// used as the authoritative result; the fallback scanner is the only
373/// source of the returned row set.
374#[derive(Debug, Clone, PartialEq)]
375pub enum HotCandidateInspection {
376 /// Mapped `RowId` materialized, is visible, live, TTL-valid, and carries
377 /// the requested PK. The branch may return this row without a fallback.
378 Hit(crate::memtable::Row),
379 /// Row does not exist at the mapped `RowId` — overlay and all runs
380 /// returned no version. The base row was removed entirely.
381 MissingRow,
382 /// Row exists but is stamped with a `(committed_epoch, commit_ts)` that
383 /// the calling `Snapshot` does not observe. Distinct from a tombstone:
384 /// the row may still be visible at a later snapshot.
385 Invisible,
386 /// The newest visible row at the mapped `RowId` is a tombstone
387 /// (`deleted = true`). A replacement row with the same PK may exist
388 /// elsewhere — the scanner is responsible for finding it.
389 Tombstone,
390 /// The newest visible row exists and is not deleted, but the row's TTL
391 /// metadata says the row expired at the calling wall clock. Distinct
392 /// from `Tombstone`: the row is still durable, just hidden by TTL.
393 TtlExpired,
394 /// Row materialized with valid visibility/TTL, but its materialized PK
395 /// does not match the requested PK bytes. The HOT map is stale and must
396 /// not return this row — only the scanner's verified result is returned.
397 PrimaryKeyMismatch {
398 /// PK bytes encoded from the materialized row's PK column.
399 materialized_pk: Vec<u8>,
400 /// PK bytes that the caller requested (post-HMAC tokenization).
401 requested: Vec<u8>,
402 },
403}
404
405impl QueryTrace {
406 /// Execute `f` with path tracing active on the current thread, returning
407 /// the result and the captured trace. Recording calls inside `f` (and
408 /// anything `f` calls on this thread) fill the returned trace.
409 ///
410 /// Nesting is supported: an inner `capture` pushes a fresh trace onto the
411 /// stack and gets its own result; the outer trace is unaffected by inner
412 /// recordings.
413 ///
414 /// When no capture is active (the normal hot path), [`QueryTrace::record`]
415 /// is a single TLS load + empty-check + return — zero allocation, zero
416 /// locking, no measurable cost.
417 pub fn capture<F, T>(f: F) -> (T, QueryTrace)
418 where
419 F: FnOnce() -> T,
420 {
421 Self::push_scope();
422 let result = f();
423 let trace = Self::pop_scope();
424 (result, trace)
425 }
426
427 /// Push a fresh trace onto the thread-local stack, starting a capture scope.
428 /// Pair with [`Self::pop_scope`] to retrieve the trace. This is the async-
429 /// compatible alternative to [`Self::capture`]: push before `await`, pop
430 /// after.
431 ///
432 /// **Thread affinity:** the trace is thread-local, so recordings must happen
433 /// on the same OS thread as the push/pop pair. This holds for synchronous
434 /// query paths (the common case) and for single-partition DataFusion scans
435 /// (physical planning + leaf execution run inline on the polling thread).
436 pub fn push_scope() {
437 STACK.with(|s| s.borrow_mut().push(QueryTrace::default()));
438 }
439
440 /// Pop the innermost trace from the thread-local stack, ending a capture
441 /// scope. Returns the captured trace. Panics if the stack is empty (unpaired
442 /// pop); see [`Self::push_scope`].
443 pub fn pop_scope() -> QueryTrace {
444 STACK.with(|s| s.borrow_mut().pop()).unwrap_or_default()
445 }
446
447 /// Whether path tracing is active on this thread (at least one
448 /// [`QueryTrace::capture`] scope is open).
449 #[inline]
450 pub fn capturing() -> bool {
451 STACK.with(|s| !s.borrow().is_empty())
452 }
453
454 /// Record into the innermost active trace via `f`. **No-op when not
455 /// capturing** — the hot path pays only the TLS load to check the stack.
456 ///
457 /// This is the primary recording primitive: call it at every decision point
458 /// (path selection, index rebuild, fast-path hit/miss). It is cheap enough
459 /// to call once per query entry point without measurable overhead.
460 #[inline]
461 pub fn record<F>(f: F)
462 where
463 F: FnOnce(&mut QueryTrace),
464 {
465 STACK.with(|s| {
466 if let Some(trace) = s.borrow_mut().last_mut() {
467 f(trace);
468 }
469 });
470 }
471
472 /// Returns `true` when this trace took a "good" (non-materializing) path:
473 /// a cursor, a pushdown, a shadow, or a count shortcut — and did **not**
474 /// rebuild indexes or materialize rows. Useful as a quick sanity check in
475 /// path-sensitive tests.
476 pub fn is_fast(&self) -> bool {
477 !matches!(self.scan_mode, ScanMode::Materialized | ScanMode::Unknown)
478 && self.index_rebuild != IndexRebuild::Rebuilt
479 && !self.row_materialized
480 }
481}
482
483impl fmt::Display for QueryTrace {
484 /// Compact one-line summary for benchmark output and ad-hoc inspection:
485 /// `native-pushdown pushed=2 survivors=12500 runs=1 idx=complete fast-rid`.
486 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
487 write!(f, "{}", self.scan_mode)?;
488 if self.run_count > 0 {
489 write!(f, " runs={}", self.run_count)?;
490 }
491 if self.conditions_pushed > 0 {
492 write!(f, " pushed={}", self.conditions_pushed)?;
493 }
494 if self.conditions_residual > 0 {
495 write!(f, " residual={}", self.conditions_residual)?;
496 }
497 if let Some(n) = self.survivor_count {
498 write!(f, " survivors={}", n)?;
499 }
500 let idx = match self.index_rebuild {
501 IndexRebuild::None => "",
502 IndexRebuild::AlreadyComplete => " idx=complete",
503 IndexRebuild::Rebuilt => " idx=REBUILT",
504 };
505 f.write_str(idx)?;
506 if self.result_cache_hit {
507 f.write_str(" cache=hit")?;
508 }
509 if self.result_cache_persist_skipped {
510 write!(
511 f,
512 " cache-persist=skipped({})",
513 self.result_cache_persist_skip_reason
514 .unwrap_or("unspecified")
515 )?;
516 }
517 if self.learned_range_used {
518 f.write_str(" learned-range")?;
519 }
520 if self.fast_row_id_map {
521 f.write_str(" fast-rid")?;
522 }
523 if self.row_materialized {
524 f.write_str(" row-mat")?;
525 }
526 if self.overlay_rows > 0 {
527 write!(f, " overlay={}", self.overlay_rows)?;
528 }
529 if self.pages_decoded > 0 {
530 write!(f, " pages={}", self.pages_decoded)?;
531 }
532 if self.pages_skipped > 0 {
533 write!(f, " skipped={}", self.pages_skipped)?;
534 }
535 if self.directory_complete {
536 write!(f, " dir=complete candidates={}", self.directory_candidates)?;
537 }
538 if self.run_readers_opened > 0 {
539 write!(f, " run-readers={}", self.run_readers_opened)?;
540 }
541 if self.early_stop {
542 f.write_str(" early-stop")?;
543 }
544 if self.controlled_scan_versions_examined > 0 {
545 write!(
546 f,
547 " controlled=versions={} emitted={}",
548 self.controlled_scan_versions_examined, self.controlled_scan_rows_emitted
549 )?;
550 }
551 if self.hot_lookup_attempted {
552 if self.hot_lookup_hit {
553 f.write_str(" hot=hit")?;
554 } else {
555 write!(
556 f,
557 " hot=fallback reason={}",
558 self.hot_fallback_reason.unwrap_or("unspecified")
559 )?;
560 }
561 }
562 if self.candidate_cap_hit {
563 write!(f, " cap-hit={}", self.final_hits)?;
564 }
565 if let Some(reason) = self.underfill_reason {
566 write!(f, " underfill={reason}")?;
567 }
568 Ok(())
569 }
570}
571
572// ---------------------------------------------------------------------------
573// Test assertion helpers — fluent methods for path-sensitive performance tests.
574// Available in integration tests and downstream test suites (not gated behind
575// #[cfg(test)] so they work from external test crates).
576// ---------------------------------------------------------------------------
577
578impl QueryTrace {
579 /// Assert the scan mode equals `expected`. Returns `&self` for chaining.
580 pub fn assert_mode(&self, expected: ScanMode) -> &Self {
581 assert_eq!(
582 self.scan_mode, expected,
583 "expected scan mode {expected:?} but got {:?} ({self})",
584 self.scan_mode
585 );
586 self
587 }
588
589 /// Assert no index rebuild happened during this query (Priority 10 guard).
590 pub fn assert_no_index_rebuild(&self) -> &Self {
591 assert_ne!(
592 self.index_rebuild,
593 IndexRebuild::Rebuilt,
594 "expected no index rebuild but indexes were rebuilt ({self})"
595 );
596 self
597 }
598
599 /// Assert the query did not materialize `Row { HashMap }` objects.
600 pub fn assert_not_materialized(&self) -> &Self {
601 assert!(
602 !self.row_materialized,
603 "expected columnar/cursor path but rows were materialized ({self})"
604 );
605 self
606 }
607
608 /// Assert the result cache returned a hit.
609 pub fn assert_cache_hit(&self) -> &Self {
610 assert!(
611 self.result_cache_hit,
612 "expected result cache hit but got miss ({self})"
613 );
614 self
615 }
616
617 /// Assert the fast clean-run row-id→position arithmetic was used.
618 pub fn assert_fast_row_id_map(&self) -> &Self {
619 assert!(
620 self.fast_row_id_map,
621 "expected fast row-id map but got fallback ({self})"
622 );
623 self
624 }
625}
626
627/// Inspect a HOT candidate at `rid` against the calling `snapshot` and the
628/// table's TTL policy. Returns the [`HotCandidateInspection`] diagnostic
629/// that the [`crate::engine::Table::resolve_pk_with_hot_fallback`] helper
630/// uses to choose between the fast-path hit and the per-reason fallback.
631///
632/// The classification preserves the **full reason** (HLC + epoch + TTL +
633/// materialized PK equality) — `Table::get` collapses several of these to
634/// `None` and is not sufficient on its own.
635///
636/// `now_nanos` is the wall-clock anchor for TTL evaluation; pass the same
637/// value the caller would use to materialize rows (`unix_nanos_now()` for the
638/// normal query path). `ttl_policy` is the table's [`TtlPolicy`] — when
639/// `None`, the candidate can never be classified as [`HotCandidateInspection::TtlExpired`].
640///
641/// `pk_encoded` is the encoded PK lookup bytes the caller would pass to
642/// `index_lookup_key` (post-HMAC tokenization). It is only compared against
643/// the materialized PK column when the row materializes successfully and is
644/// not tombstoned / expired / invisible.
645pub fn inspect_hot_candidate(
646 row: Option<&crate::memtable::Row>,
647 snapshot: crate::epoch::Snapshot,
648 ttl_policy: Option<crate::manifest::TtlPolicy>,
649 now_nanos: i64,
650 pk_column_id: u16,
651 pk_encoded: &[u8],
652 tokenize_pk: impl FnOnce(&crate::memtable::Row) -> Vec<u8>,
653) -> HotCandidateInspection {
654 let Some(row) = row else {
655 return HotCandidateInspection::MissingRow;
656 };
657 if !snapshot.observes_row(row.committed_epoch, row.commit_ts) {
658 return HotCandidateInspection::Invisible;
659 }
660 if row.deleted {
661 return HotCandidateInspection::Tombstone;
662 }
663 if let Some(policy) = ttl_policy {
664 if let Some(crate::Value::Int64(timestamp)) = row.columns.get(&policy.column_id) {
665 if timestamp.saturating_add(policy.duration_nanos as i64) <= now_nanos {
666 return HotCandidateInspection::TtlExpired;
667 }
668 }
669 }
670 let _ = pk_column_id; // pk_column_id documents the API; tokenize_pk encapsulates the encode.
671 let materialized = tokenize_pk(row);
672 if materialized != pk_encoded {
673 return HotCandidateInspection::PrimaryKeyMismatch {
674 materialized_pk: materialized,
675 requested: pk_encoded.to_vec(),
676 };
677 }
678 HotCandidateInspection::Hit(row.clone())
679}
680
681#[cfg(test)]
682mod tests {
683 use super::*;
684
685 #[test]
686 fn capture_collects_records() {
687 // Recording outside a capture is a no-op (no panic).
688 QueryTrace::record(|t| {
689 t.run_count = 999;
690 });
691 assert!(!QueryTrace::capturing());
692
693 let (result, trace) = QueryTrace::capture(|| {
694 assert!(QueryTrace::capturing());
695 QueryTrace::record(|t| {
696 t.run_count = 3;
697 t.scan_mode = ScanMode::NativePushdown;
698 });
699 42
700 });
701 assert_eq!(result, 42);
702 assert_eq!(trace.run_count, 3);
703 assert_eq!(trace.scan_mode, ScanMode::NativePushdown);
704 assert!(!QueryTrace::capturing());
705 }
706
707 #[test]
708 fn nested_captures_are_independent() {
709 let (outer, outer_trace) = QueryTrace::capture(|| {
710 QueryTrace::record(|t| t.run_count = 1);
711 let (inner, inner_trace) = QueryTrace::capture(|| {
712 QueryTrace::record(|t| t.run_count = 99);
713 "inner"
714 });
715 assert_eq!(inner, "inner");
716 // The inner capture's records must NOT bleed into the outer trace.
717 assert_eq!(inner_trace.run_count, 99);
718 // But subsequent outer records still hit the outer trace.
719 QueryTrace::record(|t| t.conditions_pushed = 2);
720 "outer"
721 });
722 assert_eq!(outer, "outer");
723 assert_eq!(outer_trace.run_count, 1);
724 assert_eq!(outer_trace.conditions_pushed, 2);
725 }
726
727 #[test]
728 fn display_summary_is_compact() {
729 let t = QueryTrace {
730 scan_mode: ScanMode::NativePushdown,
731 run_count: 1,
732 conditions_pushed: 2,
733 survivor_count: Some(12500),
734 index_rebuild: IndexRebuild::AlreadyComplete,
735 fast_row_id_map: true,
736 ..Default::default()
737 };
738 let s = format!("{t}");
739 assert!(s.contains("native-pushdown"));
740 assert!(s.contains("runs=1"));
741 assert!(s.contains("pushed=2"));
742 assert!(s.contains("survivors=12500"));
743 assert!(s.contains("idx=complete"));
744 assert!(s.contains("fast-rid"));
745 }
746
747 #[test]
748 fn is_fast_distinguishes_paths() {
749 let good = QueryTrace {
750 scan_mode: ScanMode::NativePageCursor,
751 index_rebuild: IndexRebuild::AlreadyComplete,
752 ..Default::default()
753 };
754 assert!(good.is_fast());
755
756 let mut bad = good.clone();
757 bad.index_rebuild = IndexRebuild::Rebuilt;
758 assert!(!bad.is_fast());
759
760 let mut mat = good.clone();
761 mat.scan_mode = ScanMode::Materialized;
762 assert!(!mat.is_fast());
763 }
764
765 #[test]
766 fn assertion_helpers_chain() {
767 let t = QueryTrace {
768 scan_mode: ScanMode::ArrowShadow,
769 index_rebuild: IndexRebuild::AlreadyComplete,
770 ..Default::default()
771 };
772 t.assert_mode(ScanMode::ArrowShadow)
773 .assert_no_index_rebuild()
774 .assert_not_materialized();
775 }
776}