searchi/docs/PERFORMANCE.md

Search performance diagnostics

Search performance must distinguish total request latency from the work inside it. The shared Rust schema exposes basic metrics for routine searches and a bounded nested trace for deliberate debugging. It uses monotonic Instant timing, not wall-clock timestamps. No query text, source passages or file paths belong in stage names/counters.

Shared response

SearchResponse<T> contains results: Vec<T> and metrics: SearchMetrics.

Field	Meaning
total_ms	Elapsed time inside the collector's measured request boundary
result_count	Number of final returned results
trace	null in basic mode; debug spans in begin order
dropped_spans	Spans omitted when the 512-span ceiling or invalid parent is encountered

A SearchSpan has a static name, relative start_ms, duration_ms, optional parent index and integer counters. Parent indices reference earlier spans in the same trace; child timings lie within their parent. Nested durations overlap, so summing every span would double-count work. Counters are capped at 32 keys per span, with 96-character labels. Missing spans due to the cap are visible through dropped_spans, never presented as complete instrumentation.

Basic mode retains only the request start Instant and result count; there is no per-stage span Vec or diagnostic string allocation. Debug mode captures up to 512 spans. Scope timings preserve normal closure return values and errors. Already-ended or foreign tokens are harmless, and unfinished scopes close at collector finish. Closing a parent closes its open descendants for containment.

Instrumenting the shared engine

use searchi_core::metrics::{MetricsMode, TraceCollector};
let mut trace = TraceCollector::new(MetricsMode::Debug);
let results = trace.timed("search", None, |trace, parent| {
    trace.timed("candidate_selection", parent, |trace, token| {
        trace.counter(token, "candidate_count", candidates.len() as u64);
        retrieve_candidates(candidates)
    })
});
let metrics = trace.finish(results.len());

This is an API illustration, not a measured benchmark. begin(name,parent) / end(token,counters) supports explicit scopes spanning locks or separate calls; SpanToken is Copy and exposes its index. counter records bounded integer counts without source data. elapsed_ms reports elapsed request time. Capture queue/lock boundaries in the caller, then pass that same collector into the shared core/service so stages refer to one origin.

Useful actual boundaries include request admission/reader lock, filter snapshot, filename/FTS retrieval, tokenizer/query inference, active ANN load, eligibility refresh, filtered HNSW traversal, per-file deduplication, ranking/fusion and result assembly. Name only work that is truly measured. Do not label the whole worker round trip as pure neural execution or fabricate stage splits from a single elapsed number. Model load/warmup and initial eligibility work should be reported separately from a retained worker's first foreground and warm queries.

CLI and desktop integration

The CLI exposes these actual modes:

searchi search --db searchi.sqlite contract --json
searchi search --db searchi.sqlite contract --performance --json
searchi search --db searchi.sqlite contract --debug-performance --json

Plain --json preserves the legacy result array. --performance --json emits SearchResponse with basic metrics; --debug-performance --json emits the same envelope with detailed spans. Normal terminal output prints results and reports elapsed time/count on stderr, including CLI index/session initialization. Debug terminal mode also prints the detailed metrics on stderr. Legacy Vec interfaces remain wrappers for compatibility. The desktop should use a compact ordinary summary and an optional diagnostic view, without confusing score/similarity with elapsed time or confidence.

Both measured GUI commands start the native clock at command entry, include instrumented queue/lock waits, and finish before response serialization. UI timing separately captures input/debounce, lane/retry waits, invoke/round trip and synchronous DOM updates. Display latency ends at the DOM update; actual compositor paint and deferred media preview loading are not measured. Their overlapping boundaries must not be summed. Native metrics exclude frontend delays and post-return paint. A fast Rust request does not prove a responsive first foreground interaction. Conversely, pending setup or model loading must not be silently included in a warm-query claim.

Reproducible performance validation

Record build profile, CPU/device and thread budget, VM/host resources, corpus and active generation, filters, cold/warm state, concurrent indexing and setup costs. Use multiple queries and p50/p95 distributions; retain raw reports. Compare basic and debug mode on the same corpus to quantify instrumentation overhead. Debug traces guide investigation but are not a substitute for representative benchmarks.

Current recorded filename, actual Google seed and synthetic ANN evidence is in VALIDATION and SEMANTIC. Media quality/timing is in MEDIA-QUALITY. Synthetic vectors measure index behavior only; real Google inference remains required for product semantic search. Platform, large-corpus, concurrent-indexing and GPU performance gates remain independent.

Worker round-trip diagnostics

Measured desktop failures return {message, metrics} and retain the trace for the failed attempt. Busy retries are separate attempts. If an unexpected worker task failure loses its collector, elapsed time is retained, the trace is null, and a dropped-span marker makes the missing detail explicit. Error messages are excluded from the exported timing report.

Embedding IPC spans expose named *_us integer counters for request encoding, writing, worker wait/response decode, validation, and native tokenization, batch preparation, inference and pooling/normalization when genuinely reported. They also expose worker_token_count and the GPU-to-CPU restart count. Microsecond counters are durations, not occurrence counts; their suffix records units.

The native worker clock is not aligned with Rust's collector origin. Native stage values remain counters on the IPC span rather than invented positioned child spans. Worker wait includes response-reader JSON parsing and scheduling; it is not pure inference time. The encompassing round trip and its component counters overlap. A fallback/restart may include setup outside the last worker's reported neural pass; retain that distinction when diagnosing slow requests.

Small instrumentation-overhead diagnostic

The deterministic example creates 1,000 local text files, builds/prewarms SQLite, then alternates basic/debug order over 24 exact filename queries and 20 repeats. Both modes must retrieve the correct file. It records 480 samples per mode, outer-call p50/p95/mean and actual debug span counts, excluding fixture setup and JSON serialization. It runs no model, media decoder or network.

cargo run --release -p searchi-core --example trace_overhead -- .searchi/trace-overhead.json

This tiny warm lexical corpus measures diagnostic overhead under the current VM conditions. It does not certify production search latency or model-query tracing overhead. Keep the raw report and profile/device/concurrency caveats; repeat on representative corpora and compare instrumentation policies before claiming low overhead across every retrieval mode.

Windows CPU release diagnostic, 2026-10-12 (480 samples per mode):

Mode	Mean	p50	p95
Basic	0.556 ms	0.440 ms	0.934 ms
Detailed	0.968 ms	0.819 ms	1.615 ms

The detailed searches retained 14 spans each. These measurements include the search itself and metrics assembly, and exclude fixture setup and JSON encoding. Other work in the VM could contend for CPU. Raw samples and measurement scope. The recorded Windows x86-64 release run retained 480 raw samples per mode and 14 actual debug spans per request:

Mode	Mean	p50	p95
Basic	0.556 ms	0.440 ms	0.934 ms
Debug	0.968 ms	0.819 ms	1.615 ms

Raw samples and measurement contract include the active VM-contention caveat: native photo inference and other work may overlap. This is an absolute small-corpus comparison, not an old-baseline regression claim or proof of model/media tracing overhead. The extra cost supports keeping detailed mode optional rather than claiming it is free.