From de34e32dfd45efd004b47215bcb8cb45512b187b Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Fri, 10 Jul 2026 02:58:00 -0700 Subject: [PATCH 1/2] feat(review): add cache hit/miss telemetry to grounding and review-memory (#4448) Two of the six AI-touching capabilities #4448 identified as having zero reuse-rate signal: grounding's per-file GitHub Contents cache (getCachedGroundingFileContent) and review-memory's in-isolate suppression-list TTL cache (getCachedReviewSuppressions, #4508). Both already correctly avoid redundant work -- they just had no telemetry proving it, mirroring the exact gap #4509 closed for repo-culture-profile. Instruments both with the SAME incr()+recordAuditEvent hit/miss pair convention already established for repo_culture_profile / ai_review / ai_slop / linked_issue_satisfaction / miner_detection, so a future aggregate reuse-rate computation (#4448's remaining deliverable) can read a consistent event shape across every instrumented capability. Part of epic #4445's #4448. The remaining three uninstrumented capabilities (enrichment, impact-map, reputation -- none of which have an existing cache mechanism to instrument, unlike these two), the aggregate reuse-rate computation, the daily rollup, the public API extension, and the homepage trend chart are deferred to follow-up PRs. --- src/review/grounding-wire.ts | 25 ++++++++- src/review/review-memory-wire.ts | 25 ++++++++- test/unit/grounding-wiring.test.ts | 62 +++++++++++++++++++++- test/unit/review-memory-store.test.ts | 75 ++++++++++++++++++++++++++- 4 files changed, 181 insertions(+), 6 deletions(-) diff --git a/src/review/grounding-wire.ts b/src/review/grounding-wire.ts index 9dcc7fe611..79f18729d8 100644 --- a/src/review/grounding-wire.ts +++ b/src/review/grounding-wire.ts @@ -13,9 +13,10 @@ import { createInstallationToken } from "../github/app"; import { githubRateLimitAdmissionKeyForInstallation, timeoutFetch, type GitHubRateLimitAdmissionKey } from "../github/client"; -import { getCachedGroundingFileContent, putCachedGroundingFileContent } from "../db/repositories"; +import { getCachedGroundingFileContent, putCachedGroundingFileContent, recordAuditEvent } from "../db/repositories"; import type { CheckSummaryRecord, PullRequestFileRecord } from "../types"; import { repoParts } from "../utils/json"; +import { incr } from "../selfhost/metrics"; import { isConvergenceRepoAllowed } from "./cutover-gate"; import { buildGrounding, @@ -141,7 +142,27 @@ export async function makeGithubFileFetcher(env: Env, repoFullName: string, inst // network fetch below; only a genuinely successful fetch is ever written back (see the .catch-free write // after the try block), so a transient failure is never mistaken for a confirmed-permanent one. const cached = await getCachedGroundingFileContent(env, repoFullName, path, ref).catch(() => null); - if (cached !== null) return cached; + if (cached !== null) { + // #4448: mirrors repo-culture-profile's #4509 cache hit/miss instrumentation exactly -- one of the six + // AI-touching capabilities that had no reuse-rate signal at all before this. + incr("gittensory_grounding_cache_hit_total"); + await recordAuditEvent(env, { + eventType: "github_app.grounding_cache_hit", + targetKey: repoFullName, + outcome: "completed", + detail: "reused a cached grounding file blob instead of re-fetching from GitHub", + metadata: { repoFullName, path }, + }).catch(() => undefined); + return cached; + } + incr("gittensory_grounding_cache_miss_total"); + await recordAuditEvent(env, { + eventType: "github_app.grounding_cache_miss", + targetKey: repoFullName, + outcome: "completed", + detail: "no reusable cached grounding file blob; fetching fresh from GitHub", + metadata: { repoFullName, path }, + }).catch(() => undefined); try { const url = `https://api.github.com/repos/${encodeURIComponent(owner)}/${encodeURIComponent(name)}/contents/${path .split("/") diff --git a/src/review/review-memory-wire.ts b/src/review/review-memory-wire.ts index c83b9c3217..a3b5bb94e4 100644 --- a/src/review/review-memory-wire.ts +++ b/src/review/review-memory-wire.ts @@ -6,9 +6,10 @@ // review path at all (the caller guards on this flag before doing any D1 read or matching), so the review // stays byte-identical to today. -import { listReviewSuppressions } from "../db/repositories"; +import { listReviewSuppressions, recordAuditEvent } from "../db/repositories"; import { matchSuppressions, type ReviewMemoryFindingInput } from "./review-memory-match"; import type { AdvisoryFinding, ReviewSuppressionRecord } from "../types"; +import { incr } from "../selfhost/metrics"; /** True when repeat-false-positive suppression is enabled at the operator level. Flag-OFF (default) → the * caller takes no new branch, so no suppression-store read and no matcher call ever happens. Truthy follows @@ -43,7 +44,27 @@ const reviewSuppressionCache = new Map { const hit = reviewSuppressionCache.get(repoFullName); - if (hit && nowMs - hit.at < REVIEW_SUPPRESSION_CACHE_TTL_MS) return hit.signals; + if (hit && nowMs - hit.at < REVIEW_SUPPRESSION_CACHE_TTL_MS) { + // #4448: mirrors repo-culture-profile's #4509 cache hit/miss instrumentation exactly -- one of the six + // AI-touching capabilities that had no reuse-rate signal at all before this. + incr("gittensory_review_memory_cache_hit_total"); + await recordAuditEvent(env, { + eventType: "github_app.review_memory_cache_hit", + targetKey: repoFullName, + outcome: "completed", + detail: "reused the in-isolate cached suppression list instead of re-reading D1", + metadata: { repoFullName }, + }).catch(() => undefined); + return hit.signals; + } + incr("gittensory_review_memory_cache_miss_total"); + await recordAuditEvent(env, { + eventType: "github_app.review_memory_cache_miss", + targetKey: repoFullName, + outcome: "completed", + detail: "no fresh cached suppression list; reading fresh from D1", + metadata: { repoFullName }, + }).catch(() => undefined); const signals = await listReviewSuppressions(env, repoFullName); reviewSuppressionCache.set(repoFullName, { signals, at: nowMs }); return signals; diff --git a/test/unit/grounding-wiring.test.ts b/test/unit/grounding-wiring.test.ts index 6f18746b48..2e9f0924ec 100644 --- a/test/unit/grounding-wiring.test.ts +++ b/test/unit/grounding-wiring.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it, vi } from "vitest"; +import { afterEach, describe, expect, it, vi } from "vitest"; import { runGittensoryAiReview } from "../../src/services/ai-review"; import { runAiReviewForAdvisory } from "../../src/queue/processors"; import { @@ -9,8 +9,10 @@ import { makeGithubFileFetcher, } from "../../src/review/grounding-wire"; import { getCachedGroundingFileContent, putCachedGroundingFileContent, upsertCheckSummary, upsertRepositoryFromGitHub } from "../../src/db/repositories"; +import * as repositoriesModule from "../../src/db/repositories"; import * as githubApp from "../../src/github/app"; import { githubRateLimitAdmissionKeyForInstallation, latestGitHubRestRateLimitObservation } from "../../src/github/client"; +import { renderMetrics, resetMetrics } from "../../src/selfhost/metrics"; import type { Advisory, CheckSummaryRecord, JsonValue, PullRequestFileRecord, RepositorySettings } from "../../src/types"; import { createTestEnv } from "../helpers/d1"; @@ -398,6 +400,64 @@ describe("makeGithubFileFetcher (GitHub Contents-API-backed FileFetcher)", () => fetchSpy.mockRestore(); }); + describe("cache hit/miss telemetry (#4448)", () => { + afterEach(() => resetMetrics()); + + async function auditEvent(env: Env, eventType: string, repoFullName: string) { + return env.DB.prepare("SELECT outcome, target_key FROM audit_events WHERE event_type = ? AND target_key = ?") + .bind(eventType, repoFullName) + .first<{ outcome: string; target_key: string }>(); + } + + it("INVARIANT: a cache HIT fires exactly the hit counter/audit-event pair, and NOT the miss pair", async () => { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" }); + const fetchSpy = vi.spyOn(globalThis, "fetch").mockImplementation(async () => new Response("export const v = 1;", { status: 200 })); + await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("hit.ts", "sha7"); // first call: a miss + resetMetrics(); + await env.DB.prepare("DELETE FROM audit_events").run(); // isolate to the SECOND call's telemetry only + + const second = await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("hit.ts", "sha7"); // same (repo, path, ref) -- a hit + expect(second).toBe("export const v = 1;"); + + const rendered = await renderMetrics(); + expect(rendered).toContain("gittensory_grounding_cache_hit_total 1"); + expect(rendered).not.toContain("gittensory_grounding_cache_miss_total"); + const hitEvent = await auditEvent(env, "github_app.grounding_cache_hit", "acme/telemetry"); + expect(hitEvent?.outcome).toBe("completed"); + expect(await auditEvent(env, "github_app.grounding_cache_miss", "acme/telemetry")).toBeUndefined(); + fetchSpy.mockRestore(); + }); + + it("INVARIANT: a cache MISS fires exactly the miss counter/audit-event pair, and NOT the hit pair", async () => { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" }); + const fetchSpy = vi.spyOn(globalThis, "fetch").mockImplementation(async () => new Response("export const v = 1;", { status: 200 })); + + const first = await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("miss.ts", "sha7"); + expect(first).toBe("export const v = 1;"); + + const rendered = await renderMetrics(); + expect(rendered).toContain("gittensory_grounding_cache_miss_total 1"); + expect(rendered).not.toContain("gittensory_grounding_cache_hit_total"); + const missEvent = await auditEvent(env, "github_app.grounding_cache_miss", "acme/telemetry"); + expect(missEvent?.outcome).toBe("completed"); + expect(await auditEvent(env, "github_app.grounding_cache_hit", "acme/telemetry")).toBeUndefined(); + fetchSpy.mockRestore(); + }); + + it("swallows a failing cache-hit audit-event write without throwing, still returning the cached content", async () => { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" }); + const fetchSpy = vi.spyOn(globalThis, "fetch").mockImplementation(async () => new Response("export const v = 1;", { status: 200 })); + await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("swallow.ts", "sha7"); // populates the cache + + const writeSpy = vi.spyOn(repositoriesModule, "recordAuditEvent").mockRejectedValueOnce(new Error("D1 write error")); + const second = await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("swallow.ts", "sha7"); // a cache hit + writeSpy.mockRestore(); + + expect(second).toBe("export const v = 1;"); // the failed audit write never surfaces to the caller + fetchSpy.mockRestore(); + }); + }); + it("REGRESSION (#4499, grounding-refetch incident): repeated cooldown-driven calls on an unchanged head SHA only fetch once total, not once per call", async () => { const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" }); let fetchCount = 0; diff --git a/test/unit/review-memory-store.test.ts b/test/unit/review-memory-store.test.ts index 24f1010a67..8ffd7163bb 100644 --- a/test/unit/review-memory-store.test.ts +++ b/test/unit/review-memory-store.test.ts @@ -1,7 +1,8 @@ -import { describe, expect, it, vi } from "vitest"; +import { afterEach, describe, expect, it, vi } from "vitest"; import { MAX_REVIEW_SUPPRESSIONS_PER_REPO, listReviewSuppressions, recordReviewSuppression } from "../../src/db/repositories"; import * as repositoriesModule from "../../src/db/repositories"; import { clearReviewSuppressionCacheForTest, getCachedReviewSuppressions, invalidateReviewSuppressionCache } from "../../src/review/review-memory-wire"; +import { renderMetrics, resetMetrics } from "../../src/selfhost/metrics"; import { createTestEnv } from "../helpers/d1"; // Review memory (#2178, data-model slice of #1964): insert/list repository accessors over the @@ -266,3 +267,75 @@ describe("getCachedReviewSuppressions / invalidateReviewSuppressionCache (#4508) expect(b).toHaveLength(0); }); }); + +describe("getCachedReviewSuppressions: cache hit/miss telemetry (#4448)", () => { + afterEach(() => resetMetrics()); + + async function auditEvent(env: Env, eventType: string, repoFullName: string) { + return env.DB.prepare("SELECT outcome, target_key FROM audit_events WHERE event_type = ? AND target_key = ?") + .bind(eventType, repoFullName) + .first<{ outcome: string; target_key: string }>(); + } + + it("INVARIANT: a cache HIT (within TTL) fires exactly the hit counter/audit-event pair, and NOT the miss pair", async () => { + clearReviewSuppressionCacheForTest(); + const env = createTestEnv(); + const t0 = 5_000_000; + await getCachedReviewSuppressions(env, "owner/telemetry-repo", t0); // first call: a miss (cold cache) + resetMetrics(); + await env.DB.prepare("DELETE FROM audit_events").run(); // isolate to the SECOND call's telemetry only + + const second = await getCachedReviewSuppressions(env, "owner/telemetry-repo", t0 + 30_000); // within the 60s TTL + expect(second).toEqual([]); + + const rendered = await renderMetrics(); + expect(rendered).toContain("gittensory_review_memory_cache_hit_total 1"); + expect(rendered).not.toContain("gittensory_review_memory_cache_miss_total"); + const hitEvent = await auditEvent(env, "github_app.review_memory_cache_hit", "owner/telemetry-repo"); + expect(hitEvent?.outcome).toBe("completed"); + expect(await auditEvent(env, "github_app.review_memory_cache_miss", "owner/telemetry-repo")).toBeUndefined(); + }); + + it("INVARIANT: a cache MISS (cold cache) fires exactly the miss counter/audit-event pair, and NOT the hit pair", async () => { + clearReviewSuppressionCacheForTest(); + const env = createTestEnv(); + const first = await getCachedReviewSuppressions(env, "owner/telemetry-repo-2", 6_000_000); + expect(first).toEqual([]); + + const rendered = await renderMetrics(); + expect(rendered).toContain("gittensory_review_memory_cache_miss_total 1"); + expect(rendered).not.toContain("gittensory_review_memory_cache_hit_total"); + const missEvent = await auditEvent(env, "github_app.review_memory_cache_miss", "owner/telemetry-repo-2"); + expect(missEvent?.outcome).toBe("completed"); + expect(await auditEvent(env, "github_app.review_memory_cache_hit", "owner/telemetry-repo-2")).toBeUndefined(); + }); + + it("REGRESSION: TTL expiry is correctly counted as a miss, not silently uninstrumented", async () => { + clearReviewSuppressionCacheForTest(); + const env = createTestEnv(); + const t0 = 7_000_000; + await getCachedReviewSuppressions(env, "owner/telemetry-repo-3", t0); // populates the cache + resetMetrics(); + await env.DB.prepare("DELETE FROM audit_events").run(); + + await getCachedReviewSuppressions(env, "owner/telemetry-repo-3", t0 + 60_001); // past the 60s TTL + + const rendered = await renderMetrics(); + expect(rendered).toContain("gittensory_review_memory_cache_miss_total 1"); + expect(rendered).not.toContain("gittensory_review_memory_cache_hit_total"); + }); + + it("swallows a failing cache-hit audit-event write without throwing, still returning the cached suppression list", async () => { + clearReviewSuppressionCacheForTest(); + const env = createTestEnv(); + const t0 = 8_000_000; + await recordReviewSuppression(env, { repoFullName: "owner/telemetry-repo-4", category: "ai_review_split", patternHash: "hash-swallow" }); + await getCachedReviewSuppressions(env, "owner/telemetry-repo-4", t0); // populates the cache + + const writeSpy = vi.spyOn(repositoriesModule, "recordAuditEvent").mockRejectedValueOnce(new Error("D1 write error")); + const second = await getCachedReviewSuppressions(env, "owner/telemetry-repo-4", t0 + 30_000); // a cache hit + writeSpy.mockRestore(); + + expect(second).toHaveLength(1); // the failed audit write never surfaces to the caller + }); +}); From 01184aa61541d0a9910046f6f47c1ddba4e79103 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Fri, 10 Jul 2026 03:23:18 -0700 Subject: [PATCH 2/2] test(review): cover the cache-MISS audit-write fail-safe in grounding/review-memory (#4448) codecov/patch flagged 93.75% on the prior commit -- both new hit/miss telemetry sites wrap recordAuditEvent in .catch(() => undefined), but only the cache-HIT side's failure path had a test; the cache-MISS side's catch callback was never actually invoked by any test, so it never executed. Adds the missing miss-side "swallows a failing audit-event write" test to both files, mirroring the existing hit-side test exactly. --- test/unit/grounding-wiring.test.ts | 12 ++++++++++++ test/unit/review-memory-store.test.ts | 12 ++++++++++++ 2 files changed, 24 insertions(+) diff --git a/test/unit/grounding-wiring.test.ts b/test/unit/grounding-wiring.test.ts index 2e9f0924ec..ad7b88e35e 100644 --- a/test/unit/grounding-wiring.test.ts +++ b/test/unit/grounding-wiring.test.ts @@ -456,6 +456,18 @@ describe("makeGithubFileFetcher (GitHub Contents-API-backed FileFetcher)", () => expect(second).toBe("export const v = 1;"); // the failed audit write never surfaces to the caller fetchSpy.mockRestore(); }); + + it("swallows a failing cache-MISS audit-event write without throwing, still returning the freshly-fetched content", async () => { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" }); + const fetchSpy = vi.spyOn(globalThis, "fetch").mockImplementation(async () => new Response("export const v = 1;", { status: 200 })); + + const writeSpy = vi.spyOn(repositoriesModule, "recordAuditEvent").mockRejectedValueOnce(new Error("D1 write error")); + const first = await (await makeGithubFileFetcher(env, "acme/telemetry", null)).getFileContent("miss-swallow.ts", "sha7"); // cold cache -- a miss + writeSpy.mockRestore(); + + expect(first).toBe("export const v = 1;"); // the failed audit write never surfaces to the caller, fetch still happens + fetchSpy.mockRestore(); + }); }); it("REGRESSION (#4499, grounding-refetch incident): repeated cooldown-driven calls on an unchanged head SHA only fetch once total, not once per call", async () => { diff --git a/test/unit/review-memory-store.test.ts b/test/unit/review-memory-store.test.ts index 8ffd7163bb..3b3b292f17 100644 --- a/test/unit/review-memory-store.test.ts +++ b/test/unit/review-memory-store.test.ts @@ -338,4 +338,16 @@ describe("getCachedReviewSuppressions: cache hit/miss telemetry (#4448)", () => expect(second).toHaveLength(1); // the failed audit write never surfaces to the caller }); + + it("swallows a failing cache-MISS audit-event write without throwing, still returning the freshly-read suppression list", async () => { + clearReviewSuppressionCacheForTest(); + const env = createTestEnv(); + await recordReviewSuppression(env, { repoFullName: "owner/telemetry-repo-5", category: "ai_review_split", patternHash: "hash-miss-swallow" }); + + const writeSpy = vi.spyOn(repositoriesModule, "recordAuditEvent").mockRejectedValueOnce(new Error("D1 write error")); + const first = await getCachedReviewSuppressions(env, "owner/telemetry-repo-5", 9_000_000); // cold cache -- a miss + writeSpy.mockRestore(); + + expect(first).toHaveLength(1); // the failed audit write never surfaces to the caller, D1 read still happens + }); });