fix(telemetry): a floor that moved inside the window makes the band check a comparison of two populations (#4225)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 16s
CI & Build / integration (push) Successful in 55s
CI & Build / TypeScript typecheck (push) Successful in 1m0s
CI & Build / Python tests (push) Successful in 1m34s
CI & Build / Build & push image (push) Successful in 33s
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 16s
CI & Build / integration (push) Successful in 55s
CI & Build / TypeScript typecheck (push) Successful in 1m0s
CI & Build / Python tests (push) Successful in 1m34s
CI & Build / Build & push image (push) Successful in 33s
`retrieval_telemetry(days=30)` reported, for write_path_rule:
"the weakest tenth of what this arm returns scores 0.6984, only -0.0216
above its floor of 0.72"
A negative distance above something. The tenth percentile of what an arm
RETURNED cannot sit below the floor that gates what it may return — not
inside one population.
MEASURED CAUSE. write_path_rule's floor was 0.68 until 2026-09-02, when
2385100 (#3318) raised the shipped default to 0.72. The window opened
2026-08-22, so six days of it are calls made under the old bar; top_score.min
for the surface is exactly 0.68, the old bar still in the sample.
AND THE CHANGE LEFT NO TRACE THE READOUT COULD SEE. retrieval_tuning_events
records dial turns — a person or a model choosing a number. It was silent
about the other way a floor moves: somebody edits floor_default and ships it.
retrieval_tuning_history returned {"events": []} and retrieval_surfaces said
last_change: {}, source: "shipped". All true, and all of it silent about a
floor that had in fact moved.
THE RAISE ANNOUNCED ITSELF. A LOWERED FLOOR WOULD NOT: the gap comes out
comfortably positive and reads as a clean bill of health on a sample that
half predates the bar being judged. Both directions are now pinned.
So the check is SUSPENDED, not softened. band_hugs_floor asks whether the
scores are piled on the bar; that needs the scores and the bar to come from
the same regime. Where they do not, the honest answer is that this sample
cannot say, plus the date after which one can — floor_moved_mid_window
replaces band_hugs_floor for that arm and never accompanies it. A reader told
a number is unavailable goes and gets one; a reader handed a qualified number
uses it.
NO MIGRATION. `actor` is Text with no CHECK precisely so a new kind of actor
is not one — the model's own comment says so, and this is the case it
anticipated. "release" joins "model" and "human". user_id is already
nullable, which is right: no user did this, a release acts on every account
that has not overridden the dial, and a row per user would both multiply and
misattribute it. Both readers now take the newest of (this user's change, the
release's).
THE FIRST SIGHTING IS A BASELINE, written with old_value NULL. Nothing moved;
the row exists so the next release has a predecessor. That null is
load-bearing: floor_moves_since asks for old_value IS NOT NULL, so a fresh
install's baseline does not silently retire the check on every new install.
UI: the tuning history rendered actor as `human ? 'you' : 'Claude'`, so a
release row would have told the operator that Claude moved a floor it never
touched — the one failure the actor column exists to prevent. Three-way now,
with an unknown value printing itself rather than guessing.
Recorded at startup, inline and awaited. What #4181 cost three hours was
concurrency — a background task racing the hook for the same pool. Sequential
creates no contention, and this is twelve single-row reads. It must finish
before serving because a readout served before the change was recorded is the
exact answer this exists to stop giving.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01821k5B3Ysecp9fNYs92Kuy
This commit is contained in:
@@ -182,6 +182,33 @@ def create_app() -> Quart:
|
||||
start_notification_loop()
|
||||
start_auth_token_retention_loop()
|
||||
|
||||
# Write down any shipped default that moved in this release (#4225).
|
||||
#
|
||||
# INLINE AND AWAITED, deliberately, against the instinct the block
|
||||
# below argues for. What #4181 cost three hours was CONCURRENCY — a
|
||||
# background task created here racing this hook for the same pool.
|
||||
# Running sequentially creates no such contention, and this is twelve
|
||||
# single-row reads on an index against a table with a handful of rows.
|
||||
#
|
||||
# It has to finish before serving because the thing it protects is a
|
||||
# telemetry read: `band_hugs_floor` compares a band against a floor,
|
||||
# and across a release that changed the floor those describe different
|
||||
# regimes. A readout served before the change was recorded is the very
|
||||
# answer this exists to stop giving. Failure is logged and swallowed —
|
||||
# provenance is worth a lot and never worth refusing to boot.
|
||||
try:
|
||||
from scribe.services.retrieval_tuning import record_release_defaults
|
||||
moved = await record_release_defaults()
|
||||
for row in moved:
|
||||
if not row["baseline"]:
|
||||
app.logger.info(
|
||||
"release moved %s's shipped %s: %s -> %s",
|
||||
row["surface"], row["dial"],
|
||||
row["old_value"], row["new_value"],
|
||||
)
|
||||
except Exception:
|
||||
app.logger.warning("could not record release defaults", exc_info=True)
|
||||
|
||||
# Backfill embeddings for any notes that don't have one. Runs in the
|
||||
# background so it never blocks the server from accepting requests —
|
||||
# and, since #4181, not until the rest of this hook has finished.
|
||||
|
||||
@@ -425,6 +425,12 @@ It is an UPPER BOUND per surface: a pull records the door it came
|
||||
- `band_hugs_floor` — the weakest tenth of what an arm returns sits on
|
||||
its floor. The bar is doing the selecting and the score is not, so
|
||||
moving that floor changes how MUCH you get, not how good it is.
|
||||
- `floor_moved_mid_window` — that arm's floor CHANGED inside the window,
|
||||
by a release or by a dial turn, so its calls were made under two bars
|
||||
and the band check above is suspended for it rather than answered
|
||||
wrongly. Ask again with a `days` starting after the named date. The
|
||||
warning replaces `band_hugs_floor` for that arm; it never accompanies
|
||||
it.
|
||||
- `no_duration` — rows written without timings. A logging gap, not a slow
|
||||
arm, and it devalues every other number from that source.
|
||||
- `surfaced_never_pulled` — distinct records shown and never opened, per
|
||||
|
||||
@@ -40,6 +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.settings import get_setting
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
@@ -498,7 +499,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) -> list[dict]:
|
||||
floors: dict, min_calls: int, epsilon: float,
|
||||
floor_moves: 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
|
||||
@@ -581,9 +583,41 @@ def _compute_warnings(sources: dict, usage: dict, rule_usage: dict,
|
||||
# invite tuning a dial that does not exist.
|
||||
floor = floors.get(name)
|
||||
p10 = (b.get("top_score") or {}).get("p10")
|
||||
moved = (floor_moves or {}).get(name)
|
||||
if calls >= min_calls and floor is not None and p10 is not None:
|
||||
gap = p10 - floor
|
||||
if gap < epsilon:
|
||||
# ── The floor moved inside the window ────────────────────────
|
||||
#
|
||||
# THE CHECK IS SUSPENDED, NOT SOFTENED, and this is the whole of
|
||||
# #4225. `band_hugs_floor` asks whether the scores are piled on
|
||||
# the bar. That question needs the scores and the bar to come from
|
||||
# the same regime; across a floor change they do not, and the
|
||||
# comparison quietly becomes one between two populations.
|
||||
#
|
||||
# It announced itself when the change was a RAISE: p10 computed
|
||||
# over calls made under the old, lower bar came out BELOW today's
|
||||
# floor, and the warning reported a band "-0.0216 above" its
|
||||
# floor. A negative distance above something is not a number
|
||||
# anybody can act on. A LOWERED floor hides better — the gap comes
|
||||
# out comfortably positive and reads as a clean bill of health on
|
||||
# a sample that half predates the bar being judged.
|
||||
#
|
||||
# So the honest move is to say the sample cannot answer, and say
|
||||
# when it will be able to, rather than print a figure with an
|
||||
# asterisk. A reader who is told a number is unavailable goes and
|
||||
# gets one; a reader handed a qualified number uses it.
|
||||
if moved is not None:
|
||||
out.append(_warn(
|
||||
"floor_moved_mid_window",
|
||||
f"this arm's floor changed at {moved}, inside the window, "
|
||||
f"so its calls were made under two different bars and its "
|
||||
f"band cannot be compared against the floor now in force "
|
||||
f"({floor}). The band check is suspended for this arm "
|
||||
f"until the window clears that date — ask again with a "
|
||||
f"`days` that starts after it, or wait.",
|
||||
source=name, floor=floor, p10=p10, moved_at=moved,
|
||||
))
|
||||
elif p10 - floor < epsilon:
|
||||
gap = p10 - floor
|
||||
out.append(_warn(
|
||||
"band_hugs_floor",
|
||||
f"the weakest tenth of what this arm returns scores "
|
||||
@@ -1350,8 +1384,20 @@ async def retrieval_summary(
|
||||
except Exception: # pragma: no cover - telemetry never raises
|
||||
logger.warning("could not read floor for %s", name, exc_info=True)
|
||||
|
||||
# Floors that MOVED inside this window (#4225) — a release's shipped
|
||||
# default or the operator's own dial, because the question is about the
|
||||
# sample, not about who is answerable for it. Read unconditionally rather
|
||||
# than under `if user_id`, unlike `floors` above: a release change belongs
|
||||
# to no account, and it is exactly the case that used to go unrecorded.
|
||||
floor_moves: dict[str, str] = {}
|
||||
try:
|
||||
floor_moves = await floor_moves_since(since)
|
||||
except Exception: # pragma: no cover - telemetry never raises
|
||||
logger.warning("could not read floor changes", exc_info=True)
|
||||
|
||||
out["warnings"] = _compute_warnings(
|
||||
out["sources"], usage, rule_usage, floors, min_calls, epsilon,
|
||||
floor_moves,
|
||||
)
|
||||
|
||||
# "Active" means this window saw real traffic SOMEWHERE. Without that
|
||||
|
||||
@@ -43,7 +43,7 @@ from __future__ import annotations
|
||||
|
||||
import logging
|
||||
|
||||
from sqlalchemy import select
|
||||
from sqlalchemy import or_, select
|
||||
|
||||
from scribe.models import async_session
|
||||
from scribe.models.retrieval_tuning import RetrievalTuningEvent
|
||||
@@ -61,6 +61,10 @@ logger = logging.getLogger(__name__)
|
||||
|
||||
DIALS = ("floor", "budget")
|
||||
|
||||
# The actor for a change nobody made by hand: the shipped default moved
|
||||
# between releases. Beside "model" and "human" (#4225).
|
||||
RELEASE_ACTOR = "release"
|
||||
|
||||
# Long enough to say what was read and what it showed; short enough that nobody
|
||||
# pastes a telemetry dump in. The number is not a measurement — it is the point
|
||||
# at which "0.66" stops being an acceptable answer to "why".
|
||||
@@ -168,7 +172,21 @@ async def current_settings(user_id: int) -> list[dict]:
|
||||
select(RetrievalTuningEvent)
|
||||
.where(
|
||||
RetrievalTuningEvent.surface == name,
|
||||
RetrievalTuningEvent.user_id == user_id,
|
||||
# THIS USER'S CHANGES *OR* A RELEASE'S (#4225).
|
||||
# A release's rows carry no user id because no user
|
||||
# made them, and taking the newest of the two is
|
||||
# what makes the answer true: a dial the operator
|
||||
# has tuned is explained by their change, and an
|
||||
# untouched one by the release that last shipped
|
||||
# its default. Filtering to the user alone reported
|
||||
# "still on the shipped starting point" for a
|
||||
# default that had in fact moved — the one state a
|
||||
# reader would not think to check, which is the
|
||||
# same sentence #4104 wrote about the bug above.
|
||||
or_(
|
||||
RetrievalTuningEvent.user_id == user_id,
|
||||
RetrievalTuningEvent.user_id.is_(None),
|
||||
),
|
||||
RetrievalTuningEvent.dial == dial,
|
||||
)
|
||||
.order_by(RetrievalTuningEvent.created_at.desc())
|
||||
@@ -282,6 +300,126 @@ async def set_dial(
|
||||
}
|
||||
|
||||
|
||||
async def record_release_defaults() -> list[dict]:
|
||||
"""Write down that a RELEASE moved a shipped default (#4225).
|
||||
|
||||
THE HOLE THIS FILLS. `retrieval_tuning_events` records dial turns — a
|
||||
person or a model choosing a number. It is silent about the other way a
|
||||
floor moves, which is somebody editing `floor_default` in the registry and
|
||||
shipping it. That change is invisible to every consumer of this table, and
|
||||
one of those consumers is `band_hugs_floor`, which compares a percentile
|
||||
against a floor and has no way to notice they come from different regimes.
|
||||
|
||||
Measured on the instance that found this: `write_path_rule` went 0.68 ->
|
||||
0.72 on 2026-09-02 as a shipped default, and a 30-day window opening
|
||||
2026-08-22 therefore held six days of calls made under the old bar. The
|
||||
warning reported the band sitting "-0.0216 above" its floor — a negative
|
||||
distance above something, which is what a two-population comparison looks
|
||||
like when it finally says so out loud.
|
||||
|
||||
`user_id IS NULL`, because no user did this. A release acts on every
|
||||
account that has not overridden the dial, and writing one row per user
|
||||
would both multiply the row and misattribute it. Readers take the newest of
|
||||
(this user's own change, the release's) — a dial the operator has tuned is
|
||||
explained by their change, and an untouched one by the release.
|
||||
|
||||
`actor="release"`, a third value beside "model" and "human". The column is
|
||||
Text with no CHECK precisely so a new kind of actor is not a migration —
|
||||
the model's own comment says so, and this is the case it anticipated.
|
||||
|
||||
THE FIRST SIGHTING IS A BASELINE, NOT A CHANGE, and is written with
|
||||
`old_value=None`. Nothing moved; the row exists so that the NEXT release
|
||||
has something to be different from. That distinction is load-bearing
|
||||
downstream: a warning suspends itself on a genuine move and must not
|
||||
suspend itself on a fresh install's baseline, and it tells the two apart by
|
||||
exactly this null.
|
||||
|
||||
Idempotent, and safe to call on every boot: a default that matches the last
|
||||
recorded one writes nothing.
|
||||
"""
|
||||
written: list[dict] = []
|
||||
stamp = calibration_stamp()
|
||||
async with async_session() as session:
|
||||
for name in surface_names():
|
||||
s = get_surface(name)
|
||||
for dial, shipped in (
|
||||
("floor", float(s.floor_default)),
|
||||
("budget", float(s.budget_default)),
|
||||
):
|
||||
last = (
|
||||
await session.execute(
|
||||
select(RetrievalTuningEvent)
|
||||
.where(
|
||||
RetrievalTuningEvent.surface == name,
|
||||
RetrievalTuningEvent.user_id.is_(None),
|
||||
RetrievalTuningEvent.actor == RELEASE_ACTOR,
|
||||
RetrievalTuningEvent.dial == dial,
|
||||
)
|
||||
.order_by(RetrievalTuningEvent.created_at.desc())
|
||||
.limit(1)
|
||||
)
|
||||
).scalars().first()
|
||||
if last is not None and abs(float(last.new_value) - shipped) < 1e-9:
|
||||
continue
|
||||
old = None if last is None else float(last.new_value)
|
||||
reason = (
|
||||
f"Baseline: this release ships {name}'s {dial} at {shipped}. "
|
||||
f"Recorded so a later change to the shipped value has a "
|
||||
f"date and a predecessor to be measured against; nothing "
|
||||
f"moved here."
|
||||
if old is None else
|
||||
f"A release moved {name}'s shipped {dial} from {old} to "
|
||||
f"{shipped}. Not a dial turn — the default in the registry "
|
||||
f"changed, so calls logged either side of this date were "
|
||||
f"made under different bars and cannot be pooled."
|
||||
)
|
||||
session.add(RetrievalTuningEvent(
|
||||
user_id=None, surface=name, dial=dial,
|
||||
old_value=old, new_value=shipped,
|
||||
actor=RELEASE_ACTOR, reason=reason,
|
||||
embedding_model=stamp["embedding_model"],
|
||||
shape_version=stamp["shape_version"],
|
||||
))
|
||||
written.append({
|
||||
"surface": name, "dial": dial,
|
||||
"old_value": old, "new_value": shipped,
|
||||
"baseline": old is None,
|
||||
})
|
||||
if written:
|
||||
await session.commit()
|
||||
return written
|
||||
|
||||
|
||||
async def floor_moves_since(since) -> dict[str, str]:
|
||||
"""Surfaces whose floor genuinely MOVED at or after `since`.
|
||||
|
||||
Genuinely: `old_value IS NOT NULL`, so a baseline row — which records a
|
||||
default without changing it — does not read as a change. Returns surface ->
|
||||
ISO timestamp of the newest such move, for a reader deciding whether a
|
||||
window's numbers can be pooled.
|
||||
|
||||
Covers both kinds of move, a release's and this user's, because the
|
||||
question is about the SAMPLE rather than about who is responsible for it:
|
||||
a floor that moved mid-window splits the calls either way round.
|
||||
"""
|
||||
out: dict[str, str] = {}
|
||||
async with async_session() as session:
|
||||
rows = (
|
||||
await session.execute(
|
||||
select(RetrievalTuningEvent)
|
||||
.where(
|
||||
RetrievalTuningEvent.dial == "floor",
|
||||
RetrievalTuningEvent.old_value.isnot(None),
|
||||
RetrievalTuningEvent.created_at >= since,
|
||||
)
|
||||
.order_by(RetrievalTuningEvent.created_at.desc())
|
||||
)
|
||||
).scalars().all()
|
||||
for row in rows:
|
||||
out.setdefault(row.surface, row.created_at.isoformat())
|
||||
return out
|
||||
|
||||
|
||||
async def tuning_history(
|
||||
user_id: int, *, surface: str | None = None, limit: int = 20
|
||||
) -> list[dict]:
|
||||
@@ -296,7 +434,13 @@ async def tuning_history(
|
||||
async with async_session() as session:
|
||||
q = (
|
||||
select(RetrievalTuningEvent)
|
||||
.where(RetrievalTuningEvent.user_id == user_id)
|
||||
.where(or_(
|
||||
RetrievalTuningEvent.user_id == user_id,
|
||||
# Shipped-default changes, which belong to no account and
|
||||
# would otherwise be missing from the one surface built
|
||||
# for asking why a number is where it is (#4225).
|
||||
RetrievalTuningEvent.user_id.is_(None),
|
||||
))
|
||||
.order_by(RetrievalTuningEvent.created_at.desc())
|
||||
.limit(max(1, min(int(limit), 200)))
|
||||
)
|
||||
|
||||
Reference in New Issue
Block a user