diff --git a/src/db/repositories.ts b/src/db/repositories.ts index 92991baaf..e12740dbe 100644 --- a/src/db/repositories.ts +++ b/src/db/repositories.ts @@ -66,6 +66,7 @@ import { webhookEvents, } from "./schema"; import { DEFAULT_REVIEW_EVASION_LABEL } from "../settings/agent-actions"; +import { cacheOutcomeMetadata } from "../services/cache-outcome"; import type { LinkedIssueSatisfactionResult } from "../services/linked-issue-satisfaction"; import type { Advisory, @@ -3033,6 +3034,14 @@ export async function getGlobalAgentFrozenState(env: Env): Promise<{ frozen: boo export async function recordAuditEvent(env: Env, event: AuditEventRecord): Promise { const db = getDb(env.DB); + // #10208: stamp the shared (cache_surface, cache_outcome) pair on the ~20 events that report a cache + // outcome under three different vocabularies (`*_cache_hit`, `*_reuse`, `*_one_shot_skip`), so one query can + // aggregate all of them. Done HERE rather than at each call site precisely so a future call site cannot omit + // it -- the omission is what made the vocabularies diverge in the first place. The caller's own metadata + // wins on a key collision: an explicit value at a call site is more specific than this classification, and + // this must never silently overwrite one. + const cacheOutcome = cacheOutcomeMetadata(event.eventType); + const metadata = cacheOutcome ? { ...cacheOutcome, ...(event.metadata ?? {}) } : event.metadata ?? {}; await db.insert(auditEvents).values({ id: event.id ?? crypto.randomUUID(), eventType: event.eventType, @@ -3041,7 +3050,7 @@ export async function recordAuditEvent(env: Env, event: AuditEventRecord): Promi targetKey: event.targetKey, outcome: event.outcome, detail: event.detail, - metadataJson: jsonString(event.metadata ?? {}), + metadataJson: jsonString(metadata), createdAt: event.createdAt ?? nowIso(), }); } diff --git a/src/services/cache-outcome.ts b/src/services/cache-outcome.ts new file mode 100644 index 000000000..002b0bc03 --- /dev/null +++ b/src/services/cache-outcome.ts @@ -0,0 +1,95 @@ +// One vocabulary for "a cache avoided work" (#10208). +// +// Eight cache-like surfaces each report avoidance under their OWN event name, in three different +// vocabularies -- `*_cache_hit`, `*_reuse`, and `*_one_shot_skip`. No single query knows all of them, so the +// obvious question ("is our caching working?") is answered wrongly by the obvious query. Measured on the Orb: +// asking `%cache_hit%` vs `%cache_miss%` over 24h reports the AI review cache at **0.44%** (1 hit, 228 misses) +// when its real rate is **78.1%** -- the 811 avoided runs live in `ai_review_one_shot_reuse` and +// `ai_review_frozen_reuse`, which contain neither the word "cache" nor the word "hit". A 177x understatement, +// and the kind that sends someone optimising a cache that already works. +// +// Rather than renaming events (every one is load-bearing in dashboards, alerts and existing queries), this +// maps each event to a shared `(cache_surface, cache_outcome)` pair that is stamped into its audit metadata. +// The event names are untouched and fully back-compatible; one query now aggregates all of them: +// +// SELECT metadata_json->>'cache_surface', metadata_json->>'cache_outcome', count(*) FROM audit_events ... +// +// STAMPED CENTRALLY, in recordAuditEvent, NOT at the ~20 call sites. A field each call site must remember to +// add is a field a future call site forgets -- the same "two or more places that must agree, with nothing +// enforcing it" shape #10170 catalogues and #10127 fixed by making the omission unrepresentable. Here the call +// sites are not involved at all: they emit the event they always did, and the classification happens once. + +/** The cache-like surfaces that report avoidance. `grounding` is deliberately included but is NOT comparable + * to the others -- see {@link CACHE_SURFACE_NOTES}. */ +export const CACHE_SURFACES = [ + "ai_review", + "ai_slop", + "linked_issue_satisfaction", + "miner_detection", + "grounding", + "impact_map", + "review_memory", + "repo_culture_profile", +] as const; + +export type CacheSurface = (typeof CACHE_SURFACES)[number]; + +/** `hit` = work avoided, by any mechanism. `miss` = the work was done. */ +export type CacheOutcome = "hit" | "miss"; + +/** + * `grounding` keys on `(repo, path, head_sha)` and fetches the files the PR CHANGED, whose content differs at + * every head SHA by construction. Its only possible hit is the same file grounded twice at the same commit, so + * its rate measures RE-EVALUATION CHURN, not cache health -- it fell from 27-61% to ~0% because same-SHA + * re-evaluation was deliberately driven down, i.e. because the system got better. Measured against the Orb: + * re-keying on blob content would collapse 1146 rows to 1047, only 8.6% reuse, so there is no fix to apply + * either. Included here so one query still sees every surface, flagged so nobody reads it as a peer of the + * fingerprint-keyed caches above it or "optimises" it. + */ +export const CACHE_SURFACE_NOTES: Partial> = { + grounding: "per-commit blob cache; hit rate tracks re-evaluation churn, not cache effectiveness (#10208)", +}; + +/** + * Every audit event that reports a cache outcome, and what it means. Exhaustive by construction: the + * "every cache-shaped audit event is classified" test in test/unit/cache-outcome.test.ts scans the source for + * event types matching the three vocabularies and fails if any is missing here, so a ninth surface (or a + * fourth word for "hit") cannot be added without being classified. + */ +export const CACHE_OUTCOME_EVENTS: Readonly> = Object.freeze({ + "github_app.ai_review_cache_hit": { surface: "ai_review", outcome: "hit" }, + "github_app.ai_review_cache_miss": { surface: "ai_review", outcome: "miss" }, + // The #regate-churn cooldown, not the durable cache: the durable one is bypassed by design for + // dynamic-context repos (see the `features` comment in src/review/ai-review-cache-input.ts), so on those + // repos these two ARE the reuse path and the durable cache legitimately reports almost nothing. + "github_app.ai_review_one_shot_reuse": { surface: "ai_review", outcome: "hit" }, + "github_app.ai_review_frozen_reuse": { surface: "ai_review", outcome: "hit" }, + "github_app.ai_slop_cache_hit": { surface: "ai_slop", outcome: "hit" }, + "github_app.ai_slop_cache_miss": { surface: "ai_slop", outcome: "miss" }, + "github_app.ai_slop_one_shot_skip": { surface: "ai_slop", outcome: "hit" }, + "github_app.linked_issue_satisfaction_cache_hit": { surface: "linked_issue_satisfaction", outcome: "hit" }, + "github_app.linked_issue_satisfaction_cache_miss": { surface: "linked_issue_satisfaction", outcome: "miss" }, + "github_app.linked_issue_satisfaction_one_shot_skip": { surface: "linked_issue_satisfaction", outcome: "hit" }, + "github_app.miner_detection_cache_hit": { surface: "miner_detection", outcome: "hit" }, + "github_app.miner_detection_cache_miss": { surface: "miner_detection", outcome: "miss" }, + "github_app.grounding_cache_hit": { surface: "grounding", outcome: "hit" }, + "github_app.grounding_cache_miss": { surface: "grounding", outcome: "miss" }, + "github_app.impact_map_cache_hit": { surface: "impact_map", outcome: "hit" }, + "github_app.impact_map_cache_miss": { surface: "impact_map", outcome: "miss" }, + "github_app.review_memory_cache_hit": { surface: "review_memory", outcome: "hit" }, + "github_app.review_memory_cache_miss": { surface: "review_memory", outcome: "miss" }, + "github_app.repo_culture_profile_cache_hit": { surface: "repo_culture_profile", outcome: "hit" }, + "github_app.repo_culture_profile_cache_miss": { surface: "repo_culture_profile", outcome: "miss" }, +}); + +/** + * The shared classification for `eventType`, or `undefined` when it does not report a cache outcome. + * + * DELIBERATELY returns undefined rather than guessing from the name: an event called `*_cache_hit` that nobody + * registered is exactly the drift this module exists to catch, and the guard test catches it at build time. + * Silently inferring it would make the guard unfalsifiable. + */ +export function cacheOutcomeMetadata(eventType: string): { cache_surface: CacheSurface; cache_outcome: CacheOutcome } | undefined { + const entry = CACHE_OUTCOME_EVENTS[eventType]; + return entry ? { cache_surface: entry.surface, cache_outcome: entry.outcome } : undefined; +} diff --git a/test/unit/cache-outcome.test.ts b/test/unit/cache-outcome.test.ts new file mode 100644 index 000000000..7c0490549 --- /dev/null +++ b/test/unit/cache-outcome.test.ts @@ -0,0 +1,149 @@ +import { describe, expect, it } from "vitest"; +import { readdirSync, readFileSync, statSync } from "node:fs"; +import { join } from "node:path"; + +import { CACHE_OUTCOME_EVENTS, CACHE_SURFACES, CACHE_SURFACE_NOTES, cacheOutcomeMetadata } from "../../src/services/cache-outcome"; +import { createTestEnv } from "../helpers/d1"; +import { recordAuditEvent } from "../../src/db/repositories"; + +type TestEnv = ReturnType; + +/** Read the stored metadata bag for the most recent event of `eventType`, straight from the row. */ +async function storedMetadata(env: TestEnv, eventType: string): Promise> { + const row = await env.DB.prepare("select metadata_json from audit_events where event_type = ? order by created_at desc limit 1") + .bind(eventType) + .first<{ metadata_json: string }>(); + return JSON.parse(row?.metadata_json ?? "{}") as Record; +} + +/** Every source file under src/, so the guard below scans the real tree rather than a hand-kept list. */ +function sourceFiles(dir: string, out: string[] = []): string[] { + for (const entry of readdirSync(dir)) { + const full = join(dir, entry); + if (statSync(full).isDirectory()) sourceFiles(full, out); + else if (full.endsWith(".ts")) out.push(full); + } + return out; +} + +describe("cache outcome vocabulary (#10208)", () => { + it("GUARD: every cache-shaped audit event in src/** is classified", () => { + // The whole point of the module. Eight surfaces already drifted into three vocabularies for one concept + // (`*_cache_hit`, `*_reuse`, `*_one_shot_skip`) because nothing forced a new one to be registered. This + // fails the build if a ninth appears unclassified, so the single aggregate query can never go quietly + // incomplete again -- the failure mode that made the naive query understate ai_review by 177x. + const pattern = /"(github_app\.[a-z_]*(?:cache_hit|cache_miss|one_shot_skip|one_shot_reuse|frozen_reuse))"/g; + const found = new Set(); + for (const file of sourceFiles("src")) { + for (const match of readFileSync(file, "utf8").matchAll(pattern)) found.add(match[1]!); + } + + // Sanity: the scan itself must be finding things, or an accidentally-broken regex would make this pass + // vacuously forever. + expect(found.size).toBeGreaterThanOrEqual(20); + + const unclassified = [...found].filter((eventType) => !(eventType in CACHE_OUTCOME_EVENTS)).sort(); + expect(unclassified).toEqual([]); + }); + + it("GUARD: no classified event has gone stale — every registered event still exists in src/**", () => { + // The other direction: an event removed from the code but left registered here makes the registry lie + // about what the aggregate covers. + const all = sourceFiles("src") + .map((file) => readFileSync(file, "utf8")) + .join("\n"); + const missing = Object.keys(CACHE_OUTCOME_EVENTS).filter((eventType) => !all.includes(`"${eventType}"`)).sort(); + expect(missing).toEqual([]); + }); + + it("classifies every registered event to a declared surface and a real outcome", () => { + for (const [eventType, entry] of Object.entries(CACHE_OUTCOME_EVENTS)) { + expect(CACHE_SURFACES).toContain(entry.surface); + expect(["hit", "miss"]).toContain(entry.outcome); + expect(cacheOutcomeMetadata(eventType)).toEqual({ cache_surface: entry.surface, cache_outcome: entry.outcome }); + } + }); + + it("counts the three vocabularies as one: reuse and one_shot_skip are hits, not a separate concept", () => { + // The measured failure this module exists for: `ai_review_one_shot_reuse` / `ai_review_frozen_reuse` are + // 811 of the AI review cache's 1039 avoided runs, and contain neither "cache" nor "hit". + expect(cacheOutcomeMetadata("github_app.ai_review_one_shot_reuse")).toEqual({ cache_surface: "ai_review", cache_outcome: "hit" }); + expect(cacheOutcomeMetadata("github_app.ai_review_frozen_reuse")).toEqual({ cache_surface: "ai_review", cache_outcome: "hit" }); + expect(cacheOutcomeMetadata("github_app.ai_slop_one_shot_skip")).toEqual({ cache_surface: "ai_slop", cache_outcome: "hit" }); + expect(cacheOutcomeMetadata("github_app.linked_issue_satisfaction_one_shot_skip")).toEqual({ + cache_surface: "linked_issue_satisfaction", + cache_outcome: "hit", + }); + }); + + it("returns undefined for an unregistered event rather than guessing from its name", () => { + // Inferring from the name would make the exhaustiveness guard above unfalsifiable. + expect(cacheOutcomeMetadata("github_app.some_future_cache_hit")).toBeUndefined(); + expect(cacheOutcomeMetadata("github_app.pull_request_opened")).toBeUndefined(); + expect(cacheOutcomeMetadata("")).toBeUndefined(); + }); + + it("flags grounding as not comparable to the fingerprint-keyed surfaces", () => { + expect(CACHE_SURFACE_NOTES.grounding).toMatch(/churn/); + // Only grounding carries a caveat today; the others are genuinely comparable. + expect(Object.keys(CACHE_SURFACE_NOTES)).toEqual(["grounding"]); + }); +}); + +describe("recordAuditEvent stamps the cache outcome centrally (#10208)", () => { + it("adds cache_surface/cache_outcome to a cache event without the call site doing anything", async () => { + const env = createTestEnv(); + await recordAuditEvent(env, { + eventType: "github_app.ai_review_one_shot_reuse", + targetKey: "JSONbored/loopover#1", + outcome: "completed", + detail: "reused", + metadata: { repoFullName: "JSONbored/loopover" }, + }); + const metadata = await storedMetadata(env, "github_app.ai_review_one_shot_reuse"); + expect(metadata.cache_surface).toBe("ai_review"); + expect(metadata.cache_outcome).toBe("hit"); + // The caller's own metadata survives alongside it. + expect(metadata.repoFullName).toBe("JSONbored/loopover"); + }); + + it("stamps a miss, and a cache event that carries no metadata of its own", async () => { + const env = createTestEnv(); + await recordAuditEvent(env, { eventType: "github_app.grounding_cache_miss", targetKey: "JSONbored/loopover", outcome: "completed" }); + expect(await storedMetadata(env, "github_app.grounding_cache_miss")).toEqual({ cache_surface: "grounding", cache_outcome: "miss" }); + }); + + it("leaves a non-cache event's metadata exactly as the caller passed it", async () => { + const env = createTestEnv(); + await recordAuditEvent(env, { + eventType: "github_app.pull_request_opened", + targetKey: "JSONbored/loopover#2", + outcome: "completed", + metadata: { pull: 2 }, + }); + expect(await storedMetadata(env, "github_app.pull_request_opened")).toEqual({ pull: 2 }); + }); + + it("stores an empty bag for a non-cache event that carries no metadata", async () => { + // The fourth corner of the two-by-two (cache/non-cache x metadata/none): a non-cache event with nothing of + // its own must still round-trip to {}, not to the classification and not to null. + const env = createTestEnv(); + await recordAuditEvent(env, { eventType: "github_app.pull_request_closed", targetKey: "JSONbored/loopover#4", outcome: "completed" }); + expect(await storedMetadata(env, "github_app.pull_request_closed")).toEqual({}); + }); + + it("never overwrites a value the call site set explicitly", async () => { + // An explicit value at a call site is more specific than the classification; silently replacing it would + // make this stamping lossy. + const env = createTestEnv(); + await recordAuditEvent(env, { + eventType: "github_app.ai_slop_cache_hit", + targetKey: "JSONbored/loopover#3", + outcome: "completed", + metadata: { cache_outcome: "miss" }, + }); + const metadata = await storedMetadata(env, "github_app.ai_slop_cache_hit"); + expect(metadata.cache_outcome).toBe("miss"); + expect(metadata.cache_surface).toBe("ai_slop"); + }); +});