From 5e19a1b02826cfe8df65b2ca183c3553765e71dd Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Tue, 8 Sep 2026 13:31:49 -0400 Subject: [PATCH 1/3] =?UTF-8?q?test(telemetry):=20FALSIFICATION=20?= =?UTF-8?q?=E2=80=94=20prove=20the=20identity=20guard=20can=20fail=20(#366?= =?UTF-8?q?8)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Deliberately broken, reverted in the next commit. Rule 167 requires every guard be falsified against the regression it names before it is trusted, and rule 10 puts CI as the only place that can run it — so the failure has to be made to happen here rather than argued for. The guard: both rule arms feed one `fresh` list to two recorders, so the call log and the surfacing log cannot disagree about what one call showed. The regression: `results=fresh` becomes `results=hits` in both arms, so the call log counts what the ranker found while the surfacing log counts what was shown. That is not a hypothetical shape. It is exactly the divergence that would make a correct system report a lost write when the two tables are later compared in aggregate — the reading that scoped this milestone at five steps against a defect that did not exist. Expected red: the one-already-held and all-already-held cases on both arms. The nothing-held case must still PASS — with no exclusions both recorders see the same list however wrongly they are wired, which is why it could never have been the discriminating case. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ --- src/scribe/services/plugin_context.py | 4 +- tests/test_rule_usage_wiring.py | 94 +++++++++++++++++++++++++++ 2 files changed, 96 insertions(+), 2 deletions(-) diff --git a/src/scribe/services/plugin_context.py b/src/scribe/services/plugin_context.py index 3ce4dda..a391c63 100644 --- a/src/scribe/services/plugin_context.py +++ b/src/scribe/services/plugin_context.py @@ -1300,7 +1300,7 @@ async def build_write_path_hint( user_id=user_id, source="write_path_rule", query=code or path, threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, - is_task=None, results=fresh, duration_ms=rule_ms, + is_task=None, results=hits, duration_ms=rule_ms, # What the ranker found and this session had already been told. # Without it a zero row cannot say whether the bar was too high or # the reader was simply ahead of it — and only the first is a @@ -1404,7 +1404,7 @@ async def build_tool_rule_hint( user_id=user_id, source="pre_tool_rule", query=query, threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, - is_task=None, results=fresh, duration_ms=duration_ms, + is_task=None, results=hits, duration_ms=duration_ms, # See the sibling arm. It matters more here: this arm fires on every # Bash call, so a long session excludes its way to an all-zero row # and the threshold looks wrong when nothing about it is. diff --git a/tests/test_rule_usage_wiring.py b/tests/test_rule_usage_wiring.py index f985bae..050ca89 100644 --- a/tests/test_rule_usage_wiring.py +++ b/tests/test_rule_usage_wiring.py @@ -772,3 +772,97 @@ async def test_a_shown_hit_is_not_counted_as_suppressed(): assert out["rule_ids"] == [161] assert log.call_args.kwargs["suppressed"] == 1 assert len(log.call_args.kwargs["results"]) == 1 + + +# ── The identity that falsified this milestone (#3668) ───────────────── +# +# `rule_usage.surfaced` == `pre_tool_rule.cleared` + `write_path_rule.cleared`. +# Milestone #379 was scoped on a reconstruction that put ~64% of ranked rule +# surfacings as never reaching `rule_usage_events`. Five steps were planned +# against it. One read of this identity — 17 = 17, then 39 = 39 on a second +# window — falsified the whole thing: the gap was two counters that started +# recording on different days, not a write path dropping rows. +# +# So the identity is not a nice-to-have. It is the cheapest true statement +# available about this pair of tables, and its absence is what let a magnitude +# that merely LOOKED wrong survive a code review and a five-step plan. An +# identity that must hold exactly beats a magnitude that looks wrong. +# +# WHY THE ARM IS THE RIGHT PLACE TO PIN IT, and the readout is not. Inside an +# arm, one `fresh` list feeds both recorders in one function, so the counts +# cannot legitimately differ — at any limit. The readout-level form is weaker +# than it looks: `cleared_threshold` counts CALLS that beat the bar while +# `surfaced` counts RULES, and those coincide only while `RULEHINT_LIMIT` is 1. +# Raise the limit and the readout identity breaks while nothing is wrong. +# `RULEHINT_LIMIT` has already moved once (2 → 1, `2385100`), and that move is +# half of why the original reconstruction misread its own numbers. +# +# Hence three hits below, where production currently returns at most one. The +# test is deliberately in a state the limit does not permit today, because what +# is being pinned is that the two recorders read the same list — not that the +# list happens to be short. + +_THREE_HITS = [ + (0.81, fake_rule(id=156, title="A wait with no deadline is a bug")), + (0.77, fake_rule(id=157, title="A loop re-arms in a finally")), + (0.74, fake_rule(id=161, title="Reach the forge through its MCP tools")), +] + +_ARMS = [("write_path_rule", _run_arm), ("pre_tool_rule", _run_tool_arm)] + + +def _both_ends(log, rec, source): + """What the two recorders said about one call, at the same grain. + + Ids rather than counts. Equal counts drawn from different lists is a real + way for this to break — an off-by-one slice, or one recorder reading `hits` + where the other reads `fresh` in a window where the exclusion happened to + remove as many as it added — and a count comparison would call that agreement. + """ + rows = [c for c in log.call_args_list if c.kwargs.get("source") == source] + assert len(rows) == 1, ( + f"expected exactly one {source} call row, got {len(rows)} — the " + f"identity is per call and cannot be read across several" + ) + logged = [rule.id for _score, rule in rows[0].kwargs["results"]] + surfaced = [ + rid + for c in rec.call_args_list if c.kwargs.get("source") == source + for rid in c.kwargs["rule_ids"] + ] + return logged, surfaced + + +@pytest.mark.parametrize(("source", "run"), _ARMS, ids=["write_path", "pre_tool"]) +@pytest.mark.parametrize( + ("excluded", "expected"), + [([], 3), ([157], 2), ([156, 157, 161], 0)], + ids=["nothing-held", "one-already-held", "all-already-held"], +) +@pytest.mark.asyncio +async def test_both_recorders_report_the_same_rules_for_one_call( + source, run, excluded, expected +): + """One list, two tables, no room to disagree. + + The middle case is the one that discriminates. With nothing excluded both + recorders see the same three rules however wrongly they are wired, so an + arm logging `hits` to the call log and `fresh` to the surfacing log passes + that case and fails this one — and logging `hits` is exactly the divergence + that would manufacture an apparent write loss out of a correct system. + """ + log, rec = MagicMock(), MagicMock() + await run(list(_THREE_HITS), rec, retrieval_log=log, exclude_rule_ids=excluded) + + logged, surfaced = _both_ends(log, rec, source) + assert surfaced == logged, ( + f"{source} told its two tables different stories about one call: the " + f"call log recorded {logged} and the surfacing log recorded {surfaced}. " + f"Both come from `fresh`, in one function, so any difference is a bug " + f"in the wiring — and it is the shape that reads as a lost write when " + f"the two tables are later compared in aggregate (#3668)." + ) + assert len(logged) == expected, ( + "the fixture stopped exercising what it claims to; check the exclusion " + "filter still runs before both recorders" + ) From 277aea58e4a5e00acb9f751435fcd215b16dfe4e Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Tue, 8 Sep 2026 13:36:03 -0400 Subject: [PATCH 2/3] test(telemetry): pin the identity that falsified this milestone (#3668) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Reverts the deliberate break from 5e19a1b. `plugin_context.py` is now byte-identical to before it; the only change against that baseline is the guard itself. FALSIFIED, not argued (rule 167). CI run 6046 with `results=hits` in both arms failed exactly the predicted four cases — [one-already-held-write_path] FAILED [one-already-held-pre_tool] FAILED [all-already-held-write_path] FAILED [all-already-held-pre_tool] FAILED [nothing-held-*] passed — and the nothing-held cases passing is the point, not a gap: with no exclusions both recorders see the same list however wrongly they are wired, so that case can never discriminate and a guard built only from it would read as coverage while catching nothing. WHAT IS PINNED. Both arms build one `fresh` list and hand it to two recorders in one function, so the call log and the surfacing log cannot disagree about what a single call showed. Ids, not counts: equal counts drawn from different lists is a real way for this to break, and a count comparison would call it agreement. Three hits, where production returns at most one. The identity holds at any limit because both recorders read the same list, and stating it that way survives RULEHINT_LIMIT moving again — it has moved once already (2 → 1, 2385100), and that move is half of why the original reconstruction misread its own numbers. NOT DONE, deliberately: the readout-level self-check the task also proposed. `cleared_threshold` counts CALLS that beat the bar while `surfaced` counts RULES, so that identity holds only while the limit is 1 — it would fire on a healthy system the moment the limit rises. The arm-level form has no such coupling, which is why the guard lives here. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ --- src/scribe/services/plugin_context.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/scribe/services/plugin_context.py b/src/scribe/services/plugin_context.py index a391c63..3ce4dda 100644 --- a/src/scribe/services/plugin_context.py +++ b/src/scribe/services/plugin_context.py @@ -1300,7 +1300,7 @@ async def build_write_path_hint( user_id=user_id, source="write_path_rule", query=code or path, threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, - is_task=None, results=hits, duration_ms=rule_ms, + is_task=None, results=fresh, duration_ms=rule_ms, # What the ranker found and this session had already been told. # Without it a zero row cannot say whether the bar was too high or # the reader was simply ahead of it — and only the first is a @@ -1404,7 +1404,7 @@ async def build_tool_rule_hint( user_id=user_id, source="pre_tool_rule", query=query, threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, - is_task=None, results=hits, duration_ms=duration_ms, + is_task=None, results=fresh, duration_ms=duration_ms, # See the sibling arm. It matters more here: this arm fires on every # Bash call, so a long session excludes its way to an all-zero row # and the threshold looks wrong when nothing about it is. From e7c1af32a05609cae0c5115dbaf0242d44257032 Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Tue, 8 Sep 2026 13:50:05 -0400 Subject: [PATCH 3/3] fix(telemetry): the bar can only be judged from what it rejected (#3670) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `cleared_threshold` was documented as the number to read first. It was a tautology. The search applies the threshold before returning, so every returned result cleared it by construction and a call with no results has no top_score to compare — the condition was true exactly when `result_count > 0`. It was `calls - zero_result_calls` under a name that promised a second opinion, and `zero + cleared == calls` held on all nineteen source/window readings ever taken, today's live seven included. The reading procedure built on it asked the reader to compare a number with itself, and a threshold change was unobservable through it: raise the bar and both numbers move together, so the field could never show a bar set too high. REPLACED, NOT JUST REMOVED. The question the table exists to answer is whether the bar is in the right place, and that is only answerable from the calls that returned NOTHING: how close did the best rejected candidate come? A 0.72 bar turning away a stream of 0.71s is set too high by a hair; the same bar turning away 0.30s is working. Both render as a zero-result call today and nothing separates them, because the losing score is discarded inside the search. So both searches now rank WITHOUT the bar and apply it in Python. The qualifying set is provably identical — rows arrive ordered by distance, so every above-bar row sorts ahead of every below-bar one, and an over-fetch that returned N above-bar rows returns the same N plus some losers. What changes is that the losers are visible instead of dropped in the query. `report` carries the score out without changing what a search RETURNS: eight of eleven call sites want hits and nothing else. New column (migration 0096), nullable and unbackfilled. A row written before this genuinely does not know, and a 0.0 would read as "the corpus held nothing remotely relevant" — a claim invented out of a caller's silence, which is the substitution this whole milestone corrects. The new aggregate is a percentile_cont WITHIN GROUP over a CASE, one step from the shape that produced #2663, where a rejected query was swallowed by the broad except and every counter read zero. It carries an integration guard for that reason: only real Postgres can say it parses, and the symptom of failure is silence. Also adds a guard that no int field in a bucket equals `calls - zero_result_calls`. That identity is what `cleared_threshold` satisfied for its whole life, and it survived because it had its own name and nobody added the two numbers beside it. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ --- ...0096_retrieval_log_best_available_score.py | 62 ++++++ src/scribe/mcp/tools/search.py | 46 ++++- src/scribe/models/retrieval_log.py | 8 + src/scribe/routes/search.py | 3 + src/scribe/services/embeddings.py | 54 ++++- src/scribe/services/plugin_context.py | 15 ++ src/scribe/services/retrieval_telemetry.py | 96 +++++++-- tests/test_services_retrieval_telemetry.py | 190 +++++++++++++++++- 8 files changed, 425 insertions(+), 49 deletions(-) create mode 100644 alembic/versions/0096_retrieval_log_best_available_score.py diff --git a/alembic/versions/0096_retrieval_log_best_available_score.py b/alembic/versions/0096_retrieval_log_best_available_score.py new file mode 100644 index 0000000..4772572 --- /dev/null +++ b/alembic/versions/0096_retrieval_log_best_available_score.py @@ -0,0 +1,62 @@ +"""add retrieval_logs.best_available_score — the score the bar rejected (#3670) + +Revision ID: 0096 +Revises: 0095 +Create Date: 2026-09-08 + +`cleared_threshold` was documented as the number to read FIRST — "a surface +that clears its bar on nearly every call is either well-tuned or too loose, +and p10 says which". It was never a measurement. The search applies the +threshold before returning, so every returned result cleared the bar by +construction and a call with no results has no `top_score` to compare: +the condition is true exactly when `result_count > 0`. + +`zero_result_calls + cleared_threshold == calls` held on all nineteen +source/window readings ever taken. It was `calls - zero_result_calls` +wearing a name that promised a second opinion, and a reading procedure was +built on top of it that asked the reader to compare a number against itself. + +THE MISSING NUMBER, and the reason this is a column rather than a deletion. +The question the table exists to answer is "is the bar in the right place", +and that question is only answerable from the calls that returned NOTHING: +how close did the best rejected candidate come? A bar at 0.72 turning away +a stream of 0.71s is set too high by a hair. A bar turning away 0.30s is +doing its job. Those two are indistinguishable today — both render as a +zero-result call — and no arrangement of the existing columns separates +them, because the losing score is discarded inside the search. + +So the searches now rank without the bar and apply it in Python, which +costs nothing (the rows were already ordered by distance, and the qualifying +set is provably identical — above-threshold rows sort first), and the best +score seen becomes observable. + +NULLABLE, AND UNBACKFILLED, for the reason 0095 spells out: a row written +before this shipped genuinely does not know what its best rejected candidate +scored, and saying so is the honest state. A 0.0 default would read as "the +corpus had nothing remotely relevant" — an artifact standing in for a +measurement, which is the whole defect this milestone corrects. + +`retrieval_logs` is not restored from backup, so no importer changes. + +Downgrade drops the column. Purely observational — nothing reads it for +correctness. +""" +from alembic import op +import sqlalchemy as sa + + +revision = "0096" +down_revision = "0095" +branch_labels = None +depends_on = None + + +def upgrade() -> None: + op.add_column( + "retrieval_logs", + sa.Column("best_available_score", sa.Float(), nullable=True), + ) + + +def downgrade() -> None: + op.drop_column("retrieval_logs", "best_available_score") diff --git a/src/scribe/mcp/tools/search.py b/src/scribe/mcp/tools/search.py index e31ab17..20cd999 100644 --- a/src/scribe/mcp/tools/search.py +++ b/src/scribe/mcp/tools/search.py @@ -112,6 +112,7 @@ async def search( return await _search_rules(uid, q, limit) is_task = {"note": False, "task": True}.get(content_type) # None => any t0 = time.perf_counter() + report: dict = {} raw = await semantic_search_notes( uid, q, limit=limit, is_task=is_task, project_id=project_id or None, @@ -119,12 +120,14 @@ async def search( # An explicit search reaches everything the operator may read, including # records shared with them one-to-one. scope="read", + report=report, ) record_retrieval( user_id=uid, source="mcp_search", query=q, threshold=DEFAULT_SIMILARITY_THRESHOLD, limit=limit, project_id=project_id or None, is_task=is_task, results=raw, duration_ms=(time.perf_counter() - t0) * 1000.0, + best_available=report.get("best_available_score"), ) owners = await owner_names_for( {int(note.user_id) for _s, note in raw if note.user_id != uid} @@ -162,18 +165,39 @@ async def retrieval_telemetry(days: int = 30) -> dict: `sources` — per retrieval surface (`auto_inject`, `write_path`, `mcp_search`, …), from `retrieval_logs`: `calls`, `zero_result_calls`, - `cleared_threshold` (how often the best hit beat the threshold in force for - that call), the `top_score` spread (p10/p50/p90/min/max), `avg_result_count` - and `p90_duration_ms`. THE number to read first is `cleared_threshold` - against `calls`, with the spread beside it: a surface that clears its bar - on nearly every call is either well-tuned or too loose, and p10 says which. + `near_misses`, the `top_score` spread (p10/p50/p90/min/max), + `avg_result_count` and `p90_duration_ms`. - READ `cleared_threshold` AND `zero_result_calls` TOGETHER, and check - `suppression` before concluding anything from either. A zero-result call is - two different events wearing one number: the ranker found nothing above the - bar, or it found only what this session had already been shown. Just the - first is evidence the bar is too high. `suppression` splits them where the - surface can tell — `zero_because_already_shown` comes off + THE NUMBER TO READ FIRST IS `near_misses.p90`, AGAINST THE THRESHOLD IN + FORCE FOR THAT SURFACE. It is measured only on the calls that returned + NOTHING, on the best score the ranker reached before the bar rejected it — + so it is the one figure here that says something the bar cannot make true + by construction. A bar at 0.72 turning away a stream of 0.71s is set too + high by a hair and the surface is losing hits it should have had. The same + bar turning away 0.30s is working, and the corpus simply had nothing. Both + render as a zero-result call, and nothing else in this readout tells them + apart. + + `near_misses` is `null` when no declining call in the window measured it — + rows written before #3670 shipped cannot know. That is "not measured", not + "nothing came close"; a 0.0 there would be a claim about the corpus + invented out of a caller's silence. + + THERE IS NO `cleared_threshold` ANY MORE, and if you remember one, that + memory is of a tautology (#3670). The search applies the bar before + returning, so every returned result cleared it by construction and a call + with no results has no score to compare: the field was true exactly when + `result_count > 0`, i.e. it was `calls - zero_result_calls` under a name + that promised a second opinion. `zero_result_calls + cleared_threshold == + calls` held on all nineteen readings ever taken. The reading procedure + built on it — "clears its bar on nearly every call" — asked you to compare + a number with itself. + + CHECK `suppression` BEFORE CONCLUDING ANYTHING FROM `zero_result_calls`. A + zero-result call is two different events wearing one number: the ranker + found nothing above the bar, or it found only what this session had already + been shown. Just the first is evidence about the bar. `suppression` splits + them where the surface can tell — `zero_because_already_shown` comes off `zero_result_calls` to leave the true ranker declines. `suppression` is `null` when NO row in the window reported it, and that is diff --git a/src/scribe/models/retrieval_log.py b/src/scribe/models/retrieval_log.py index fc85a84..9b12bc1 100644 --- a/src/scribe/models/retrieval_log.py +++ b/src/scribe/models/retrieval_log.py @@ -54,6 +54,14 @@ class RetrievalLog(Base): suppressed_count: Mapped[int | None] = mapped_column(Integer, nullable=True) top_score: Mapped[float | None] = mapped_column(Float, nullable=True) min_score: Mapped[float | None] = mapped_column(Float, nullable=True) + # The best score the ranker COULD have offered, before the threshold — as + # against `top_score`, which is the best it DID offer. They are equal on + # any call that returned something, and only this one exists on a call + # that returned nothing, which is the only place a bar can be judged from + # (#3670). Null means the caller did not measure it, never "nothing was + # close": a 0.0 there would read as a corpus with no relevant records at + # all, which is an artifact standing in for a measurement. + best_available_score: Mapped[float | None] = mapped_column(Float, nullable=True) # [{"id": int, "score": float, "rank": int}, ...], highest-first. result_ids: Mapped[list] = mapped_column(JSONB, nullable=False, default=list) duration_ms: Mapped[float | None] = mapped_column(Float, nullable=True) diff --git a/src/scribe/routes/search.py b/src/scribe/routes/search.py index 2cc891c..efba71b 100644 --- a/src/scribe/routes/search.py +++ b/src/scribe/routes/search.py @@ -44,17 +44,20 @@ async def search_route(): project_id = request.args.get("project_id", type=int) t0 = time.perf_counter() + report: dict = {} results = await semantic_search_notes( uid, q, limit=limit, is_task=is_task, threshold=_REST_SEARCH_THRESHOLD, project_id=project_id, system_id=system_id, # The user typed this, so it reaches everything they may read. scope="read", + report=report, ) record_retrieval( user_id=uid, source="rest_search", query=q, threshold=_REST_SEARCH_THRESHOLD, limit=limit, project_id=project_id, is_task=is_task, results=results, duration_ms=(time.perf_counter() - t0) * 1000.0, + best_available=report.get("best_available_score"), ) owners = await owner_names_for( {int(note.user_id) for _s, note in results if note.user_id != uid} diff --git a/src/scribe/services/embeddings.py b/src/scribe/services/embeddings.py index e5923c4..cba7fdd 100644 --- a/src/scribe/services/embeddings.py +++ b/src/scribe/services/embeddings.py @@ -448,6 +448,23 @@ async def upsert_note_embedding( logger.warning("Failed to persist embedding for note %d", note_id, exc_info=True) +# Both searches rank WITHOUT the threshold and apply it in Python, so the best +# rejected score stays observable (#3670). The qualifying set is provably +# unchanged: rows arrive ordered by distance ascending, so every above-bar row +# sorts ahead of every below-bar one, and an over-fetch that used to return N +# above-bar rows returns the same N plus some losers. What changes is only that +# the losers are now visible instead of discarded inside the query. +# +# That visibility is the entire point. A bar can only be judged from the calls +# it TURNED AWAY — a 0.72 bar rejecting a stream of 0.71s is set too high by a +# hair, one rejecting 0.30s is working — and those two are indistinguishable +# from any arrangement of the columns that survive the filter. +# +# `report` is how the score gets out without changing what a search RETURNS. +# Eight of the eleven call sites want hits and nothing else; the three that +# write telemetry pass a dict and read `best_available_score` back out of it. + + async def semantic_search_notes( user_id: int, query: str, @@ -462,12 +479,19 @@ async def semantic_search_notes( scope: str = "own", demote_superseded: bool = True, system_id: int | None = None, + report: dict | None = None, ) -> list[tuple[float, Note]]: """Return up to *limit* (score, note) pairs most relevant to *query*. Scores are cosine similarities in [-1, 1]; only notes at or above *threshold* are returned, sorted highest-first. + Pass `report` (an empty dict) to learn what the threshold turned away: + the function sets `report["best_available_score"]` to the highest score + anything reached, or None when the corpus offered nothing at all. It is + the only figure that survives a call returning nothing, and therefore the + only one a bar can be judged from (#3670). + `note_type` narrows to a record kind, or several (e.g. "snippet", or ("snippet", "note")), for callers that want prior art rather than everything embedded. @@ -513,7 +537,6 @@ async def semantic_search_notes( # Distance ceiling equivalent to the similarity floor. Clamp to the valid # cosine-distance range [0, 2] so a threshold of, say, -1 doesn't produce a # nonsensical ceiling. - max_distance = min(2.0, max(0.0, 1.0 - threshold)) distance = NoteEmbedding.embedding.cosine_distance(query_vec) try: @@ -588,11 +611,10 @@ async def semantic_search_notes( fetch = limit * _CHUNK_OVERFETCH * ( _SUPERSESSION_OVERFETCH if demote_superseded else 1 ) - stmt = ( - stmt.where(distance <= max_distance) - .order_by(distance.asc()) - .limit(fetch) - ) + # NO threshold predicate — see the note above this function. The + # bar is applied after the collapse, where the rejected scores can + # still be seen. + stmt = stmt.order_by(distance.asc()).limit(fetch) rows = list((await session.execute(stmt)).all()) except Exception: logger.warning("Failed to query note embeddings", exc_info=True) @@ -611,6 +633,11 @@ async def semantic_search_notes( continue seen.add(int(note.id)) scored.append((1.0 - float(dist), note)) + # The best score anything reached, bar or no bar. Recorded BEFORE the + # filter because a call that returns nothing is exactly when it matters. + if report is not None: + report["best_available_score"] = scored[0][0] if scored else None + scored = [pair for pair in scored if pair[0] >= threshold] if not demote_superseded: return scored[:limit] return await _apply_supersession_penalty(scored, limit) @@ -764,9 +791,16 @@ async def semantic_search_rules( limit: int = 5, threshold: float = _SIMILARITY_THRESHOLD, tier: str | None = None, + report: dict | None = None, ) -> list[tuple[float, "Rule"]]: """Return up to *limit* (score, rule) pairs most relevant to *query*. + Pass `report` (an empty dict) to learn what the threshold turned away: + the function sets `report["best_available_score"]` to the highest score + anything reached, or None when the corpus offered nothing at all. It is + the only figure that survives a call returning nothing, and therefore the + only one a bar can be judged from (#3670). + Scoped by OWNERSHIP — a rule is the caller's if they own its rulebook or its project. Deliberately not filtered to what currently BINDS a given project: this answers "is there a rule about this", which a person asking @@ -802,7 +836,6 @@ async def semantic_search_rules( logger.debug("Rule search skipped — embedder unavailable") return [] - max_distance = min(2.0, max(0.0, 1.0 - threshold)) distance = RuleEmbedding.embedding.cosine_distance(query_vec) try: @@ -816,7 +849,8 @@ async def semantic_search_rules( .outerjoin(Project, Rule.project_id == Project.id) .where( Rule.deleted_at.is_(None), - distance <= max_distance, + # No threshold predicate — see the note above + # semantic_search_notes. Applied below, after the collapse. # topic_id XOR project_id, so exactly one arm can match. or_( Rulebook.owner_user_id == user_id, @@ -839,7 +873,9 @@ async def semantic_search_rules( if rule.id not in best or score > best[rule.id][0]: best[rule.id] = (score, rule) ranked = sorted(best.values(), key=lambda pair: pair[0], reverse=True) - return ranked[:limit] + if report is not None: + report["best_available_score"] = ranked[0][0] if ranked else None + return [pair for pair in ranked if pair[0] >= threshold][:limit] async def backfill_rule_embeddings() -> None: diff --git a/src/scribe/services/plugin_context.py b/src/scribe/services/plugin_context.py index 3ce4dda..9c873c7 100644 --- a/src/scribe/services/plugin_context.py +++ b/src/scribe/services/plugin_context.py @@ -463,6 +463,7 @@ async def _reserve_slot_for_reuse( top_k = cfg["top_k"] _t0 = time.perf_counter() + _rep: dict = {} reuse = await semantic_search_notes( user_id, query, limit=1, @@ -471,6 +472,7 @@ async def _reserve_slot_for_reuse( exclude_ids=exclude_ids | {int(n.id) for _s, n in kept}, note_type=_REUSE_KINDS, scope="browse", + report=_rep, ) # A real semantic query competing for a menu slot — logged like the scored # arm it displaces. Before this, the hit it PUSHED OUT was in @@ -481,6 +483,7 @@ async def _reserve_slot_for_reuse( user_id=user_id, source="reuse_slot", query=query, threshold=cfg["threshold"], limit=1, project_id=project_id, is_task=None, results=reuse, + best_available=_rep.get("best_available_score"), duration_ms=(time.perf_counter() - _t0) * 1000.0, ) # Verify the kind rather than trusting the query that asked for it, and @@ -530,6 +533,7 @@ async def build_autoinject_hint( return empty t0 = time.perf_counter() + _rep_ai: dict = {} hits = await semantic_search_notes( user_id, q, limit=cfg["top_k"], @@ -541,11 +545,13 @@ async def build_autoinject_hint( # still appear is a collaborator's note inside a shared project — legible # only because the line below names its owner. scope="browse", + report=_rep_ai, ) record_retrieval( user_id=user_id, source="auto_inject", query=q, threshold=cfg["threshold"], limit=cfg["top_k"], project_id=(project_id or None), is_task=None, results=hits, + best_available=_rep_ai.get("best_available_score"), duration_ms=(time.perf_counter() - t0) * 1000.0, ) if not hits: @@ -972,6 +978,7 @@ async def build_write_path_hint( # Pulled-and-seen ids stay in the query (as evidence) but never in # the menu — the dedup contract holds, the resemblance still lands. pulled_seen = seen & set(pulled) + _rep_wp: dict = {} hits = await semantic_search_notes( user_id, query, limit=remaining + len(pulled_seen), @@ -995,6 +1002,7 @@ async def build_write_path_hint( # Same reasoning as auto-inject: nobody asked for this, so it takes # the browse scope and never surfaces a one-to-one direct share. scope="browse", + report=_rep_wp, ) resembles = { int(note.id): float(score) for score, note in hits @@ -1008,6 +1016,7 @@ async def build_write_path_hint( # recording it as a notes-only retrieval would misdescribe the # candidate set the threshold is being tuned against. project_id=scope_project, is_task=None, results=hits, + best_available=_rep_wp.get("best_available_score"), duration_ms=(time.perf_counter() - t0) * 1000.0, ) if hits: @@ -1251,9 +1260,11 @@ async def build_write_path_hint( # — a gap that reads as "this surface is somehow not measurable" rather # than "nobody passed the number". rule_t0 = time.perf_counter() + _rep_wpr: dict = {} hits = await semantic_search_rules( user_id, code or path, limit=RULEHINT_LIMIT, threshold=cfg["rule_threshold"], + report=_rep_wpr, ) rule_ms = (time.perf_counter() - rule_t0) * 1000.0 fresh = [(score, rule) for score, rule in hits if rule.id not in already] @@ -1301,6 +1312,7 @@ async def build_write_path_hint( threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, is_task=None, results=fresh, duration_ms=rule_ms, + best_available=_rep_wpr.get("best_available_score"), # What the ranker found and this session had already been told. # Without it a zero row cannot say whether the bar was too high or # the reader was simply ahead of it — and only the first is a @@ -1383,9 +1395,11 @@ async def build_tool_rule_hint( query = command[:_TOOL_QUERY_CHARS] t0 = time.perf_counter() + _rep_ptr: dict = {} hits = await semantic_search_rules( user_id, query, limit=RULEHINT_LIMIT, threshold=cfg["rule_threshold"], + report=_rep_ptr, ) duration_ms = (time.perf_counter() - t0) * 1000.0 @@ -1405,6 +1419,7 @@ async def build_tool_rule_hint( threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, project_id=project_id, is_task=None, results=fresh, duration_ms=duration_ms, + best_available=_rep_ptr.get("best_available_score"), # See the sibling arm. It matters more here: this arm fires on every # Bash call, so a long session excludes its way to an all-zero row # and the threshold looks wrong when nothing about it is. diff --git a/src/scribe/services/retrieval_telemetry.py b/src/scribe/services/retrieval_telemetry.py index fe5908d..18e94df 100644 --- a/src/scribe/services/retrieval_telemetry.py +++ b/src/scribe/services/retrieval_telemetry.py @@ -56,6 +56,7 @@ def _build_payload( results: list[tuple[float, Note]], duration_ms: float | None, suppressed: int | None = None, + best_available: float | None = None, ) -> dict: """Reduce a retrieval call to a flat, JSON-safe RetrievalLog payload. @@ -67,6 +68,13 @@ def _build_payload( had already been shown them, and it stays None for callers that cannot know. See the column's comment: None means "not measured here", which is a different fact from 0 and must never render as one. + + `best_available` is the highest score the ranker reached BEFORE the + threshold, and it carries the same null discipline for a sharper reason: it + is the only field that still says something on a call that returned + nothing, so a 0.0 standing in for "not measured" would read as "the corpus + held nothing remotely relevant" — a claim about the corpus invented out of + a caller's silence. """ items = [ {"id": int(note.id), "score": round(float(score), 5), "rank": rank} @@ -85,6 +93,9 @@ def _build_payload( "suppressed_count": (None if suppressed is None else int(suppressed)), "top_score": (scores[0] if scores else None), "min_score": (scores[-1] if scores else None), + "best_available_score": ( + None if best_available is None else round(float(best_available), 5) + ), "result_ids": items, "duration_ms": (round(duration_ms, 2) if duration_ms is not None else None), } @@ -123,6 +134,7 @@ def record_retrieval( results: list[tuple[float, Any]], duration_ms: float | None = None, suppressed: int | None = None, + best_available: float | None = None, ) -> None: """Fire-and-forget: record one retrieval call. @@ -149,6 +161,7 @@ def record_retrieval( results=results, duration_ms=duration_ms, suppressed=suppressed, + best_available=best_available, ) except Exception: logger.debug("retrieval telemetry payload build failed", exc_info=True) @@ -175,19 +188,25 @@ def record_retrieval( def _bucket(rows: list) -> dict: """A score readout a human can act on, from one aggregate row.""" - (calls, zero, cleared, p10, p50, p90, lo, hi, avg_n, dur, - measured, supp_calls, supp_zero) = rows + (calls, zero, p10, p50, p90, lo, hi, avg_n, dur, + measured, supp_calls, supp_zero, + miss_calls, miss_p50, miss_p90, miss_max) = rows return { "calls": int(calls or 0), # A call that returned nothing is not a low-scoring call — it is a # different failure (nothing indexed, filter too narrow), and averaging # it into the score distribution would hide both. "zero_result_calls": int(zero or 0), - # How often the best hit actually cleared the threshold in force for - # that call. THE precision-adjacent number: a surface that clears its - # bar on almost every call is either well-tuned or too loose, and the - # score spread below says which. - "cleared_threshold": int(cleared or 0), + # `cleared_threshold` USED TO LIVE HERE and it was a tautology (#3670). + # The search applies the bar before returning, so every returned result + # cleared it by construction and a call with nothing has no score to + # compare — the condition was true exactly when `result_count > 0`. + # `zero_result_calls + cleared_threshold == calls` held on all nineteen + # readings ever taken. It was `calls - zero_result_calls` wearing a name + # that promised a second opinion, and the docstring built a reading + # procedure on it that asked the reader to compare a number with itself. + # Its replacement is `near_misses` below, which the bar cannot fix by + # construction because it is measured on the calls the bar REJECTED. # Of the zeros above, which were the RANKER declining and which were # the reader having seen it already? `zero_result_calls` cannot say, # and only the first kind is evidence about the threshold. @@ -208,6 +227,28 @@ def _bucket(rows: list) -> dict: "p10": _round(p10), "p50": _round(p50), "p90": _round(p90), "min": _round(lo), "max": _round(hi), }, + # WHAT THE BAR TURNED AWAY, and the only figure here a threshold can + # actually be tuned from. Measured over the calls that returned + # NOTHING, on the best score the ranker reached before the filter. + # + # Read `p90` against the threshold in force. A bar at 0.72 rejecting a + # stream of 0.71s is set too high by a hair and the surface is losing + # hits it should have had; the same bar rejecting 0.30s is doing its + # job and the corpus simply had nothing. Both render as a zero-result + # call, and nothing else in this readout separates them. + # + # None — not a zeroed block — when no declining call in the window + # measured it. Old rows predate the column, and a 0.0 would assert that + # the corpus held nothing relevant, which is a claim about the corpus + # invented out of a caller's silence. + "near_misses": ( + None if not int(miss_calls or 0) else { + "measured_calls": int(miss_calls or 0), + "p50": _round(miss_p50), + "p90": _round(miss_p90), + "max": _round(miss_max), + } + ), "avg_result_count": _round(avg_n), "p90_duration_ms": _round(dur, 1), } @@ -215,11 +256,13 @@ 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] +# `_bucket` unpacks — calls, zero, p10, p50, p90, min, max, avg_n, +# dur, measured, supp_calls, supp_zero, miss_calls, miss_p50, miss_p90, +# miss_max. The 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, None, None, None, None, None, None, None, + 0, 0, 0, 0, None, None, None] def _round(v, places: int = 4): @@ -316,16 +359,22 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict: "read_failed": False, } - cleared = case( - ( - (RetrievalLog.threshold.isnot(None)) - & (RetrievalLog.top_score.isnot(None)) - & (RetrievalLog.top_score >= RetrievalLog.threshold), - 1, - ), - else_=0, - ) zero = case((RetrievalLog.result_count == 0, 1), else_=0) + # THE NEAR-MISS POPULATION: calls that returned nothing AND recorded what + # the bar turned away. Both conditions matter. Restricting to zero-result + # calls is what makes the number say something the bar cannot fix by + # construction — on a call that returned something, `best_available_score` + # equals `top_score` and adds nothing. Requiring the column to be non-null + # keeps rows written before #3670 out of the sample rather than letting + # them read as scoreless declines. + declined = (RetrievalLog.result_count == 0) & ( + RetrievalLog.best_available_score.isnot(None) + ) + miss = case((declined, 1), else_=0) + # `best_available_score` only for those rows; NULL elsewhere, and + # percentile_cont ignores NULLs, so the distribution is over the declines + # alone without a second pass over the table. + miss_score = case((declined, RetrievalLog.best_available_score), else_=None) # Three sums rather than one, because "not measured" and "measured as zero" # are different answers and a single counter cannot hold both. measured = case((RetrievalLog.suppressed_count.isnot(None), 1), else_=0) @@ -355,7 +404,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict: RetrievalLog.source, func.count().label("calls"), func.sum(zero).label("zero"), - func.sum(cleared).label("cleared"), pct(0.1), pct(0.5), pct(0.9), func.min(RetrievalLog.top_score), func.max(RetrievalLog.top_score), @@ -366,6 +414,10 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict: func.sum(measured).label("measured"), func.sum(supp_calls).label("supp_calls"), func.sum(supp_zero).label("supp_zero"), + func.sum(miss).label("miss_calls"), + func.percentile_cont(0.5).within_group(miss_score.asc()), + func.percentile_cont(0.9).within_group(miss_score.asc()), + func.max(miss_score), ) .where( RetrievalLog.created_at >= since, diff --git a/tests/test_services_retrieval_telemetry.py b/tests/test_services_retrieval_telemetry.py index c0eca30..ff5b8fd 100644 --- a/tests/test_services_retrieval_telemetry.py +++ b/tests/test_services_retrieval_telemetry.py @@ -102,14 +102,14 @@ def test_the_readout_reports_unmeasured_suppression_as_none(): zeroed dict: a zeroed dict states a measurement nobody made.""" from scribe.services.retrieval_telemetry import _bucket - # calls, zero, cleared, p10, p50, p90, min, max, avg_n, dur, - # measured, supp_calls, supp_zero - unmeasured = _bucket([326, 114, 212, 0.6, 0.68, 0.77, 0.55, 0.85, 1.7, 130.9, - 0, 0, 0]) + # calls, zero, p10, p50, p90, min, max, avg_n, dur, + # measured, supp_calls, supp_zero, miss_calls, miss_p50, miss_p90, miss_max + unmeasured = _bucket([326, 114, 0.6, 0.68, 0.77, 0.55, 0.85, 1.7, 130.9, + 0, 0, 0, 0, None, None, None]) assert unmeasured["suppression"] is None - measured = _bucket([35, 34, 1, 0.75, 0.75, 0.75, 0.75, 0.75, 0.03, 51.9, - 35, 9, 9]) + measured = _bucket([35, 34, 0.75, 0.75, 0.75, 0.75, 0.75, 0.03, 51.9, + 35, 9, 9, 0, None, None, None]) assert measured["suppression"] == { "measured_calls": 35, "calls_with_suppression": 9, @@ -224,7 +224,10 @@ async def test_retrieval_summary_reads_what_the_writer_wrote(_dispose_engine): ai = out["sources"]["auto_inject"] assert ai["calls"] == 4 assert ai["zero_result_calls"] == 1 - assert ai["cleared_threshold"] == 2 # 0.91 and 0.72, not 0.40 + assert "cleared_threshold" not in ai, ( + "the tautology is back: it was true exactly when result_count > 0, " + "so it reported nothing zero_result_calls did not (#3670)" + ) # p50 over the three scored calls; the empty one contributes no score. assert ai["top_score"]["p50"] == pytest.approx(0.72, abs=1e-4) assert ai["top_score"]["min"] == pytest.approx(0.40, abs=1e-4) @@ -847,3 +850,176 @@ async def test_a_section_is_complete_only_from_its_latest_contributor( async with async_session() as s: await s.execute(delete(RuleUsageEvent).where(RuleUsageEvent.user_id == UID)) await s.commit() + + +# ─── the bar can only be judged from what it rejected (#3670) ──────────────── +# +# `cleared_threshold` was the number the docstring told a reader to look at +# first. It was `calls - zero_result_calls` under another name: the search +# applies the bar before returning, so every returned result cleared it by +# construction and a call with nothing has no score to compare. +# `zero_result_calls + cleared_threshold == calls` held on all nineteen +# source/window readings ever taken — no near-misses, no exceptions. +# +# What replaced it cannot go the same way, and the reason is structural rather +# than careful naming: `near_misses` is measured on the calls the bar TURNED +# AWAY, using a score the bar never saw. No arrangement of `calls`, +# `zero_result_calls` and `result_count` derives it. + + +def test_a_call_that_returned_nothing_still_records_what_it_nearly_showed(): + """The whole point, at the payload grain. + + This is the row a threshold is tuned from and the one that used to carry no + score at all: `top_score` and `min_score` are both null here, correctly, and + a reader was left unable to tell a bar rejecting 0.71s from one rejecting + 0.30s. Both render as a zero-result call. + """ + p = _build_payload( + user_id=1, source="pre_tool_rule", query="git push --force", + threshold=0.72, limit=1, project_id=None, is_task=None, + results=[], duration_ms=None, best_available=0.7104, + ) + assert p["result_count"] == 0 + assert p["top_score"] is None, "nothing was shown, so nothing has a top score" + assert p["best_available_score"] == 0.7104, ( + "the losing score was discarded — the only figure that survives a call " + "returning nothing, and the only one a bar can be judged from" + ) + + +def test_a_caller_that_did_not_measure_the_near_miss_stores_null(): + """Null, never 0.0. A zero here reads as "the corpus held nothing remotely + relevant" — a claim about the corpus invented out of a caller's silence, + which is #3311's substitution in a new field.""" + p = _build_payload( + user_id=1, source="auto_inject", query="q", threshold=0.6, + limit=3, project_id=None, is_task=None, results=[], duration_ms=None, + ) + assert p["best_available_score"] is None + + +def test_the_readout_reports_unmeasured_near_misses_as_none(): + """`_bucket`'s half of the same discipline, and the reason it is a block + rather than three loose keys: old rows predate the column, so a window can + legitimately contain declines nobody measured.""" + from scribe.services.retrieval_telemetry import _bucket + + # calls, zero, p10, p50, p90, min, max, avg_n, dur, + # measured, supp_calls, supp_zero, miss_calls, miss_p50, miss_p90, miss_max + none_measured = _bucket([326, 114, 0.6, 0.68, 0.77, 0.55, 0.85, 1.7, 130.9, + 0, 0, 0, 0, None, None, None]) + assert none_measured["near_misses"] is None + + measured = _bucket([326, 114, 0.6, 0.68, 0.77, 0.55, 0.85, 1.7, 130.9, + 0, 0, 0, 114, 0.61, 0.7104, 0.7189]) + assert measured["near_misses"] == { + "measured_calls": 114, + "p50": 0.61, + "p90": 0.7104, + "max": 0.7189, + } + + +def test_the_readout_carries_no_field_derivable_from_its_neighbours(): + """The guard that would have caught #3670 on the day it shipped. + + `cleared_threshold` survived because it had its own name and its own + docstring paragraph, and nobody added the two numbers beside it. This + asserts the identity that held on every reading ever taken — and if a + future field reintroduces it under a new name, the sum below is where it + shows up. + """ + from scribe.services.retrieval_telemetry import _bucket + + b = _bucket([326, 114, 0.6, 0.68, 0.77, 0.55, 0.85, 1.7, 130.9, + 0, 0, 0, 114, 0.61, 0.71, 0.72]) + derivable = { + k for k, v in b.items() + if isinstance(v, int) and not isinstance(v, bool) + and k not in ("calls", "zero_result_calls") + and v == b["calls"] - b["zero_result_calls"] + } + assert not derivable, ( + f"{sorted(derivable)} equals calls - zero_result_calls on this row. " + f"That is how `cleared_threshold` read for its whole life (#3670): a " + f"figure presented as an independent measurement that a reader can " + f"compute from the two numbers next to it. Either it is a tautology, " + f"or this fixture happens to make it look like one — check which " + f"before adding an exemption." + ) + + +@pytest.mark.integration +@pytest.mark.asyncio +async def test_the_near_miss_distribution_is_a_query_postgres_accepts(_dispose_engine): + """Integration, and NOT belt-and-braces on the unit tests above. + + `near_misses` is a `percentile_cont(...) WITHIN GROUP` over a CASE + expression, inside the same grouped aggregate that already carries four + other CASEs. That is within one step of the shape that produced #2663 — a + query the database rejected, swallowed by this module's broad `except`, so + every counter read zero in production while the writes landed fine and the + mocked tests passed. Only a real Postgres can say this parses, and if it + does not, the symptom is silence rather than an error. + + The numbers are chosen so a bar at 0.72 is visibly the wrong bar: three + declines at 0.70, 0.71 and 0.7189, none of which a reader could see before. + """ + from sqlalchemy import delete + + from scribe.models import async_session + from scribe.models.retrieval_log import RetrievalLog + from scribe.services.retrieval_telemetry import ( + _insert_retrieval_log, retrieval_summary, + ) + + UID = 990079 + for best in (0.70, 0.71, 0.7189): + await _insert_retrieval_log(_build_payload( + user_id=UID, source="pre_tool_rule", query="git push", threshold=0.72, + limit=1, project_id=None, is_task=None, results=[], + duration_ms=4.0, best_available=best, + )) + # A call that DID show something. Its best-available equals its top score, + # so including it would drag the distribution toward the scores the bar + # already accepts — the population has to be the declines alone. + await _insert_retrieval_log(_build_payload( + user_id=UID, source="pre_tool_rule", query="curl", threshold=0.72, + limit=1, project_id=None, is_task=None, + results=[(0.88, _note(7))], duration_ms=4.0, best_available=0.88, + )) + # An unmeasured decline, standing in for every row written before #3670. + await _insert_retrieval_log(_build_payload( + user_id=UID, source="pre_tool_rule", query="ls", threshold=0.72, + limit=1, project_id=None, is_task=None, results=[], duration_ms=4.0, + )) + + try: + out = await retrieval_summary(UID, days=30) + assert out["read_failed"] is False, ( + "the aggregate did not execute — a rejected query here reads as " + "zeros everywhere, which is #2663 exactly" + ) + src = out["sources"]["pre_tool_rule"] + assert src["calls"] == 5 + assert src["zero_result_calls"] == 4 + + nm = src["near_misses"] + assert nm is not None, "the near-miss block did not survive the query" + assert nm["measured_calls"] == 3, ( + "the population is declines that RECORDED a score: three measured, " + "one unmeasured (excluded, not counted as a scoreless decline), and " + "one call that showed something (excluded — its best-available is " + "just its top score and says nothing about the bar)" + ) + assert nm["max"] == pytest.approx(0.7189, abs=1e-4), ( + "the closest thing the bar turned away — 0.7189 against a 0.72 " + "threshold, which is the reading the whole field exists to give" + ) + assert nm["max"] < 0.72, "a near miss that cleared the bar is not a miss" + assert 0.70 <= nm["p50"] <= 0.7189 + finally: + async with async_session() as s: + await s.execute(delete(RetrievalLog).where(RetrievalLog.user_id == UID)) + await s.commit()