fix(telemetry): silence is only an answer where the ledger was watching (#4268)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / TypeScript typecheck (push) Successful in 55s
CI & Build / integration (push) Successful in 59s
CI & Build / Python tests (push) Successful in 1m44s
CI & Build / Build & push image (push) Successful in 31s

`band_hugs_floor` compares an arm's weakest tenth against its floor, and
#4225 made it SUSPEND rather than soften when the floor moved inside the
window — because across a change the scores and the bar come from two
different populations. It reads `floor_moves_since`, which answers "did
this arm's floor move", and it read an empty answer as "no, it held
steady".

Those are the same answer only where the ledger was watching. Before an
arm's first floor row there is nothing to move, nothing to report, and no
way to tell a steady floor from an unrecorded one. The suspension was
reading absence of evidence as evidence of absence, and the symptom is the
one #4225 documented: a band "-0.0208 above its floor" — an impossible
negative distance, printed with the suspension silent.

Every install passes through this. The ledger's first row for an arm is
written when that install first boots the release that records baselines,
so any window longer than the install is old reaches back past it. The
lowered-floor direction hides: the gap comes out comfortably positive and
reads as a clean bill of health.

`floor_history_gaps(since)` answers the question its companion cannot:
which arms' floor history does not REACH the start of the window. Arms
come from `surface_names()`, not from the ledger — an arm the ledger has
never heard of is exactly the one at risk, so it cannot be the ledger that
decides which arms get asked about.

Baselines count here, which is the one place the two deliberately
disagree. A baseline records a default without changing it, so it is not a
move and `floor_moves_since` filters it out. It IS the ledger beginning to
observe the arm, and from that moment silence genuinely means the floor
held — filtering it out here would suspend the band check forever on every
install that has never tuned.

`floor_history_unknown` sits between the known move and the band, so an
arm with a date to give gives it. Two sentences, because the remedies
differ: a date says ask again with a smaller `days`; no history at all
says there is nothing to wait for, and names what starts the record.

Why now: #4261 measures the work-log change by reading these warnings, and
every window for the next month opens before this ledger's first row.
Measuring against an instrument that prints a number it cannot support is
the #4225 trap one level up.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01821k5B3Ysecp9fNYs92Kuy
This commit is contained in:
2026-09-21 14:38:16 -04:00
co-authored by Claude Opus 5
parent a58a225d7b
commit 42360f616c
4 changed files with 367 additions and 6 deletions
+58 -3
View File
@@ -40,7 +40,7 @@ from scribe.services.retrieval_registry import (
POINTS, UNBIDDEN, get_point, is_registered, sources_expected_to_emit,
)
from scribe.services.retrieval_surfaces import SURFACES, floor_for
from scribe.services.retrieval_tuning import floor_moves_since
from scribe.services.retrieval_tuning import floor_history_gaps, floor_moves_since
from scribe.services.settings import get_setting
logger = logging.getLogger(__name__)
@@ -500,7 +500,8 @@ def _warn(code, detail, source=None, **numbers) -> dict:
def _compute_warnings(sources: dict, usage: dict, rule_usage: dict,
floors: dict, min_calls: int, epsilon: float,
floor_moves: dict | None = None) -> list[dict]:
floor_moves: dict | None = None,
floor_gaps: dict | None = None) -> list[dict]:
"""The four checks, over whatever sources the window actually contains.
DELIBERATELY NOT KEYED ON A HARD-CODED SOURCE LIST. An arm added next
@@ -634,6 +635,7 @@ def _compute_warnings(sources: dict, usage: dict, rule_usage: dict,
floor = floors.get(name)
p10 = (b.get("top_score") or {}).get("p10")
moved = (floor_moves or {}).get(name)
gaps = floor_gaps or {}
if calls >= min_calls and floor is not None and p10 is not None:
# ── The floor moved inside the window ────────────────────────
#
@@ -666,6 +668,48 @@ def _compute_warnings(sources: dict, usage: dict, rule_usage: dict,
f"`days` that starts after it, or wait.",
source=name, floor=floor, p10=p10, moved_at=moved,
))
# ── The ledger does not reach back this far ──────────────────
#
# The same suspension, for the case the one above cannot see. The
# check overhead asks `floor_moves_since` whether this arm's floor
# moved, and reads an empty answer as "it held steady". That
# reading is only sound where the ledger was WATCHING; before its
# first row for this arm, "no move recorded" and "no move" are
# different statements, and the first was standing in for the
# second.
#
# Not theoretical, and not a one-off: every install passes
# through it. A window longer than the install is old reaches back
# past the ledger's first row, and the symptom is the same
# impossible negative the comment above describes — printed with
# the suspension silent, because there was nothing on record for
# it to notice.
#
# Deliberately ordered after the known move: when both apply, the
# arm that has a date to give should give it.
elif name in gaps:
known_from = gaps[name]
out.append(_warn(
"floor_history_unknown",
(
f"this arm's floor has been recorded since "
f"{known_from}, which is after this window opens, so "
f"whether it moved earlier in the window is not known "
f"— and an unrecorded move is exactly what makes a "
f"band reading meaningless. The band check is "
f"suspended for this arm until the window starts at "
f"or after that date: ask again with a smaller `days`, "
f"or wait."
if known_from else
f"this arm has no floor history at all, so there is "
f"nothing to say whether its floor of {floor} is the "
f"one its calls were made under. The band check is "
f"suspended for this arm until a floor is recorded for "
f"it — moving it once with `tune_retrieval`, or the "
f"next release baseline, starts the record."
),
source=name, floor=floor, p10=p10, known_from=known_from,
))
elif p10 - floor < epsilon:
gap = p10 - floor
out.append(_warn(
@@ -1445,9 +1489,20 @@ async def retrieval_summary(
except Exception: # pragma: no cover - telemetry never raises
logger.warning("could not read floor changes", exc_info=True)
# And the arms whose floor history does not REACH the start of the window.
# `floor_moves` answers "did it move"; for a window that opens before this
# arm's first ledger row, that answer is unavailable rather than no — and
# the band check was reading the two as the same. Read the same way and for
# the same reason: the ledger belongs to the install, not to an account.
floor_gaps: dict[str, str | None] = {}
try:
floor_gaps = await floor_history_gaps(since)
except Exception: # pragma: no cover - telemetry never raises
logger.warning("could not read floor history coverage", exc_info=True)
out["warnings"] = _compute_warnings(
out["sources"], usage, rule_usage, floors, min_calls, epsilon,
floor_moves,
floor_moves, floor_gaps,
)
# "Active" means this window saw real traffic SOMEWHERE. Without that
+51 -1
View File
@@ -43,7 +43,7 @@ from __future__ import annotations
import logging
from sqlalchemy import or_, select
from sqlalchemy import func, or_, select
from scribe.models import async_session
from scribe.models.retrieval_tuning import RetrievalTuningEvent
@@ -420,6 +420,56 @@ async def floor_moves_since(since) -> dict[str, str]:
return out
async def floor_history_gaps(since) -> dict[str, str | None]:
"""Surfaces whose floor history does NOT cover a window starting at `since`.
The companion `floor_moves_since` needs, and the hole #4225's fix left.
That function answers "did this arm's floor move inside the window", and an
empty answer was being read as "no, it held steady". Those are the same
answer only while the LEDGER covers the window. Before the ledger existed
there are no rows for any arm, so every arm reported "no move" for a period
nobody had recorded — absence of evidence arriving as evidence of absence.
It is not hypothetical, and it is not a one-off: every install passes
through it. The ledger's first row for an arm is written when that install
first boots the release that records baselines, so for a window longer
than the install is old — or than the arm is old, for an arm added
later — there is no history to consult, and the band check was reading
that silence as a clean bill of health.
Returns ONLY the arms with a gap, mapped to the ISO timestamp from which
their floor IS knowable — or None when the arm has no floor history at all.
An arm absent from the result is fully covered and can be judged. Shaped
that way so a caller loops over what it is already judging and asks one
question per arm, rather than reasoning about the ledger itself.
Every row counts here, baselines included, which is the one place
`floor_moves_since` and this deliberately disagree. A baseline is not a
change — so it is not a move — but it IS the ledger observing the arm, and
from that moment on silence genuinely means the floor held.
"""
out: dict[str, str | None] = {}
async with async_session() as session:
rows = (
await session.execute(
select(
RetrievalTuningEvent.surface,
func.min(RetrievalTuningEvent.created_at),
)
.where(RetrievalTuningEvent.dial == "floor")
.group_by(RetrievalTuningEvent.surface)
)
).all()
earliest = {surface: first for surface, first in rows}
for name in surface_names():
first = earliest.get(name)
if first is None:
out[name] = None
elif first > since:
out[name] = first.isoformat()
return out
async def tuning_history(
user_id: int, *, surface: str | None = None, limit: int = 20
) -> list[dict]:
+132
View File
@@ -340,3 +340,135 @@ async def test_a_baseline_is_not_reported_as_a_floor_move():
stmt = str(session.execute.call_args.args[0])
assert "old_value IS NOT NULL" in stmt
assert "dial" in stmt
# ── floor_history_gaps: "no move recorded" is not "no move" ───────────────
#
# THE HOLE ITS COMPANION LEFT. `floor_moves_since` answers "did this arm's
# floor move inside the window", and the band check read an empty answer as
# "no, it held steady". Those are the same answer only where the ledger was
# WATCHING. Before an arm's first row there is nothing to move, nothing to
# report, and no way to tell a steady floor from an unrecorded change.
#
# Measured the day the ledger was seeded on this instance: its earliest event
# of any kind is 2026-09-17, its `write_path_rule` floor rows begin at
# 2026-09-21, and a 30-day window opening 2026-08-22 reported that arm's band
# sitting "-0.0208 above" its floor. That negative distance is the documented
# tell of a raise inside the window — announced by the check the suspension
# was built to stop, because the suspension had nothing to read.
def _gap_rows(rows):
"""Patch `async_session` so the reader sees `rows` as the whole ledger.
`rows` maps surface -> the datetime of its earliest floor event. A surface
left out has no floor history at all, which is the harder of the two
cases: absent from the ledger AND present in the registry.
"""
session = make_mock_session()
result = MagicMock()
result.all.return_value = list(rows.items())
session.execute = AsyncMock(return_value=result)
return session
@pytest.mark.asyncio
async def test_an_arm_recorded_before_the_window_opens_has_no_gap():
"""The ordinary case, and the one that must stay silent: a ledger that
covers the window means silence from `floor_moves_since` is trustworthy,
and the band check should go ahead and judge."""
from datetime import datetime, timedelta, timezone
since = datetime(2026, 8, 22, tzinfo=timezone.utc)
covered = {n: since - timedelta(days=1) for n in rt.surface_names()}
session = _gap_rows(covered)
with patch.object(rt, "async_session", MagicMock(return_value=session)):
out = await rt.floor_history_gaps(since)
assert out == {}, "a covered arm is absent from the result, not present-and-false"
@pytest.mark.asyncio
async def test_an_arm_first_recorded_inside_the_window_reports_when_it_clears():
"""The symptom case. A finding with no remedy is a complaint, so the value
IS the date from which the floor becomes knowable."""
from datetime import datetime, timezone
since = datetime(2026, 8, 22, tzinfo=timezone.utc)
first = datetime(2026, 9, 21, 11, 58, tzinfo=timezone.utc)
name = rt.surface_names()[0]
rows = {n: since for n in rt.surface_names()}
rows[name] = first
session = _gap_rows(rows)
with patch.object(rt, "async_session", MagicMock(return_value=session)):
out = await rt.floor_history_gaps(since)
assert set(out) == {name}
assert out[name] == first.isoformat()
@pytest.mark.asyncio
async def test_an_arm_with_no_floor_history_at_all_is_reported_as_unknowable():
"""Distinct from "recorded too late", and it has a different remedy: there
is no date to wait for, so the caller is told to start the record. Mapping
it to None rather than leaving it out is the point — leaving it out is what
the band check was already doing wrong."""
from datetime import datetime, timezone
since = datetime(2026, 8, 22, tzinfo=timezone.utc)
names = rt.surface_names()
session = _gap_rows({n: since for n in names[1:]})
with patch.object(rt, "async_session", MagicMock(return_value=session)):
out = await rt.floor_history_gaps(since)
assert out == {names[0]: None}
@pytest.mark.asyncio
async def test_a_baseline_counts_here_though_it_is_not_a_move():
"""The one place this and `floor_moves_since` deliberately disagree.
A baseline records a default without changing it, so it is not a move and
that function filters it out. It IS the ledger beginning to watch the arm,
and from that moment silence genuinely means the floor held — so filtering
it out here would suspend the band check forever on an install whose only
floor rows are baselines, which is every install that has never tuned.
"""
from datetime import datetime, timezone
session = _gap_rows({n: datetime(2026, 1, 1, tzinfo=timezone.utc)
for n in rt.surface_names()})
with patch.object(rt, "async_session", MagicMock(return_value=session)):
out = await rt.floor_history_gaps(datetime(2026, 8, 22, tzinfo=timezone.utc))
assert out == {}
stmt = str(session.execute.call_args.args[0])
assert "old_value IS NOT NULL" not in stmt, (
"a baseline is not a move, but it is the ledger observing the arm"
)
assert "dial" in stmt and "min" in stmt.lower()
@pytest.mark.asyncio
async def test_the_registry_supplies_the_arms_not_the_ledger():
"""An arm the ledger has never heard of is exactly the one at risk, so it
cannot be the ledger that decides which arms get asked about."""
from datetime import datetime, timezone
session = _gap_rows({})
with patch.object(rt, "async_session", MagicMock(return_value=session)):
out = await rt.floor_history_gaps(datetime(2026, 8, 22, tzinfo=timezone.utc))
assert set(out) == set(rt.surface_names())
assert all(v is None for v in out.values())
@pytest.mark.asyncio
async def test_a_row_written_exactly_as_the_window_opens_covers_it():
"""The boundary, from both sides. `since` is the first instant the window
contains, so a floor recorded AT it leaves nothing earlier unaccounted
for — and one microsecond later does. Asserted because an off-by-one here
fails in the expensive direction: a covered arm reported as unknowable
retires a working check on the strength of a rounding."""
from datetime import datetime, timedelta, timezone
since = datetime(2026, 8, 22, tzinfo=timezone.utc)
names = rt.surface_names()
session = _gap_rows({n: since for n in names})
with patch.object(rt, "async_session", MagicMock(return_value=session)):
assert await rt.floor_history_gaps(since) == {}
later = since + timedelta(microseconds=1)
session = _gap_rows({n: later for n in names})
with patch.object(rt, "async_session", MagicMock(return_value=session)):
assert set(await rt.floor_history_gaps(since)) == set(names)
+126 -2
View File
@@ -49,10 +49,10 @@ def src(**kw) -> dict:
def warn(sources, usage=None, rule_usage=None, floors=None,
min_calls=N, epsilon=EPS, floor_moves=None) -> list[dict]:
min_calls=N, epsilon=EPS, floor_moves=None, floor_gaps=None) -> list[dict]:
return _compute_warnings(
sources, usage or {}, rule_usage or {}, floors or {}, min_calls, epsilon,
floor_moves or {},
floor_moves or {}, floor_gaps or {},
)
@@ -523,3 +523,127 @@ def test_the_registry_declares_which_arms_ask_a_fixed_question():
# not fixed, and marking one would silence a warning that works there.
for varying in ("auto_inject", "write_path", "pre_tool_rule", "prompt_rule"):
assert POINTS[varying].fixed_query is False, varying
# ── floor_history_unknown: the window reaches back past the ledger ─────────
#
# THE SAME SUSPENSION, FOR THE CASE THE ONE ABOVE CANNOT SEE.
#
# `floor_moved_mid_window` fires on a move the ledger recorded. The check
# overhead reads an EMPTY `floor_moves` as "the floor held steady" — and that
# reading is sound only where the ledger was watching. Before an arm's first
# floor row, "no move recorded" and "no move" are different statements, and
# the first was standing in for the second.
#
# It showed up the day this instance's ledger was seeded. Its earliest event
# of any kind is 2026-09-17; `write_path_rule`'s only floor row is a release
# baseline written 2026-09-21; a 30-day window opens 2026-08-22. The readout
# printed that arm's band as "-0.0208 above its floor" — the impossible
# negative the section above exists to prevent — with the suspension silent,
# because there was nothing on record for it to notice.
#
# The distinction is not academic for #4261: every window for the next month
# opens before that date, and measuring a change against an instrument that
# reports a number it cannot support is the #4225 trap one level up.
GAP_FROM = "2026-09-21T11:58:00+00:00"
def test_an_arm_whose_floor_history_starts_mid_window_is_suspended() -> None:
ws = warn({"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": GAP_FROM})
assert "floor_history_unknown" in codes(ws, "write_path_rule")
assert "band_hugs_floor" not in codes(ws), (
"a suspended check must not also answer"
)
def test_the_negative_gap_that_exposed_this_is_never_printed() -> None:
"""The observed symptom, reproduced: p10 0.6992 under a floor of 0.72 is
a band -0.0208 "above" its floor. Arithmetically impossible inside one
population, and no reader can act on it."""
ws = warn({"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": GAP_FROM})
assert not any(w.get("numbers", {}).get("gap", 0) < 0 for w in ws)
def test_a_healthy_looking_gap_is_suspended_too() -> None:
"""The direction that hides. A gap of 0.10 reads as a comfortable margin
and is computed against a bar nothing can vouch for over that window — the
same asymmetry as a lowered floor, and the reason this suspends rather
than only catching negatives."""
ws = warn({"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.82)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": GAP_FROM})
assert "floor_history_unknown" in codes(ws, "write_path_rule")
def test_an_arm_with_no_history_at_all_says_how_to_start_one() -> None:
"""`None` rather than a date: there is nothing to wait for, so the remedy
is different and the sentence has to be too. A reader told to "wait for
2026-…" when no date exists would wait forever."""
w = next(w for w in warn(
{"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": None},
) if w["code"] == "floor_history_unknown")
assert w["numbers"]["known_from"] is None
assert "no floor history" in w["detail"]
assert "tune_retrieval" in w["detail"], "a finding with no remedy is a complaint"
def test_the_dated_case_says_when_the_check_comes_back() -> None:
w = next(w for w in warn(
{"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": GAP_FROM},
) if w["code"] == "floor_history_unknown")
assert w["numbers"]["known_from"] == GAP_FROM
assert GAP_FROM in w["detail"] and "days" in w["detail"]
def test_a_covered_arm_is_still_judged() -> None:
"""The mirror error, and the expensive one. An arm absent from the gap map
is fully covered; suspending it would retire a working check on the
strength of nothing."""
ws = warn({"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.7205)},
floors={"write_path_rule": 0.72}, floor_gaps={})
assert "band_hugs_floor" in codes(ws, "write_path_rule")
assert "floor_history_unknown" not in codes(ws)
def test_a_known_move_wins_over_a_history_gap() -> None:
"""Both can apply — a ledger that starts mid-window may still have caught
a move inside it. The arm that has a date to give should give it, and
exactly one line should be printed either way."""
ws = warn({"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_moves={"write_path_rule": MOVED},
floor_gaps={"write_path_rule": GAP_FROM})
assert "floor_moved_mid_window" in codes(ws, "write_path_rule")
assert "floor_history_unknown" not in codes(ws)
assert "band_hugs_floor" not in codes(ws)
def test_only_the_uncovered_arm_is_suspended() -> None:
"""Coverage is per-arm: the ledger can start watching one arm before
another, and one arm's blind spot says nothing about the next."""
ws = warn(
{"write_path_rule": src(calls=100, zero_result_calls=5, p10=0.7205),
"auto_inject": src(calls=100, zero_result_calls=5, p10=0.705)},
floors={"write_path_rule": 0.72, "auto_inject": 0.70},
floor_gaps={"write_path_rule": GAP_FROM},
)
assert "floor_history_unknown" in codes(ws, "write_path_rule")
assert "band_hugs_floor" in codes(ws, "auto_inject")
def test_a_quiet_arm_is_not_suspended_either() -> None:
"""Below `min_calls` nothing in this block runs — a ledger gap does not
promote an arm nobody used into something worth a line."""
ws = warn({"write_path_rule": src(calls=1, zero_result_calls=0, p10=0.6992)},
floors={"write_path_rule": 0.72},
floor_gaps={"write_path_rule": GAP_FROM})
assert "floor_history_unknown" not in codes(ws)