feat(review): capture review turnaround duration onto the publish audit event (#4446)

src/db/repositories.ts

@@ -5298,6 +5298,22 @@ export async function hasActiveReviewForHeadSha(env: Env, repoFullName: string,
   return row !== undefined && row.status === "active" && row.headSha === headSha;
 }
 
+// Review turnaround-time tracking (#4446): reuses the SAME startedAt startActiveReviewTracking already records
+// for review-evasion protection -- reads it (for the exact headSha this pass is publishing) rather than
+// duplicating a second "when did this review start" clock. Not gated on status === "active": the publish site
+// this feeds reads it BEFORE terminalizeActiveReviewTracking runs later in the same pass (see processors.ts),
+// but staying permissive here means a future reordering degrades to "no duration" rather than a silent wrong
+// number. A DIFFERENT headSha (a newer pass already raced in) or no row at all correctly returns null -- the
+// caller's duration computation is skipped entirely rather than measuring the wrong pass's window.
+export async function getActiveReviewStartedAt(env: Env, repoFullName: string, pullNumber: number, headSha: string): Promise<string | null> {
+  const row = await getDb(env.DB)
+    .select({ headSha: activeReviewTracking.headSha, startedAt: activeReviewTracking.startedAt })
+    .from(activeReviewTracking)
+    .where(and(eq(activeReviewTracking.repoFullName, boundedString(repoFullName, 200)), eq(activeReviewTracking.pullNumber, pullNumber)))
+    .get();
+  return row !== undefined && row.headSha === headSha ? row.startedAt : null;
+}
+
 // Review-evasion protection: guarded status transition -- terminalize the active-review row for
 // repoFullName#pullNumber ONLY if it is still 'active' (and, when given, still pinned to headSha), the same
 // CAS shape as claimPendingAgentActionDecision, so a stale/already-terminalized row is never double-processed.

src/queue/processors.ts

@@ -72,6 +72,7 @@ import {
   recordGateBlockOutcome,
   getGateBlockOutcome,
   hasActiveReviewForHeadSha,
+  getActiveReviewStartedAt,
   isDbFrozenForRepo,
   markGateOutcomeOverridden,
   markPullRequestLinkedIssueHardRuleViolated,
@@ -8654,6 +8655,15 @@ async function resolveManifestPassedValidationCount(
   return liveCi.ciState === "passed" ? 1 : 0;
 }
 
+// review turnaround-time (#4446): elapsed ms between startedAt and "now", clamped to a sane non-negative
+// finite value -- a clock-skew or malformed-timestamp edge case (a future startedAt, or an unparseable one)
+// degrades to undefined rather than ever letting a negative or NaN duration reach the public payload.
+export function reviewDurationMsSince(startedAt: string | null, nowMs: number): number | undefined {
+  if (!startedAt) return undefined;
+  const ms = nowMs - Date.parse(startedAt);
+  return Number.isFinite(ms) && ms >= 0 ? ms : undefined;
+}
+
 async function maybePublishPrPublicSurface(
   env: Env,
   installationId: number,
@@ -9246,6 +9256,17 @@ async function maybePublishPrPublicSurface(
       )
       .then((effort) => effort.minutes)
       .catch(() => undefined);
+    // review turnaround-time (#4446): reuses the SAME startedAt startActiveReviewTracking already records for
+    // review-evasion protection -- persisted onto this SAME published event, mirroring reviewEffortMinutes'
+    // exact precedent above (a raw per-PR number in audit metadata; the daily rollup job aggregates it later).
+    // Read before terminalizeActiveReviewTracking runs later in this same pass, matched to the EXACT headSha
+    // being published so a race with a newer pass degrades to "no duration" (undefined), never a wrong number.
+    // Fail-safe: a lookup error must never block the publish audit itself.
+    const reviewDurationMsForStats = pr.headSha
+      ? await getActiveReviewStartedAt(env, repoFullName, pr.number, pr.headSha)
+          .then((startedAt) => reviewDurationMsSince(startedAt, Date.now()))
+          .catch(() => undefined)
+      : undefined;
     await recordAuditEvent(env, {
       eventType: "github_app.pr_public_surface_published",
       actor: author,
@@ -9263,6 +9284,7 @@ async function maybePublishPrPublicSurface(
         failedOutputs,
         gateCheckFinalized: gateFinalized,
         ...(reviewEffortMinutesForStats !== undefined ? { reviewEffortMinutes: reviewEffortMinutesForStats } : {}),
+        ...(reviewDurationMsForStats !== undefined ? { reviewDurationMs: reviewDurationMsForStats } : {}),
       },
     });
     await recordGithubProductUsage(env, "pr_public_surface_published", {

test/unit/db-persistence.test.ts

@@ -1,5 +1,6 @@
 import { describe, expect, it } from "vitest";
 import {
+  getActiveReviewStartedAt,
   getContributorScoringProfile,
   getOpenUpstreamDriftReportByFingerprint,
   hasActiveReviewForHeadSha,
@@ -397,4 +398,38 @@ describe("active-review tracking (#review-evasion-protection)", () => {
     const row = await rawRow(env, "owner/repo", 1);
     expect(row?.author_login).toBeNull();
   });
+
+  describe("getActiveReviewStartedAt (#4446)", () => {
+    it("returns null when no row exists at all", async () => {
+      const env = createTestEnv();
+      expect(await getActiveReviewStartedAt(env, "owner/repo", 1, "sha1")).toBeNull();
+    });
+
+    it("returns the row's startedAt for the exact matching headSha", async () => {
+      const env = createTestEnv();
+      await startActiveReviewTracking(env, { repoFullName: "owner/repo", pullNumber: 1, headSha: "sha1", deliveryId: "delivery-1" });
+      const row = await rawRow(env, "owner/repo", 1);
+      expect(await getActiveReviewStartedAt(env, "owner/repo", 1, "sha1")).toBe(row?.started_at);
+    });
+
+    it("REGRESSION: returns null for a DIFFERENT headSha than the tracked row -- never measures the wrong pass's window", async () => {
+      const env = createTestEnv();
+      await startActiveReviewTracking(env, { repoFullName: "owner/repo", pullNumber: 1, headSha: "sha1", deliveryId: "delivery-1" });
+      expect(await getActiveReviewStartedAt(env, "owner/repo", 1, "sha-different")).toBeNull();
+    });
+
+    it("returns null for a different PR number, even under the same repo", async () => {
+      const env = createTestEnv();
+      await startActiveReviewTracking(env, { repoFullName: "owner/repo", pullNumber: 1, headSha: "sha1", deliveryId: "delivery-1" });
+      expect(await getActiveReviewStartedAt(env, "owner/repo", 2, "sha1")).toBeNull();
+    });
+
+    it("still returns startedAt for a matching headSha AFTER the row has been terminalized -- not gated on status === 'active'", async () => {
+      const env = createTestEnv();
+      await startActiveReviewTracking(env, { repoFullName: "owner/repo", pullNumber: 1, headSha: "sha1", deliveryId: "delivery-1" });
+      const row = await rawRow(env, "owner/repo", 1);
+      await terminalizeActiveReviewTracking(env, "owner/repo", 1);
+      expect(await getActiveReviewStartedAt(env, "owner/repo", 1, "sha1")).toBe(row?.started_at);
+    });
+  });
 });

test/unit/queue.test.ts

@@ -57,7 +57,7 @@ import {
   listReviewSuppressions,
   setGlobalAgentFrozen,
 } from "../../src/db/repositories";
-import { agentMaintenanceHeadMatchesGate, changedPathsForGuardrail, claimAiReviewLock, claimPrActuationLock, contributorEvidenceBatchSize, enrichOpenPullRequestsWithChangedFiles, processJob, reconcileLiveDuplicateSiblings, releaseAiReviewLock, releasePrActuationLock, SWEEP_FANOUT_RESOLUTION_CONCURRENCY } from "../../src/queue/processors";
+import { agentMaintenanceHeadMatchesGate, changedPathsForGuardrail, claimAiReviewLock, claimPrActuationLock, contributorEvidenceBatchSize, enrichOpenPullRequestsWithChangedFiles, processJob, reconcileLiveDuplicateSiblings, releaseAiReviewLock, releasePrActuationLock, reviewDurationMsSince, SWEEP_FANOUT_RESOLUTION_CONCURRENCY } from "../../src/queue/processors";
 import type { PullRequestRecord } from "../../src/types";
 import { aiReviewCacheInputFingerprint } from "../../src/review/ai-review-cache-input";
 import { fingerprint as reviewMemoryFingerprint } from "../../src/review/review-memory-match";
@@ -4028,6 +4028,136 @@ describe("queue processors", () => {
       expect(reputationPrepares).toHaveLength(3); // submitter_stats + review_targets quality scan + cadence scan, ONCE
     });
 
+    it("INVARIANT (#4446): a real agent-regate-pr pass with AI review persists a non-negative reviewDurationMs onto the publish audit event", async () => {
+      const env = createTestEnv({
+        GITHUB_APP_PRIVATE_KEY: await generatePrivateKeyPem(),
+        AI: { run: async () => ({ response: JSON.stringify({ assessment: "Looks fine.", blockers: [], nits: [], suggestions: [] }) }) } as unknown as Ai,
+        AI_SUMMARIES_ENABLED: "true",
+        AI_PUBLIC_COMMENTS_ENABLED: "true",
+        AI_DAILY_NEURON_BUDGET: "100000",
+      });
+      await seedRegateChurnRepo(env);
+      await upsertPullRequestFromGitHub(env, "JSONbored/gittensory", { number: 63, title: "Turnaround PR", state: "open", user: { login: "contributor" }, head: { sha: "a63" }, labels: [], body: "Closes #1" });
+      await upsertPullRequestDetailSyncState(env, { repoFullName: "JSONbored/gittensory", pullNumber: 63, status: "complete", reviewsSyncedAt: new Date().toISOString() });
+      vi.stubGlobal("fetch", async (input: RequestInfo | URL, init?: RequestInit) => {
+        const url = input.toString();
+        const method = init?.method ?? "GET";
+        if (url.includes("/access_tokens")) return Response.json({ token: "fake-installation-token" });
+        if (url.includes("/pulls/63/files")) return Response.json([{ filename: "src/a.ts", status: "modified", additions: 1, deletions: 0, changes: 1, patch: "@@\n+export const ok = true;" }]);
+        if (url.endsWith("/pulls/63")) return Response.json({ number: 63, title: "Turnaround PR", state: "open", user: { login: "contributor" }, head: { sha: "a63" }, labels: [], body: "Closes #1", mergeable_state: "clean" });
+        if (url.includes("/commits/a63/check-runs")) return Response.json({ total_count: 0, check_runs: [] });
+        if (url.includes("/commits/a63/status")) return Response.json({ state: "success", statuses: [] });
+        if (url.includes("/issues/63/comments")) return method === "POST" ? Response.json({ id: 63 }, { status: 201 }) : Response.json([]);
+        if (url.includes("/issues/1")) return Response.json({ number: 1, title: "Issue", state: "open", labels: [], user: { login: "reporter" } });
+        if (url.includes("/branches/")) return Response.json({ protected: false, protection: { required_status_checks: { contexts: [] } } });
+        return Response.json({});
+      });
+
+      await processJob(env, { type: "agent-regate-pr", deliveryId: "turnaround-capture", repoFullName: "JSONbored/gittensory", prNumber: 63, installationId: 123 });
+
+      const published = await env.DB.prepare("select metadata_json from audit_events where event_type = ? and target_key = ?")
+        .bind("github_app.pr_public_surface_published", "JSONbored/gittensory#63")
+        .first<{ metadata_json: string }>();
+      const metadata = JSON.parse(published?.metadata_json ?? "{}");
+      expect(typeof metadata.reviewDurationMs).toBe("number");
+      expect(metadata.reviewDurationMs).toBeGreaterThanOrEqual(0);
+    });
+
+    it("REGRESSION (#4446): reviewDurationMs is correctly ABSENT (not a bogus 0) when no active-review-tracking row exists for this exact headSha", async () => {
+      const env = createTestEnv({
+        GITHUB_APP_PRIVATE_KEY: await generatePrivateKeyPem(),
+        AI: { run: async () => ({ response: JSON.stringify({ assessment: "Looks fine.", blockers: [], nits: [], suggestions: [] }) }) } as unknown as Ai,
+        AI_SUMMARIES_ENABLED: "true",
+        AI_PUBLIC_COMMENTS_ENABLED: "true",
+        AI_DAILY_NEURON_BUDGET: "100000",
+      });
+      await seedRegateChurnRepo(env, { aiReviewMode: "off" }); // AI review never runs -> startActiveReviewTracking never fires
+      await upsertPullRequestFromGitHub(env, "JSONbored/gittensory", { number: 64, title: "No AI review PR", state: "open", user: { login: "contributor" }, head: { sha: "a64" }, labels: [], body: "Closes #1" });
+      await upsertPullRequestDetailSyncState(env, { repoFullName: "JSONbored/gittensory", pullNumber: 64, status: "complete", reviewsSyncedAt: new Date().toISOString() });
+      vi.stubGlobal("fetch", async (input: RequestInfo | URL, init?: RequestInit) => {
+        const url = input.toString();
+        const method = init?.method ?? "GET";
+        if (url.includes("/access_tokens")) return Response.json({ token: "fake-installation-token" });
+        if (url.includes("/pulls/64/files")) return Response.json([{ filename: "src/a.ts", status: "modified", additions: 1, deletions: 0, changes: 1, patch: "@@\n+export const ok = true;" }]);
+        if (url.endsWith("/pulls/64")) return Response.json({ number: 64, title: "No AI review PR", state: "open", user: { login: "contributor" }, head: { sha: "a64" }, labels: [], body: "Closes #1", mergeable_state: "clean" });
+        if (url.includes("/commits/a64/check-runs")) return Response.json({ total_count: 0, check_runs: [] });
+        if (url.includes("/commits/a64/status")) return Response.json({ state: "success", statuses: [] });
+        if (url.includes("/issues/64/comments")) return method === "POST" ? Response.json({ id: 64 }, { status: 201 }) : Response.json([]);
+        if (url.includes("/issues/1")) return Response.json({ number: 1, title: "Issue", state: "open", labels: [], user: { login: "reporter" } });
+        if (url.includes("/branches/")) return Response.json({ protected: false, protection: { required_status_checks: { contexts: [] } } });
+        return Response.json({});
+      });
+
+      await processJob(env, { type: "agent-regate-pr", deliveryId: "turnaround-absent", repoFullName: "JSONbored/gittensory", prNumber: 64, installationId: 123 });
+
+      const published = await env.DB.prepare("select metadata_json from audit_events where event_type = ? and target_key = ?")
+        .bind("github_app.pr_public_surface_published", "JSONbored/gittensory#64")
+        .first<{ metadata_json: string }>();
+      const metadata = JSON.parse(published?.metadata_json ?? "{}");
+      expect(metadata.reviewDurationMs).toBeUndefined();
+    });
+
+    it("swallows a failing getActiveReviewStartedAt lookup without throwing, publishing with no reviewDurationMs (#4446)", async () => {
+      const env = createTestEnv({
+        GITHUB_APP_PRIVATE_KEY: await generatePrivateKeyPem(),
+        AI: { run: async () => ({ response: JSON.stringify({ assessment: "Looks fine.", blockers: [], nits: [], suggestions: [] }) }) } as unknown as Ai,
+        AI_SUMMARIES_ENABLED: "true",
+        AI_PUBLIC_COMMENTS_ENABLED: "true",
+        AI_DAILY_NEURON_BUDGET: "100000",
+      });
+      await seedRegateChurnRepo(env);
+      await upsertPullRequestFromGitHub(env, "JSONbored/gittensory", { number: 65, title: "Lookup failure PR", state: "open", user: { login: "contributor" }, head: { sha: "a65" }, labels: [], body: "Closes #1" });
+      await upsertPullRequestDetailSyncState(env, { repoFullName: "JSONbored/gittensory", pullNumber: 65, status: "complete", reviewsSyncedAt: new Date().toISOString() });
+      vi.stubGlobal("fetch", async (input: RequestInfo | URL, init?: RequestInit) => {
+        const url = input.toString();
+        const method = init?.method ?? "GET";
+        if (url.includes("/access_tokens")) return Response.json({ token: "fake-installation-token" });
+        if (url.includes("/pulls/65/files")) return Response.json([{ filename: "src/a.ts", status: "modified", additions: 1, deletions: 0, changes: 1, patch: "@@\n+export const ok = true;" }]);
+        if (url.endsWith("/pulls/65")) return Response.json({ number: 65, title: "Lookup failure PR", state: "open", user: { login: "contributor" }, head: { sha: "a65" }, labels: [], body: "Closes #1", mergeable_state: "clean" });
+        if (url.includes("/commits/a65/check-runs")) return Response.json({ total_count: 0, check_runs: [] });
+        if (url.includes("/commits/a65/status")) return Response.json({ state: "success", statuses: [] });
+        if (url.includes("/issues/65/comments")) return method === "POST" ? Response.json({ id: 65 }, { status: 201 }) : Response.json([]);
+        if (url.includes("/issues/1")) return Response.json({ number: 1, title: "Issue", state: "open", labels: [], user: { login: "reporter" } });
+        if (url.includes("/branches/")) return Response.json({ protected: false, protection: { required_status_checks: { contexts: [] } } });
+        return Response.json({});
+      });
+      const lookupSpy = vi.spyOn(repositoriesModule, "getActiveReviewStartedAt").mockRejectedValueOnce(new Error("D1 read error"));
+
+      await expect(
+        processJob(env, { type: "agent-regate-pr", deliveryId: "turnaround-lookup-fail", repoFullName: "JSONbored/gittensory", prNumber: 65, installationId: 123 }),
+      ).resolves.toBeUndefined(); // the publish still completes — a lookup failure is best-effort, never fatal
+      lookupSpy.mockRestore();
+
+      const published = await env.DB.prepare("select metadata_json from audit_events where event_type = ? and target_key = ?")
+        .bind("github_app.pr_public_surface_published", "JSONbored/gittensory#65")
+        .first<{ metadata_json: string }>();
+      const metadata = JSON.parse(published?.metadata_json ?? "{}");
+      expect(metadata.reviewDurationMs).toBeUndefined();
+    });
+
+    describe("reviewDurationMsSince (#4446, pure)", () => {
+      it("returns undefined for a null startedAt (no active-review-tracking row)", () => {
+        expect(reviewDurationMsSince(null, 1_000_000)).toBeUndefined();
+      });
+
+      it("returns the elapsed ms for a valid past startedAt", () => {
+        expect(reviewDurationMsSince(new Date(1_000_000).toISOString(), 1_005_000)).toBe(5_000);
+      });
+
+      it("returns 0 for a startedAt exactly equal to now", () => {
+        const now = new Date(1_000_000).toISOString();
+        expect(reviewDurationMsSince(now, 1_000_000)).toBe(0);
+      });
+
+      it("REGRESSION: returns undefined (not a negative number) for a startedAt in the FUTURE relative to now (clock skew)", () => {
+        expect(reviewDurationMsSince(new Date(2_000_000).toISOString(), 1_000_000)).toBeUndefined();
+      });
+
+      it("REGRESSION: returns undefined (not NaN) for an unparseable startedAt string", () => {
+        expect(reviewDurationMsSince("not-a-real-timestamp", 1_000_000)).toBeUndefined();
+      });
+    });
+
     it("swallows a failing hit/skip audit write without throwing (cache-hit path)", async () => {
       const env = createTestEnv({
         GITHUB_APP_PRIVATE_KEY: await generatePrivateKeyPem(),