cli(query): per-phase timings line in human-readable render

Surfaces where the per-call cost lands. The audit-line `7.5s`
already shows total_ms but it's hidden inline with the verdict
& cache_status. The new `timings:` line (after `capacity:`) breaks
total wall-clock into its components so an operator can see at a
glance whether a slow query was Hermes-bound, search-bound, or
something else.

Format:

    timings: cache 0.00s · search 0.30s · context 0.16s ·
             llm 6.50s · persist 0.20s · **total 7.16s**

Skipped phases (cache=0 on cache-miss; persist=0 on cache-hit;
context=0 when retrieval pre-loaded) are filtered so the line
stays compact. **total** stays bold to match the audit-line
elapsed value already on screen.

JSON mode (`--json`) already exposes `timings` — this just lifts
the same data into the human render.

Tests pass (641 / -n auto / 11s).
This commit is contained in:
russell@unturf.com 2026-05-02 11:49:36 -04:00
parent 780f5afd69
commit 0177c2d278
No known key found for this signature in database

View file

@ -794,6 +794,32 @@ def _render_query_human(result: dict, question: str) -> str:
f"answer {result.get('answer_chars', 0):,} chars"
)
# Per-phase timings — surfaces where the per-call cost lands.
# Hermes-bound queries should show `llm_ms` dominating; if
# search_ms or persist_ms creeps up that's a retrieval / WAL
# signal the operator wants visible. Cache-hit rows skip llm
# entirely so the breakdown also tells you which path you're
# paying for.
timings = result.get("timings") or {}
if timings:
parts: list[str] = []
order = (
("cache_lookup_ms", "cache"),
("search_ms", "search"),
("context_ms", "context"),
("llm_ms", "llm"),
("persist_ms", "persist"),
)
for key, label in order:
v = timings.get(key)
if isinstance(v, (int, float)) and v > 0:
parts.append(f"{label} {v / 1000:.2f}s")
total = timings.get("total_ms")
if isinstance(total, (int, float)):
parts.append(f"**total {total / 1000:.2f}s**")
if parts:
lines.append("timings: " + " · ".join(parts))
# Reference-frame notes (Ticket #000002). When detect_frame
# classified the query as `reference`, surface the named work
# so an operator knows the substrate routed to a fictional