Log per-arm timings for every hybrid fusion

[samuelvkwong]

What

One INFO line per hybrid fusion, attributing the cost to its arms:

hybrid fusion timings: caller=Hybrid search query=2cb18c39 degraded=False
  fts_ms=12371 fts_rows=10000 embed_ms=858 vec_ms=290 vec_rows=734
  fuse_ms=20 fused=10707 total_ms=13306

• fts_ms — the FTS arm: rank every match, sort, keep the window
• embed_ms — the query embedding (gateway call, or ~0 on its cache) — separated from the scan so gateway load and ranking cost can never be confused
• vec_ms / vec_rows — one HNSW beam pass and what it emitted
• fuse_ms — the in-process RRF
• query — a short hash, never the search text: queries can contain patient identifiers, so the log correlates repeats without recording what was searched
• degraded=True — the embedding service failed and this result is FTS-only

Why

"Search is slow" had two competing explanations in the team — the ranking pipeline vs. embedding-gateway contention — and no way to attribute a given slow search to either. With this line, production logs answer it per search. Measured on staging (1.7M reports), the attribution is unambiguous and stable across configurations:

configuration	fts_ms for "Fraktur" (414,572 matches)	every other arm
full hybrid	12,087–13,436	embed ≤1,232 · vec ≤290 · fuse ≤22
semantic arm disabled (EMBEDDINGS_MODEL=)	11,828–13,421	all ~0
FTS window removed (2024 retrieval shape)	12,371–13,075	fuse grows to ~600–750 over 414k ids

A rare term ("Krebs", 26 matches) runs the identical code in 62–150 ms. The FTS ranking cost is invariant across every configuration and tracks only the match count — the motivating evidence for the BM25 work (#285).

Test plan

New test asserts the line is emitted with all arm fields and that the query text never appears in it. Full radis/pgsearch + radis/search suites: 240 passed; lint clean. Running on staging now — any UI search logs the line (docker service logs radis_staging_web | grep "hybrid fusion"). Independent of the other open search PRs: based directly on main; the vec_rows values in the staging evidence above were measured with #282's ef_search fix deployed (without it, the beam emits ~51 candidates — the bug that PR fixes — while fts_ms is unaffected).

🤖 Generated with Claude Code

https://claude.ai/code/session_01VDei6anDxfR5eoHhFfXBGs

[coderabbitai]

Important

Review skipped

Auto reviews are disabled on base/target branches other than the default branch.

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro Plus

Run ID: 5f866110-933c-4a7d-ae19-49a9a80e13b0

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

Use the checkbox below for a quick retry:

• 🔍 Trigger review

---

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

• X
• Mastodon
• Reddit
• LinkedIn

_{Comment @coderabbitai help to get the list of available commands.}