feat: add multimodal search and granular performance diagnostics

crates/searchi-core/examples/trace_overhead.rs

@@ -0,0 +1,80 @@
+//! Small prepared SQLite instrumentation diagnostic; not a production benchmark.
+use anyhow::{ensure, Result};
+use searchi_core::SearchIndex;
+use std::{fs, path::Path, time::Instant};
+
+fn distribution(samples: &[f64]) -> serde_json::Value {
+    let mut sorted = samples.to_vec();
+    sorted.sort_by(f64::total_cmp);
+    let percentile = |fraction: f64| {
+        sorted[((sorted.len() as f64 * fraction).ceil() as usize).saturating_sub(1)]
+    };
+    serde_json::json!({"samples":sorted.len(),"p50_ms":percentile(0.50),"p95_ms":percentile(0.95),"mean_ms":sorted.iter().sum::<f64>()/sorted.len() as f64})
+}
+fn main() -> Result<()> {
+    let fixture = tempfile::tempdir()?;
+    let root = fixture.path().join("files");
+    fs::create_dir(&root)?;
+    for index in 0..1000 {
+        fs::write(
+            root.join(format!("record-{index:04}.txt")),
+            format!(
+                "Supplier agreement {index}. Cancellation needs written notice. Group {}.",
+                index % 31
+            ),
+        )?;
+    }
+    let mut index = SearchIndex::open(fixture.path().join("index.sqlite"))?;
+    let report = index.index_folder(&root)?;
+    index.prewarm()?;
+    ensure!(report.indexed == 1000, "Unexpected fixture indexing count");
+    let queries: Vec<String> = (0..24)
+        .map(|index| format!("record-{:04}.txt", index * 37))
+        .collect();
+    for query in &queries {
+        index.search_measured(query, 10, false)?;
+        index.search_measured(query, 10, true)?;
+    }
+    let mut basic = Vec::new();
+    let mut debug = Vec::new();
+    let mut trace_spans = Vec::new();
+    // Alternate order to reduce monotonic cache/CPU-order effects.
+    for repetition in 0..20 {
+        for query in &queries {
+            for detailed in if repetition % 2 == 0 {
+                [false, true]
+            } else {
+                [true, false]
+            } {
+                let started = Instant::now();
+                let response = index.search_measured(query, 10, detailed)?;
+                let elapsed = started.elapsed().as_secs_f64() * 1000.0;
+                ensure!(
+                    response
+                        .results
+                        .first()
+                        .is_some_and(|result| &result.filename == query),
+                    "Fixture retrieval changed"
+                );
+                if detailed {
+                    trace_spans.push(response.metrics.trace.as_ref().unwrap().len());
+                    debug.push(elapsed);
+                } else {
+                    ensure!(
+                        response.metrics.trace.is_none(),
+                        "Basic unexpectedly stored traces"
+                    );
+                    basic.push(elapsed);
+                }
+            }
+        }
+    }
+    let output = serde_json::json!({"kind":"prepared_sqlite_trace_overhead","production_claim":false,"profile":if cfg!(debug_assertions){"debug"}else{"release"},"os":std::env::consts::OS,"arch":std::env::consts::ARCH,"files":1000,"queries":24,"repetitions":20,"measurement":"outer Rust call including metrics assembly; excludes fixture setup/JSON serialization","basic":distribution(&basic),"debug":distribution(&debug),"basic_samples_ms":basic,"debug_samples_ms":debug,"debug_span_count_min":trace_spans.iter().min(),"debug_span_count_max":trace_spans.iter().max(),"limits":"tiny warm lexical corpus; harness serial/no model/media/GPU; other VM work including native photo inference may contend; not isolated production performance"});
+    let serialized = serde_json::to_string_pretty(&output)?;
+    if let Some(path) = std::env::args_os().nth(1) {
+        fs::write(Path::new(&path), serialized)?;
+    } else {
+        println!("{serialized}");
+    }
+    Ok(())
+}

crates/searchi-core/src/lib.rs

@@ -4,7 +4,10 @@
 //! Text and document extraction have byte limits, but still run in this process.
 //! Worker isolation remains a production milestone.
 mod extraction;
