Files
FabledScribe/src/scribe/models/retrieval_log.py
T
bvandeusenandClaude Opus 5 d5ac8408f6
CI & Build / Python lint (push) Successful in 8s
CI & Build / Plugin hooks (push) Successful in 16s
CI & Build / integration (push) Successful in 40s
CI & Build / TypeScript typecheck (push) Successful in 43s
CI & Build / Python tests (push) Successful in 1m14s
CI & Build / Build & push image (push) Successful in 2m59s
feat(telemetry): record WHAT the bar turned away, not only how close it came (#3807)
#3670 added `best_available_score` so a threshold could be judged from its
rejections. It records how CLOSE the bar came to firing and not WHAT it
refused, and that is the half a decision actually needs.

Live, pre_tool_rule sits at a ~0.72 bar with a near-miss p90 of 0.7071 —
about 117 declines a day within 0.013 of firing. Dropping to 0.707 would
take that arm from 22 hits a day to roughly 139: six-fold, on a surface
that runs before every Bash call. The percentile says the mass is there.
Nothing said whether it was worth showing.

NEITHER OBVIOUS INSTRUMENT ANSWERS IT. Pull-through cannot: the injected
rule line already carries title and trigger, so a session can comply
without ever calling get_rule, and rule pull-through understates
usefulness by construction. Reading the rejected records can — and
`result_ids` holds only what was RETURNED, so on a zero-result call the
near-missed record had no name at all.

So the id, from the SAME ranked candidate as the score. Both searches
unpack `best` once and read both fields off it, because splitting that
into two expressions is exactly how a later edit pairs a score with its
neighbour's id — and a score attached to the wrong record is worse than no
id, since it invites judging the wrong one and concluding the bar is fine.

write_path withholds the id on the same condition it withholds the score
(#3739): a surviving id beside a null score names a record without saying
what it scored, the pair disagreeing in the other direction.

THE READ PATH IS A LISTING, NOT A STATISTIC — an id cannot be percentiled,
and a reader tuning a bar needs to go and read the records. Opt-in via
`near_miss_samples` (0-20, default 0) so the ordinary readout keeps its
size, and deliberately NOT a window function: this module's one production
outage was a grouped query Postgres rejected, swallowed by the broad
except, every counter reading zero while the mocked tests passed (#2663).
One flat ordered query, overfetched, bucketed in Python — the shape that
lesson prescribes.

Migration 0097, nullable and unbackfilled. Not a foreign key: the table
spans record types and `source` says which, exactly as result_ids works.

The integration guard pins the listing as PER SOURCE. A global LIMIT would
let a noisy source eat the whole quota and leave the surface being tuned
showing nothing — which reads as "nothing was close", the misreading this
milestone has spent itself correcting.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
2026-09-09 21:24:32 -04:00

103 lines
5.4 KiB
Python

from datetime import datetime, timezone
from sqlalchemy import Boolean, DateTime, Float, Index, Integer, Text
from sqlalchemy.dialects.postgresql import JSONB
from sqlalchemy.orm import Mapped, mapped_column
from scribe.models import Base
from scribe.models.base import iso
class RetrievalLog(Base):
"""One row per semantic-retrieval call, for KB-injection tuning.
Captures what a query asked for, what came back, and the score
distribution of the results — the empirical basis for tuning the
similarity threshold and top-k per surface. `result_ids` holds the ranked
hits (id + score + rank) so a later pass can correlate "what we surfaced"
against "what the agent then fetched/referenced".
Deliberately FK-free on user_id (mirrors AppLog): telemetry should outlive
the row it describes, and a deleted user shouldn't cascade away history.
"""
__tablename__ = "retrieval_logs"
id: Mapped[int] = mapped_column(primary_key=True)
# Declared here rather than via CreatedAtMixin on purpose: the composite
# index below orders on `created_at.desc()`, which needs the column object
# in this class body — a mixin's column is not in scope there.
created_at: Mapped[datetime] = mapped_column(
DateTime(timezone=True), default=lambda: datetime.now(timezone.utc)
)
user_id: Mapped[int | None] = mapped_column(Integer, nullable=True)
# Retrieval surface: 'mcp_search' | 'rest_search' | 'auto_inject' | ...
source: Mapped[str] = mapped_column(Text, nullable=False)
query: Mapped[str | None] = mapped_column(Text, nullable=True)
# Effective parameters actually used for this call.
threshold: Mapped[float | None] = mapped_column(Float, nullable=True)
limit_n: Mapped[int | None] = mapped_column(Integer, nullable=True)
project_id: Mapped[int | None] = mapped_column(Integer, nullable=True)
# The content-type filter as passed to semantic_search_notes: True=tasks,
# False=notes, NULL=any.
is_task: Mapped[bool | None] = mapped_column(Boolean, nullable=True)
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)
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)
# WHICH record scored that, so a reader can judge what the bar refused
# rather than only how close it came (#3807). Written from the same ranked
# candidate as the score above — the two describing different records would
# be worse than no id at all, because it invites judging the wrong one.
#
# Not a foreign key on purpose: this table spans record types (the rule arms
# store rule ids, the note arms store note ids) and `source` is what says
# which, exactly as `result_ids` has always worked.
best_available_id: Mapped[int | None] = mapped_column(Integer, nullable=True)
# [{"id": int, "score": float, "rank": int}, ...], highest-first.
result_ids: Mapped[list] = mapped_column(JSONB, nullable=False, default=list)
duration_ms: Mapped[float | None] = mapped_column(Float, nullable=True)
__table_args__ = (
Index("ix_retrieval_logs_created_at", "created_at"),
Index("ix_retrieval_logs_user_id", "user_id"),
Index("ix_retrieval_logs_source", "source"),
Index("ix_retrieval_logs_source_created_at", "source", created_at.desc()),
)
def to_dict(self) -> dict:
return {
"id": self.id,
"created_at": iso(self.created_at),
"user_id": self.user_id,
"source": self.source,
"query": self.query,
"threshold": self.threshold,
"limit_n": self.limit_n,
"project_id": self.project_id,
"is_task": self.is_task,
"result_count": self.result_count,
"suppressed_count": self.suppressed_count,
"top_score": self.top_score,
"min_score": self.min_score,
"result_ids": self.result_ids,
"duration_ms": self.duration_ms,
}