diff --git a/src/services/ai-review.ts b/src/services/ai-review.ts index 6b164bb80d..0cd4faa72c 100644 --- a/src/services/ai-review.ts +++ b/src/services/ai-review.ts @@ -1007,6 +1007,11 @@ function isSubscriptionCliTimeout(error: unknown): boolean { return error instanceof Error && error.message === "subscription_cli_timeout"; } +/** Cap on the diagnostic prefix logged for an unparseable model response (#observability-unparseable) -- long + * enough to tell a markdown-fenced/truncated-mid-JSON/plain-prose response apart, short enough to never dump + * a large chunk of model output into Sentry/audit context. */ +const UNPARSEABLE_RESPONSE_SNIPPET_MAX_CHARS = 400; + /** One reviewer opinion (whichever provider `env.AI` resolves to — self-host Codex/Claude Code/etc, or the * legacy Workers-AI pair) with a per-slot reliable fallback and a 3× retry on the primary. */ async function runWorkersOpinion( @@ -1037,7 +1042,7 @@ async function runWorkersOpinion( // logs are warn (noisy retries, skipped by the central Sentry forwarder); the exhausted summary is error (#26). let lastError: unknown; let lastUnparseable: - | { model: string; attempt: number; responseChars: number; hasJsonObject: boolean } + | { model: string; attempt: number; responseChars: number; hasJsonObject: boolean; responseSnippet: string } | undefined; const models = fallback && fallback !== primary ? [primary, fallback] : [primary]; for (const [modelIndex, model] of models.entries()) { @@ -1085,10 +1090,15 @@ async function runWorkersOpinion( return { review: parsed }; } const hasJsonObject = Boolean(extractLastJsonObject(text)); - const status = text.trim() ? "unparseable_output" : "empty_output"; + const trimmedText = text.trim(); + const status = trimmedText ? "unparseable_output" : "empty_output"; diagnostics.push({ model, attempt, status, responseChars: text.length, hasJsonObject, ...usageFields }); - if (text.trim()) { - lastUnparseable = { model, attempt, responseChars: text.length, hasJsonObject }; + if (trimmedText) { + // NOT added to the diagnostics entry above: reviewDiagnostics flows into result/Sentry context that + // must never carry raw provider text (see the "withholds unsafe provider and reviewer fallback text" + // test) -- logged here instead, which reaches only the structured-log Sentry forwarder, never `result`. + const responseSnippet = trimmedText.slice(0, UNPARSEABLE_RESPONSE_SNIPPET_MAX_CHARS); + lastUnparseable = { model, attempt, responseChars: text.length, hasJsonObject, responseSnippet }; console.warn( JSON.stringify({ level: "warn", @@ -1097,6 +1107,7 @@ async function runWorkersOpinion( attempt, responseChars: text.length, hasJsonObject, + responseSnippet, }), ); } @@ -1149,6 +1160,7 @@ async function runWorkersOpinion( attempt: lastUnparseable.attempt, responseChars: lastUnparseable.responseChars, hasJsonObject: lastUnparseable.hasJsonObject, + responseSnippet: lastUnparseable.responseSnippet, }), ); } diff --git a/test/unit/ai-review.test.ts b/test/unit/ai-review.test.ts index 00603577c0..bb7c02fa65 100644 --- a/test/unit/ai-review.test.ts +++ b/test/unit/ai-review.test.ts @@ -8,6 +8,7 @@ import { resolveEffectiveAiReviewPlan, runGittensoryAiReview, type AiContentBlock, + type AiReviewDiagnostic, type GittensoryAiReviewInput, } from "../../src/services/ai-review"; import { createTestEnv } from "../helpers/d1"; @@ -3081,7 +3082,7 @@ describe("pure helpers", () => { warnSpy.mockRestore(); }); - it("logs unparseable exhaustion separately when the model runs but returns unparseable output", async () => { + it("logs unparseable exhaustion separately when the model runs but returns unparseable output, including a response snippet for diagnosis (#observability-unparseable)", async () => { const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); const run = vi.fn(async () => ({ response: "not json at all" })); const env = createTestEnv({ AI: { run } as unknown as Ai }); @@ -3092,14 +3093,35 @@ describe("pure helpers", () => { .map((c) => c[0]) .some((l) => typeof l === "string" && l.includes("ai_review_provider_exhausted")), ).toBe(false); - expect( - logSpy.mock.calls - .map((c) => c[0]) - .some((l) => typeof l === "string" && l.includes("ai_review_provider_unparseable_exhausted")), - ).toBe(true); + const exhausted = logSpy.mock.calls + .map((c) => c[0]) + .find((l) => typeof l === "string" && l.includes("ai_review_provider_unparseable_exhausted")); + expect(exhausted).toBeDefined(); + expect(JSON.parse(exhausted as string)).toMatchObject({ + event: "ai_review_provider_unparseable_exhausted", + responseSnippet: "not json at all", + }); logSpy.mockRestore(); }); + it("truncates the unparseable-output response snippet to 400 chars instead of logging the full response (#observability-unparseable), and never puts it on the returned diagnostics (#4111-style public/private boundary)", async () => { + const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {}); + const longResponse = "not json, ".repeat(60); // 600 chars, well over the 400-char cap + const run = vi.fn(async () => ({ response: longResponse })); + const env = createTestEnv({ AI: { run } as unknown as Ai }); + const diagnostics: AiReviewDiagnostic[] = []; + await runWorkersOpinion(env, "primary-model", "primary-model", "sys", "user", 256, diagnostics); + // reviewDiagnostics flows into result/Sentry context that must never carry raw provider text (see the + // "withholds unsafe provider and reviewer fallback text" test) -- the snippet only ever reaches the log. + expect(diagnostics[0]).not.toHaveProperty("responseSnippet"); + const firstWarn = warnSpy.mock.calls + .map((c) => c[0]) + .find((l) => typeof l === "string" && l.includes("ai_review_provider_unparseable_output")); + expect(JSON.parse(firstWarn as string).responseSnippet).toBe(longResponse.slice(0, 400)); + expect(JSON.parse(firstWarn as string).responseSnippet.length).toBe(400); + warnSpy.mockRestore(); + }); + it("applies the default daily neuron budget when none is configured", async () => { const run = vi.fn(async (_model: string) => ({ response: reviewJson() })); const env = createTestEnv({