Compare commits

...
21 Commits
Author SHA1 Message Date
bvandeusen 53df6742cb Merge pull request 'Milestone 379 closes: the readout can now say what it did not measure' (#144) from dev into main
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / Python tests (push) Successful in 1m3s
CI & Build / Python lint (push) Successful in 3s
CI & Build / TypeScript typecheck (push) Successful in 36s
CI & Build / integration (push) Successful in 39s
CI & Build / Build & push image (push) Successful in 15s
2026-09-08 16:06:14 -04:00
bvandeusenandClaude Opus 5 e7c1af32a0 fix(telemetry): the bar can only be judged from what it rejected (#3670)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / TypeScript typecheck (push) Successful in 23s
CI & Build / integration (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 28s
`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 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 13:50:05 -04:00
bvandeusenandClaude Opus 5 277aea58e4 test(telemetry): pin the identity that falsified this milestone (#3668)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / TypeScript typecheck (push) Successful in 10s
CI & Build / integration (push) Successful in 27s
CI & Build / Build & push image (push) Successful in 23s
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 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 13:36:03 -04:00
bvandeusenandClaude Opus 5 5e19a1b028 test(telemetry): FALSIFICATION — prove the identity guard can fail (#3668)
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / Python lint (push) Successful in 3s
CI & Build / TypeScript typecheck (push) Successful in 23s
CI & Build / integration (push) Successful in 34s
CI & Build / Python tests (push) Failing after 45s
CI & Build / Build & push image (push) Skipped
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 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 13:31:49 -04:00
bvandeusen be08edcd7e Merge pull request 'Telemetry coverage, and the rule arms stop filtering to one tier' (#143) from dev into main
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 13s
CI & Build / integration (push) Successful in 34s
CI & Build / TypeScript typecheck (push) Successful in 24s
CI & Build / Python tests (push) Successful in 1m4s
CI & Build / Build & push image (push) Successful in 13s
2026-09-08 11:11:40 -04:00
bvandeusenandClaude Opus 5 7a2aff7bc1 fix(telemetry): a surface that stopped recording is not one that never ran (#3720)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / TypeScript typecheck (push) Successful in 23s
CI & Build / integration (push) Successful in 34s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 24s
`out["sources"]` was built only from the windowed aggregate, so a source
with rows in `retrieval_logs` but none inside the window got no bucket at
all. Absent is exactly how a source that never existed renders, so a
surface that WAS recording and went silent became unreadable — #2663 one
level up, the failure that looks like the correct answer.

Two queries at different scopes, and only one shaped the output.
`_complete_from` reads all-time and knows every source the table has ever
held; the windowed loop dropped whatever it did not return.

Every such source now gets a zero bucket. Zero is a real measurement here
rather than a manufactured one: the all-time query proves the source was
recording, and it made no calls across a window it fully covers. No
`covers_window` special case is needed either — a source whose first row
fell after `since` would have that row IN the window and already hold a
bucket, so anything reaching this branch began before it.

The counts are 0 and everything else is null. A sampled distribution is
not the same claim as a call count, and rendering p50 as 0.0 for a source
nobody sampled would assert a measurement — #3311's mistake, in the
readout built to prevent it.

Found while fixing #3712's fixture, which failed with KeyError for this
exact reason.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 11:07:21 -04:00
bvandeusenandClaude Opus 5 0808e8259a test(telemetry): the old surface needs a row in the window to have a bucket at all (#3712)
CI & Build / integration (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m5s
CI & Build / Build & push image (push) Successful in 15s
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 11s
CI & Build / TypeScript typecheck (push) Successful in 11s
The per-source grain test gave `auto_inject` a single row 90 days back and
`pre_tool_rule` one 2 days back, then asserted on both buckets. Only the
young arm got a bucket: `out["sources"]` is built from the WINDOWED query,
so a source with no rows inside the window is absent entirely, and the
assertion died on KeyError before it could test anything.

`complete_from` and the bucket come from different queries — all-time for
the first, windowed for the second — and the fixture only satisfied one of
them. Gave `auto_inject` a second row inside the window, which is also the
shape being described: an old surface that is STILL recording. The 90-day
row still sets its `complete_from`.

Still discriminating: auto_inject reads True and pre_tool_rule False, and a
per-table `_complete_from` would make both 90 days and fail the second
assertion — the regression this test is for.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 10:39:42 -04:00
bvandeusenandClaude Opus 5 950c93c5d4 fix(telemetry): the coverage helpers were defined inside the function they serve (#3712)
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / Python lint (push) Successful in 4s
CI & Build / integration (push) Failing after 28s
CI & Build / TypeScript typecheck (push) Successful in 35s
CI & Build / Python tests (push) Successful in 1m5s
CI & Build / Build & push image (push) Successful in 32s
`_complete_from` and `_coverage` landed between `retrieval_summary`'s
docstring and its body. Python does not object to that the way it looks
like it should: blank lines do not close a block, so the whole remaining
body — indented four spaces, sitting after `_coverage`'s `return` —
became unreachable code INSIDE `_coverage`, and `retrieval_summary`
became a function that is nothing but a docstring.

The error surfaced three ways at once, none of which named the cause:
fourteen F821s for `days` and `user_id` (real: those are
`retrieval_summary`'s parameters, and the body no longer lived there), a
SyntaxError on `async with` (real: `_coverage` is sync), and every test
module that imports this file failing to collect.

Moved both helpers above `retrieval_summary`, beside `_bucket` and
`_round`, where the file's other helpers already are. No behaviour
change — this is the code that was meant to be there.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 10:34:57 -04:00
bvandeusenandClaude Opus 5 21a5831479 feat(telemetry): every counter says when it started being recorded (#3712)
CI & Build / Python lint (push) Failing after 3s
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / integration (push) Failing after 17s
CI & Build / Python tests (push) Failing after 26s
CI & Build / TypeScript typecheck (push) Successful in 34s
CI & Build / Build & push image (push) Skipped
A window that opens before a counter existed reports that counter as though
it had been measured throughout. The reader cannot tell "zero because
nothing happened" from "zero because nobody was counting yet", and — worse
— cannot tell a partial count from a complete one. That middle case yields
a plausible FRACTION rather than an obvious zero, which is what makes it
dangerous.

It is not hypothetical. A 7-day window opened while the ranked rule
surfacing recorders were four days old produced an apparent 64% write loss,
which survived a code review, four ruled-out alternative causes and a
five-step milestone before an identity check falsified it in one read.

Every counter block now carries `complete_from` and `covers_window`.

THE GRAIN IS THE SOURCE. retrieval_logs accumulates for months, so a
per-table earliest row says months for every source it holds — including an
arm added days ago whose counter means something else entirely. The old
source would vouch for the young one, which is the exact reading this
prevents.

A SECTION TAKES ITS LATEST CONTRIBUTOR, NOT ITS EARLIEST. A figure summing
several sources is complete only once every one of them was being written,
so "*" is a max. Using min would reproduce the original error in miniature.

`covers_window` is null, never false, when nothing was ever recorded: "no
measurement" is not "partial measurement" — the null convention #3497
established for `suppression`, one level up.

Also corrects a stale claim in the tool docstring: it still taught readers
that write_path_rule "has never once declined to fire" (#3311). That was
the arm writing its retrieval_logs row only on calls that found something;
#3497 fixed it, and the arm declines the large majority of its calls.

_complete_from takes the caller's session rather than opening its own,
departing from the services canon (#2860) because it runs inside an
existing block; to be recorded against the ledger once it ingests.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 10:29:02 -04:00
bvandeusen 4a85220aea Merge pull request 'feat(rules): the rule arms stop filtering the corpus to one tier (#3702)' (#142) from dev into main
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / TypeScript typecheck (push) Successful in 39s
CI & Build / integration (push) Successful in 40s
CI & Build / Python tests (push) Successful in 1m13s
CI & Build / Build & push image (push) Successful in 19s
2026-09-08 00:31:12 -04:00
bvandeusenandClaude Opus 5 dd1e6e2645 feat(rules): the rule arms stop filtering the corpus to one tier (#3702)
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / TypeScript typecheck (push) Successful in 1m3s
CI & Build / Python lint (push) Successful in 4s
CI & Build / integration (push) Successful in 33s
CI & Build / Python tests (push) Successful in 1m7s
CI & Build / Build & push image (push) Successful in 1m29s
Both arms passed tier="conditional", on the reasoning that an always-on
rule is already in the session so re-surfacing it is pure noise. That
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 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 likelier it sat in that
class.

Underneath, the filter was doing the THRESHOLD's job. Whether a rule belongs
in a 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.

MEASURED, NOT SETTLED. 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. It
had simply never been checked, and retrieval_logs already records the scores
to check it with. Rules clearing often and high means the fear was justified
and the BAR is the work; rules clearing rarely in a thin band means relevance
was always sufficient.

Only eligibility moved. The bar stays at 0.72 and k stays at 1, so the
resulting distribution has one cause — and k=1 bounds the blast radius: a
wider pool can change which rule surfaces and how often, never how long a
single hint gets.

The threshold rationale's first premise ("the eligible corpus is TINY —
tier=conditional only") is updated rather than deleted: a larger pool makes
clearing the bar mean MORE, so that argument weakened, and the bar was left
alone anyway rather than move two variables at once.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-08 00:24:02 -04:00
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
bvandeusenandClaude Opus 5 c3ecdf0972 feat(rules): the rule gate becomes a practice with a question, not a prohibition (#3557)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / TypeScript typecheck (push) Successful in 11s
CI & Build / integration (push) Successful in 32s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 25s
The first cut opened "NOT YOURS TO CALL UNPROMPTED", and that is the wrong
instrument. A caller reading a prohibition stops NOTICING rule-shaped things
rather than noticing them and asking — which trades a small failure for a
larger one. The wanted behaviour is more proposals, not fewer.

So both docstrings now describe the practice: propose readily, state the
four things, and close with a question the operator answers in one word —
approve it as written / let's talk about it / no. Named options where the
interface has them, three written-out options where it does not.

"Approve it as written" is what makes element 1 load-bearing: they approved
TEXT, so that text is stored verbatim. "Let's talk about it" is framed as
the expected answer rather than a setback. "No" routes the observation to
create_note, which records without binding.

The argument for asking is also better than consent. The operator's yes is
the one moment the rule is certainly in front of them: afterwards a
conditional rule is not read aloud at session start, and a project rule is
absent from an unfiltered list_rules(). The proposal IS the review.

Guard gains the answers-offered-back element and drops the wording that
forbade; its header records why the framing changed, so the prohibition does
not get reintroduced as a tidy-up.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-04 20:11:42 -04:00
bvandeusenandClaude Opus 5 1a34363059 feat(rules): the rule-creation tools ask for approval, and ask what would enforce it (#3557)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / integration (push) Successful in 32s
CI & Build / TypeScript typecheck (push) Successful in 34s
CI & Build / Python tests (push) Successful in 1m6s
CI & Build / Build & push image (push) Successful in 41s
Every gate on create_rule and create_project_rule was about SHAPE — rule vs
process vs snippet, one-thing-you-could-violate, general-enough, not-a-dupe.
All of them improve a rule someone has already decided to write. None asked
the prior question: has the person this will bind agreed to be bound by it?

Both docstrings now open with the gate, and with the four things a proposal
carries: what it would require in the words it would carry, its intent, why
now, and how it would be enforced.

The fourth is the one that decides it. "A test, a CI check, a hook, a schema
constraint... or nothing" is a question that sometimes dissolves the rule:
what a test can assert should BE that test, and a rule is what is left when
nothing mechanical can hold the thing. A rulebook grows by default and
shrinks only on purpose.

create_project_rule needs the gate more, not less, and says so: a project
rule is absent from an unfiltered list_rules(), and a conditional one is
absent from session start too, so one written there can bind for months
without ever having been in front of the person it binds.

test_rule_creation_asks_first pins structure, never wording — each element
matches a family of synonyms, and the gate must precede the Args: block,
because a caller who has decided to make the call reads the parameters and
not the prose under them.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-04 20:02:05 -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
bvandeusenandClaude Opus 5 30d87e461a feat(rules): the instruction surfaces say to RETRIEVE a rule, not only to receive one (#3523)
CI & Build / Python lint (push) Successful in 4s
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / integration (push) Successful in 32s
CI & Build / Python tests (push) Successful in 1m7s
CI & Build / TypeScript typecheck (push) Successful in 4m18s
CI & Build / Build & push image (push) Successful in 25s
Every instruction surface told a session to load the always-on rules and
stopped there. None said the loaded set is partial, so an empty one read as
"no rule applies" when it only ever meant "none was pushed" — different
claims, and only one of them has been checked.

That is #2198's asymmetry one level in. The earlier defect was trusting the
SessionStart push over the explicit pull; this is trusting the resident TIER
as if it were the whole rulebook.

It is also why the always-on tier was the only one that worked, on any install
rather than this one (rule 115): a rule nothing retrieves must be resident to
bind at all, and a resident rule costs tokens in every session forever — so a
rulebook that only delivers cannot grow past what one session holds.
Retrieval lifts that ceiling, and it fires only if something asks. A
tool-choice reflex asks least of all (#3476, #161).

The same obligation now lands on all three session-start surfaces, because
rule 119 makes them the specification jointly and a surface stating it
differently IS the product behaving differently (#2497). Pinned by
test_every_session_start_surface_states_the_conditional_retrieval, mirroring
the pull test beside it.

THE BUDGET TRADE. _INSTRUCTIONS sat at 1978 against a 2000 test budget, and
its own comment says an addition there is a trade, never an append. Bought the
new clause by trading out "Processes are saved procedures (follow verbatim)"
and "Deletes are trash-recoverable" — both already in DISPLACED_TOPICS and
already stated on a delivered surface, and both per-tool guidance, which by
this block's doctrine belongs in the tool docstring. Now 1976. Recorded in the
comment above the block so it is not silently reversed.

Plugin version minted: shipped plugin content moved.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-03 21:41:53 -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
bvandeusenandClaude Opus 5 8be555d6dd feat(telemetry): tell a ranker decline from a repeat before the observation window opens (#3497)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 8s
CI & Build / integration (push) Successful in 31s
CI & Build / TypeScript typecheck (push) Successful in 37s
CI & Build / Python tests (push) Successful in 1m4s
CI & Build / Build & push image (push) Successful in 28s
Making the rule arms log every call exposed a second ambiguity in the same
row. `result_count == 0` is two unrelated events wearing one number:

  - the ranker found nothing above the bar — the only evidence a threshold is
    set too high; and
  - the ranker found only what this session had already been shown — which
    says nothing whatever about the bar.

A long session excludes its way into the second, so the arm reads worse the
longer it runs correctly. Rows written now carry the ambiguity permanently,
which is why this lands before any watch period rather than after.

`retrieval_logs.suppressed_count` (0095, nullable) holds what the caller
dropped as already-shown. Both rule arms report it; they filter in Python and
always know. The note arms pass exclusions INTO semantic_search_notes and
never see what was dropped, so they store NULL.

THE NULL IS LOAD-BEARING. It means "not measured here", and the readout
renders it as `suppression: null` rather than a zeroed dict. Defaulting to 0
would let an unmeasured surface read as a perfectly clean one — the same
substitution of an artifact for a measurement that #3311 made. No backfill,
for the same reason: existing rows genuinely do not know.

`retrieval_telemetry`'s `sources` gains `suppression` with `measured_calls`,
`calls_with_suppression` and `zero_because_already_shown`; subtract the last
from `zero_result_calls` for the true ranker declines. The MCP tool docstring
says to read the two together and warns against reading the null as a zero.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-03 21:12:38 -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
bvandeusenandClaude Opus 5 48804c437d fix(tests): the write-path telemetry test asserted the defect, not the split (#3497)
CI & Build / Python lint (push) Successful in 5s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / integration (push) Successful in 28s
CI & Build / TypeScript typecheck (push) Successful in 34s
CI & Build / Python tests (push) Successful in 1m8s
CI & Build / Build & push image (push) Successful in 28s
`assert_called_once` held only because the rule arm skipped its retrieval_logs
row when it found nothing. With the arm logging every call, the test now
asserts what it was always about — exactly one `write_path` row, no
`auto_inject`, and the rule arm keeping its own separate source.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-03 06:59:52 -04:00
bvandeusenandClaude Opus 5 154a5de13e fix(telemetry): both rule arms logged only their hits, so the clear-rate could only read 100% (#3497)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / TypeScript typecheck (push) Successful in 22s
CI & Build / integration (push) Successful in 33s
CI & Build / Python tests (push) Failing after 48s
CI & Build / Build & push image (push) Skipped
`write_path_rule` reported `zero_result_calls: 0` and `cleared_threshold:
133/133` — a perfect record no other surface comes near (`write_path` 421
zeroes of 613, `reuse_slot` 124/199, `auto_inject` 114/326). #3311 read that
as a measurement and milestone 333 was scoped on it.

It was an artifact. Both arms called `record_retrieval` inside a guard on
having results — the write-path arm behind `if fresh:`, the pre-tool arm
below `if not fresh: return out` — so a call that found nothing wrote no row.
The statistic was a fact about the shape of the code, true at any threshold
whatsoever.

The call log moves out of the guard in both arms. The surfacing log stays in
it: nothing was shown, so no surfacing occurred. `results=fresh` is kept
deliberately — the note arms pass exclusions into `semantic_search_notes`, so
what they log is already post-exclusion, and logging `hits` here would make
this row mean something other than every other row in the same readout.

The defect bites hardest on the pre-tool arm, which fires on every Bash call:
with no rows at all, a ranker that declined is indistinguishable from a hook
that never fired — the silent failure the arm exists to stop.

Tests cover both arms behaviourally (found nothing; found only what the
session already held; searched nothing at all, which must stay silent) plus a
structural guard, because this was one level of indentation and it appeared
independently in two places.

#3311 and the `rule_usage` docstring corrected rather than quietly rewritten.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-03 06:57:13 -04:00
19 changed files with 1671 additions and 103 deletions
@@ -0,0 +1,52 @@
"""add retrieval_logs.suppressed_count — tell a ranker decline from a repeat (#3497)
Revision ID: 0095
Revises: 0094
Create Date: 2026-09-03
`result_count == 0` has always meant "this surface said nothing", which is the
right number for "was the hint any use" and the wrong one for tuning a
threshold. It folds together two unrelated events:
- the ranker found nothing above the bar — the ONLY evidence a threshold is
set too high; and
- the ranker found something the session had already been shown — a decline
that says nothing whatever about the bar.
The rule arms filter in Python after the search, so they can count the second
kind exactly. The note arms pass `exclude_ids` INTO semantic_search_notes, so
the dropped rows never come back and there is nothing to count.
NULLABLE, AND THE NULL IS THE POINT. A surface that does not measure
suppression stores NULL, not 0, and the readout renders it as "not measured"
rather than "none". Defaulting to 0 would make an unmeasured surface look like
a perfectly clean one — the exact substitution of an artifact for a
measurement that #3311 made and that #3497 exists to correct. Doing it again,
in the migration that fixes it, would be its own small joke.
No backfill for the same reason: existing rows genuinely do not know, and
saying so is the honest state. `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 = "0095"
down_revision = "0094"
branch_labels = None
depends_on = None
def upgrade() -> None:
op.add_column(
"retrieval_logs",
sa.Column("suppressed_count", sa.Integer(), nullable=True),
)
def downgrade() -> None:
op.drop_column("retrieval_logs", "suppressed_count")
@@ -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")
+1 -1
View File
@@ -1,7 +1,7 @@
{ {
"name": "scribe", "name": "scribe",
"description": "Scribe system-of-record for Claude Code: MCP tools over your notes/tasks/projects/rules, a session-start push channel that surfaces your always-on rules + active-project context, process-skills (writing-plans, systematic-debugging, verification, brainstorming, reusing-code), and your saved Scribe Processes auto-surfaced as skills (/scribe:sync). Replaces superpowers + file-memory with one app-backed plugin.", "description": "Scribe system-of-record for Claude Code: MCP tools over your notes/tasks/projects/rules, a session-start push channel that surfaces your always-on rules + active-project context, process-skills (writing-plans, systematic-debugging, verification, brainstorming, reusing-code), and your saved Scribe Processes auto-surfaced as skills (/scribe:sync). Replaces superpowers + file-memory with one app-backed plugin.",
"version": "2026.09.03.0329", "version": "2026.09.04.0140",
"author": { "author": {
"name": "Bryan Van Deusen" "name": "Bryan Van Deusen"
}, },
+10
View File
@@ -21,6 +21,16 @@ for the operator's work, and as your own working memory across sessions.
compaction — call `list_always_on_rules()` (and `enter_project()` when a compaction — call `list_always_on_rules()` (and `enter_project()` when a
project is in scope) BEFORE acting. When a loaded rule and a default habit project is in scope) BEFORE acting. When a loaded rule and a default habit
disagree, the rule wins; if no rule speaks to it, ask rather than assume. disagree, the rule wins; if no rule speaks to it, ask rather than assume.
- **What you loaded is not all of the rules.** Only the always-on tier arrives
that way; conditional rules are RETRIEVED, and one you were never handed
binds exactly as hard. So before a consequential act, `search` for a rule
about it (`content_type="rule"`) rather than concluding from an empty
loaded set that nothing applies. "I was not told" is not the same as "there
is no rule," and only one of those is checkable.
This bites hardest on which TOOL to reach for — curling an API that has an
MCP client, standing up a local stack, running a suite CI owns. Those feel
like mechanics rather than decisions, so they raise no doubt and generate no
query; the moment you are most confident is the moment to look.
- **Recall before acting** — before you answer anything about the operator's - **Recall before acting** — before you answer anything about the operator's
work or start a task, `search` Scribe first; assume a related note, task, or work or start a task, `search` Scribe first; assume a related note, task, or
decision already exists. Concretely, reach for recall whenever a request decision already exists. Concretely, reach for recall whenever a request
+25 -4
View File
@@ -56,10 +56,31 @@ Two constraints on *how* that's achieved:
re-deriving it or opening a duplicate. When a project is in scope, pass its re-deriving it or opening a duplicate. When a project is in scope, pass its
`project_id` so results stay scoped. `project_id` so results stay scoped.
2. **Standing rules are binding.** Load them via `list_always_on_rules()` at 2. **Standing rules are binding — and the ones you were handed are not all of
session start (see "Do this first"); treat every one as binding. Pull a them.** Load the resident set via `list_always_on_rules()` at session start
rule's full statement with `get_rule(id)` when it's about to bite. When a (see "Do this first"); treat every one as binding. Pull a rule's full
project is in scope, `enter_project(id)` also returns its applicable rules. statement with `get_rule(id)` when it's about to bite. When a project is in
scope, `enter_project(id)` also returns its applicable rules.
Rules come in two tiers. **Always-on** rules are delivered — they arrive
whether or not you ask. **Conditional** rules are RETRIEVED, and one binds
just as hard for never having been handed to you. So before a consequential
act, `search(content_type="rule")` on what you are about to do. An empty
loaded set is not evidence that no rule applies; it is only evidence that
none was pushed, and those are different claims.
The tier split exists because delivery does not scale: every resident rule
costs tokens in every session forever, so a rulebook that grows past a few
dozen either stops growing or stops fitting. Retrieval is what lets the
rulebook keep growing — but retrieval only fires if something asks.
**Ask hardest where you feel most certain.** Rules about which TOOL to reach
for — use the forge's MCP client rather than curling its API, don't stand up
a local stack, don't run the suite CI owns — govern moves that feel like
mechanics rather than decisions. A reflex raises no doubt, so it generates
no query, so the rule that would have stopped it is never retrieved. That is
the failure this instruction exists to prevent, and confidence is its only
warning sign.
3. **Update over duplicate.** When recording, prefer updating an existing 3. **Update over duplicate.** When recording, prefer updating an existing
note/rule/task over creating a new one. Search first; revise what's there. note/rule/task over creating a new one. Search first; revise what's there.
+28 -3
View File
@@ -45,6 +45,31 @@ from quart import Quart
# The accepted cost: an agent that never opens create_note's docstring never # The accepted cost: an agent that never opens create_note's docstring never
# learns the field exists. Guidance lives in the create_note / update_note # learns the field exists. Guidance lives in the create_note / update_note
# docstrings and the using-scribe skill instead. # docstrings and the using-scribe skill instead.
#
# Milestone 333 step 3 (2026-09-04) bought the HOW bullet's second clause —
# search(content_type="rule") before a consequential act — by TRADING OUT
# "Processes are saved procedures (follow verbatim)" and "Deletes are
# trash-recoverable". Recorded so the trade is not silently reversed:
# - Both were already in test_instruction_surfaces_agree's DISPLACED_TOPICS
# and already stated on a delivered surface, so nothing fell off: the
# process reflex is in every scribe-proc-* skill listing (each says the
# process governs and is followed verbatim), and trash recovery is in the
# delete_*/list_trash/restore docstrings, which is where per-tool guidance
# belongs by this block's own doctrine.
# - What it bought is not per-tool guidance and has nowhere else to live at
# session-start altitude. Rules were retrievable only by RESIDENCY: the
# always-on preload put them in front of the agent, and nothing told a
# session to go looking for one it had not been handed. The tier split is
# therefore load-bearing on ANY install (rule 115): a delivered rule costs
# tokens in every session forever, so a rulebook that only delivers cannot
# grow past what one session can hold, and every rule worth keeping has to
# become resident to bind at all. Retrieval is what lets it keep growing —
# and retrieval fires only if something asks, which nothing told a session
# to do. A tool-choice reflex asks least of all (#3476, #161).
# - This states the PULL for conditional rules, exactly as the surrounding
# line states it for always-on ones. Rule 119 makes these surfaces the
# specification, so the same sentence lands on all three session-start
# surfaces, and test_instruction_surfaces_agree pins it.
_INSTRUCTIONS = """ _INSTRUCTIONS = """
Scribe is the operator's self-hosted second brain and system of record — and Scribe is the operator's self-hosted second brain and system of record — and
yours: recall from it before acting, record as you go. Keep no parallel copy yours: recall from it before acting, record as you go. Keep no parallel copy
@@ -63,13 +88,13 @@ Hierarchy: Project -> Milestone -> Task/Note. The map, by purpose:
active project_id to stay in scope. active project_id to stay in scope.
- WHERE work happens: Systems. Tag records with system_ids as you write; - WHERE work happens: Systems. Tag records with system_ids as you write;
create_system when the area is unmodelled. create_system when the area is unmodelled.
- HOW: rules are binding — list_always_on_rules() at session start. - HOW: rules bind. list_always_on_rules() at start; before a consequential
act, search(content_type="rule") — the resident set is not all of them.
- UI: the project's design system is binding — resolve_design_system / - UI: the project's design system is binding — resolve_design_system /
get_design_system_stylesheet before hand-writing a value. get_design_system_stylesheet before hand-writing a value.
- REUSE: search snippets before writing a helper; record what you build with - REUSE: search snippets before writing a helper; record what you build with
create_snippet; classify shapes against canon (classify_shapes) — a create_snippet; classify shapes against canon (classify_shapes) — a
consumer map is rows, never prose. Processes are saved procedures (follow consumer map is rows, never prose.
verbatim). Deletes are trash-recoverable.
A task is a note with status (*_note vs *_task tools). A task is a note with status (*_note vs *_task tools).
Creates are duplicate-gated: a near-match BLOCKS and returns the existing Creates are duplicate-gated: a near-match BLOCKS and returns the existing
+65
View File
@@ -315,6 +315,61 @@ async def create_rule(
) -> dict: ) -> dict:
"""Create a new rule in a rulebook (a SHARED rule — keep it general). """Create a new rule in a rulebook (a SHARED rule — keep it general).
PROPOSE RULES READILY, AND WRITE ONE WHEN THE OPERATOR SAYS YES. Noticing
that something has hardened into a standing instruction is valuable work,
and a session that notices it and says nothing has thrown the observation
away. So raise it whenever you see one. The single step that belongs
between noticing and writing is the operator's yes: a rule binds every
future session, and they are the person it binds.
Their yes is also the only moment the rule is reliably IN FRONT of them.
After the write it may not be again for months — a conditional rule is not
read aloud at session start, and a project-scoped one does not appear in
an unfiltered list_rules() at all. So the proposal is the review.
When the operator asks for a rule in so many words, that IS the yes —
write it and move on. The loop below is for the rule you thought of.
A PROPOSAL CARRIES FOUR THINGS, and the fourth is the one that decides it:
1. WHAT it would require — the statement, in the words it would carry,
not a gloss of them. The operator is agreeing to text.
2. INTENT — what it changes about how work gets done, and what goes
wrong today without it. "Be careful about X" is not an intent; the
behaviour that would differ tomorrow is.
3. WHY NOW — the incident, observation or decision behind it. Pass that
record as arose_from_id, and say it in the conversation too: the
field is for the reader six months out, the sentence is for the
person deciding.
4. HOW IT WOULD BE ENFORCED — a test, a CI check, a hook, a schema
constraint, a duplicate gate, a review step... or nothing, in which
case say so plainly: "nothing — this is prose a session has to
remember." Answer this one honestly and it will sometimes dissolve
the rule, which is the point rather than a side effect. What a test
can assert should BE that test; a rule is what remains when nothing
mechanical can hold the thing. A rulebook grows by default and
shrinks only on purpose, so a question that prevents a rule is worth
more than any question that improves one's wording.
THEN CLOSE WITH A QUESTION THEY CAN ANSWER IN ONE WORD. Offer three
answers, and make the middle one the easy one:
* "Approve it AS WRITTEN" — you create it with the statement exactly as
shown. This is what makes element 1 load-bearing: they approved TEXT,
so that text is what gets stored, verbatim.
* "LET'S TALK ABOUT IT" — the wording, the scope, the tier, whether it
wants to be a rule at all. Most good rules arrive this way, so treat
this answer as the expected one rather than a setback.
* "NO" — let it go. If the observation is still worth keeping, it is a
note (create_note): recorded, findable, and binding on nobody.
Where the interface offers structured choices, ask it that way — a
question with named options is answered in a click, while the same
question inside a paragraph is answered by scrolling past. Where it does
not, write the three options out as three options. Either way ask once
and let the answer stand; re-raising a declined proposal argues a rule
into existence, which is the thing this whole loop exists to prevent.
A rulebook rule is shared by every project that gets the rulebook: an A rulebook rule is shared by every project that gets the rulebook: an
always_on rulebook binds ALL your projects; a subscribed rulebook binds the always_on rulebook binds ALL your projects; a subscribed rulebook binds the
projects that opt in. So a rulebook rule must read as a general standard — projects that opt in. So a rulebook rule must read as a general standard —
@@ -433,6 +488,16 @@ async def create_project_rule(
the rule is returned in get_project's applicable_rules (under the rule is returned in get_project's applicable_rules (under
project_rules) and in list_rules(project_id=...). project_rules) and in list_rules(project_id=...).
PROPOSE, THEN WRITE ON A YES — create_rule's opening carries the whole
loop: the four things a proposal states (what it would require, its
intent, why now, and how it would be enforced) and the one-word question
that closes it (approve as written / talk about it / no). All of it
applies here unchanged. Reach for that loop MORE readily on this surface,
not less: a project rule stays out of an unfiltered list_rules(), and a
conditional one stays out of session start too, so the operator's yes is
the one moment this rule is certain to have been seen by the person it
binds.
Check first whether a rule is the right shape at all — create_rule's Check first whether a rule is the right shape at all — create_rule's
opening asks that question and it applies identically here. A visual opening asks that question and it applies identically here. A visual
standard is a design system; a procedure is a process (create_process); standard is a design system; a procedure is a process (create_process);
+74 -9
View File
@@ -112,6 +112,7 @@ async def search(
return await _search_rules(uid, q, limit) return await _search_rules(uid, q, limit)
is_task = {"note": False, "task": True}.get(content_type) # None => any is_task = {"note": False, "task": True}.get(content_type) # None => any
t0 = time.perf_counter() t0 = time.perf_counter()
report: dict = {}
raw = await semantic_search_notes( raw = await semantic_search_notes(
uid, q, limit=limit, is_task=is_task, uid, q, limit=limit, is_task=is_task,
project_id=project_id or None, project_id=project_id or None,
@@ -119,12 +120,14 @@ async def search(
# An explicit search reaches everything the operator may read, including # An explicit search reaches everything the operator may read, including
# records shared with them one-to-one. # records shared with them one-to-one.
scope="read", scope="read",
report=report,
) )
record_retrieval( record_retrieval(
user_id=uid, source="mcp_search", query=q, user_id=uid, source="mcp_search", query=q,
threshold=DEFAULT_SIMILARITY_THRESHOLD, limit=limit, threshold=DEFAULT_SIMILARITY_THRESHOLD, limit=limit,
project_id=project_id or None, is_task=is_task, results=raw, project_id=project_id or None, is_task=is_task, results=raw,
duration_ms=(time.perf_counter() - t0) * 1000.0, duration_ms=(time.perf_counter() - t0) * 1000.0,
best_available=report.get("best_available_score"),
) )
owners = await owner_names_for( owners = await owner_names_for(
{int(note.user_id) for _s, note in raw if note.user_id != uid} {int(note.user_id) for _s, note in raw if note.user_id != uid}
@@ -162,11 +165,46 @@ async def retrieval_telemetry(days: int = 30) -> dict:
`sources` — per retrieval surface (`auto_inject`, `write_path`, `sources` — per retrieval surface (`auto_inject`, `write_path`,
`mcp_search`, …), from `retrieval_logs`: `calls`, `zero_result_calls`, `mcp_search`, …), from `retrieval_logs`: `calls`, `zero_result_calls`,
`cleared_threshold` (how often the best hit beat the threshold in force for `near_misses`, the `top_score` spread (p10/p50/p90/min/max),
that call), the `top_score` spread (p10/p50/p90/min/max), `avg_result_count` `avg_result_count` and `p90_duration_ms`.
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 THE NUMBER TO READ FIRST IS `near_misses.p90`, AGAINST THE THRESHOLD IN
on nearly every call is either well-tuned or too loose, and p10 says which. 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
"not measured here", NOT "none suppressed". Surfaces that pass their
exclusions into the search never see what was dropped, so they cannot say.
Do not read a null as a zero: reading an artifact as a measurement is how
this surface got mis-scoped once already (#3311, #3497).
`usage` — NOTES ONLY, from `note_usage_events`, at the per-note grain `usage` — NOTES ONLY, from `note_usage_events`, at the per-note grain
`retrieval_logs` cannot be indexed at: `surfaced` (ranked surfacings — a `retrieval_logs` cannot be indexed at: `surfaced` (ranked surfacings — a
@@ -223,10 +261,37 @@ 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 those same rules over time: a resident set surfaced thousands of times and
opened never is the dead-weight signal, one tier up. opened never is the dead-weight signal, one tier up.
Read it against `sources["write_path_rule"]`. That surface has never once Read it against `sources["write_path_rule"]`. That arm was once believed
declined to fire, and until this block existed there was no way to tell a never to decline — the reading that scoped #3311 — but it was the arm's
well-tuned arm from a bar it cannot fail to clear (#3311). `pull_through` `retrieval_logs` row being written only on calls that FOUND something, so
is the number that tells them apart. 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.
`rule_usage_failed: true` means that read failed while the rest of the `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 readout stood. The counts are still present so a caller can render, but
+19
View File
@@ -42,8 +42,26 @@ class RetrievalLog(Base):
# False=notes, NULL=any. # False=notes, NULL=any.
is_task: Mapped[bool | None] = mapped_column(Boolean, nullable=True) is_task: Mapped[bool | None] = mapped_column(Boolean, nullable=True)
result_count: Mapped[int] = mapped_column(Integer, nullable=False, default=0) result_count: Mapped[int] = mapped_column(Integer, nullable=False, default=0)
# How many scored hits this call DROPPED because the session had already
# been shown them. NULLABLE, and the null is load-bearing: it means "this
# surface does not report suppression", which must not read as "nothing was
# suppressed". `result_count == 0` alone conflates two different events —
# the ranker found nothing above threshold, and the ranker found something
# the reader already had — and only the first says a threshold is too high.
# Reading a zero as a ranker decline is how #3311 mis-scoped a milestone;
# an unmeasured value that renders as 0 is the same mistake with a nicer
# face, so surfaces that filter INSIDE the search leave this null.
suppressed_count: Mapped[int | None] = mapped_column(Integer, nullable=True)
top_score: Mapped[float | None] = mapped_column(Float, nullable=True) top_score: Mapped[float | None] = mapped_column(Float, nullable=True)
min_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. # [{"id": int, "score": float, "rank": int}, ...], highest-first.
result_ids: Mapped[list] = mapped_column(JSONB, nullable=False, default=list) result_ids: Mapped[list] = mapped_column(JSONB, nullable=False, default=list)
duration_ms: Mapped[float | None] = mapped_column(Float, nullable=True) duration_ms: Mapped[float | None] = mapped_column(Float, nullable=True)
@@ -67,6 +85,7 @@ class RetrievalLog(Base):
"project_id": self.project_id, "project_id": self.project_id,
"is_task": self.is_task, "is_task": self.is_task,
"result_count": self.result_count, "result_count": self.result_count,
"suppressed_count": self.suppressed_count,
"top_score": self.top_score, "top_score": self.top_score,
"min_score": self.min_score, "min_score": self.min_score,
"result_ids": self.result_ids, "result_ids": self.result_ids,
+3
View File
@@ -44,17 +44,20 @@ async def search_route():
project_id = request.args.get("project_id", type=int) project_id = request.args.get("project_id", type=int)
t0 = time.perf_counter() t0 = time.perf_counter()
report: dict = {}
results = await semantic_search_notes( results = await semantic_search_notes(
uid, q, limit=limit, is_task=is_task, threshold=_REST_SEARCH_THRESHOLD, uid, q, limit=limit, is_task=is_task, threshold=_REST_SEARCH_THRESHOLD,
project_id=project_id, system_id=system_id, project_id=project_id, system_id=system_id,
# The user typed this, so it reaches everything they may read. # The user typed this, so it reaches everything they may read.
scope="read", scope="read",
report=report,
) )
record_retrieval( record_retrieval(
user_id=uid, source="rest_search", query=q, user_id=uid, source="rest_search", query=q,
threshold=_REST_SEARCH_THRESHOLD, limit=limit, threshold=_REST_SEARCH_THRESHOLD, limit=limit,
project_id=project_id, is_task=is_task, results=results, project_id=project_id, is_task=is_task, results=results,
duration_ms=(time.perf_counter() - t0) * 1000.0, duration_ms=(time.perf_counter() - t0) * 1000.0,
best_available=report.get("best_available_score"),
) )
owners = await owner_names_for( owners = await owner_names_for(
{int(note.user_id) for _s, note in results if note.user_id != uid} {int(note.user_id) for _s, note in results if note.user_id != uid}
+56 -13
View File
@@ -448,6 +448,23 @@ async def upsert_note_embedding(
logger.warning("Failed to persist embedding for note %d", note_id, exc_info=True) 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( async def semantic_search_notes(
user_id: int, user_id: int,
query: str, query: str,
@@ -462,12 +479,19 @@ async def semantic_search_notes(
scope: str = "own", scope: str = "own",
demote_superseded: bool = True, demote_superseded: bool = True,
system_id: int | None = None, system_id: int | None = None,
report: dict | None = None,
) -> list[tuple[float, Note]]: ) -> list[tuple[float, Note]]:
"""Return up to *limit* (score, note) pairs most relevant to *query*. """Return up to *limit* (score, note) pairs most relevant to *query*.
Scores are cosine similarities in [-1, 1]; only notes at or above Scores are cosine similarities in [-1, 1]; only notes at or above
*threshold* are returned, sorted highest-first. *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 `note_type` narrows to a record kind, or several (e.g. "snippet", or
("snippet", "note")), for callers that want prior art rather than everything ("snippet", "note")), for callers that want prior art rather than everything
embedded. embedded.
@@ -513,7 +537,6 @@ async def semantic_search_notes(
# Distance ceiling equivalent to the similarity floor. Clamp to the valid # 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 # cosine-distance range [0, 2] so a threshold of, say, -1 doesn't produce a
# nonsensical ceiling. # nonsensical ceiling.
max_distance = min(2.0, max(0.0, 1.0 - threshold))
distance = NoteEmbedding.embedding.cosine_distance(query_vec) distance = NoteEmbedding.embedding.cosine_distance(query_vec)
try: try:
@@ -588,11 +611,10 @@ async def semantic_search_notes(
fetch = limit * _CHUNK_OVERFETCH * ( fetch = limit * _CHUNK_OVERFETCH * (
_SUPERSESSION_OVERFETCH if demote_superseded else 1 _SUPERSESSION_OVERFETCH if demote_superseded else 1
) )
stmt = ( # NO threshold predicate — see the note above this function. The
stmt.where(distance <= max_distance) # bar is applied after the collapse, where the rejected scores can
.order_by(distance.asc()) # still be seen.
.limit(fetch) stmt = stmt.order_by(distance.asc()).limit(fetch)
)
rows = list((await session.execute(stmt)).all()) rows = list((await session.execute(stmt)).all())
except Exception: except Exception:
logger.warning("Failed to query note embeddings", exc_info=True) logger.warning("Failed to query note embeddings", exc_info=True)
@@ -611,6 +633,11 @@ async def semantic_search_notes(
continue continue
seen.add(int(note.id)) seen.add(int(note.id))
scored.append((1.0 - float(dist), note)) 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: if not demote_superseded:
return scored[:limit] return scored[:limit]
return await _apply_supersession_penalty(scored, limit) return await _apply_supersession_penalty(scored, limit)
@@ -764,9 +791,16 @@ async def semantic_search_rules(
limit: int = 5, limit: int = 5,
threshold: float = _SIMILARITY_THRESHOLD, threshold: float = _SIMILARITY_THRESHOLD,
tier: str | None = None, tier: str | None = None,
report: dict | None = None,
) -> list[tuple[float, "Rule"]]: ) -> list[tuple[float, "Rule"]]:
"""Return up to *limit* (score, rule) pairs most relevant to *query*. """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 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 its project. Deliberately not filtered to what currently BINDS a given
project: this answers "is there a rule about this", which a person asking project: this answers "is there a rule about this", which a person asking
@@ -774,10 +808,17 @@ async def semantic_search_rules(
is the surfacing question, and it has its own machinery is the surfacing question, and it has its own machinery
(get_applicable_rules) rather than a second, subtly different copy here. (get_applicable_rules) rather than a second, subtly different copy here.
`tier` narrows to one tier. The write-path hint passes "conditional", `tier` narrows to one tier, and NONE is the ordinary case. The write-path
because an always-on rule is ALREADY in the session — surfacing it again as and pre-tool hints deliberately pass nothing: an always-on rule is already
a suggestion is pure noise, and noise on a hint that fires on every write in the session, but being in a list from turn zero is not the same as being
is how a hint gets ignored. 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.
Collapses to best-chunk-per-rule like the note search, so a long rule split 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. across chunks competes once rather than crowding the results with itself.
@@ -795,7 +836,6 @@ async def semantic_search_rules(
logger.debug("Rule search skipped — embedder unavailable") logger.debug("Rule search skipped — embedder unavailable")
return [] return []
max_distance = min(2.0, max(0.0, 1.0 - threshold))
distance = RuleEmbedding.embedding.cosine_distance(query_vec) distance = RuleEmbedding.embedding.cosine_distance(query_vec)
try: try:
@@ -809,7 +849,8 @@ async def semantic_search_rules(
.outerjoin(Project, Rule.project_id == Project.id) .outerjoin(Project, Rule.project_id == Project.id)
.where( .where(
Rule.deleted_at.is_(None), 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. # topic_id XOR project_id, so exactly one arm can match.
or_( or_(
Rulebook.owner_user_id == user_id, Rulebook.owner_user_id == user_id,
@@ -832,7 +873,9 @@ async def semantic_search_rules(
if rule.id not in best or score > best[rule.id][0]: if rule.id not in best or score > best[rule.id][0]:
best[rule.id] = (score, rule) best[rule.id] = (score, rule)
ranked = sorted(best.values(), key=lambda pair: pair[0], reverse=True) 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: async def backfill_rule_embeddings() -> None:
+125 -25
View File
@@ -94,13 +94,17 @@ WRITEPATH_DEFAULT_THRESHOLD = 0.68
# THE STRUCTURAL ARGUMENT, which is the only kind admissible here (rule 115). # 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: # Two facts hold on any install, including one with six rules and no telemetry:
# #
# 1. The eligible corpus is TINY. The arm searches `tier="conditional"` # 1. The eligible corpus is SMALL — every rule an install owns, still only
# rules only — a handful to a few dozen documents against thousands of # a few dozen documents against thousands of notes. A top-k over a small
# notes. A top-k over forty candidates always returns something, so # pool always returns something, so "the best match cleared the bar"
# "the best match cleared the bar" stops meaning "a good match exists" # drifts from "a good match exists" toward "N things were ranked". A bar
# and starts meaning "forty things were ranked". A bar calibrated for # calibrated for best-of-thousands is cleared by best-of-forty as
# best-of-thousands is cleared by best-of-forty as arithmetic, not # arithmetic rather than relevance.
# 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.
# 2. Rules are short imperative technical English — a far more HOMOGENEOUS # 2. Rules are short imperative technical English — a far more HOMOGENEOUS
# corpus than note prose. #2223 measured the floor for code against prose # 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 # at 0.55-0.63 and set 0.68 above it. A more homogeneous corpus has a
@@ -128,9 +132,14 @@ RULEHINT_DEFAULT_THRESHOLD = 0.72
# ONE rule per write, not two — and this is deliberately NOT a knob. # 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 # With a corpus this small, top-k does as much damage as the threshold: k=2
# over forty candidates means the second line is almost always the second-best # over a few dozen candidates means the second line is almost always the
# noise, arriving with the same confident framing as the first. Halving k # second-best noise, arriving with the same confident framing as the first.
# halves that regardless of where the bar sits. # 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.
# #
# It stays a constant because it is a decision about how LOUD one hint may be, # 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 # not a per-install tuning question. The hint already carries prior art, shape
@@ -140,6 +149,45 @@ RULEHINT_DEFAULT_THRESHOLD = 0.72
# adds a way to misconfigure the surface (rule 25 cuts both ways). # adds a way to misconfigure the surface (rule 25 cuts both ways).
RULEHINT_LIMIT = 1 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 # 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 # 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 # pasted script whose bulk says nothing about which rule applies. The VERB AND
@@ -415,6 +463,7 @@ async def _reserve_slot_for_reuse(
top_k = cfg["top_k"] top_k = cfg["top_k"]
_t0 = time.perf_counter() _t0 = time.perf_counter()
_rep: dict = {}
reuse = await semantic_search_notes( reuse = await semantic_search_notes(
user_id, query, user_id, query,
limit=1, limit=1,
@@ -423,6 +472,7 @@ async def _reserve_slot_for_reuse(
exclude_ids=exclude_ids | {int(n.id) for _s, n in kept}, exclude_ids=exclude_ids | {int(n.id) for _s, n in kept},
note_type=_REUSE_KINDS, note_type=_REUSE_KINDS,
scope="browse", scope="browse",
report=_rep,
) )
# A real semantic query competing for a menu slot — logged like the scored # 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 # arm it displaces. Before this, the hit it PUSHED OUT was in
@@ -433,6 +483,7 @@ async def _reserve_slot_for_reuse(
user_id=user_id, source="reuse_slot", query=query, user_id=user_id, source="reuse_slot", query=query,
threshold=cfg["threshold"], limit=1, project_id=project_id, threshold=cfg["threshold"], limit=1, project_id=project_id,
is_task=None, results=reuse, is_task=None, results=reuse,
best_available=_rep.get("best_available_score"),
duration_ms=(time.perf_counter() - _t0) * 1000.0, duration_ms=(time.perf_counter() - _t0) * 1000.0,
) )
# Verify the kind rather than trusting the query that asked for it, and # Verify the kind rather than trusting the query that asked for it, and
@@ -482,6 +533,7 @@ async def build_autoinject_hint(
return empty return empty
t0 = time.perf_counter() t0 = time.perf_counter()
_rep_ai: dict = {}
hits = await semantic_search_notes( hits = await semantic_search_notes(
user_id, q, user_id, q,
limit=cfg["top_k"], limit=cfg["top_k"],
@@ -493,11 +545,13 @@ async def build_autoinject_hint(
# still appear is a collaborator's note inside a shared project — legible # still appear is a collaborator's note inside a shared project — legible
# only because the line below names its owner. # only because the line below names its owner.
scope="browse", scope="browse",
report=_rep_ai,
) )
record_retrieval( record_retrieval(
user_id=user_id, source="auto_inject", query=q, user_id=user_id, source="auto_inject", query=q,
threshold=cfg["threshold"], limit=cfg["top_k"], threshold=cfg["threshold"], limit=cfg["top_k"],
project_id=(project_id or None), is_task=None, results=hits, 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, duration_ms=(time.perf_counter() - t0) * 1000.0,
) )
if not hits: if not hits:
@@ -924,6 +978,7 @@ async def build_write_path_hint(
# Pulled-and-seen ids stay in the query (as evidence) but never in # Pulled-and-seen ids stay in the query (as evidence) but never in
# the menu — the dedup contract holds, the resemblance still lands. # the menu — the dedup contract holds, the resemblance still lands.
pulled_seen = seen & set(pulled) pulled_seen = seen & set(pulled)
_rep_wp: dict = {}
hits = await semantic_search_notes( hits = await semantic_search_notes(
user_id, query, user_id, query,
limit=remaining + len(pulled_seen), limit=remaining + len(pulled_seen),
@@ -947,6 +1002,7 @@ async def build_write_path_hint(
# Same reasoning as auto-inject: nobody asked for this, so it takes # Same reasoning as auto-inject: nobody asked for this, so it takes
# the browse scope and never surfaces a one-to-one direct share. # the browse scope and never surfaces a one-to-one direct share.
scope="browse", scope="browse",
report=_rep_wp,
) )
resembles = { resembles = {
int(note.id): float(score) for score, note in hits int(note.id): float(score) for score, note in hits
@@ -960,6 +1016,7 @@ async def build_write_path_hint(
# recording it as a notes-only retrieval would misdescribe the # recording it as a notes-only retrieval would misdescribe the
# candidate set the threshold is being tuned against. # candidate set the threshold is being tuned against.
project_id=scope_project, is_task=None, results=hits, 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, duration_ms=(time.perf_counter() - t0) * 1000.0,
) )
if hits: if hits:
@@ -1203,9 +1260,11 @@ async def build_write_path_hint(
# — a gap that reads as "this surface is somehow not measurable" rather # — a gap that reads as "this surface is somehow not measurable" rather
# than "nobody passed the number". # than "nobody passed the number".
rule_t0 = time.perf_counter() rule_t0 = time.perf_counter()
_rep_wpr: dict = {}
hits = await semantic_search_rules( hits = await semantic_search_rules(
user_id, code or path, limit=RULEHINT_LIMIT, user_id, code or path, limit=RULEHINT_LIMIT,
threshold=cfg["rule_threshold"], tier="conditional", threshold=cfg["rule_threshold"],
report=_rep_wpr,
) )
rule_ms = (time.perf_counter() - rule_t0) * 1000.0 rule_ms = (time.perf_counter() - rule_t0) * 1000.0
fresh = [(score, rule) for score, rule in hits if rule.id not in already] fresh = [(score, rule) for score, rule in hits if rule.id not in already]
@@ -1218,24 +1277,49 @@ async def build_write_path_hint(
"does not apply; it is not in this session's loaded set." "does not apply; it is not in this session's loaded set."
) )
rule_ids.append(rule.id) rule_ids.append(rule.id)
if fresh:
# TWO tables, and the split is not arbitrary. retrieval_logs is one # TWO tables, and the split is not arbitrary. retrieval_logs is one
# row per CALL, keyed on the score distribution a threshold is # row per CALL, keyed on the score distribution a threshold is tuned
# tuned from. rule_usage_events is one row per RULE per event, # from. rule_usage_events is one row per RULE per event, which is the
# which is the grain "was this hint ever acted on" needs and the # grain "was this hint ever acted on" needs and the grain a JSONB
# grain a JSONB result_ids array cannot be indexed at. # result_ids array cannot be indexed at.
# #
# This comment used to say rule ids had nowhere to go — that # This comment used to say rule ids had nowhere to go — that
# note_usage_events remaps ids on restore, so a rule id there would # note_usage_events remaps ids on restore, so a rule id there would
# return attached to whatever note took that number. That is still # return attached to whatever note took that number. That is still
# true of the NOTE table, and it is exactly why rule_usage_events # true of the NOTE table, and it is exactly why rule_usage_events is
# is its own (milestone 333 step 1). The gap it described is closed. # its own (milestone 333 step 1). The gap it described is closed.
#
# THE CALL LOG IS UNCONDITIONAL; THE SURFACING LOG IS NOT, and the
# asymmetry is the correction #3497 exists to make. Both used to sit
# inside an `if fresh:`, which is how this arm came to report
# `zero_result_calls: 0` and `cleared_threshold: 133/133` — not a
# perfectly tuned surface but one structurally unable to record its
# own misses. #3311 read that artifact as a measurement and a whole
# milestone was scoped on it. A call that found nothing is the ONLY
# evidence a threshold is set too high, and it is the row every note
# surface has always written (write_path: 421 zeroes of 613 calls;
# auto_inject: 114 of 326). A SURFACING is different in kind: nothing
# was shown, so no such event occurred, and its log stays guarded.
#
# `results=fresh`, not `hits`: the note arms pass their exclusions
# INTO semantic_search_notes, so what they log is already
# post-exclusion. semantic_search_rules takes no such parameter and
# this filter is where the equivalent happens — logging `hits` would
# quietly make this row mean something other than every other row in
# the same readout.
record_retrieval( record_retrieval(
user_id=user_id, source="write_path_rule", query=code or path, user_id=user_id, source="write_path_rule", query=code or path,
threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT, threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT,
project_id=project_id, project_id=project_id,
is_task=None, results=fresh, duration_ms=rule_ms, 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
# reason to move the threshold.
suppressed=len(hits) - len(fresh),
) )
if fresh:
# `rule_ids` is `fresh`, i.e. AFTER exclude_rule_ids. A rule the # `rule_ids` is `fresh`, i.e. AFTER exclude_rule_ids. A rule the
# session already holds was considered and not shown, and counting # session already holds was considered and not shown, and counting
# it would inflate the denominator with claims the agent never saw # it would inflate the denominator with claims the agent never saw
@@ -1311,14 +1395,36 @@ async def build_tool_rule_hint(
query = command[:_TOOL_QUERY_CHARS] query = command[:_TOOL_QUERY_CHARS]
t0 = time.perf_counter() t0 = time.perf_counter()
_rep_ptr: dict = {}
hits = await semantic_search_rules( hits = await semantic_search_rules(
user_id, query, limit=RULEHINT_LIMIT, user_id, query, limit=RULEHINT_LIMIT,
threshold=cfg["rule_threshold"], tier="conditional", threshold=cfg["rule_threshold"],
report=_rep_ptr,
) )
duration_ms = (time.perf_counter() - t0) * 1000.0 duration_ms = (time.perf_counter() - t0) * 1000.0
already = set(exclude_rule_ids or []) already = set(exclude_rule_ids or [])
fresh = [(score, rule) for score, rule in hits if rule.id not in already] fresh = [(score, rule) for score, rule in hits if rule.id not in already]
# Logged BEFORE the early return, for the reason spelled out at length
# on the write-path arm above: a call that found nothing is the only
# evidence a threshold is too high, and an arm that logs only the calls
# it liked reports a flawless clear-rate however badly it is tuned.
# This arm shipped with the same defect inherited from its sibling, and
# it mattered more here — a surface with no rows at all cannot be told
# apart from a hook that never fired, which is precisely the silent
# failure the arm was built to stop.
record_retrieval(
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,
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.
suppressed=len(hits) - len(fresh),
)
if not fresh: if not fresh:
return out return out
@@ -1335,12 +1441,6 @@ async def build_tool_rule_hint(
) )
rule_ids.append(rule.id) rule_ids.append(rule.id)
record_retrieval(
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,
)
# RANKED, not ambient: this arm chose what it showed, so a pull can # RANKED, not ambient: this arm chose what it showed, so a pull can
# settle whether the choice was any good. `rule_usage.RANKED_SOURCES` # settle whether the choice was any good. `rule_usage.RANKED_SOURCES`
# carries the same name. # carries the same name.
+203 -16
View File
@@ -55,12 +55,26 @@ def _build_payload(
is_task: bool | None, is_task: bool | None,
results: list[tuple[float, Note]], results: list[tuple[float, Note]],
duration_ms: float | None, duration_ms: float | None,
suppressed: int | None = None,
best_available: float | None = None,
) -> dict: ) -> dict:
"""Reduce a retrieval call to a flat, JSON-safe RetrievalLog payload. """Reduce a retrieval call to a flat, JSON-safe RetrievalLog payload.
Pure and synchronous (no DB, no event loop) so it is unit-testable and safe Pure and synchronous (no DB, no event loop) so it is unit-testable and safe
to run inline before scheduling the write. `results` is the to run inline before scheduling the write. `results` is the
`(score, Note)` list from semantic_search_notes, already highest-first. `(score, Note)` list from semantic_search_notes, already highest-first.
`suppressed` is how many scored hits the caller dropped because the session
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 = [ items = [
{"id": int(note.id), "score": round(float(score), 5), "rank": rank} {"id": int(note.id), "score": round(float(score), 5), "rank": rank}
@@ -76,8 +90,12 @@ def _build_payload(
"project_id": project_id, "project_id": project_id,
"is_task": is_task, "is_task": is_task,
"result_count": len(items), "result_count": len(items),
"suppressed_count": (None if suppressed is None else int(suppressed)),
"top_score": (scores[0] if scores else None), "top_score": (scores[0] if scores else None),
"min_score": (scores[-1] 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, "result_ids": items,
"duration_ms": (round(duration_ms, 2) if duration_ms is not None else None), "duration_ms": (round(duration_ms, 2) if duration_ms is not None else None),
} }
@@ -115,6 +133,8 @@ def record_retrieval(
is_task: bool | None, is_task: bool | None,
results: list[tuple[float, Any]], results: list[tuple[float, Any]],
duration_ms: float | None = None, duration_ms: float | None = None,
suppressed: int | None = None,
best_available: float | None = None,
) -> None: ) -> None:
"""Fire-and-forget: record one retrieval call. """Fire-and-forget: record one retrieval call.
@@ -140,6 +160,8 @@ def record_retrieval(
is_task=is_task, is_task=is_task,
results=results, results=results,
duration_ms=duration_ms, duration_ms=duration_ms,
suppressed=suppressed,
best_available=best_available,
) )
except Exception: except Exception:
logger.debug("retrieval telemetry payload build failed", exc_info=True) logger.debug("retrieval telemetry payload build failed", exc_info=True)
@@ -166,31 +188,138 @@ def record_retrieval(
def _bucket(rows: list) -> dict: def _bucket(rows: list) -> dict:
"""A score readout a human can act on, from one aggregate row.""" """A score readout a human can act on, from one aggregate row."""
calls, zero, cleared, p10, p50, p90, lo, hi, avg_n, dur = 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 { return {
"calls": int(calls or 0), "calls": int(calls or 0),
# A call that returned nothing is not a low-scoring call — it is a # A call that returned nothing is not a low-scoring call — it is a
# different failure (nothing indexed, filter too narrow), and averaging # different failure (nothing indexed, filter too narrow), and averaging
# it into the score distribution would hide both. # it into the score distribution would hide both.
"zero_result_calls": int(zero or 0), "zero_result_calls": int(zero or 0),
# How often the best hit actually cleared the threshold in force for # `cleared_threshold` USED TO LIVE HERE and it was a tautology (#3670).
# that call. THE precision-adjacent number: a surface that clears its # The search applies the bar before returning, so every returned result
# bar on almost every call is either well-tuned or too loose, and the # cleared it by construction and a call with nothing has no score to
# score spread below says which. # compare — the condition was true exactly when `result_count > 0`.
"cleared_threshold": int(cleared or 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.
#
# None — not a zeroed dict — when no row in the window reported it. A
# surface that filters inside the search genuinely does not know, and
# rendering that as `{"calls": 0}` would state a measurement nobody
# made. That substitution is the whole of #3311.
"suppression": (
None if not int(measured or 0) else {
"measured_calls": int(measured or 0),
"calls_with_suppression": int(supp_calls or 0),
# Subtract from zero_result_calls for the true ranker declines.
"zero_because_already_shown": int(supp_zero or 0),
}
),
"top_score": { "top_score": {
"p10": _round(p10), "p50": _round(p50), "p90": _round(p90), "p10": _round(p10), "p50": _round(p50), "p90": _round(p90),
"min": _round(lo), "max": _round(hi), "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), "avg_result_count": _round(avg_n),
"p90_duration_ms": _round(dur, 1), "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): def _round(v, places: int = 4):
return None if v is None else round(float(v), places) 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: async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
"""What the retrieval telemetry says, per surface, over a window. """What the retrieval telemetry says, per surface, over a window.
@@ -230,16 +359,30 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
"read_failed": False, "read_failed": False,
} }
cleared = case( zero = case((RetrievalLog.result_count == 0, 1), else_=0)
( # THE NEAR-MISS POPULATION: calls that returned nothing AND recorded what
(RetrievalLog.threshold.isnot(None)) # the bar turned away. Both conditions matter. Restricting to zero-result
& (RetrievalLog.top_score.isnot(None)) # calls is what makes the number say something the bar cannot fix by
& (RetrievalLog.top_score >= RetrievalLog.threshold), # construction — on a call that returned something, `best_available_score`
1, # 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)
supp_calls = case((RetrievalLog.suppressed_count > 0, 1), else_=0)
supp_zero = case(
((RetrievalLog.result_count == 0) & (RetrievalLog.suppressed_count > 0), 1),
else_=0, else_=0,
) )
zero = case((RetrievalLog.result_count == 0, 1), else_=0)
def pct(p: float): def pct(p: float):
return func.percentile_cont(p).within_group(RetrievalLog.top_score.asc()) return func.percentile_cont(p).within_group(RetrievalLog.top_score.asc())
@@ -249,6 +392,9 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
by_source_rows = None by_source_rows = None
rule_rows = None rule_rows = None
distinct_rules_surfaced = distinct_rules_pulled = 0 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: try:
async with async_session() as session: async with async_session() as session:
@@ -258,7 +404,6 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
RetrievalLog.source, RetrievalLog.source,
func.count().label("calls"), func.count().label("calls"),
func.sum(zero).label("zero"), func.sum(zero).label("zero"),
func.sum(cleared).label("cleared"),
pct(0.1), pct(0.5), pct(0.9), pct(0.1), pct(0.5), pct(0.9),
func.min(RetrievalLog.top_score), func.min(RetrievalLog.top_score),
func.max(RetrievalLog.top_score), func.max(RetrievalLog.top_score),
@@ -266,6 +411,13 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
func.percentile_cont(0.9).within_group( func.percentile_cont(0.9).within_group(
RetrievalLog.duration_ms.asc() RetrievalLog.duration_ms.asc()
), ),
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( .where(
RetrievalLog.created_at >= since, RetrievalLog.created_at >= since,
@@ -274,8 +426,34 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(RetrievalLog.source) .group_by(RetrievalLog.source)
) )
).all() ).all()
log_complete = await _complete_from(session, RetrievalLog, user_id)
for row in rows: for row in rows:
out["sources"][row[0]] = _bucket(list(row[1:])) 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
# The corpus side, at its own grain. `ambient` mirrors # The corpus side, at its own grain. `ambient` mirrors
# note_usage.usage_for_notes: an ambient surfacing was not a scored # note_usage.usage_for_notes: an ambient surfacing was not a scored
@@ -302,6 +480,7 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(NoteUsageEvent.event, NoteUsageEvent.source) .group_by(NoteUsageEvent.event, NoteUsageEvent.source)
) )
).all() ).all()
note_complete = await _complete_from(session, NoteUsageEvent, user_id)
# Distinct-note counts need their OWN queries, and this is not # Distinct-note counts need their OWN queries, and this is not
# fussiness: count(distinct note_id) per (event, source) group # fussiness: count(distinct note_id) per (event, source) group
@@ -429,6 +608,9 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
.group_by(RuleUsageEvent.event, RuleUsageEvent.source) .group_by(RuleUsageEvent.event, RuleUsageEvent.source)
) )
).all() ).all()
rule_complete = await _complete_from(
session, RuleUsageEvent, user_id,
)
# The rows carry `source`, so the ranked/ambient split is done # The rows carry `source`, so the ranked/ambient split is done
# below rather than in SQL — the bulk surfaces started emitting # below rather than in SQL — the bulk surfaces started emitting
# on 2026-09-03 (#3473), so there IS an ambient class now. # on 2026-09-03 (#3473), so there IS an ambient class now.
@@ -538,6 +720,10 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
} }
usage["by_source"] = by_source 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 out["usage"] = usage
# ── Rules, deliberately a SEPARATE block ──────────────────────────── # ── Rules, deliberately a SEPARATE block ────────────────────────────
@@ -615,6 +801,7 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
round(rule_usage["pulled_by_agent"] / rule_usage["surfaced"], 4) round(rule_usage["pulled_by_agent"] / rule_usage["surfaced"], 4)
if rule_usage["surfaced"] else None if rule_usage["surfaced"] else None
) )
rule_usage.update(_coverage((rule_complete or {}).get("*"), since))
out["rule_usage"] = rule_usage out["rule_usage"] = rule_usage
return out return out
+17 -5
View File
@@ -12,11 +12,23 @@ Two event streams, deliberately independent:
WHY THIS ARM AND NOT ANOTHER. Every other surface declines most of the time — WHY THIS ARM AND NOT ANOTHER. Every other surface declines most of the time —
`write_path` returns nothing on 78% of calls, `reuse_slot` on 79%, auto-inject `write_path` returns nothing on 78% of calls, `reuse_slot` on 79%, auto-inject
on 39%. The rule arm has never once returned nothing (#3311). That is either a on 39%. The rule arm APPEARED never to have returned nothing (#3311), and this
perfectly tuned surface or a bar it cannot fail to clear, and `retrieval_logs` docstring used to put that forward as the puzzle worth measuring: "either a
cannot tell the two apart: it records what the ranker scored, never whether the perfectly tuned surface or a bar it cannot fail to clear".
hint was any use. The ratio these two streams produce is the missing half, and
without it any threshold change is a number picked off a histogram. It was neither, and the correction belongs here rather than being quietly
deleted. The arm wrote its `retrieval_logs` row only on calls that FOUND
something (#3497), so `zero_result_calls` sat at 0 and `cleared_threshold` at
`calls` because of the shape of the code — at any threshold whatsoever. A
statistic that could not vary was read as a finding about the corpus. It is the
#2663 failure mode one level up: there the broken readout was a zero, here it
was a hundred percent, which is far better camouflage.
The reason to measure this arm survives the correction, and is stronger for it.
`retrieval_logs` records what the ranker scored, never whether the hint was any
use, so even an honest clear-rate would not settle the question. The ratio these
two streams produce is the missing half, and without it any threshold change is
a number picked off a histogram.
Design notes, mirroring `note_usage`: Design notes, mirroring `note_usage`:
- Writes are fire-and-forget through `background.spawn`, so telemetry never - Writes are fire-and-forget through `background.spawn`, so telemetry never
+40
View File
@@ -195,6 +195,46 @@ def test_displaced_topics_live_on_a_delivered_surface():
) )
# The SECOND pull (milestone 333 step 3). `list_always_on_rules()` fetches the
# resident tier; this one says that tier is not all of them, and that a
# conditional rule has to be gone looking for. However a surface words the
# surrounding prose, it names the call.
RETRIEVE = 'content_type="rule"'
def test_every_session_start_surface_states_the_conditional_retrieval():
"""The push/pull asymmetry, one level in.
The tests above pin that a session PULLS the resident rules rather than
trusting the SessionStart push. This pins the same shape between the two
TIERS: an always-on rule is delivered, a conditional one is retrieved, and
a surface that states only the first leaves a session reading its loaded
set as the whole rulebook.
That reading is wrong in the direction that costs something. "Nothing was
pushed" and "no rule applies" are different claims, and only one of them
has been checked — the same asymmetry as #2198, now between tiers instead
of between channels.
It is also what made the always-on tier the only one that worked, on any
install rather than this one (rule 115). A rule nothing retrieves has to be
resident to bind at all, so every rule worth keeping becomes resident; and
a resident rule costs tokens in every session forever, so a rulebook that
only delivers cannot grow past what one session can hold. Retrieval is what
lifts that ceiling — and it only fires if something asks.
"""
missing = []
for path in SESSION_START_SURFACES:
if RETRIEVE not in path.read_text():
missing.append(str(path.relative_to(ROOT)))
assert not missing, (
f"these surfaces state the always-on pull but never tell the agent to "
f"retrieve a conditional rule ({RETRIEVE}): {missing}. A session that "
f"reads its loaded set as the whole rulebook will act on \"I was not "
f"told\" as if it meant \"there is no rule\" (milestone 333 step 3)."
)
def test_no_surface_names_the_push_without_stating_the_pull(): def test_no_surface_names_the_push_without_stating_the_pull():
"""The exact shape #2497 took. """The exact shape #2497 took.
+120
View File
@@ -0,0 +1,120 @@
"""Both rule-creation tools run the propose-then-approve loop (#3557).
WHY THIS EXISTS
Every other gate on `create_rule` and `create_project_rule` is about SHAPE:
is this a rule or a process, is it one thing you could violate, is it general
enough for a rulebook, is it a near-duplicate. All of those improve a rule
someone has already decided to write. None of them asks the prior question —
whether the person the rule will bind has agreed to be bound by it.
That question belongs at the tool, because the tool is the last surface a
caller reads before the write, and because the write is less reversible than
it looks. The operator's yes is not merely consent; it is the one moment the
rule is certainly IN FRONT of them. Afterwards it may not be again for
months: a conditional rule is not read aloud at session start, and a
project-scoped rule does not appear in an unfiltered `list_rules()` at all.
The proposal IS the review, so there had better be one.
WHY IT IS PHRASED AS A PRACTICE AND NOT A PROHIBITION
The first cut of this guidance opened "NOT YOURS TO CALL UNPROMPTED." That is
the wrong instrument, and the failure it invites is worse than the one it
prevents: a caller reading a prohibition stops NOTICING rule-shaped things,
rather than noticing them and asking. The wanted behaviour is more proposals,
not fewer — spotting that something has hardened into a standing instruction
is valuable work, and the only step that was ever missing came after it.
So the docstrings describe what to DO: propose readily, state four things,
close with a question the operator answers in one word. This test is written
the same way — it asserts the parts of the loop are present, and has nothing
to say about any wording that forbids.
The fourth element — how the rule would be ENFORCED — is not ceremony. It is
the part that sometimes dissolves the rule: a thing a test can assert should
be that test, and a rule is what is left when nothing mechanical can hold it.
A rulebook grows by default and shrinks only on purpose, so the question that
prevents a rule earns more than any question that improves one's wording.
WHAT THIS PINS, AND WHAT IT DOES NOT
STRUCTURE, never wording — the same bargain the disambiguator guard (#3123)
strikes next door. Each element matches a family of synonyms, so the prose
stays free to be rewritten, reordered or sharpened; only DELETING one fails.
Pinning phrasing would make every improvement a red build, and a test that
punishes editing is a test someone deletes.
It cannot tell whether an agent actually proposes. Nothing in a docstring
can. It catches the regression that really happens: guidance tidied away in
a later pass by someone who read it as throat-clearing in front of the Args.
"""
import pytest
from tests.helpers import tool_doc as _doc
# Both surfaces, because the one that needs it most is the one that looks
# minor. A project rule is the least visible record the system can hold —
# absent from an unfiltered list_rules(), and absent from session start too
# whenever it is conditional — so the surface that writes one carries the
# larger risk while reading as the smaller act.
_SURFACES = [
("scribe.mcp.tools.rulebooks", "create_rule"),
("scribe.mcp.tools.rulebooks", "create_project_rule"),
]
# The loop, element by element, each as a family of ways to say it. A
# docstring satisfies an element by containing ANY member — that is the room
# left for rewriting. The families deliberately exclude bare words a
# docstring would hold by accident ("why", "how", "reason", "rule"), which
# would let the assertion pass on prose that says nothing of the kind.
_ELEMENTS = {
"the invitation to propose": ("propose", "proposal"),
"the operator's approval": ("approve", "approval", "says yes", "a yes"),
"the rule's intent": ("intent", "what it changes about how work"),
"why it is being proposed now": (
"why now", "arose_from_id", "the incident", "prompted it",
),
"how it would be enforced": ("enforc",),
"the answers offered back": ("as written", "talk about it", "discuss"),
}
@pytest.mark.parametrize(("module", "name"), _SURFACES)
@pytest.mark.parametrize("element", sorted(_ELEMENTS))
def test_a_rule_surface_carries_every_part_of_the_proposal_loop(
module, name, element
):
"""Each element of propose → state four things → ask survives."""
doc = _doc(module, name).lower()
assert any(token in doc for token in _ELEMENTS[element]), (
f"{name}'s docstring no longer mentions {element}. A caller reads "
f"this immediately before writing a rule that will bind every future "
f"session, and the proposal is the one moment that rule is certain to "
f"be seen by the operator. Say it in whatever words you like; this "
f"guard only checks it is still said. See create_rule's opening."
)
@pytest.mark.parametrize(("module", "name"), _SURFACES)
def test_the_proposal_loop_comes_before_the_parameter_contract(module, name):
"""It has to be read to work, and the Args: block is where reading stops.
A caller who has decided to make the call skims down to the parameters.
Guidance parked below them — or folded into one argument's description —
arrives after the decision it was meant to inform, which is the same as
not being there.
"""
doc = _doc(module, name).lower()
args_at = doc.find("args:")
assert args_at > 0, f"{name}'s docstring has no Args: block"
loop_at = min(
(doc.find(t) for t in _ELEMENTS["the invitation to propose"]
if doc.find(t) >= 0),
default=-1,
)
assert 0 <= loop_at < args_at, (
f"{name} introduces the proposal loop at or after its Args: block "
f"(loop {loop_at}, args {args_at}). Move it to the opening — a "
f"caller who has already decided to write the rule reads the "
f"parameters, not the prose under them."
)
+301 -12
View File
@@ -47,12 +47,14 @@ _PRIOR_ART = [(0.72, fake_note(id=9, title="debounce helper", user_id=1,
note_type="snippet"))] note_type="snippet"))]
def _arm_patches(pc, hits, recorder, prior_art=None, cfg=None, rule_search=None): def _arm_patches(pc, hits, recorder, prior_art=None, cfg=None, rule_search=None,
retrieval_log=None):
"""The minimum stubbing that lets the rule arm run and nothing else. """The minimum stubbing that lets the rule arm run and nothing else.
`cfg` and `rule_search` are overridable so a caller can inspect what the `cfg`, `rule_search` and `retrieval_log` are overridable so a caller can
arm ASKED for rather than only what it did with the answer — patching them inspect what the arm ASKED for, and what it told the CALL log, rather than
a second time on top would work, but reads as an accident. only what it did with the answer — patching them a second time on top would
work, but reads as an accident.
""" """
return ( return (
patch.object(pc, "get_writepath_config", patch.object(pc, "get_writepath_config",
@@ -66,7 +68,7 @@ def _arm_patches(pc, hits, recorder, prior_art=None, cfg=None, rule_search=None)
else prior_art)), else prior_art)),
patch.object(pc, "semantic_search_rules", patch.object(pc, "semantic_search_rules",
rule_search or AsyncMock(return_value=hits)), rule_search or AsyncMock(return_value=hits)),
patch.object(pc, "record_retrieval", MagicMock()), patch.object(pc, "record_retrieval", retrieval_log or MagicMock()),
patch.object(pc, "record_surfaced", MagicMock()), patch.object(pc, "record_surfaced", MagicMock()),
patch.object(pc, "record_rule_surfaced", recorder), patch.object(pc, "record_rule_surfaced", recorder),
patch.object(pc, "owner_names_for", AsyncMock(return_value={})), patch.object(pc, "owner_names_for", AsyncMock(return_value={})),
@@ -74,10 +76,11 @@ def _arm_patches(pc, hits, recorder, prior_art=None, cfg=None, rule_search=None)
) )
async def _run_arm(hits, recorder, prior_art=None, **kwargs): async def _run_arm(hits, recorder, prior_art=None, retrieval_log=None, **kwargs):
from scribe.services import plugin_context as pc from scribe.services import plugin_context as pc
with ExitStack() as stack: with ExitStack() as stack:
for ctx in _arm_patches(pc, hits, recorder, prior_art): for ctx in _arm_patches(pc, hits, recorder, prior_art,
retrieval_log=retrieval_log):
stack.enter_context(ctx) stack.enter_context(ctx)
return await pc.build_write_path_hint( return await pc.build_write_path_hint(
1, "frontend/src/api/client.ts", code="x" * 400, **kwargs 1, "frontend/src/api/client.ts", code="x" * 400, **kwargs
@@ -157,7 +160,15 @@ async def test_the_arm_searches_on_its_OWN_bar_not_the_code_one():
kw = search.await_args.kwargs kw = search.await_args.kwargs
assert kw["threshold"] == 0.81, "the arm is still using the code threshold" assert kw["threshold"] == 0.81, "the arm is still using the code threshold"
assert kw["limit"] == pc.RULEHINT_LIMIT assert kw["limit"] == pc.RULEHINT_LIMIT
assert kw["tier"] == "conditional" # 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"
)
@pytest.mark.asyncio @pytest.mark.asyncio
@@ -410,7 +421,7 @@ def test_the_marker_paths_stay_silent():
# is why they all had to be resident. These cover the surface that changes it. # is why they all had to be resident. These cover the surface that changes it.
def _tool_patches(pc, hits, recorder, cfg=None): def _tool_patches(pc, hits, recorder, cfg=None, retrieval_log=None):
return ( return (
patch.object(pc, "get_writepath_config", patch.object(pc, "get_writepath_config",
AsyncMock(return_value=cfg or { AsyncMock(return_value=cfg or {
@@ -418,16 +429,16 @@ def _tool_patches(pc, hits, recorder, cfg=None):
"top_k": 3, "rule_threshold": 0.6, "top_k": 3, "rule_threshold": 0.6,
})), })),
patch.object(pc, "semantic_search_rules", AsyncMock(return_value=hits)), patch.object(pc, "semantic_search_rules", AsyncMock(return_value=hits)),
patch.object(pc, "record_retrieval", MagicMock()), patch.object(pc, "record_retrieval", retrieval_log or MagicMock()),
patch.object(pc, "record_rule_surfaced", recorder), patch.object(pc, "record_rule_surfaced", recorder),
) )
async def _run_tool_arm(hits, recorder, command="curl -s https://git.example/api/v1/runs", async def _run_tool_arm(hits, recorder, command="curl -s https://git.example/api/v1/runs",
tool="Bash", **kwargs): tool="Bash", retrieval_log=None, **kwargs):
from scribe.services import plugin_context as pc from scribe.services import plugin_context as pc
with ExitStack() as stack: with ExitStack() as stack:
for ctx in _tool_patches(pc, hits, recorder): for ctx in _tool_patches(pc, hits, recorder, retrieval_log=retrieval_log):
stack.enter_context(ctx) stack.enter_context(ctx)
return await pc.build_tool_rule_hint(1, tool, command, **kwargs) return await pc.build_tool_rule_hint(1, tool, command, **kwargs)
@@ -577,3 +588,281 @@ def test_the_hook_and_the_route_agree_on_every_parameter_name():
assert f'request.args.get("{arg}")' in handler, ( assert f'request.args.get("{arg}")' in handler, (
f"the hook sends {arg!r} and the route never reads it" f"the hook sends {arg!r} and the route never reads it"
) )
# ── The CALL log is unconditional; the SURFACING log is not (#3497) ────
#
# Both arms used to write their retrieval_logs row inside a guard on having
# results, so `zero_result_calls` was pinned at 0 and `cleared_threshold` at
# `calls` by the shape of the code — at any threshold whatsoever. #3311 read
# that as a measurement of the corpus and a milestone was scoped on it.
#
# The distinction these tests hold: a CALL happened whether or not it found
# anything, and the calls that found nothing are the only evidence a threshold
# is set too high. A SURFACING did not happen when nothing was shown.
@pytest.mark.asyncio
async def test_the_write_path_arm_logs_the_call_that_found_nothing():
log, rec = MagicMock(), MagicMock()
await _run_arm([], rec, retrieval_log=log)
rule_calls = [c for c in log.call_args_list
if c.kwargs.get("source") == "write_path_rule"]
assert len(rule_calls) == 1, (
"a rule call that found nothing wrote no row — `zero_result_calls` can "
"then only ever read 0, however badly the threshold is tuned"
)
assert rule_calls[0].kwargs["results"] == []
rec.assert_not_called()
@pytest.mark.asyncio
async def test_the_write_path_arm_logs_a_call_whose_only_hit_was_already_shown():
"""The subtler half. The ranker DID find something; the session had already
been told. That is a decline from the reader's side and must be logged as
one — the note arms get this for free by passing exclusions into the search,
so their zero-result rows already include this case."""
log, rec = MagicMock(), MagicMock()
hits = [(0.71, fake_rule(id=156, title="A wait with no deadline is a bug"))]
await _run_arm(hits, rec, retrieval_log=log, exclude_rule_ids=[156])
rule_calls = [c for c in log.call_args_list
if c.kwargs.get("source") == "write_path_rule"]
assert len(rule_calls) == 1
assert rule_calls[0].kwargs["results"] == [], (
"the row must record what the arm could SHOW, so this row is comparable "
"with an auto_inject row, whose exclusions are applied by the search"
)
rec.assert_not_called()
@pytest.mark.asyncio
async def test_the_tool_arm_logs_the_call_that_found_nothing():
"""It matters more here than on the sibling. This arm fires on every Bash
call, so an empty `sources` row is the normal outcome — and with no row at
all, "the ranker declined" is indistinguishable from "the hook never fired",
which is exactly the silent failure the arm was built to stop (#3476)."""
log, rec = MagicMock(), MagicMock()
out = await _run_tool_arm([], rec, retrieval_log=log)
assert out == {"context": "", "rule_ids": []}
assert log.call_count == 1
assert log.call_args.kwargs["source"] == "pre_tool_rule"
assert log.call_args.kwargs["results"] == []
assert log.call_args.kwargs["query"] == "curl -s https://git.example/api/v1/runs", (
"the query is the point of the row: it is what a threshold is tuned against"
)
rec.assert_not_called()
@pytest.mark.asyncio
async def test_the_tool_arm_logs_a_call_whose_only_hit_was_already_shown():
log, rec = MagicMock(), MagicMock()
hits = [(0.71, fake_rule(id=161, title="Reach the forge through its MCP tools"))]
out = await _run_tool_arm(hits, rec, retrieval_log=log, exclude_rule_ids=[161])
assert out["rule_ids"] == []
assert log.call_count == 1
assert log.call_args.kwargs["results"] == []
rec.assert_not_called()
@pytest.mark.asyncio
async def test_a_command_the_arm_never_searched_writes_no_row_at_all():
"""The one case that must stay silent, and the boundary of the rule above.
A blank command costs no embedding query, so there was no retrieval to log.
A row here would report a call that never happened and drag the clear-rate
down with phantom declines — the mirror of the defect, from the other side.
"""
from scribe.services import plugin_context as pc
log = MagicMock()
with ExitStack() as stack:
for ctx in _tool_patches(pc, [], MagicMock(), retrieval_log=log):
stack.enter_context(ctx)
await pc.build_tool_rule_hint(1, "Bash", " ")
log.assert_not_called()
def test_neither_rule_arm_logs_its_call_behind_a_results_guard():
"""Structural, on top of the behavioural pair above, because the defect was
one level of indentation and it appeared INDEPENDENTLY in two places — the
pre-tool arm inherited it by being modelled on its sibling. The third arm
modelled on either of them is the one this catches.
"""
pc_src = Path("src/scribe/services/plugin_context.py").read_text()
# Write-path arm: what remains inside `if fresh:` is the SURFACING log only.
guarded = pc_src.split('source="write_path_rule", query=code or path')[1]
guarded = guarded.split("if fresh:")[1].split("except Exception:")[0]
assert "record_rule_surfaced" in guarded, "the surfacing log must stay guarded"
assert "record_retrieval" not in guarded, (
"the call log is back inside the results guard — a call that found "
"nothing is the only evidence a threshold is set too high"
)
# Pre-tool arm: the call log comes BEFORE the early return.
body = pc_src.split("async def build_tool_rule_hint")[1]
assert body.index('source="pre_tool_rule"') < body.index("if not fresh:"), (
"the pre-tool arm returns before logging its call — a surface with no "
"rows at all cannot be told apart from a hook that never fired"
)
# ── Suppression: which zeros were the ranker, which were repeats (#3497) ──
#
# Making the call log unconditional exposed a second ambiguity in the same row.
# A zero-result rule call is two unrelated events: the ranker found nothing
# above the bar, or it found only what this session already held. Only the
# first says anything about the threshold, and a long session excludes its way
# into the second — so without the split, the arm looks worse the longer it
# runs correctly.
@pytest.mark.asyncio
async def test_the_write_path_arm_reports_what_the_session_already_held():
log, rec = MagicMock(), MagicMock()
hits = [(0.71, fake_rule(id=156, title="A wait with no deadline is a bug")),
(0.70, fake_rule(id=157, title="A loop re-arms in a finally"))]
await _run_arm(hits, rec, retrieval_log=log, exclude_rule_ids=[156, 157])
row = next(c for c in log.call_args_list
if c.kwargs.get("source") == "write_path_rule")
assert row.kwargs["results"] == []
assert row.kwargs["suppressed"] == 2, (
"both hits were repeats, so this zero is not evidence about the bar"
)
@pytest.mark.asyncio
async def test_a_genuine_ranker_decline_reports_zero_suppression():
"""Zero, not None. The arm filters in Python, so it always knows — and
'measured none' has to stay distinguishable from 'cannot measure'."""
log, rec = MagicMock(), MagicMock()
await _run_arm([], rec, retrieval_log=log)
row = next(c for c in log.call_args_list
if c.kwargs.get("source") == "write_path_rule")
assert row.kwargs["suppressed"] == 0
assert row.kwargs["suppressed"] is not None
@pytest.mark.asyncio
async def test_the_tool_arm_reports_suppression_too():
log, rec = MagicMock(), MagicMock()
hits = [(0.75, fake_rule(id=161, title="Reach the forge through its MCP tools"))]
await _run_tool_arm(hits, rec, retrieval_log=log, exclude_rule_ids=[161])
assert log.call_args.kwargs["results"] == []
assert log.call_args.kwargs["suppressed"] == 1
@pytest.mark.asyncio
async def test_a_shown_hit_is_not_counted_as_suppressed():
"""The obvious inverse, worth pinning: `suppressed` counts what was DROPPED,
not what came back. Off by one here and every zero row reads as a repeat."""
log, rec = MagicMock(), MagicMock()
hits = [(0.75, fake_rule(id=161, title="Reach the forge through its MCP tools")),
(0.70, fake_rule(id=12, title="Don't run a local stack unless asked"))]
out = await _run_tool_arm(hits, rec, retrieval_log=log, exclude_rule_ids=[12])
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"
)
+448 -1
View File
@@ -57,6 +57,68 @@ def test_build_payload_rounds_scores_to_5dp():
assert p["result_ids"][0]["score"] == 0.12346 assert p["result_ids"][0]["score"] == 0.12346
# ─── suppression: "not measured" is not "none" (#3497) ───────────────────────
def test_a_caller_that_cannot_measure_suppression_stores_null():
"""The distinction the whole column exists for.
A surface that passes its exclusions into the search never sees what was
dropped. Storing 0 would assert a clean run nobody observed — reading an
artifact as a measurement, which is exactly #3311's mistake.
"""
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["suppressed_count"] is None, "unmeasured must not render as zero"
def test_a_caller_that_measured_no_suppression_stores_zero():
"""The other side of it. Zero is a real observation and must survive."""
p = _build_payload(
user_id=1, source="pre_tool_rule", query="git status", threshold=0.6,
limit=1, project_id=None, is_task=None, results=[], duration_ms=None,
suppressed=0,
)
assert p["suppressed_count"] == 0
def test_the_count_of_hits_the_reader_already_held_is_carried():
p = _build_payload(
user_id=1, source="write_path_rule", query="code", threshold=0.6,
limit=2, project_id=None, is_task=None, results=[], duration_ms=None,
suppressed=2,
)
assert p["result_count"] == 0
assert p["suppressed_count"] == 2, (
"a zero row that was really two repeats must be distinguishable from "
"a zero row where the ranker found nothing"
)
def test_the_readout_reports_unmeasured_suppression_as_none():
"""`_bucket` renders the aggregate. No row reporting it → null, never a
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])
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])
assert measured["suppression"] == {
"measured_calls": 35,
"calls_with_suppression": 9,
"zero_because_already_shown": 9,
}
# The number the threshold is actually tuned from.
assert measured["zero_result_calls"] - 9 == 25
def test_record_retrieval_without_event_loop_is_safe(): def test_record_retrieval_without_event_loop_is_safe():
"""Called from a sync context (no running loop) it must swallow and return, """Called from a sync context (no running loop) it must swallow and return,
never raise — telemetry can't be allowed to break a caller.""" never raise — telemetry can't be allowed to break a caller."""
@@ -162,7 +224,10 @@ async def test_retrieval_summary_reads_what_the_writer_wrote(_dispose_engine):
ai = out["sources"]["auto_inject"] ai = out["sources"]["auto_inject"]
assert ai["calls"] == 4 assert ai["calls"] == 4
assert ai["zero_result_calls"] == 1 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. # 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"]["p50"] == pytest.approx(0.72, abs=1e-4)
assert ai["top_score"]["min"] == pytest.approx(0.40, abs=1e-4) assert ai["top_score"]["min"] == pytest.approx(0.40, abs=1e-4)
@@ -576,3 +641,385 @@ async def test_ambient_alone_reports_no_ratio(_dispose_engine):
assert ru["pull_through"] is None assert ru["pull_through"] is None
finally: finally:
await cleanup() 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,
))
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()
+12 -4
View File
@@ -360,10 +360,18 @@ async def test_telemetry_uses_its_own_source():
patch.object(pc, "record_retrieval", rec), \ patch.object(pc, "record_retrieval", rec), \
patch.object(pc, "owner_names_for", AsyncMock(return_value={})): patch.object(pc, "owner_names_for", AsyncMock(return_value={})):
await pc.build_write_path_hint(1, "src/x.py", code=REAL_CODE, project_id=4) await pc.build_write_path_hint(1, "src/x.py", code=REAL_CODE, project_id=4)
rec.assert_called_once() sources = [c.kwargs["source"] for c in rec.call_args_list]
assert rec.call_args.kwargs["source"] == "write_path" assert sources.count("write_path") == 1, sources
assert rec.call_args.kwargs["source"] != "auto_inject" assert "auto_inject" not in sources
assert rec.call_args.kwargs["project_id"] == 4
note_arm = next(c for c in rec.call_args_list if c.kwargs["source"] == "write_path")
assert note_arm.kwargs["project_id"] == 4
# The rule arm rides along on the same hint and logs its own call even when
# it finds nothing (#3497). This assertion used to be `assert_called_once`,
# which passed only because that row was never written — the test encoded
# the defect. The second row is the point of having two sources.
assert "write_path_rule" in sources, sources
@pytest.mark.asyncio @pytest.mark.asyncio