diff --git a/src/scribe/services/retrieval_telemetry.py b/src/scribe/services/retrieval_telemetry.py index 6c1a477..7667f11 100644 --- a/src/scribe/services/retrieval_telemetry.py +++ b/src/scribe/services/retrieval_telemetry.py @@ -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 diff --git a/src/scribe/services/retrieval_tuning.py b/src/scribe/services/retrieval_tuning.py index 2441f1c..98d9da6 100644 --- a/src/scribe/services/retrieval_tuning.py +++ b/src/scribe/services/retrieval_tuning.py @@ -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]: diff --git a/tests/test_retrieval_tuning.py b/tests/test_retrieval_tuning.py index 804294b..39564dc 100644 --- a/tests/test_retrieval_tuning.py +++ b/tests/test_retrieval_tuning.py @@ -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) diff --git a/tests/test_retrieval_warnings.py b/tests/test_retrieval_warnings.py index c64119c..0bb5f5a 100644 --- a/tests/test_retrieval_warnings.py +++ b/tests/test_retrieval_warnings.py @@ -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)