feat(review): add cache hit/miss telemetry to grounding and review-memory (#4448)

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("/")

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<string, { signals: ReviewSuppressionRecor
  *  cache decision. */
 export async function getCachedReviewSuppressions(env: Env, repoFullName: string, nowMs: number): Promise<ReviewSuppressionRecord[]> {
   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;

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,76 @@ 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("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 () => {
     const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "ghp_test" });
     let fetchCount = 0;

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,87 @@ 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
+  });
+
+  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
+  });
+});