+pub mod metrics;
 use anyhow::{bail, Context, Result};
+pub use metrics::{MetricsMode, SearchMetrics, SearchResponse, SearchSpan};
+use metrics::{SpanToken, TraceCollector};
 use rusqlite::{params, params_from_iter, types::Value, Connection, OptionalExtension};
 use serde::Serialize;
 use std::{
@@ -16,7 +19,7 @@ use std::{
 };
 use walkdir::WalkDir;
 
-const SCHEMA_VERSION: i64 = 9;
+const SCHEMA_VERSION: i64 = 10;
 const MAX_RESULTS: usize = 1000;
 
 #[derive(Debug, Default, Serialize)]
@@ -53,6 +56,8 @@ pub struct SearchOptions {
     pub max_size: Option<u64>,
     pub modified_after_unix_ms: Option<i64>,
     pub modified_before_unix_ms: Option<i64>,
+    pub min_duration_ms: Option<u32>,
+    pub max_duration_ms: Option<u32>,
 }
 
 #[derive(Debug, Serialize)]
@@ -66,7 +71,8 @@ pub struct SearchResult {
     pub extraction_error: Option<String>,
 }
 
-/// A verified matching passage location; numbers are one based.
+/// Verified source location. Document numbers are one based; timestamp_ms
+/// numbers are milliseconds from media start, and image numbers are zero.
 #[derive(Debug, Clone, Serialize)]
 pub struct SourceLocation {
     pub kind: String,
@@ -227,6 +233,15 @@ impl SearchIndex {
                     UPDATE name_statistics_state SET dirty=1 WHERE singleton=1; END;
                 PRAGMA user_version=9;",
             )?;
+            initialization.execute_batch("CREATE INDEX IF NOT EXISTS files_extension ON files(extension,id);
+                CREATE TABLE IF NOT EXISTS media_metadata(path TEXT PRIMARY KEY, file_id INTEGER NOT NULL UNIQUE, tags TEXT NOT NULL,duration_ms INTEGER NOT NULL);
+                CREATE VIRTUAL TABLE IF NOT EXISTS media_tags USING fts5(tags,content='media_metadata',content_rowid='file_id');
+                CREATE TRIGGER IF NOT EXISTS media_metadata_insert AFTER INSERT ON media_metadata BEGIN INSERT INTO media_tags(rowid,tags) VALUES(new.file_id,new.tags); END;
+                CREATE TRIGGER IF NOT EXISTS media_metadata_delete AFTER DELETE ON media_metadata BEGIN INSERT INTO media_tags(media_tags,rowid,tags) VALUES('delete',old.file_id,old.tags); END;
+                CREATE TRIGGER IF NOT EXISTS media_metadata_update AFTER UPDATE ON media_metadata BEGIN INSERT INTO media_tags(media_tags,rowid,tags) VALUES('delete',old.file_id,old.tags); INSERT INTO media_tags(rowid,tags) VALUES(new.file_id,new.tags); END;
+                CREATE TRIGGER IF NOT EXISTS files_media_delete AFTER DELETE ON files BEGIN DELETE FROM media_metadata WHERE path=old.path; END;
+                CREATE TRIGGER IF NOT EXISTS files_media_update AFTER UPDATE ON files WHEN new.path!=old.path OR new.size!=old.size OR new.mtime!=old.mtime BEGIN DELETE FROM media_metadata WHERE path=old.path; END;
+                PRAGMA user_version=10;")?;
             initialization.commit()?;
         }
         Ok(Self {
@@ -236,6 +251,32 @@ impl SearchIndex {
         })
     }
 
+    /// Persist genuine extracted media tags, guarded against filesystem changes.
+    pub fn set_media_metadata(
+        &mut self,
+        path: &str,
+        tags: &str,
+        duration_ms: u32,
+        size: u64,
+        mtime_ns: i64,
+    ) -> Result<()> {
+        if tags.len() > 32768 {
+            bail!("Media tags exceed 32 KiB bound");
+        }
+        let tx = self.connection.transaction()?;
+        let id: Option<i64> = tx
+            .query_row(
+                "SELECT id FROM files WHERE path=?1 AND size=?2 AND mtime=?3",
+                params![path, i64::try_from(size)?, mtime_ns],
+                |r| r.get(0),
+            )
+            .optional()?;
+        let id = id.context("Media metadata file changed since indexing")?;
+        tx.execute("INSERT INTO media_metadata(path,file_id,tags,duration_ms) VALUES(?1,?2,?3,?4) ON CONFLICT(path) DO UPDATE SET tags=excluded.tags,duration_ms=excluded.duration_ms",params![path,id,tags,duration_ms])?;
+        tx.commit()?;
+        Ok(())
+    }
+
     /// Refresh candidate-frequency statistics off the foreground search path.
     /// Stale/missing estimates can affect speed, never literal-match correctness.
     /// The app invokes this during background startup and after reconciliation.
@@ -465,6 +506,56 @@ impl SearchIndex {
         limit: usize,
         options: &SearchOptions,
     ) -> Result<Vec<SearchResult>> {
+        let mut trace = TraceCollector::new(MetricsMode::Basic);
+        self.search_with_options_traced(query, limit, options, &mut trace, None)
+    }
+    pub fn search_measured(
+        &self,
+        query: &str,
+        limit: usize,
+        debug: bool,
+    ) -> Result<SearchResponse<SearchResult>> {
+        self.search_with_options_measured(query, limit, &SearchOptions::default(), debug)
+    }
+    pub fn search_with_options_measured(
+        &self,
+        query: &str,
+        limit: usize,
+        options: &SearchOptions,
+        debug: bool,
+    ) -> Result<SearchResponse<SearchResult>> {
+        let mut trace = TraceCollector::new(if debug {
+            MetricsMode::Debug
+        } else {
+            MetricsMode::Basic
+        });
+        let results = self.search_with_options_traced(query, limit, options, &mut trace, None)?;
+        let metrics = trace.finish(results.len());
+        Ok(SearchResponse { results, metrics })
+    }
+    /// Share one monotonic request collector with downstream retrieval lanes.
+    pub fn search_with_options_traced(
+        &self,
+        query: &str,
+        limit: usize,
+        options: &SearchOptions,
+        trace: &mut TraceCollector,
+        parent: Option<SpanToken>,
+    ) -> Result<Vec<SearchResult>> {
+        trace.timed("lexical.search", parent, |trace, parent| {
+            self.search_inner(query, limit, options, trace, parent)
+        })
+    }
+    fn search_inner(
+        &self,
+        query: &str,
+        limit: usize,
+        options: &SearchOptions,
+        trace: &mut TraceCollector,
+        parent: Option<SpanToken>,
+    ) -> Result<Vec<SearchResult>> {
+        let normalization = trace.begin("lexical.normalization", parent);
+
         if options
             .min_size
             .zip(options.max_size)
@@ -479,6 +570,13 @@ impl SearchIndex {
         {
             bail!("modified-after exceeds modified-before");
         }
+        if options
+            .min_duration_ms
+            .zip(options.max_duration_ms)
+            .is_some_and(|(a, b)| a > b)
+        {
+            bail!("Minimum duration exceeds maximum duration");
+        }
         let folder = options
             .folder
             .as_ref()
@@ -518,11 +616,16 @@ impl SearchIndex {
             .map(|term| format!("\"{}\"", term.replace('"', "\"\"")))
             .collect::<Vec<_>>()
             .join(" AND ");
+        trace.counter(normalization, "query_bytes", query.len() as u64);
+        trace.end(normalization, Default::default());
+        let planning = trace.begin("lexical.candidate_plan", parent);
         let limit = limit.min(MAX_RESULTS);
         let filters = " AND (?3 IS NULL OR substr(f.path,1,length(?3))=?3)
             AND (?4 IS NULL OR f.extension=?4)
             AND (?5 IS NULL OR f.size>=?5) AND (?6 IS NULL OR f.size<=?6)
-            AND (?7 IS NULL OR f.mtime/1000000>=?7) AND (?8 IS NULL OR f.mtime/1000000<=?8)";
+            AND (?7 IS NULL OR f.mtime/1000000>=?7) AND (?8 IS NULL OR f.mtime/1000000<=?8)
+            AND (?10 IS NULL OR EXISTS(SELECT 1 FROM media_metadata m WHERE m.file_id=f.id AND m.duration_ms>=?10))
+            AND (?11 IS NULL OR EXISTS(SELECT 1 FROM media_metadata m WHERE m.file_id=f.id AND m.duration_ms<=?11))";
         let filter_values = [
             folder_prefix.map_or(Value::Null, Value::Text),
             extension.map_or(Value::Null, Value::Text),
@@ -535,7 +638,9 @@ impl SearchIndex {
                 .modified_before_unix_ms
                 .map_or(Value::Null, Value::Integer),
         ];
-        let has_filters = filter_values.iter().any(|value| *value != Value::Null);
+        let has_filters = filter_values.iter().any(|value| *value != Value::Null)
+            || options.min_duration_ms.is_some()
+            || options.max_duration_ms.is_some();
         let mut results = Vec::new();
         let mut selected = Vec::<i64>::new();
         // Each lane filters its entire candidate set before LIMIT. There is no
@@ -561,13 +666,17 @@ impl SearchIndex {
         if cache.len() + grams.len() > 4096 {
             cache.clear();
         }
+        let mut frequency_hits = 0u64;
+        let mut frequency_misses = 0u64;
         let mut rare_first = grams
             .into_iter()
             .map(|gram| {
                 let term = gram.to_lowercase();
                 let frequency = if let Some(frequency) = cache.get(&term) {
+                    frequency_hits += 1;
                     *frequency
                 } else {
+                    frequency_misses += 1;
                     let frequency = vocabulary
                         .query_row([&term], |row| row.get::<_, i64>(0))
                         .optional()?
@@ -581,6 +690,9 @@ impl SearchIndex {
         rare_first.sort();
         drop(cache);
         let anchor = substring_anchor(&characters, &rare_first);
+        trace.counter(planning, "frequency_cache_hits", frequency_hits);
+        trace.counter(planning, "frequency_cache_misses", frequency_misses);
+        trace.counter(planning, "trigram_index", u64::from(trigram));
         let grams = format!("\"{}\"", anchor.replace('"', "\"\""));
         let mut lanes = vec![
             (
@@ -648,10 +760,30 @@ impl SearchIndex {
                 "rank,f.id",
             ));
         }
+        lanes.push((
+            "media_metadata",
+            "media_tags CROSS JOIN files f ON f.id=media_tags.rowid".into(),
+            "media_tags MATCH ?1".into(),
+            fts.clone(),
+            "rank,f.id",
+        ));
+        trace.end(planning, Default::default());
         for (kind, from, condition, expression, ordering) in lanes {
             if results.len() == limit {
                 break;
             }
+            let lane = trace.begin(
+                match kind {
+                    "exact_filename" => "lexical.exact_filename",
+                    "filename" => "lexical.filename_substring",
+                    "path" => "lexical.path_substring",
+                    "name_terms" => "lexical.filename_terms",
+                    "content" => "lexical.content",
+                    "media_metadata" => "lexical.media_metadata",
+                    _ => "lexical.other",
+                },
+                parent,
+            );
             let exclusions = if selected.is_empty() {
                 String::new()
             } else {
@@ -664,12 +796,14 @@ impl SearchIndex {
                         .join(",")
                 )
             };
-            let rank = if matches!(kind, "content" | "name_terms") {
+            let rank = if matches!(kind, "content" | "name_terms" | "media_metadata") {
                 "rank"
             } else {
                 "0.0"
             };
-            let snippet = if kind == "content" {
+            let snippet = if kind == "media_metadata" {
+                "snippet(media_tags,0,'','',' … ',24)"
+            } else if kind == "content" {
                 "snippet(content_search,0,'','',' … ',24)"
             } else if kind == "name_terms" {
                 "snippet(search,2,'','',' … ',24)"
@@ -698,6 +832,20 @@ impl SearchIndex {
             let mut values = vec![Value::Text(expression), Value::Text(query.into())];
             values.extend(filter_values.iter().cloned());
             values.push(Value::Integer((limit - results.len()) as i64));
+            if sql.contains("?10") {
+                values.push(
+                    options
+                        .min_duration_ms
+                        .map_or(Value::Null, |v| Value::Integer(i64::from(v))),
+                );
+                values.push(
+                    options
+                        .max_duration_ms
+                        .map_or(Value::Null, |v| Value::Integer(i64::from(v))),
+                );
+            }
+            let sql_span = trace.begin("lexical.filtered_sql", lane);
+            trace.counter(sql_span, "filters_active", u64::from(has_filters));
             let mut statement = self.connection.prepare(&sql)?;
             let matches = statement
                 .query_map(params_from_iter(values), |row| {
@@ -715,12 +863,16 @@ impl SearchIndex {
                     ))
                 })?
                 .collect::<rusqlite::Result<Vec<_>>>()?;
+            trace.counter(sql_span, "rows", matches.len() as u64);
+            trace.end(sql_span, Default::default());
             for (id, result) in matches {
                 selected.push(id);
                 results.push(result);
             }
+            trace.end(lane, Default::default());
         }
         if !results.is_empty() {
+            let source_span = trace.begin("lexical.source_locations", parent);
             // Ownership has a B-tree index. The rowid IN constraint intersects
             // the FTS postings with only the actual finalists' passage IDs.
             let placeholders = (0..results.len())
@@ -762,6 +914,9 @@ impl SearchIndex {
                     result.snippet = snippet.clone();
                 }
             }
+            trace.counter(source_span, "files", results.len() as u64);
+            trace.counter(source_span, "matched_sources", sources.len() as u64);
+            trace.end(source_span, Default::default());
         }
         Ok(results)
     }
@@ -856,6 +1011,100 @@ fn substring_anchor(characters: &[char], frequencies: &[(i64, String)]) -> Strin
 
 #[cfg(test)]
 mod tests {
+    #[test]
+    fn measured_search_preserves_results_and_contains_private_free_nested_spans(
+    ) -> anyhow::Result<()> {
+        let directory = tempfile::tempdir()?;
+        let root = directory.path().join("sensitive-private-location");
+        std::fs::create_dir(&root)?;
+        std::fs::write(
+            root.join("agreement.txt"),
+            "confidentialneedle cancellation policy",
+        )?;
+        let db = directory.path().join("index.db");
+        let mut index = super::SearchIndex::open(&db)?;
+        index.index_folder(&root)?;
+        let basic = index.search_measured("confidentialneedle", 10, false)?;
+        let debug = index.search_measured("confidentialneedle", 10, true)?;
+        assert_eq!(
+            serde_json::to_value(&basic.results)?,
+            serde_json::to_value(&debug.results)?
+        );
+        assert_eq!(basic.metrics.result_count, 1);
+        assert!(basic.metrics.trace.is_none());
+        let spans = debug.metrics.trace.as_ref().unwrap();
+        assert!(spans.iter().any(|s| s.name == "lexical.content"));
+        assert!(spans.iter().any(|s| s.name == "lexical.source_locations"));
+        for span in spans {
+            assert!(span.start_ms >= 0.0 && span.duration_ms >= 0.0);
+            assert!(span.start_ms + span.duration_ms <= debug.metrics.total_ms + 1e-6);
+            if let Some(parent) = span.parent {
+                let parent = &spans[parent];
+                assert!(span.start_ms >= parent.start_ms);
+                assert!(
+                    span.start_ms + span.duration_ms <= parent.start_ms + parent.duration_ms + 1e-6
+                );
+            }
+        }
+        let trace = serde_json::to_string(spans)?;
+        assert!(!trace.contains("confidentialneedle"));
+        assert!(!trace.contains("sensitive-private-location"));
+        Ok(())
+    }
+    #[test]
+    fn genuine_media_tags_search_duration_filter_and_lifecycle() -> anyhow::Result<()> {
+        let directory = tempfile::tempdir()?;
+        let root = directory.path().join("music");
+        std::fs::create_dir(&root)?;
+        let file = root.join("track.ogg");
+        std::fs::write(&file, b"storage fixture")?;
+        let db = directory.path().join("index.db");
+        let mut index = super::SearchIndex::open(&db)?;
+        index.index_folder(&root)?;
+        let path = file.canonicalize()?.to_string_lossy().into_owned();
+        let (size, mtime): (u64, i64) = index.connection.query_row(
+            "SELECT size,mtime FROM files WHERE path=?1",
+            [&path],
+            |r| Ok((r.get(0)?, r.get(1)?)),
+        )?;
+        index.set_media_metadata(
+            &path,
+            "artist: Kimiko Ishizaka\ntitle: Variatio 13 a 2 Clav.",
+            180000,
+            size,
+            mtime,
+        )?;
+        let results = index.search("Kimiko Ishizaka", 10)?;
+        assert_eq!(results.len(), 1);
+        assert_eq!(results[0].match_kind, "media_metadata");
+        assert!(results[0].snippet.contains("Kimiko"));
+        let too_short = super::SearchOptions {
+            max_duration_ms: Some(100000),
+            ..Default::default()
+        };
+        assert!(index
+            .search_with_options("track.ogg", 10, &too_short)?
+            .is_empty());
+        let correct = super::SearchOptions {
+            min_duration_ms: Some(170000),
+            max_duration_ms: Some(190000),
+            ..Default::default()
+        };
+        assert_eq!(index.search_with_options("Kimiko", 10, &correct)?.len(), 1);
+        drop(index);
+        let mut index = super::SearchIndex::open(&db)?;
+        assert_eq!(index.search("Variatio", 10)?.len(), 1);
+        std::fs::write(&file, b"changed file bytes")?;
+        index.index_folder(&root)?;
+        assert!(index.search("Kimiko", 10)?.is_empty());
+        assert!(index
+            .set_media_metadata(&path, "stale", 180000, size, mtime)
+            .is_err());
+        std::fs::remove_file(&file)?;
+        index.index_folder(&root)?;
+        assert!(index.search("Variatio", 10)?.is_empty());
+        Ok(())
+    }
     use super::*;
     #[test]
     fn persistence_updates_deletes_and_exact_priority() -> Result<()> {

crates/searchi-core/src/metrics.rs

@@ -0,0 +1,292 @@
+//! Monotonic request metrics. Stage names are static labels, never queries/paths.
+use serde::{Deserialize, Serialize};
+use std::{
+    collections::BTreeMap,
+    sync::atomic::{AtomicU64, Ordering},
+    time::Instant,
+};
+const MAX_SPANS: usize = 512;
+static COLLECTOR_ID: AtomicU64 = AtomicU64::new(1);
+
+#[derive(Debug, Clone, Serialize, Deserialize)]
+pub struct SearchResponse<T> {
+    pub results: Vec<T>,
+    pub metrics: SearchMetrics,
+}
+#[derive(Debug, Clone, Serialize, Deserialize)]
+pub struct SearchMetrics {
+    pub total_ms: f64,
+    pub result_count: usize,
+    pub trace: Option<Vec<SearchSpan>>,
+    #[serde(default)]
+    pub dropped_spans: u64,
+}
+#[derive(Debug, Clone, Serialize, Deserialize)]
+pub struct SearchSpan {
+    pub name: String,
+    pub start_ms: f64,
+    pub duration_ms: f64,
+    pub parent: Option<usize>,
+    pub counters: BTreeMap<String, u64>,
+}
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub enum MetricsMode {
+    Basic,
+    Debug,
+}
+#[derive(Debug, Clone, Copy)]
+pub struct SpanToken {
+    collector: u64,
+    index: usize,
+}
+impl SpanToken {
+    pub fn index(self) -> usize {
+        self.index
+    }
+}
+struct OpenSpan {
+    value: SearchSpan,
+    started: Instant,
+    ended: bool,
+}
+struct DebugTrace {
+    id: u64,
+    spans: Vec<OpenSpan>,
+    dropped: u64,
+}
+/// Basic mode stores only one Instant: no span Vec or stage/counter allocation.
+pub struct TraceCollector {
+    started: Instant,
+    debug: Option<DebugTrace>,
+}
+impl TraceCollector {
+    pub fn new(mode: MetricsMode) -> Self {
+        Self {
+            started: Instant::now(),
+            debug: match mode {
+                MetricsMode::Basic => None,
+                MetricsMode::Debug => Some(DebugTrace {
+                    id: COLLECTOR_ID.fetch_add(1, Ordering::Relaxed),
+                    spans: Vec::new(),
+                    dropped: 0,
+                }),
+            },
+        }
+    }
+    pub fn elapsed_ms(&self) -> f64 {
+        self.started.elapsed().as_secs_f64() * 1000.0
+    }
+    pub fn is_debug(&self) -> bool {
+        self.debug.is_some()
+    }
+    pub fn begin(&mut self, name: &'static str, parent: Option<SpanToken>) -> Option<SpanToken> {
+        let debug = self.debug.as_mut()?;
+        let parent_index = match parent {
+            Some(token)
+                if token.collector == debug.id
+                    && debug.spans.get(token.index).is_some_and(|span| !span.ended) =>
+            {
+                Some(token.index)
+            }
+            Some(_) => {
+                debug.dropped = debug.dropped.saturating_add(1);
+                return None;
+            }
+            None => None,
+        };
+        if debug.spans.len() >= MAX_SPANS {
+            debug.dropped = debug.dropped.saturating_add(1);
+            return None;
+        }
+        let started = Instant::now();
+        let index = debug.spans.len();
+        debug.spans.push(OpenSpan {
+            value: SearchSpan {
+                name: name.chars().take(96).collect(),
+                start_ms: started.duration_since(self.started).as_secs_f64() * 1000.0,
+                duration_ms: 0.0,
+                parent: parent_index,
+                counters: BTreeMap::new(),
+            },
+            started,
+            ended: false,
+        });
+        Some(SpanToken {
+            collector: debug.id,
+            index,
+        })
+    }
+    /// Invalid/previously ended tokens are harmless. Closing a parent also
+    /// closes open descendants at the same instant, preserving containment.
+    pub fn end(&mut self, token: Option<SpanToken>, counters: BTreeMap<String, u64>) {
+        let Some(token) = token else {
+            return;
+        };
+        let Some(debug) = self.debug.as_mut() else {
+            return;
+        };
+        if token.collector != debug.id
+            || token.index >= debug.spans.len()
+            || debug.spans[token.index].ended
+        {
+            return;
+        }
+        let now = Instant::now();
+        for index in token.index..debug.spans.len() {
+            let mut ancestor = Some(index);
+            let mut contained = false;
+            while let Some(current) = ancestor {
+                if current == token.index {
+                    contained = true;
+                    break;
+                }
+                ancestor = debug.spans[current].value.parent;
+            }
+            if contained && !debug.spans[index].ended {
+                let span = &mut debug.spans[index];
+                span.value.duration_ms = now.duration_since(span.started).as_secs_f64() * 1000.0;
+                span.ended = true;
+            }
+        }
+        // At most32 distinct bounded keys; callers should use static diagnostic
+        // names and counts, never source text or paths.
+        let stored = &mut debug.spans[token.index].value.counters;
+        for (key, value) in counters.into_iter().take(32) {
+            let key: String = key.chars().take(96).collect();
+            if stored.len() < 32 || stored.contains_key(&key) {
+                stored.insert(key, value);
+            }
+        }
+    }
+    pub fn counter(&mut self, token: Option<SpanToken>, name: &'static str, value: u64) {
+        let Some(token) = token else {
+            return;
+        };
+        let Some(debug) = self.debug.as_mut() else {
+            return;
+        };
+        if token.collector != debug.id {
+            return;
+        }
+        let Some(span) = debug.spans.get_mut(token.index) else {
+            return;
+        };
+        if span.value.counters.len() < 32 || span.value.counters.contains_key(name) {
+            span.value
+                .counters
+                .insert(name.chars().take(96).collect(), value);
+        }
+    }
+    /// Return the closure's value unchanged, including any Result error.
+    /// The closure receives its parent token for safe nested instrumentation.
+    pub fn timed<R>(
+        &mut self,
+        name: &'static str,
+        parent: Option<SpanToken>,
+        run: impl FnOnce(&mut Self, Option<SpanToken>) -> R,
+    ) -> R {
+        let token = self.begin(name, parent);
+        let value = run(self, token);
+        self.end(token, BTreeMap::new());
+        value
+    }
+    pub fn finish(mut self, result_count: usize) -> SearchMetrics {
+        let now = Instant::now();
+        if let Some(debug) = self.debug.as_mut() {
+            for span in &mut debug.spans {
+                if !span.ended {
+                    span.value.duration_ms =
+                        now.duration_since(span.started).as_secs_f64() * 1000.0;
+                    span.ended = true;
+                }
+            }
+        }
+        let (trace, dropped_spans) = match self.debug {
+            Some(debug) => (
+                Some(debug.spans.into_iter().map(|span| span.value).collect()),
+                debug.dropped,
+            ),
+            None => (None, 0),
+        };
+        SearchMetrics {
+            total_ms: now.duration_since(self.started).as_secs_f64() * 1000.0,
+            result_count,
+            trace,
+            dropped_spans,
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    #[test]
+    fn nesting_contains_children_and_preserves_error() {
+        let mut trace = TraceCollector::new(MetricsMode::Debug);
+        let result: Result<(), &str> = trace.timed("request", None, |trace, parent| {
+            trace.timed("index", parent, |trace, child| {
+                trace.counter(child, "rows", 7);
+                Err("failure")
+            })
+        });
+        assert_eq!(result, Err("failure"));
+        let metrics = trace.finish(0);
+        let spans = metrics.trace.unwrap();
+        assert_eq!(spans[1].parent, Some(0));
+        assert_eq!(spans[1].counters["rows"], 7);
+        assert!(spans[1].start_ms >= spans[0].start_ms);
+        assert!(
+            spans[1].start_ms + spans[1].duration_ms
+                <= spans[0].start_ms + spans[0].duration_ms + 1e-6
+        );
+        assert!(metrics.total_ms >= spans[0].start_ms + spans[0].duration_ms - 1e-6);
+    }
+    #[test]
+    fn basic_disables_stage_storage_and_preserves_counts() {
+        let mut trace = TraceCollector::new(MetricsMode::Basic);
+        assert!(!trace.is_debug());
+        assert!(trace.begin("unused", None).is_none());
+        assert_eq!(trace.timed("unused", None, |_, _| 42), 42);
+        let metrics = trace.finish(3);
+        assert_eq!(metrics.result_count, 3);
+        assert!(metrics.trace.is_none());
+        assert_eq!(metrics.dropped_spans, 0);
+    }
+    #[test]
+    fn trace_is_capped_and_reports_dropped_spans() {
+        let mut trace = TraceCollector::new(MetricsMode::Debug);
+        for index in 0..520 {
+            let token = trace.begin("stage", None);
+            if index == 0 {
+                trace.counter(token, "existing", 99);
+            }
+            let counters = if index == 0 {
+                (0..40).map(|key| (format!("counter_{key}"), key)).collect()
+            } else {
+                BTreeMap::new()
+            };
+            trace.end(token, counters);
+        }
+        let metrics = trace.finish(2);
+        let spans = metrics.trace.unwrap();
+        assert_eq!(spans.len(), 512);
+        assert_eq!(spans[0].counters.len(), 32);
+        assert_eq!(spans[0].counters["existing"], 99);
+        assert_eq!(metrics.dropped_spans, 8);
+    }
+    #[test]
+    fn foreign_tokens_and_early_parent_close_are_safe() {
+        let mut one = TraceCollector::new(MetricsMode::Debug);
+        let mut two = TraceCollector::new(MetricsMode::Debug);
+        let root = one.begin("root", None);
+        let child = one.begin("child", root);
+        assert!(two.begin("foreign", root).is_none());
+        one.end(root, BTreeMap::new());
+        one.end(child, BTreeMap::new());
+        let spans = one.finish(0).trace.unwrap();
+        assert!(
+            spans[1].start_ms + spans[1].duration_ms
+                <= spans[0].start_ms + spans[0].duration_ms + 1e-6
+        );
+    }
+}