⚡ PERF: instrument search latency and add a 4s progressive offline fallback

[Asim-2000]

What this does

Instruments the whole search path first, then fixes what the measurements pointed at, then adds the 4-second progressive offline fallback on top.

Full report: https://claude.ai/code/artifact/ebb324eb-f0e1-4b85-af55-17d306c915ea

Root cause — Gemini was not the bottleneck, its transport was

Provider calls went through urllib.request.urlopen on a worker thread, so every model call opened a fresh DNS + TCP + TLS connection. Over 25 sequential calls the median was 501 ms but two calls took 20.4 s and 23.5 s — roughly 8% of searches blowing past any 4-second budget at random, with no retry involved. The same 25 calls over a pooled httpx client maxed out at 856 ms.

Two further costs, both previously invisible because totalLatencyMs started inside the service, after FastAPI had already resolved dependencies:

• OpenEntity warm-up takes 2.2–4.0 s (11,269 entities). A request landing in that window waits for it. A cold request measured 2,835 ms at the client while the backend reported 1,024 ms.
• NullPool opened a new MySQL connection per request: 178 ms each, versus 30 ms from a pool.

Ruled out by measurement: network (~35 ms warm), serialization (0.2 ms), entity resolution (p50 27 ms), SearchPlan build (0.0 ms).

Backend

• New app/observability/: request-scoped phase timings, contextvar request identity, JSON log formatter, and middleware that measures the whole request starting before dependency resolution — so DB connect and index warm-up can no longer hide outside the reported total.
• Pooled process-wide httpx.AsyncClient replaces per-call urllib, with separate connect and read timeouts so a stalled connect fails fast.
• Real SQLAlchemy pool with pool_pre_ping and pool_recycle, replacing NullPool.
• Gemini API key moves from the URL query string to the x-goog-api-key header, so URL logging on any hop cannot capture it.
• App loggers lifted above uvicorn's default config — which is why the warm-up cost never reached production logs.
• Query-understanding service is memoised instead of rebuilt on every request.

Timing records carry a request id, durations and small flags only. Query text, transcripts and credentials are stripped by an explicit deny-list.

Flutter

• One authoritative LatencyPolicy. The HTTP client's timeouts derive from it, so client and coordinator cannot disagree.
• SearchLatencyCoordinator implements the progressive fallback as a cancellation-aware event stream.
• Deletes OfflineSearchRouter. It had a full 4-second budget implementation and passing unit tests, but the search screen never called it — the shipped behaviour was only "offline → local" and "backend error → local". Consolidating it leaves exactly one 4-second rule.
• Connectivity is probed once per search rather than twice, and the previous search's subscription is cancelled without awaiting it, so a new query no longer queues behind the old one's teardown.

Runtime policy

When	Behaviour
Known offline	Local snapshot answers immediately; no online request is issued
Online / unknown	Online starts at once, safe local answer prepared in parallel, 4,000 ms budget
Online < 4 s	Online result shown — it wins even if local was ready first
Budget elapsed, local available	Local shown as offline_fallback; online keeps running, never cancelled
Budget elapsed, no safe local answer	Nothing fabricated; waits for online under the normal 35 s timeout
Online lands late	Offered as "HQ has fresh results — Show latest", never applied on its own
Online fails late	Local stays exactly where it is; only the label changes

Two bugs found while testing

• A late response carrying an error was being offered as "HQ has fresh results".
• Cancelling a search left a timer alive past dispose.

Both fixed.

Results

Steady state after the changes: p50 1,106 ms, p95 1,999 ms, max 2,401 ms, 0/25 over 4 s. Cold start remains the one case that breaches the budget — which is what the fallback exists for.

Suite	Result
Backend tests/unit + tests/parity	227 passed (11 new instrumentation tests)
Flutter latency suite	27 passed — covers all 15 requested scenarios
Offline benchmark	wrong_confident = 0, coverage 88.9%, execution parity 16/16
Full Flutter suite	470 passed, 4 failed
flutter analyze	clean in every changed file

The 4 Flutter failures are pre-existing live-Gemini eval tests in test/eval/ that assert on model output wording. None imports a changed module, and they fail identically on main.

Reviewer notes

• Not implemented on purpose: the deterministic fast path (skipping Gemini for high-confidence queries). The offline parser covers 88.9% at zero wrong-confident, but it is Dart resolving against a SQLite snapshot while the backend is Python resolving against the authoritative MySQL index. Reusing it online means porting it or trusting a client-built SearchQuery, and the latter breaks the rule that identity resolution belongs to the backend. Its confidence is calibrated against a snapshot, not the live index. Worth doing as its own project with its own benchmark gate — the instrumentation already emits query_understanding_source, so the skip rate is measurable the day it lands.
• Follow-up needed: Railway cold start is the last thing that reliably exceeds 4 s. Cheapest first — keep one instance warm, gate traffic on /ready, or persist the built index. The 3.6 s spent fetching 11,269 rows also suggests the warm-up query itself is worth a look.
• Verify under load: pool is 5 + 5 overflow per worker. Confirm workers × (pool_size + max_overflow) × replicas stays under MySQL's max_connections.
• test/latency/progressive_fallback_screen_test.dart existed but had never compiled green — it completed the parser on raw text while the service normalizes first ("rallies in ireland" → "rallies in Ireland"). Fixed the harness, not the assertions.
• Adds clock as a direct dependency so latency is measured through a zone-overridable clock — real durations in production, fake-clock durations under widget tests.

🤖 Generated with Claude Code