Compare commits

..
9 Commits
Author SHA1 Message Date
bvandeusen 14ff41faf5 Merge pull request 'feat(rules): rule creation becomes propose-then-approve (#3557)' (#141) from dev into main
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / TypeScript typecheck (push) Successful in 22s
CI & Build / integration (push) Successful in 30s
CI & Build / Python tests (push) Successful in 1m2s
CI & Build / Build & push image (push) Successful in 19s
2026-09-04 22:01:47 -04:00
bvandeusen 67df41ae00 Merge pull request 'feat(rules): the instruction surfaces say to RETRIEVE a rule, not only to receive one (#3523)' (#140) from dev into main
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / integration (push) Successful in 32s
CI & Build / Python tests (push) Successful in 1m5s
CI & Build / TypeScript typecheck (push) Successful in 3m18s
CI & Build / Build & push image (push) Successful in 16s
2026-09-03 22:07:10 -04:00
bvandeusen 0915c48bb0 Merge pull request 'feat(telemetry): tell a ranker decline from a repeat before the observation window opens (#3497)' (#139) from dev into main
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / integration (push) Successful in 30s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / TypeScript typecheck (push) Successful in 5m20s
CI & Build / Build & push image (push) Successful in 17s
2026-09-03 21:23:01 -04:00
bvandeusen aea7b63b62 Merge pull request 'fix(telemetry): both rule arms logged only their hits, so the clear-rate could only read 100% (#3497)' (#138) from dev into main
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / integration (push) Successful in 30s
CI & Build / TypeScript typecheck (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m5s
CI & Build / Build & push image (push) Successful in 17s
2026-09-03 07:19:08 -04:00
bvandeusen 5b02908dfd dev → main: rules become measurable at the preload, and retrievable at the tool call (#137)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / integration (push) Successful in 29s
CI & Build / TypeScript typecheck (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 17s
2026-09-02 23:41:09 -04:00
bvandeusen 34cd389371 dev → main: rule usage telemetry, the plugin's derived version (#136)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / TypeScript typecheck (push) Successful in 23s
CI & Build / integration (push) Successful in 30s
CI & Build / Python tests (push) Successful in 1m5s
CI & Build / Build & push image (push) Successful in 16s
2026-09-02 18:52:20 -04:00
bvandeusen b267037911 Two milestones: a note can carry its own check (317), and a rule keeps what it used to say (323) (#135)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 11s
CI & Build / TypeScript typecheck (push) Successful in 38s
CI & Build / integration (push) Successful in 55s
CI & Build / Python tests (push) Successful in 1m37s
CI & Build / Build & push image (push) Successful in 29s
2026-08-31 00:01:15 -04:00
bvandeusen 93d660b710 Tool disambiguators, kind badges, and a badge layer that clears AA (#3123, #3124, #3132)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / integration (push) Successful in 31s
CI & Build / TypeScript typecheck (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m17s
CI & Build / Build & push image (push) Successful in 15s
2026-08-27 21:28:48 -04:00
bvandeusen 056c7c75da A task's kind is correctable — the Kind select stops lying (#3129)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 7s
CI & Build / integration (push) Successful in 28s
CI & Build / TypeScript typecheck (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 15s
2026-08-27 18:05:16 -04:00
9 changed files with 66 additions and 982 deletions
@@ -1,62 +0,0 @@
"""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")
+15 -68
View File
@@ -112,7 +112,6 @@ 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,
@@ -120,14 +119,12 @@ 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}
@@ -165,41 +162,18 @@ 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`,
`near_misses`, the `top_score` spread (p10/p50/p90/min/max),
`avg_result_count` and `p90_duration_ms`.
`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.
THE NUMBER TO READ FIRST IS `near_misses.p90`, AGAINST THE THRESHOLD IN
FORCE FOR THAT SURFACE. It is measured on the calls the BAR turned away —
zero-result calls, minus the ones whose zero was a repeat the reader had
already been shown — using 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, and `max` is always below the threshold:
an above-bar candidate nobody excluded would have been returned. 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
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
`zero_result_calls` to leave the true ranker declines.
`suppression` is `null` when NO row in the window reported it, and that is
@@ -263,37 +237,10 @@ It is an UPPER BOUND per surface: a pull records the door it came
those same rules over time: a resident set surfaced thousands of times and
opened never is the dead-weight signal, one tier up.
Read it against `sources["write_path_rule"]`. That arm was once believed
never to decline — the reading that scoped #3311 — but it was the arm's
`retrieval_logs` row being written only on calls that FOUND something, so
the zeros were missing rather than absent (#3497). Measured since, it
declines the large majority of its calls like any other surface.
EVERY COUNTER BLOCK CARRIES ITS OWN COVERAGE — `complete_from` and
`covers_window`. `complete_from` is when the number became trustworthy:
for one source, its first recorded row; for a section that sums several,
the LATEST of theirs, because a total is complete only once every
contributor was being written. `covers_window: false` means the window
reaches back further than the recording does, so the count is a fraction
of the period it appears to describe.
READ IT BEFORE COMPARING TWO NUMBERS, and especially before comparing
across a deploy. A counter added last week, read over a 30-day window,
reports a real count against an imagined denominator — and the result is
a plausible fraction rather than an obvious zero, which is what makes it
dangerous. That reading cost milestone #379 five steps aimed at a defect
that did not exist.
`covers_window` is null, never false, when nothing was ever recorded:
"no measurement" is not "partial measurement", the same distinction
`suppression`'s null carries a few paragraphs up.
A SOURCE SHOWING `calls: 0` WAS RECORDING AND MADE NO CALLS. `sources`
lists every source the table has ever held, not only those active in the
window, so a surface that stopped firing stays visible rather than
disappearing — being absent is reserved for a source that has never
recorded at all. Its score fields are null, not zero: the calls are a
real observation, the distribution is not one.
Read it against `sources["write_path_rule"]`. That surface has never once
declined to fire, and until this block existed there was no way to tell a
well-tuned arm from a bar it cannot fail to clear (#3311). `pull_through`
is the number that tells them apart.
`rule_usage_failed: true` means that read failed while the rest of the
readout stood. The counts are still present so a caller can render, but
-8
View File
@@ -54,14 +54,6 @@ 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)
-3
View File
@@ -44,20 +44,17 @@ 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}
+13 -56
View File
@@ -448,23 +448,6 @@ 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,
@@ -479,19 +462,12 @@ 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.
@@ -537,6 +513,7 @@ 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:
@@ -611,10 +588,11 @@ async def semantic_search_notes(
fetch = limit * _CHUNK_OVERFETCH * (
_SUPERSESSION_OVERFETCH if demote_superseded else 1
)
# 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)
stmt = (
stmt.where(distance <= max_distance)
.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)
@@ -633,11 +611,6 @@ 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)
@@ -791,16 +764,9 @@ 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
@@ -808,17 +774,10 @@ async def semantic_search_rules(
is the surfacing question, and it has its own machinery
(get_applicable_rules) rather than a second, subtly different copy here.
`tier` narrows to one tier, and NONE is the ordinary case. The write-path
and pre-tool hints deliberately pass nothing: an always-on rule is already
in the session, but being in a list from turn zero is not the same as being
in front of the reader when the action it governs is taken, and filtering
on tier made a whole class of rules permanently ineligible for the one
mechanism that surfaces a rule AT the moment. Relevance is the threshold's
job; see the block above RULEHINT_LIMIT in services/plugin_context.py for
the argument and for what the resulting scores are being read against.
Pass a tier when a caller genuinely wants one class — a listing, an audit,
a UI that renders the tiers apart. Not to approximate relevance.
`tier` narrows to one tier. The write-path hint passes "conditional",
because an always-on rule is ALREADY in the session — surfacing it again as
a suggestion is pure noise, and noise on a hint that fires on every write
is how a hint gets ignored.
Collapses to best-chunk-per-rule like the note search, so a long rule split
across chunks competes once rather than crowding the results with itself.
@@ -836,6 +795,7 @@ 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:
@@ -849,8 +809,7 @@ async def semantic_search_rules(
.outerjoin(Project, Rule.project_id == Project.id)
.where(
Rule.deleted_at.is_(None),
# No threshold predicate — see the note above
# semantic_search_notes. Applied below, after the collapse.
distance <= max_distance,
# topic_id XOR project_id, so exactly one arm can match.
or_(
Rulebook.owner_user_id == user_id,
@@ -873,9 +832,7 @@ 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)
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]
return ranked[:limit]
async def backfill_rule_embeddings() -> None:
+12 -75
View File
@@ -94,17 +94,13 @@ WRITEPATH_DEFAULT_THRESHOLD = 0.68
# THE STRUCTURAL ARGUMENT, which is the only kind admissible here (rule 115).
# Two facts hold on any install, including one with six rules and no telemetry:
#
# 1. The eligible corpus is SMALL — every rule an install owns, still only
# a few dozen documents against thousands of notes. A top-k over a small
# pool always returns something, so "the best match cleared the bar"
# drifts from "a good match exists" toward "N things were ranked". A bar
# calibrated for best-of-thousands is cleared by best-of-forty as
# arithmetic rather than relevance.
# This argument WEAKENED when the arms stopped filtering to one tier
# (see the note on that below): a larger pool makes clearing the bar
# mean more, not less. The threshold was deliberately left where it was
# anyway — moving two variables at once would make the resulting
# distribution unreadable, and this one errs toward silence on purpose.
# 1. The eligible corpus is TINY. The arm searches `tier="conditional"`
# rules only — a handful to a few dozen documents against thousands of
# notes. A top-k over forty candidates always returns something, so
# "the best match cleared the bar" stops meaning "a good match exists"
# and starts meaning "forty things were ranked". A bar calibrated for
# best-of-thousands is cleared by best-of-forty as arithmetic, not
# relevance.
# 2. Rules are short imperative technical English — a far more HOMOGENEOUS
# corpus than note prose. #2223 measured the floor for code against prose
# at 0.55-0.63 and set 0.68 above it. A more homogeneous corpus has a
@@ -132,14 +128,9 @@ RULEHINT_DEFAULT_THRESHOLD = 0.72
# ONE rule per write, not two — and this is deliberately NOT a knob.
#
# With a corpus this small, top-k does as much damage as the threshold: k=2
# over a few dozen candidates means the second line is almost always the
# second-best noise, arriving with the same confident framing as the first.
# Halving k halves that regardless of where the bar sits.
#
# It also BOUNDS the blast radius of widening the pool (below): with k=1 a
# wider corpus can change WHICH rule surfaces and how often one does, but it
# can never make a single hint longer. The loudness of one hint and the
# eligibility of a rule are separate controls, and only one of them moved.
# over forty candidates means the second line is almost always the second-best
# noise, arriving with the same confident framing as the first. Halving k
# halves that regardless of where the bar sits.
#
# It stays a constant because it is a decision about how LOUD one hint may be,
# not a per-install tuning question. The hint already carries prior art, shape
@@ -149,45 +140,6 @@ RULEHINT_DEFAULT_THRESHOLD = 0.72
# adds a way to misconfigure the surface (rule 25 cuts both ways).
RULEHINT_LIMIT = 1
# WHY THE ARMS NO LONGER FILTER TO ONE TIER (#3702).
#
# Both arms used to pass `tier="conditional"`, on the reasoning that an
# always-on rule is already in the session, so surfacing it again is pure
# noise. That reasoning conflates two different things:
#
# PRESENT IN CONTEXT — the rule was delivered at session start.
# SALIENT AT THE MOMENT — the rule is in front of the reader when the
# action it governs is about to be taken.
#
# A rule handed over in a list at turn zero is present while a session writes
# a config value three hundred turns later. It is not surfaced. So the filter
# did not merely skip a redundant hint — it made a whole class of rules
# permanently ineligible for the only mechanism that puts a rule in front of
# an agent AT the moment, and the more important a rule is, the more likely
# it was in that class.
#
# The deeper defect is that the filter was doing the THRESHOLD's job. Whether
# a rule belongs in this hint is a relevance question, and a similarity bar is
# the control for relevance. A categorical exclusion standing in for a
# relevance judgment cannot be tuned, cannot be measured, and cannot be wrong
# in a way anybody notices.
#
# THIS IS A MEASURED CHANGE, NOT A SETTLED ONE. The old comment's fear is
# real — a hint that fires on every write and says obvious things teaches the
# reader to skip the block, and the surface is then lost along with its true
# positives. That fear had simply never been checked. `retrieval_logs` already
# records top_score, result_count and the query for every call, so the
# evidence now arrives on its own:
#
# - rules clear the bar often and at high scores -> the fear was justified,
# the filter was a crude proxy for a bar set too low, and the WORK IS THE
# BAR. Any reinstated filter should then carry a measured reason.
# - rules clear rarely, in a thin band near the bar -> the filter was never
# the right instrument and relevance was always sufficient.
#
# Only the eligibility moved. The bar and k=1 were both left exactly where
# they were, so the resulting distribution has one cause.
# How much of a command reaches the embedding (#3476). A shell call is not a
# file: most are short, and the ones that are not are usually a heredoc or a
# pasted script whose bulk says nothing about which rule applies. The VERB AND
@@ -463,7 +415,6 @@ 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,
@@ -472,7 +423,6 @@ 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
@@ -483,7 +433,6 @@ 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
@@ -533,7 +482,6 @@ 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"],
@@ -545,13 +493,11 @@ 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:
@@ -978,7 +924,6 @@ 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),
@@ -1002,7 +947,6 @@ 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
@@ -1016,7 +960,6 @@ 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:
@@ -1260,11 +1203,9 @@ 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,
threshold=cfg["rule_threshold"], tier="conditional",
)
rule_ms = (time.perf_counter() - rule_t0) * 1000.0
fresh = [(score, rule) for score, rule in hits if rule.id not in already]
@@ -1312,7 +1253,6 @@ 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
@@ -1395,11 +1335,9 @@ 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,
threshold=cfg["rule_threshold"], tier="conditional",
)
duration_ms = (time.perf_counter() - t0) * 1000.0
@@ -1419,7 +1357,6 @@ 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.
+18 -198
View File
@@ -56,7 +56,6 @@ 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.
@@ -68,13 +67,6 @@ 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}
@@ -93,9 +85,6 @@ 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),
}
@@ -134,7 +123,6 @@ 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.
@@ -161,7 +149,6 @@ 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)
@@ -188,25 +175,19 @@ def record_retrieval(
def _bucket(rows: list) -> dict:
"""A score readout a human can act on, from one aggregate row."""
(calls, zero, p10, p50, p90, lo, hi, avg_n, dur,
measured, supp_calls, supp_zero,
miss_calls, miss_p50, miss_p90, miss_max) = rows
(calls, zero, cleared, p10, p50, p90, lo, hi, avg_n, dur,
measured, supp_calls, supp_zero) = 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),
# `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.
# 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),
# 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.
@@ -227,99 +208,15 @@ 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),
}
# 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, 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):
return None if v is None else round(float(v), places)
async def _complete_from(session, model, user_id) -> dict[str, Any]:
"""When each source in `model` started being recorded, and the instant the
WHOLE table is complete from. Returns {source: earliest_row, "*": latest}.
THE GRAIN IS THE SOURCE, and that is the whole point. `retrieval_logs` has
rows going back months, so a table-level "earliest row" says months and
tells a reader their window is fully covered — while a source added last
week has a week of rows and a counter that silently means something else.
Per-source is the only grain at which partial coverage is visible.
THE AGGREGATE USES THE LATEST, NOT THE EARLIEST. A number that sums several
sources is complete only once EVERY contributor was recording, so "*" is a
max over the sources, not a min. Taking the min here would reproduce the
exact reading this exists to prevent: the oldest source vouching for the
youngest.
All-time, deliberately unfiltered by the window — a query bounded by
`since` can only ever report something at or after `since`, which answers
nothing.
"""
rows = (
await session.execute(
select(model.source, func.min(model.created_at))
.where(model.user_id == user_id)
.group_by(model.source)
)
).all()
out: dict[str, Any] = {src: ts for src, ts in rows if ts is not None}
stamps = list(out.values())
out["*"] = max(stamps) if stamps else None
return out
def _coverage(complete_from, since) -> dict:
"""The two keys every counter block carries, from one timestamp.
`covers_window` is None — never False — when nothing was ever recorded.
"No rows at all" is not "partial coverage", it is no measurement, and the
null convention #3497 established for `suppression` holds here for the
same reason: absent must not read as a verdict.
"""
return {
# iso() already returns None for an unset value (#2845) — the guard
# belongs on covers_window, which is a verdict, not a serialisation.
"complete_from": iso(complete_from),
"covers_window": (
None if complete_from is None else complete_from <= since
),
}
async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
"""What the retrieval telemetry says, per surface, over a window.
@@ -359,52 +256,16 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
"read_failed": False,
}
zero = case((RetrievalLog.result_count == 0, 1), else_=0)
# THE NEAR-MISS POPULATION: calls that returned nothing BECAUSE THE BAR
# TURNED SOMETHING AWAY, and recorded what it was. Three conditions, and
# the third was missing for one deploy (#3739).
#
# Zero-result only: on a call that returned something,
# `best_available_score` equals `top_score` and adds nothing.
#
# Non-null only: rows written before #3670 genuinely do not know, and must
# not read as scoreless declines.
#
# AND NOT A REPEAT. A zero-result call is two unrelated events — the ranker
# found nothing above the bar, or it found only what this session had
# already been shown — and just the first says anything about the bar. That
# is the whole of #3497, and #3670 reintroduced the conflation one level up:
# the rule arms filter exclusions in PYTHON, after the search, so a rule
# that cleared the bar and was dropped as a repeat still reported a high
# `best_available_score` on a zero-result row. Live proof, first read after
# deploy: pre_tool_rule's near-miss max was 0.7457 while the lowest score it
# ever RETURNED was 0.7204 — a "rejection" that outscored acceptances.
#
# The NULL arm is principled, not permissive: `suppressed_count IS NULL`
# means the caller passed its exclusions INTO the search, which is exactly
# the case where the reported score is already post-exclusion and cannot be
# contaminated. Note arms stay measured; rule arms get cleaned.
#
# Deliberately conservative: a call carrying both a repeat and a lower
# genuine miss is dropped whole, losing that point. It undercounts; it
# cannot corrupt — the right way round for a number read against a bar.
#
# This also makes `near_misses.max < threshold` true BY CONSTRUCTION. An
# above-bar candidate that was not excluded would have been returned, so
# its call is not in this population at all.
declined = (
(RetrievalLog.result_count == 0)
& (RetrievalLog.best_available_score.isnot(None))
& (
RetrievalLog.suppressed_count.is_(None)
| (RetrievalLog.suppressed_count == 0)
)
cleared = case(
(
(RetrievalLog.threshold.isnot(None))
& (RetrievalLog.top_score.isnot(None))
& (RetrievalLog.top_score >= RetrievalLog.threshold),
1,
),
else_=0,
)
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)
zero = case((RetrievalLog.result_count == 0, 1), else_=0)
# 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)
@@ -422,9 +283,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
by_source_rows = None
rule_rows = None
distinct_rules_surfaced = distinct_rules_pulled = 0
# None means the coverage read did not happen — distinct from a table with
# no rows, which is {"*": None}. Same reason `read_failed` exists.
note_complete = rule_complete = None
try:
async with async_session() as session:
@@ -434,6 +292,7 @@ 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),
@@ -444,10 +303,6 @@ 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,
@@ -456,34 +311,8 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(RetrievalLog.source)
)
).all()
log_complete = await _complete_from(session, RetrievalLog, user_id)
for row in rows:
source = row[0]
bucket = _bucket(list(row[1:]))
# Per SOURCE, not per table: retrieval_logs goes back months
# while any individual arm may be days old, and the table's
# age would vouch for an arm that has barely started.
bucket.update(_coverage(log_complete.get(source), since))
out["sources"][source] = bucket
# A source with rows in the table but NONE in this window would
# otherwise be absent from the readout — and absent is exactly how
# a source that never existed renders, so a surface that WAS
# recording and went silent is unreadable (#3720). That is #2663
# one level up: the failure that looks like the correct answer.
#
# Zero here is a real measurement, not a manufactured one. The
# all-time query proves the source was recording, and it made no
# calls across a window it fully covers — which is why no
# `covers_window` special case is needed: a source whose first row
# fell after `since` would have that row IN the window and already
# hold a bucket, so anything reaching here began before it.
for src, first_row in log_complete.items():
if src == "*" or first_row is None or src in out["sources"]:
continue
quiet = _bucket(list(_NO_ROWS_IN_WINDOW))
quiet.update(_coverage(first_row, since))
out["sources"][src] = quiet
out["sources"][row[0]] = _bucket(list(row[1:]))
# The corpus side, at its own grain. `ambient` mirrors
# note_usage.usage_for_notes: an ambient surfacing was not a scored
@@ -510,7 +339,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(NoteUsageEvent.event, NoteUsageEvent.source)
)
).all()
note_complete = await _complete_from(session, NoteUsageEvent, user_id)
# Distinct-note counts need their OWN queries, and this is not
# fussiness: count(distinct note_id) per (event, source) group
@@ -638,9 +466,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(RuleUsageEvent.event, RuleUsageEvent.source)
)
).all()
rule_complete = await _complete_from(
session, RuleUsageEvent, user_id,
)
# The rows carry `source`, so the ranked/ambient split is done
# below rather than in SQL — the bulk surfaces started emitting
# on 2026-09-03 (#3473), so there IS an ambient class now.
@@ -750,10 +575,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
}
usage["by_source"] = by_source
# The SECTION's coverage, from the latest source to start recording — a
# figure that sums several sources is complete only once every one of them
# was being written. `_complete_from` computes that as "*".
usage.update(_coverage((note_complete or {}).get("*"), since))
out["usage"] = usage
# ── Rules, deliberately a SEPARATE block ────────────────────────────
@@ -831,7 +652,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
round(rule_usage["pulled_by_agent"] / rule_usage["surfaced"], 4)
if rule_usage["surfaced"] else None
)
rule_usage.update(_coverage((rule_complete or {}).get("*"), since))
out["rule_usage"] = rule_usage
return out
+1 -103
View File
@@ -160,15 +160,7 @@ async def test_the_arm_searches_on_its_OWN_bar_not_the_code_one():
kw = search.await_args.kwargs
assert kw["threshold"] == 0.81, "the arm is still using the code threshold"
assert kw["limit"] == pc.RULEHINT_LIMIT
# NO tier filter (#3702). The arms search every rule the caller owns,
# because "already in the session" is not the same as "in front of the
# reader at the moment it applies" — and relevance is the threshold's
# job, not a category's. If this assertion is failing because a tier
# argument came back, read the block above RULEHINT_LIMIT first: the
# filter may legitimately return, but only carrying a measured reason.
assert "tier" not in kw or kw["tier"] is None, (
"the arm is filtering the rule corpus by tier again"
)
assert kw["tier"] == "conditional"
@pytest.mark.asyncio
@@ -772,97 +764,3 @@ 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"
)
+7 -409
View File
@@ -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, 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])
# 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])
assert unmeasured["suppression"] is None
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])
measured = _bucket([35, 34, 1, 0.75, 0.75, 0.75, 0.75, 0.75, 0.03, 51.9,
35, 9, 9])
assert measured["suppression"] == {
"measured_calls": 35,
"calls_with_suppression": 9,
@@ -224,10 +224,7 @@ 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 "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)"
)
assert ai["cleared_threshold"] == 2 # 0.91 and 0.72, not 0.40
# 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)
@@ -641,402 +638,3 @@ async def test_ambient_alone_reports_no_ratio(_dispose_engine):
assert ru["pull_through"] is None
finally:
await cleanup()
# ── Window coverage (#3712) ────────────────────────────────────────────
#
# A counter added last week, read over a 30-day window, reports a real count
# against an imagined denominator. The result is a plausible FRACTION rather
# than an obvious zero, which is what makes it dangerous — #379 spent five
# planned steps on a defect that turned out to be a window opening before the
# recording it was measuring existed.
def test_coverage_says_nothing_rather_than_false_when_nothing_was_recorded():
"""Null, never False. "No measurement" is not "partial measurement".
The same distinction `suppression`'s null carries (#3497): absent must not
read as a verdict. A False here would assert the window is under-covered,
which is a claim nobody is in a position to make.
"""
from datetime import datetime, timezone
from scribe.services.retrieval_telemetry import _coverage
since = datetime(2026, 9, 1, tzinfo=timezone.utc)
assert _coverage(None, since) == {
"complete_from": None, "covers_window": None,
}
def test_coverage_reads_a_start_before_the_window_as_covered():
from datetime import datetime, timezone
from scribe.services.retrieval_telemetry import _coverage
since = datetime(2026, 9, 1, tzinfo=timezone.utc)
older = datetime(2026, 8, 1, tzinfo=timezone.utc)
newer = datetime(2026, 9, 5, tzinfo=timezone.utc)
assert _coverage(older, since)["covers_window"] is True
assert _coverage(newer, since)["covers_window"] is False, (
"a counter that started inside the window covers only part of it"
)
assert _coverage(newer, since)["complete_from"] == newer.isoformat()
@pytest.mark.integration
@pytest.mark.asyncio
async def test_coverage_is_per_source_because_the_table_is_older_than_its_arms(
_dispose_engine,
):
"""THE grain question, and the reason a per-table answer is useless.
`retrieval_logs` accumulates for months. A table-level "earliest row"
therefore says months for every source it holds — including one added
days ago whose counter means something quite different. The old source
would vouch for the young one, which is exactly the reading this exists
to prevent.
"""
from datetime import datetime, timedelta, timezone
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.retrieval_log import RetrievalLog
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990077
now = datetime.now(timezone.utc)
async with async_session() as s:
# An old surface, recording since well before any window we ask for,
# AND still recording inside it. Both rows are needed: `complete_from`
# comes from the all-time query, but a source only gets a bucket at all
# if it has rows in the window, so the 90-day row alone would leave
# nothing to assert on.
s.add(RetrievalLog(
user_id=UID, source="auto_inject", result_count=1,
created_at=now - timedelta(days=90),
))
s.add(RetrievalLog(
user_id=UID, source="auto_inject", result_count=1,
created_at=now - timedelta(days=1),
))
# A young arm, first written INSIDE the window below.
s.add(RetrievalLog(
user_id=UID, source="pre_tool_rule", result_count=1,
created_at=now - timedelta(days=2),
))
await s.commit()
try:
out = await retrieval_summary(UID, days=30)
assert out["sources"]["auto_inject"]["covers_window"] is True
assert out["sources"]["pre_tool_rule"]["covers_window"] is False, (
"the young arm was reported as covering a 30-day window — the "
"table's age has been allowed to vouch for one of its sources"
)
finally:
async with async_session() as s:
await s.execute(delete(RetrievalLog).where(RetrievalLog.user_id == UID))
await s.commit()
@pytest.mark.integration
@pytest.mark.asyncio
async def test_a_surface_that_went_silent_is_not_the_same_as_one_that_never_ran(
_dispose_engine,
):
"""#3720 — absent is how "never existed" renders, so it cannot also be how
"stopped recording" renders.
A surface losing its recorder is one of the failures this milestone exists
to make visible, and dropping it from the readout is the most complete way
to hide it. Zero here is a real measurement: the table proves the source
was recording, and it made no calls across a window it fully covers.
"""
from datetime import datetime, timedelta, timezone
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.retrieval_log import RetrievalLog
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990078
now = datetime.now(timezone.utc)
async with async_session() as s:
# Recorded once, well before the window, and never since.
s.add(RetrievalLog(
user_id=UID, source="auto_inject", result_count=3, top_score=0.81,
created_at=now - timedelta(days=60),
))
await s.commit()
try:
out = await retrieval_summary(UID, days=7)
assert "auto_inject" in out["sources"], (
"a source with rows in the table but none in the window was "
"dropped from the readout — a surface that stopped recording now "
"reads exactly like one that never existed"
)
quiet = out["sources"]["auto_inject"]
assert quiet["calls"] == 0
# The window IS covered; what was observed across it is nothing.
assert quiet["covers_window"] is True
# ...but nothing was sampled, so no distribution may be claimed. A
# zeroed score would assert a measurement, which is #3311's mistake.
assert quiet["top_score"] == {
"p10": None, "p50": None, "p90": None, "min": None, "max": None,
}
assert quiet["suppression"] is None
assert quiet["avg_result_count"] is None
finally:
async with async_session() as s:
await s.execute(delete(RetrievalLog).where(RetrievalLog.user_id == UID))
await s.commit()
@pytest.mark.integration
@pytest.mark.asyncio
async def test_a_section_is_complete_only_from_its_latest_contributor(
_dispose_engine,
):
"""A sum is complete once EVERY contributor was being written — so the
section takes the LATEST first-row, not the earliest.
Taking the earliest would be worse than reporting nothing: it would pick
the oldest source in the table and use it to certify a total that a
newer source is still only partly contributing to. That is the original
error in miniature.
"""
from datetime import datetime, timedelta, timezone
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.rule_usage import RuleUsageEvent
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990078
now = datetime.now(timezone.utc)
old = now - timedelta(days=90)
young = now - timedelta(days=2)
async with async_session() as s:
s.add_all([
RuleUsageEvent(
user_id=UID, rule_id=1, event="surfaced",
source="list_always_on_rules", created_at=old,
),
RuleUsageEvent(
user_id=UID, rule_id=2, event="surfaced",
source="pre_tool_rule", created_at=young,
),
])
await s.commit()
try:
out = await retrieval_summary(UID, days=30)
ru = out["rule_usage"]
assert ru["complete_from"] == young.isoformat(), (
"the section reported completeness from its OLDEST source; a "
"total is only as complete as its newest contributor"
)
assert ru["covers_window"] is False
finally:
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,
))
# THE CASE WHOSE ABSENCE LET THIS GUARD PASS OVER BROKEN CODE (#3739).
# A zero-result call whose zero was a REPEAT, not a rejection: the ranker
# cleared the bar at 0.9 and the session had already been shown that rule,
# so the arm dropped it in Python after the search. Without the suppression
# arm of the predicate this row lands in the near-miss population and drags
# `max` to 0.9 — above the very threshold the field is read against.
await _insert_retrieval_log(_build_payload(
user_id=UID, source="pre_tool_rule", query="git commit", threshold=0.72,
limit=1, project_id=None, is_task=None, results=[], duration_ms=4.0,
best_available=0.9, suppressed=1,
))
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"] == 6
assert src["zero_result_calls"] == 5
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 the BAR caused, that recorded a score. "
"Three qualify. Excluded: the unmeasured row (predates the column, "
"not a scoreless decline), the call that showed something (its "
"best-available is just its top score), and the REPEAT — a zero "
"the reader caused, not the bar (#3739)"
)
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 rejection that outscores the bar is not a rejection. This is "
"structural once the suppression arm is in the predicate: an "
"above-bar candidate that was not excluded would have been "
"RETURNED, so its call cannot be in this population (#3739)"
)
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()