From 7a2aff7bc12eecfb0f0460289d96a04a7aadcc55 Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Tue, 8 Sep 2026 11:07:21 -0400 Subject: [PATCH] fix(telemetry): a surface that stopped recording is not one that never ran (#3720) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `out["sources"]` was built only from the windowed aggregate, so a source with rows in `retrieval_logs` but none inside the window got no bucket at all. Absent is exactly how a source that never existed renders, so a surface that WAS recording and went silent became unreadable — #2663 one level up, the failure that looks like the correct answer. Two queries at different scopes, and only one shaped the output. `_complete_from` reads all-time and knows every source the table has ever held; the windowed loop dropped whatever it did not return. Every such source now gets a zero bucket. Zero is a real measurement here rather than a manufactured one: the all-time query proves the source was recording, and it made no calls across a window it fully covers. No `covers_window` special case is needed either — a source whose first row fell after `since` would have that row IN the window and already hold a bucket, so anything reaching this branch began before it. The counts are 0 and everything else is null. A sampled distribution is not the same claim as a call count, and rendering p50 as 0.0 for a source nobody sampled would assert a measurement — #3311's mistake, in the readout built to prevent it. Found while fixing #3712's fixture, which failed with KeyError for this exact reason. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ --- src/scribe/mcp/tools/search.py | 7 +++ src/scribe/services/retrieval_telemetry.py | 28 +++++++++++ tests/test_services_retrieval_telemetry.py | 56 ++++++++++++++++++++++ 3 files changed, 91 insertions(+) diff --git a/src/scribe/mcp/tools/search.py b/src/scribe/mcp/tools/search.py index f84ce78..e31ab17 100644 --- a/src/scribe/mcp/tools/search.py +++ b/src/scribe/mcp/tools/search.py @@ -262,6 +262,13 @@ It is an UPPER BOUND per surface: a pull records the door it came "no measurement" is not "partial measurement", the same distinction `suppression`'s null carries a few paragraphs up. + A SOURCE SHOWING `calls: 0` WAS RECORDING AND MADE NO CALLS. `sources` + lists every source the table has ever held, not only those active in the + window, so a surface that stopped firing stays visible rather than + disappearing — being absent is reserved for a source that has never + recorded at all. Its score fields are null, not zero: the calls are a + real observation, the distribution is not one. + `rule_usage_failed: true` means that read failed while the rest of the readout stood. The counts are still present so a caller can render, but they are zeros meaning "could not find out", not "nothing happened" — do diff --git a/src/scribe/services/retrieval_telemetry.py b/src/scribe/services/retrieval_telemetry.py index 2a75c26..fe5908d 100644 --- a/src/scribe/services/retrieval_telemetry.py +++ b/src/scribe/services/retrieval_telemetry.py @@ -213,6 +213,15 @@ def _bucket(rows: list) -> dict: } +# The aggregate row Postgres would have returned for a source with no rows in +# the window: nothing counted, nothing scored. Positional, matching the SELECT +# `_bucket` unpacks — calls, zero, cleared, p10, p50, p90, min, max, avg_n, +# dur, measured, supp_calls, supp_zero. The three counts are 0 because zero +# calls is a real observation; everything else is None because a distribution +# nobody sampled has no value, and rendering it as 0.0 would state one. +_NO_ROWS_IN_WINDOW = [0, 0, 0, None, None, None, None, None, None, None, 0, 0, 0] + + def _round(v, places: int = 4): return None if v is None else round(float(v), places) @@ -375,6 +384,25 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict: bucket.update(_coverage(log_complete.get(source), since)) out["sources"][source] = bucket + # A source with rows in the table but NONE in this window would + # otherwise be absent from the readout — and absent is exactly how + # a source that never existed renders, so a surface that WAS + # recording and went silent is unreadable (#3720). That is #2663 + # one level up: the failure that looks like the correct answer. + # + # Zero here is a real measurement, not a manufactured one. The + # all-time query proves the source was recording, and it made no + # calls across a window it fully covers — which is why no + # `covers_window` special case is needed: a source whose first row + # fell after `since` would have that row IN the window and already + # hold a bucket, so anything reaching here began before it. + for src, first_row in log_complete.items(): + if src == "*" or first_row is None or src in out["sources"]: + continue + quiet = _bucket(list(_NO_ROWS_IN_WINDOW)) + quiet.update(_coverage(first_row, since)) + out["sources"][src] = quiet + # The corpus side, at its own grain. `ambient` mirrors # note_usage.usage_for_notes: an ambient surfacing was not a scored # CHOICE, so folding it into pull-through would understate it. diff --git a/tests/test_services_retrieval_telemetry.py b/tests/test_services_retrieval_telemetry.py index 8605e39..c0eca30 100644 --- a/tests/test_services_retrieval_telemetry.py +++ b/tests/test_services_retrieval_telemetry.py @@ -740,6 +740,62 @@ async def test_coverage_is_per_source_because_the_table_is_older_than_its_arms( await s.commit() +@pytest.mark.integration +@pytest.mark.asyncio +async def test_a_surface_that_went_silent_is_not_the_same_as_one_that_never_ran( + _dispose_engine, +): + """#3720 — absent is how "never existed" renders, so it cannot also be how + "stopped recording" renders. + + A surface losing its recorder is one of the failures this milestone exists + to make visible, and dropping it from the readout is the most complete way + to hide it. Zero here is a real measurement: the table proves the source + was recording, and it made no calls across a window it fully covers. + """ + from datetime import datetime, timedelta, timezone + + from sqlalchemy import delete + + from scribe.models import async_session + from scribe.models.retrieval_log import RetrievalLog + from scribe.services.retrieval_telemetry import retrieval_summary + + UID = 990078 + now = datetime.now(timezone.utc) + async with async_session() as s: + # Recorded once, well before the window, and never since. + s.add(RetrievalLog( + user_id=UID, source="auto_inject", result_count=3, top_score=0.81, + created_at=now - timedelta(days=60), + )) + await s.commit() + + try: + out = await retrieval_summary(UID, days=7) + + assert "auto_inject" in out["sources"], ( + "a source with rows in the table but none in the window was " + "dropped from the readout — a surface that stopped recording now " + "reads exactly like one that never existed" + ) + quiet = out["sources"]["auto_inject"] + assert quiet["calls"] == 0 + # The window IS covered; what was observed across it is nothing. + assert quiet["covers_window"] is True + # ...but nothing was sampled, so no distribution may be claimed. A + # zeroed score would assert a measurement, which is #3311's mistake. + assert quiet["top_score"] == { + "p10": None, "p50": None, "p90": None, "min": None, "max": None, + } + assert quiet["suppression"] is None + assert quiet["avg_result_count"] is None + finally: + async with async_session() as s: + await s.execute(delete(RetrievalLog).where(RetrievalLog.user_id == UID)) + await s.commit() + + @pytest.mark.integration @pytest.mark.asyncio async def test_a_section_is_complete_only_from_its_latest_contributor(