Files
searchi/docs/PERFORMANCE.md
T

12 KiB

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

Automatic filesystem refreshes start a new frontend measurement at the refresh event. trigger: "filesystem_refresh" distinguishes them from user searches; SHOWN and latest_displayed_ms exclude time spent idle before that event. original_input retains a fixed-size snapshot of the original debounce and display timings. Refreshes do not replay previous attempts or append ancestor traces. A refresh before the first response leaves that original response timing null rather than inventing a first-input measurement.

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

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 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.

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.

Prepared-reader publication

The desktop shares a bounded process-local prepared ANN between indexing and its retained query service. The graph is registered before SQL activation and matched by canonical database, dimensions, generation, policy and checksum. semantic.prepared_graph_lookup measures that handoff; a successful handoff sets semantic.ann_load cache_hit to one, without blob read/checksum/deserialization. The query model and real-vector LRU remain warm. Eligibility refresh and query inference still have costs and are measured independently.

The actual CPU regression checks both a repeated cached query and an unseen query after publication; the unseen input must record query_cache_hit zero. See RECOVERY-AND-HANDOFF.md. Its single-document request times do not establish representative-corpus p95, native first input or foreground priority during indexing.

Shared inference admission

The desktop now shares one CPU thread budget across its persistent query and indexing workers. The default is two threads, clamped to available logical CPUs and a maximum of eight. Indexing uses one thread; the query worker uses the remaining threads (at least one). Pending searches have priority over new background encodes, and document indexing yields between individual encodes. Cached query vectors do not acquire an inference permit.

Settings version two stores the total budget. Version-one settings counted threads per worker; migration adds one background thread, capped at eight. An explicit version-two budget of one remains one. Resource changes are rejected during active semantic work; a failed settings save preserves the warm session.

Debug traces record semantic.inference.admission_wait separately from native inference. Admission waits are bounded at 30 seconds. Already executing native inference cannot be preempted: a one-thread budget or single-core machine can still delay a search during a long media encode. This budget covers admitted inference worker threads, not extraction, decoding, ANN construction, rendering or total operating-system CPU usage.

The real Google CPU regression budget_google_cpu confirmed overlapping query and background inference with a two-thread budget: one query thread, one indexing thread, six background document calls, an unseen query taking 103.407 ms including 0.034 ms admission in the final scoped-cleanup run. These are Windows VM debug measurements on a small fixture, not representative-corpus p95, native UI latency, GPU or scale evidence.