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}
86
87impl fmt::Display for ScanMode {
88 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
89 let s = match self {
90 ScanMode::Unknown => "unknown",
91 ScanMode::CountMetadata => "count-metadata",
92 ScanMode::CountSurvivors => "count-survivors",
93 ScanMode::ArrowShadow => "arrow-shadow",
94 ScanMode::NativePageCursor => "native-page-cursor",
95 ScanMode::MultiRunCursor => "multi-run-cursor",
96 ScanMode::NativePushdown => "native-pushdown",
97 ScanMode::Materialized => "materialized",
98 ScanMode::DirectDispatch => "direct-dispatch",
99 };
100 f.write_str(s)
101 }
102}
103
104/// Which join execution path served a query (Priority 13: join diagnostics).
105/// `None` for non-join queries.
106#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
107pub enum JoinMode {
108 /// No join in the query (or the join path was never reached).
109 #[default]
110 None,
111 /// Native FK↔PK roaring-bitmap intersection — no hash-join materialization
112 /// ([`crate::engine::Table`] index resolve only).
113 FkBitmap,
114 /// Fell back to DataFusion's hash join (shape the native path can't serve).
115 DataFusionHash,
116}
117
118impl fmt::Display for JoinMode {
119 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
120 f.write_str(match self {
121 JoinMode::None => "none",
122 JoinMode::FkBitmap => "fk-bitmap",
123 JoinMode::DataFusionHash => "datafusion-hash",
124 })
125 }
126}
127
128/// Whether `ensure_indexes_complete` rebuilt indexes during this query. A
129/// rebuild is the user-facing stall case (Priority 10); this field exposes it.
130#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
131pub enum IndexRebuild {
132 /// No index rebuild happened (no query ran, or the table had no indexes).
133 #[default]
134 None,
135 /// Indexes were already complete; `ensure_indexes_complete` was a no-op.
136 AlreadyComplete,
137 /// Indexes were rebuilt from runs during this query (the stall case).
138 Rebuilt,
139}
140
141/// Records which engine path a query took. Filled at decision points via
142/// [`QueryTrace::record`]; collected via [`QueryTrace::capture`].
143///
144/// All fields are `#[derive(Default)]`, so adding a new field is non-breaking.
145/// Fields default to zero / `false` / `None` so a trace from an uninstrumented
146/// path still reads cleanly.
147#[derive(Debug, Default, Clone)]
148pub struct QueryTrace {
149 /// The physical scan path that served this query.
150 pub scan_mode: ScanMode,
151 /// Number of sorted runs in the table at query time. `1` = single-run fast
152 /// path eligible; `>1` = k-way merge; `0` = empty/memtable-only table.
153 pub run_count: usize,
154 /// Rows in the memtable overlay (unflushed puts/updates/deletes).
155 pub memtable_rows: usize,
156 /// Rows in the mutable-run tier overlay.
157 pub mutable_run_rows: usize,
158 /// Rows in the materialized overlay batch yielded by a cursor (memtable +
159 /// mutable-run combined, post-filter). Non-zero means the query paid
160 /// overlay materialization cost.
161 pub overlay_rows: usize,
162 /// How many conditions were translated to native pushdown (index-served).
163 pub conditions_pushed: usize,
164 /// How many conditions could not be pushed down (residual / fallback).
165 pub conditions_residual: usize,
166 /// Survivor row count after predicate resolution, if known without decoding
167 /// data columns (set for index-served and count paths).
168 pub survivor_count: Option<usize>,
169 /// Whether `ensure_indexes_complete` rebuilt indexes during this query.
170 pub index_rebuild: IndexRebuild,
171 /// Whether the fast clean-run row-id→position arithmetic was used (avoids
172 /// decoding + binary-searching the system row-id column).
173 pub fast_row_id_map: bool,
174 /// Whether a learned (PGM) range index served a `Range`/`RangeF64`
175 /// condition (in-memory, no column read).
176 pub learned_range_used: bool,
177 /// Whether the result cache returned a hit (no re-decode / re-resolve).
178 pub result_cache_hit: bool,
179 /// Whether rows were materialized as `Row { HashMap }` (the slow path).
180 pub row_materialized: bool,
181 /// Number of pages decoded (lazily filled by cursors when capturing).
182 pub pages_decoded: usize,
183 /// Number of pages skipped by page-stat pruning or empty page plans.
184 pub pages_skipped: usize,
185 /// Which join path served the query (Priority 13). `None` for non-joins.
186 pub join_mode: JoinMode,
187 /// Logical-planning time in nanoseconds (Priority 8: parse + plan, separate
188 /// from execution). `0` on a result-cache hit (planning was skipped) or when
189 /// the plan came from the logical-plan cache.
190 pub planning_nanos: u64,
191}
192
193impl QueryTrace {
194 /// Execute `f` with path tracing active on the current thread, returning
195 /// the result and the captured trace. Recording calls inside `f` (and
196 /// anything `f` calls on this thread) fill the returned trace.
197 ///
198 /// Nesting is supported: an inner `capture` pushes a fresh trace onto the
199 /// stack and gets its own result; the outer trace is unaffected by inner
200 /// recordings.
201 ///
202 /// When no capture is active (the normal hot path), [`QueryTrace::record`]
203 /// is a single TLS load + empty-check + return — zero allocation, zero
204 /// locking, no measurable cost.
205 pub fn capture<F, T>(f: F) -> (T, QueryTrace)
206 where
207 F: FnOnce() -> T,
208 {
209 Self::push_scope();
210 let result = f();
211 let trace = Self::pop_scope();
212 (result, trace)
213 }
214
215 /// Push a fresh trace onto the thread-local stack, starting a capture scope.
216 /// Pair with [`Self::pop_scope`] to retrieve the trace. This is the async-
217 /// compatible alternative to [`Self::capture`]: push before `await`, pop
218 /// after.
219 ///
220 /// **Thread affinity:** the trace is thread-local, so recordings must happen
221 /// on the same OS thread as the push/pop pair. This holds for synchronous
222 /// query paths (the common case) and for single-partition DataFusion scans
223 /// (physical planning + leaf execution run inline on the polling thread).
224 pub fn push_scope() {
225 STACK.with(|s| s.borrow_mut().push(QueryTrace::default()));
226 }
227
228 /// Pop the innermost trace from the thread-local stack, ending a capture
229 /// scope. Returns the captured trace. Panics if the stack is empty (unpaired
230 /// pop); see [`Self::push_scope`].
231 pub fn pop_scope() -> QueryTrace {
232 STACK.with(|s| s.borrow_mut().pop()).unwrap_or_default()
233 }
234
235 /// Whether path tracing is active on this thread (at least one
236 /// [`QueryTrace::capture`] scope is open).
237 #[inline]
238 pub fn capturing() -> bool {
239 STACK.with(|s| !s.borrow().is_empty())
240 }
241
242 /// Record into the innermost active trace via `f`. **No-op when not
243 /// capturing** — the hot path pays only the TLS load to check the stack.
244 ///
245 /// This is the primary recording primitive: call it at every decision point
246 /// (path selection, index rebuild, fast-path hit/miss). It is cheap enough
247 /// to call once per query entry point without measurable overhead.
248 #[inline]
249 pub fn record<F>(f: F)
250 where
251 F: FnOnce(&mut QueryTrace),
252 {
253 STACK.with(|s| {
254 if let Some(trace) = s.borrow_mut().last_mut() {
255 f(trace);
256 }
257 });
258 }
259
260 /// Returns `true` when this trace took a "good" (non-materializing) path:
261 /// a cursor, a pushdown, a shadow, or a count shortcut — and did **not**
262 /// rebuild indexes or materialize rows. Useful as a quick sanity check in
263 /// path-sensitive tests.
264 pub fn is_fast(&self) -> bool {
265 !matches!(self.scan_mode, ScanMode::Materialized | ScanMode::Unknown)
266 && self.index_rebuild != IndexRebuild::Rebuilt
267 && !self.row_materialized
268 }
269}
270
271impl fmt::Display for QueryTrace {
272 /// Compact one-line summary for benchmark output and ad-hoc inspection:
273 /// `native-pushdown pushed=2 survivors=12500 runs=1 idx=complete fast-rid`.
274 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
275 write!(f, "{}", self.scan_mode)?;
276 if self.run_count > 0 {
277 write!(f, " runs={}", self.run_count)?;
278 }
279 if self.conditions_pushed > 0 {
280 write!(f, " pushed={}", self.conditions_pushed)?;
281 }
282 if self.conditions_residual > 0 {
283 write!(f, " residual={}", self.conditions_residual)?;
284 }
285 if let Some(n) = self.survivor_count {
286 write!(f, " survivors={}", n)?;
287 }
288 let idx = match self.index_rebuild {
289 IndexRebuild::None => "",
290 IndexRebuild::AlreadyComplete => " idx=complete",
291 IndexRebuild::Rebuilt => " idx=REBUILT",
292 };
293 f.write_str(idx)?;
294 if self.result_cache_hit {
295 f.write_str(" cache=hit")?;
296 }
297 if self.learned_range_used {
298 f.write_str(" learned-range")?;
299 }
300 if self.fast_row_id_map {
301 f.write_str(" fast-rid")?;
302 }
303 if self.row_materialized {
304 f.write_str(" row-mat")?;
305 }
306 if self.overlay_rows > 0 {
307 write!(f, " overlay={}", self.overlay_rows)?;
308 }
309 if self.pages_decoded > 0 {
310 write!(f, " pages={}", self.pages_decoded)?;
311 }
312 if self.pages_skipped > 0 {
313 write!(f, " skipped={}", self.pages_skipped)?;
314 }
315 Ok(())
316 }
317}
318
319// ---------------------------------------------------------------------------
320// Test assertion helpers — fluent methods for path-sensitive performance tests.
321// Available in integration tests and downstream test suites (not gated behind
322// #[cfg(test)] so they work from external test crates).
323// ---------------------------------------------------------------------------
324
325impl QueryTrace {
326 /// Assert the scan mode equals `expected`. Returns `&self` for chaining.
327 pub fn assert_mode(&self, expected: ScanMode) -> &Self {
328 assert_eq!(
329 self.scan_mode, expected,
330 "expected scan mode {expected:?} but got {:?} ({self})",
331 self.scan_mode
332 );
333 self
334 }
335
336 /// Assert no index rebuild happened during this query (Priority 10 guard).
337 pub fn assert_no_index_rebuild(&self) -> &Self {
338 assert_ne!(
339 self.index_rebuild,
340 IndexRebuild::Rebuilt,
341 "expected no index rebuild but indexes were rebuilt ({self})"
342 );
343 self
344 }
345
346 /// Assert the query did not materialize `Row { HashMap }` objects.
347 pub fn assert_not_materialized(&self) -> &Self {
348 assert!(
349 !self.row_materialized,
350 "expected columnar/cursor path but rows were materialized ({self})"
351 );
352 self
353 }
354
355 /// Assert the result cache returned a hit.
356 pub fn assert_cache_hit(&self) -> &Self {
357 assert!(
358 self.result_cache_hit,
359 "expected result cache hit but got miss ({self})"
360 );
361 self
362 }
363
364 /// Assert the fast clean-run row-id→position arithmetic was used.
365 pub fn assert_fast_row_id_map(&self) -> &Self {
366 assert!(
367 self.fast_row_id_map,
368 "expected fast row-id map but got fallback ({self})"
369 );
370 self
371 }
372}
373
374#[cfg(test)]
375mod tests {
376 use super::*;
377
378 #[test]
379 fn capture_collects_records() {
380 // Recording outside a capture is a no-op (no panic).
381 QueryTrace::record(|t| {
382 t.run_count = 999;
383 });
384 assert!(!QueryTrace::capturing());
385
386 let (result, trace) = QueryTrace::capture(|| {
387 assert!(QueryTrace::capturing());
388 QueryTrace::record(|t| {
389 t.run_count = 3;
390 t.scan_mode = ScanMode::NativePushdown;
391 });
392 42
393 });
394 assert_eq!(result, 42);
395 assert_eq!(trace.run_count, 3);
396 assert_eq!(trace.scan_mode, ScanMode::NativePushdown);
397 assert!(!QueryTrace::capturing());
398 }
399
400 #[test]
401 fn nested_captures_are_independent() {
402 let (outer, outer_trace) = QueryTrace::capture(|| {
403 QueryTrace::record(|t| t.run_count = 1);
404 let (inner, inner_trace) = QueryTrace::capture(|| {
405 QueryTrace::record(|t| t.run_count = 99);
406 "inner"
407 });
408 assert_eq!(inner, "inner");
409 // The inner capture's records must NOT bleed into the outer trace.
410 assert_eq!(inner_trace.run_count, 99);
411 // But subsequent outer records still hit the outer trace.
412 QueryTrace::record(|t| t.conditions_pushed = 2);
413 "outer"
414 });
415 assert_eq!(outer, "outer");
416 assert_eq!(outer_trace.run_count, 1);
417 assert_eq!(outer_trace.conditions_pushed, 2);
418 }
419
420 #[test]
421 fn display_summary_is_compact() {
422 let t = QueryTrace {
423 scan_mode: ScanMode::NativePushdown,
424 run_count: 1,
425 conditions_pushed: 2,
426 survivor_count: Some(12500),
427 index_rebuild: IndexRebuild::AlreadyComplete,
428 fast_row_id_map: true,
429 ..Default::default()
430 };
431 let s = format!("{t}");
432 assert!(s.contains("native-pushdown"));
433 assert!(s.contains("runs=1"));
434 assert!(s.contains("pushed=2"));
435 assert!(s.contains("survivors=12500"));
436 assert!(s.contains("idx=complete"));
437 assert!(s.contains("fast-rid"));
438 }
439
440 #[test]
441 fn is_fast_distinguishes_paths() {
442 let good = QueryTrace {
443 scan_mode: ScanMode::NativePageCursor,
444 index_rebuild: IndexRebuild::AlreadyComplete,
445 ..Default::default()
446 };
447 assert!(good.is_fast());
448
449 let mut bad = good.clone();
450 bad.index_rebuild = IndexRebuild::Rebuilt;
451 assert!(!bad.is_fast());
452
453 let mut mat = good.clone();
454 mat.scan_mode = ScanMode::Materialized;
455 assert!(!mat.is_fast());
456 }
457
458 #[test]
459 fn assertion_helpers_chain() {
460 let t = QueryTrace {
461 scan_mode: ScanMode::ArrowShadow,
462 index_rebuild: IndexRebuild::AlreadyComplete,
463 ..Default::default()
464 };
465 t.assert_mode(ScanMode::ArrowShadow)
466 .assert_no_index_rebuild()
467 .assert_not_materialized();
468 }
469}