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

```rust
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:

```sh
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](VALIDATION.md) and [SEMANTIC](SEMANTIC.md). Media quality/timing is in
[MEDIA-QUALITY](MEDIA-QUALITY.md). 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

The retained hybrid service now keeps a bounded 32-query vector LRU. Debug
`semantic.query_embedding` spans report `query_cache_hit` and `query_cache_miss`.
A hit reuses an actual model vector and performs no neural inference; it must
not carry the previous worker's tokenization/inference counters. Filters, current
source eligibility, ANN retrieval and fusion still execute. Warmup performs an
actual neural probe and does not seed an unseen foreground-query result.
Compare fresh queries, repeats and filter changes separately. The current
[EmbeddingGemma 2 audit](EMBEDDINGGEMMA2-AUDIT.md) includes paired real-CPU
measurements, startup boundaries and remaining indexing/media costs.

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.

```powershell
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](evidence/windows-cpu-trace-overhead.json).
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](evidence/windows-cpu-trace-overhead.json)
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.