feat(telemetry): pull-through per surface, not just per corpus (#3311)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 8s
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 25s

The readout already grouped usage by source — `group_by(event, source)` —
and the loop directly below it threw the source away, collapsing every
surface into one corpus-wide ratio. So the question a threshold is
actually tuned against, "is THIS surface worth its noise", could not be
asked of any surface, while the data to answer it sat in the table.

`usage.by_source` reports notes_surfaced / notes_pulled / pull_through
per surface. The grain is the note, not the call: a pull records the
door it came through, not the surface that led there, so grouping the
pulled rows by source would answer a different question. Joining
surfaced rows to pulled rows on note_id answers this one without the
session identity #2085 declined to invent — at the cost of being an
upper bound per surface, which the docstring says where it is read.

Ambient surfaces report counts and a null ratio: nothing chose those
records, so "surfaced often, opened never" is not a judgment about them.
A surface that genuinely produced nothing reports 0.0, which must not
look like the null.

The join is guarded separately from the two reads above it. #2663 was a
novel SQL shape the database rejected inside a broad except; this is the
novel shape here, and it must not take down two readouts that work.

Tests are integration for that same reason — a mock passes on a query
Postgres refuses. They pin the distinct-first property (three surfacings
of one note are one note), the ambient null, and the LIKE escape, since
an unescaped `mcp_%` also matches `mcpXget_note` and nothing else in the
payload would show the difference.
This commit is contained in:
2026-08-31 15:52:17 -04:00
parent 05da26eb24
commit 0d4b155699
3 changed files with 271 additions and 0 deletions
+17
View File
@@ -182,6 +182,23 @@ async def retrieval_telemetry(days: int = 30) -> dict:
tuned against — only by a pull the agent made. Aggregating across the
mcp_/rest_ prefix would silently answer the wrong one.
`usage["by_source"]` — THE number to tune a threshold against, because the
top-level `pull_through` is a corpus average and averages the surfaces
together. Per surface: `notes_surfaced`, `notes_pulled`, `pull_through`,
and `ambient: true` on surfaces whose surfacings were not scored choices
(their ratio is null — "surfaced often, opened never" is not a judgment
about a record nothing chose). Read it as: of the distinct notes THIS
surface put in front of the agent, how many did the agent then open?
Two limits on it, both deliberate. It is an UPPER BOUND per surface: a pull
records the door it came through, not the surface that led there, so a note
surfaced by two surfaces and opened once counts for both — attribution
would need the session identity #2085 declined to invent. And RULE
surfacings are absent: `write_path_rule` appears in `sources` with its
scores but has no usage counter at all, so it has no row here (#3311).
`by_source_failed: true` means that one query failed while the rest of the
readout stood.
Scoped to your own telemetry — a retrieval log records what your agent
asked for, query text included, and is not a shared record kind.
+117
View File
@@ -199,6 +199,12 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
it was built for. Reading each from its own table is both cheaper and more
honest than correlating them through JSONB.
`usage["by_source"]` is the one join, and it stays INSIDE
`note_usage_events` — surfaced rows against pulled rows on note_id. That
answers "of the notes this surface chose, how many were opened", which the
top-level ratio averages away. It does not cross into `retrieval_logs`, so
the sentence above still holds.
Scoped to one user's own telemetry. There is no sharing model for a
retrieval log — it records what THIS user's agent asked for, including the
query text — so an owner filter is the whole access rule here rather than a
@@ -231,6 +237,10 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
def pct(p: float):
return func.percentile_cont(p).within_group(RetrievalLog.top_score.asc())
# Assigned inside the try below; named here so the readout can tell
# "this query failed" from "this window has no rows" (#2663).
by_source_rows = None
try:
async with async_session() as session:
rows = (
@@ -310,6 +320,77 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
)
)
).scalar_one()
# Per-source pull-through, at the NOTE grain (#3311).
#
# The `urows` query above already groups by source and the loop
# below then throws the source away, so until now this readout
# could say what the corpus's overall pull-through was and nothing
# about WHICH surface earned it. The data was always here; only
# the aggregation discarded it.
#
# It cannot be had by grouping the PULLED rows by source: a pull
# records the door it came through (`mcp_get_note`), not the
# surface that put the record in front of the agent. Correlating
# those within a session is what #2085 ruled out — there is no
# session identity server-side and inventing one would mean
# threading a client-supplied token through every read path. The
# note grain answers the question without one: of the distinct
# notes surface X chose, how many did an agent open in this window?
#
# Guarded separately from the reads above, on #2663's actual
# lesson. That outage was a NOVEL SQL SHAPE the database rejected
# inside a broad except. This join is the novel shape here, and a
# failure in it must not take down two readouts that already work.
try:
pulled_ids = (
select(NoteUsageEvent.note_id)
.where(
NoteUsageEvent.created_at >= since,
NoteUsageEvent.user_id == user_id,
NoteUsageEvent.event == PULLED,
# autoescape because `_` is a LIKE wildcard: a bare
# like("mcp_%") also matches "mcpX…". The Python half
# of this readout uses str.startswith and has no such
# hazard; this is the SQL half's version of it.
NoteUsageEvent.source.startswith("mcp_", autoescape=True),
)
.distinct()
.subquery()
)
surfaced_pairs = (
select(NoteUsageEvent.source, NoteUsageEvent.note_id)
.where(
NoteUsageEvent.created_at >= since,
NoteUsageEvent.user_id == user_id,
NoteUsageEvent.event == SURFACED,
)
.distinct()
.subquery()
)
# DISTINCT on (source, note_id) FIRST, which is what lets the
# outer aggregate be a plain count(): the pairs are already
# unique, so the left join cannot multiply them and no
# count(DISTINCT) is needed to undo damage that never happens.
by_source_rows = (
await session.execute(
select(
surfaced_pairs.c.source,
func.count().label("notes_surfaced"),
func.count(pulled_ids.c.note_id).label("notes_pulled"),
)
.select_from(
surfaced_pairs.outerjoin(
pulled_ids,
pulled_ids.c.note_id == surfaced_pairs.c.note_id,
)
)
.group_by(surfaced_pairs.c.source)
)
).all()
except Exception:
logger.warning("per-source pull-through read failed", exc_info=True)
by_source_rows = None
except Exception:
logger.warning("retrieval summary read failed", exc_info=True)
out["read_failed"] = True
@@ -350,5 +431,41 @@ async def retrieval_summary(user_id: int | None, *, days: int = 30) -> dict:
round(usage["pulled_by_agent"] / usage["surfaced"], 4)
if usage["surfaced"] else None
)
# The same question, per surface — which is the one the top-level ratio
# cannot answer. A corpus average of 0.05 is compatible with one surface
# earning its noise and another producing none, and tuning a threshold
# needs to know which.
#
# UPPER BOUND, and say so where it will be read: a pull records the door,
# not the surface that led to it, so a note surfaced by two surfaces and
# opened once counts as pulled for both. Attribution would need the session
# identity #2085 declined to invent. The bound is still decisive in the
# direction that matters — a surface reading near zero here is not being
# flattered by the double-count.
if by_source_rows is None:
usage["by_source"] = {}
# Distinct from an empty window, for the same reason `read_failed` is.
usage["by_source_failed"] = True
else:
by_source: dict[str, dict] = {}
for source, n_surfaced, n_pulled in by_source_rows:
n_surfaced, n_pulled = int(n_surfaced or 0), int(n_pulled or 0)
ambient = source in AMBIENT_SOURCES
by_source[source] = {
"notes_surfaced": n_surfaced,
"notes_pulled": n_pulled,
# None rather than a number on an ambient surface: nothing
# CHOSE those records, so "surfaced often, opened never" is not
# a judgment about them. The counts stay visible; the ratio
# that would be misread does not.
"pull_through": (
None if ambient or not n_surfaced
else round(n_pulled / n_surfaced, 4)
),
"ambient": ambient,
}
usage["by_source"] = by_source
out["usage"] = usage
return out
+137
View File
@@ -195,6 +195,10 @@ async def test_retrieval_summary_is_empty_not_broken_for_a_fresh_install(_dispos
assert out["sources"] == {}
assert out["usage"]["pull_through"] is None # no division by zero
assert out["usage"]["surfaced"] == 0
# An empty dict, not a missing key and not a failure flag — the same
# "no rows" / "read broke" distinction the rest of this readout keeps.
assert out["usage"]["by_source"] == {}
assert "by_source_failed" not in out["usage"]
@pytest.mark.integration
@@ -222,3 +226,136 @@ async def test_retrieval_summary_sees_only_its_own_users_telemetry(_dispose_engi
async with async_session() as s:
await s.execute(delete(RetrievalLog).where(RetrievalLog.user_id == 990004))
await s.commit()
# ─── per-source pull-through (#3311) ─────────────────────────────────────────
# Integration for the same reason the block above is: this is a self-join with
# two DISTINCT subqueries and a LIKE escape, which is a new SQL shape in a
# module whose one production outage (#2663) was a new SQL shape the database
# rejected inside a broad except. A mock would pass on a query Postgres refuses.
@pytest.mark.integration
@pytest.mark.asyncio
async def test_by_source_separates_a_surface_that_earns_its_noise_from_one_that_does_not(
_dispose_engine,
):
"""The whole point: the corpus average cannot say WHICH surface is working.
Two ranked surfaces, identical volume, opposite outcomes — and a top-level
ratio that describes neither of them.
"""
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.note_usage import NoteUsageEvent
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990010
async with async_session() as s:
s.add_all([
# auto_inject chose note 1 three times and note 2 once. Three
# surfacings of one note is ONE note surfaced — the DISTINCT that
# keeps the join from multiplying rows is what this pins.
NoteUsageEvent(user_id=UID, note_id=1, event="surfaced", source="auto_inject"),
NoteUsageEvent(user_id=UID, note_id=1, event="surfaced", source="auto_inject"),
NoteUsageEvent(user_id=UID, note_id=1, event="surfaced", source="auto_inject"),
NoteUsageEvent(user_id=UID, note_id=2, event="surfaced", source="auto_inject"),
# write_path_semantic chose two notes and got nothing opened.
NoteUsageEvent(user_id=UID, note_id=3, event="surfaced", source="write_path_semantic"),
NoteUsageEvent(user_id=UID, note_id=4, event="surfaced", source="write_path_semantic"),
# One agent pull, of a note only auto_inject surfaced.
NoteUsageEvent(user_id=UID, note_id=1, event="pulled", source="mcp_get_note"),
])
await s.commit()
try:
out = await retrieval_summary(UID, days=30)
assert out["read_failed"] is False
by_source = out["usage"]["by_source"]
assert "by_source_failed" not in out["usage"], "the join did not execute"
ai = by_source["auto_inject"]
assert ai["notes_surfaced"] == 2, "three surfacings of note 1 are one note"
assert ai["notes_pulled"] == 1
assert ai["pull_through"] == pytest.approx(0.5)
wp = by_source["write_path_semantic"]
assert wp["notes_surfaced"] == 2
assert wp["notes_pulled"] == 0
# 0.0, NOT None. "This surface produced nothing" is a finding; None is
# what a surface with no data reads as, and they must not look alike.
assert wp["pull_through"] == 0.0
# And the number that exists today, which is true of neither surface:
# one agent pull over six ranked surfacings.
assert out["usage"]["pull_through"] == pytest.approx(1 / 6, abs=1e-4)
finally:
async with async_session() as s:
await s.execute(delete(NoteUsageEvent).where(NoteUsageEvent.user_id == UID))
await s.commit()
@pytest.mark.integration
@pytest.mark.asyncio
async def test_an_ambient_surface_reports_its_counts_but_no_ratio(_dispose_engine):
"""`enter_project` bulk-loads records; nothing CHOSE them. "Surfaced often,
opened never" is not a judgment about a record that was never picked, so the
counts stay visible and the ratio that would be misread is null."""
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.note_usage import NoteUsageEvent
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990011
async with async_session() as s:
s.add_all([
NoteUsageEvent(user_id=UID, note_id=1, event="surfaced", source="enter_project"),
NoteUsageEvent(user_id=UID, note_id=2, event="surfaced", source="enter_project"),
])
await s.commit()
try:
row = (await retrieval_summary(UID, days=30))["usage"]["by_source"]["enter_project"]
assert row["ambient"] is True
assert row["notes_surfaced"] == 2
assert row["pull_through"] is None
finally:
async with async_session() as s:
await s.execute(delete(NoteUsageEvent).where(NoteUsageEvent.user_id == UID))
await s.commit()
@pytest.mark.integration
@pytest.mark.asyncio
async def test_the_agent_pull_filter_does_not_treat_its_underscore_as_a_wildcard(
_dispose_engine,
):
"""`_` is a LIKE wildcard, so an unescaped `LIKE 'mcp_%'` also matches
`mcpXsomething`. The Python half of this readout uses str.startswith and
cannot have the bug; the SQL half needs autoescape to match it, and nothing
else in the payload would reveal the difference."""
from sqlalchemy import delete
from scribe.models import async_session
from scribe.models.note_usage import NoteUsageEvent
from scribe.services.retrieval_telemetry import retrieval_summary
UID = 990012
async with async_session() as s:
s.add_all([
NoteUsageEvent(user_id=UID, note_id=1, event="surfaced", source="auto_inject"),
# Not an agent pull: the door is `mcpXget_note`, not `mcp_get_note`.
NoteUsageEvent(user_id=UID, note_id=1, event="pulled", source="mcpXget_note"),
])
await s.commit()
try:
row = (await retrieval_summary(UID, days=30))["usage"]["by_source"]["auto_inject"]
assert row["notes_pulled"] == 0, "a wildcard match counted a non-agent pull"
assert row["pull_through"] == 0.0
finally:
async with async_session() as s:
await s.execute(delete(NoteUsageEvent).where(NoteUsageEvent.user_id == UID))
await s.commit()