fix(sentry): report a reviewed chat setup wait only after its retry decision (#20205)

A reviewed chat attestation that exhausts its short lock or delivery wait fails setup with reviewed_chat_execution_binding_not_ready, and the bounded retry then owns recovery. The failed-status write sent the Sentry report before the retry was scheduled, so a wait that the retry recovered still created an unexpected-failure event.

The setup path now marks that write as pending and reports once after the retry decision. A scheduled retry keeps the failure local; an exhausted, unscheduled or failed retry decision still reports. Other setup failures keep their report on the failed-status write.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Devin FoleyandClaude Opus 5.5 authored and GitHub committed 2026-11-09 12:32:15 -08:00
1 parent 98f49af70a
commit 90ec0b9673
5 files changed
+288 -2

No files matched your search

@@ -0,0 +1,123 @@
import { randomUUID } from "node:crypto";
import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
import { agents, applyPendingMigrations, closeRegisteredClients, companies, createDb, heartbeatRuns } from "@paperclipai/db";
import {
getEmbeddedPostgresTestSupport,
startEmbeddedPostgresTestDatabase,
} from "../../__tests__/helpers/embedded-postgres.js";
const mockCaptureRunFailure = vi.hoisted(() => vi.fn());
vi.mock("../../sentry.js", () => ({
captureRunFailure: mockCaptureRunFailure,
}));
import { reportRunFailure } from "../run-failure-report.js";
import { REVIEWED_CHAT_BINDING_NOT_READY } from "../reviewed-chat-binding-diagnostics.js";
const testDatabaseUrl = process.env.PAPERCLIP_TEST_DATABASE_URL;
const embeddedPostgresSupport = testDatabaseUrl ? { supported: true } : await getEmbeddedPostgresTestSupport();
const describeEmbeddedPostgres = embeddedPostgresSupport.supported ? describe : describe.skip;
describeEmbeddedPostgres("reportRunFailure reviewed chat setup waits", () => {
let db!: ReturnType<typeof createDb>;
let tempDb: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | null = null;
let companyId!: string;
let agentId!: string;
let inheritedEnv: NodeJS.ProcessEnv;
beforeAll(async () => {
if (testDatabaseUrl) {
await applyPendingMigrations(testDatabaseUrl);
db = createDb(testDatabaseUrl);
} else {
tempDb = await startEmbeddedPostgresTestDatabase("paperclip-run-failure-reviewed-chat-");
db = createDb(tempDb.connectionString);
}
}, 20_000);
beforeEach(async () => {
inheritedEnv = process.env;
process.env = Object.fromEntries(
["PATH", "HOME", "USER", "USERNAME", "LOGNAME", "USERPROFILE", "TMPDIR", "TEMP", "TMP"]
.flatMap((key) => inheritedEnv[key] === undefined ? [] : [[key, inheritedEnv[key]]]),
);
process.env.PAPERCLIP_SENTRY_RUN_FAILURES = "unexpected";
companyId = randomUUID();
agentId = randomUUID();
await db.insert(companies).values({
id: companyId,
name: "Paperclip",
issuePrefix: `T${companyId.replace(/-/g, "").slice(0, 6).toUpperCase()}`,
requireBoardApprovalForNewAgents: false,
defaultResponsibleUserId: "responsible-user",
});
await db.insert(agents).values({
id: agentId,
companyId,
name: "ReviewBot",
role: "engineer",
status: "active",
adapterType: "paperclip_runner",
adapterConfig: {},
runtimeConfig: {},
permissions: {},
});
});
afterEach(async () => {
vi.clearAllMocks();
vi.unstubAllEnvs();
process.env = inheritedEnv;
await db.delete(heartbeatRuns);
await db.delete(agents);
await db.delete(companies);
});
afterAll(async () => {
if (testDatabaseUrl) await closeRegisteredClients(testDatabaseUrl);
await tempDb?.cleanup();
});
function reviewedChatWaitRun(
overrides: Partial<typeof heartbeatRuns.$inferSelect> = {},
): typeof heartbeatRuns.$inferSelect {
return {
id: randomUUID(),
companyId,
agentId,
status: "failed",
error: REVIEWED_CHAT_BINDING_NOT_READY,
errorCode: REVIEWED_CHAT_BINDING_NOT_READY,
runtimeMode: "legacy",
executionStage: "preparing",
nativeIssueId: null,
contextSnapshot: null,
resultJson: { executionRecovery: { kind: "bootstrap", providerWorkStarted: false } },
...overrides,
} as unknown as typeof heartbeatRuns.$inferSelect;
}
it("keeps a wait local until its retry decision, and after a scheduled retry", async () => {
const run = reviewedChatWaitRun();
await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "pending" });
await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "scheduled" });
// The setup path reports once more with its decision, so a pending write stays local in every mode.
vi.stubEnv("PAPERCLIP_SENTRY_RUN_FAILURES", "all");
await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "pending" });
expect(mockCaptureRunFailure).not.toHaveBeenCalled();
});
it.each([
["no retry was scheduled", {}, "not_scheduled", "unexpected"],
["the decision is unknown", {}, undefined, "unexpected"],
["every run failure is reported", {}, "scheduled", "all"],
["the run failed for another reason", { errorCode: "setup_failed" }, "scheduled", "unexpected"],
] as const)("reports a reviewed chat setup failure when %s", async (_label, overrides, reviewedChatRetry, mode) => {
vi.stubEnv("PAPERCLIP_SENTRY_RUN_FAILURES", mode);
const run = reviewedChatWaitRun(overrides);
await reportRunFailure(db, run, { phase: "setup", ...(reviewedChatRetry ? { reviewedChatRetry } : {}) });
expect(mockCaptureRunFailure).toHaveBeenCalledOnce();
expect(mockCaptureRunFailure.mock.calls[0]![0]).toMatchObject({ errorCode: run.errorCode, runStatus: "failed" });
});
});
@@ -0,0 +1,129 @@
import { agents, agentWakeupRequests, companies, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, type Db } from "@paperclipai/db";
import { eq, sql } from "drizzle-orm";
import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js";
import { createAgentIdentityRedactor } from "../agent-identity-redaction.js";
import { ReviewedChatBindingNotReadyError } from "../reviewed-chat-binding-diagnostics.js";
import { reportRunFailure } from "../run-failure-report.js";
import { createHeartbeatLifecycle, type HeartbeatLifecycleDependencies } from "./run-lifecycle.js";
import { createHeartbeatRunPreparation } from "./run-preparation.js";
import { createHeartbeatRunState } from "./run-state.js";
import { createHeartbeatRunCompletion, type HeartbeatRunCompletionDependencies } from "./run-completion.js";
vi.mock("../live-events.js", () => ({ publishLiveEvent: vi.fn() }));
// The Sentry report is an outbound boundary; the tests observe the decision handed to it.
vi.mock("../run-failure-report.js", async importOriginal => {
const actual = await importOriginal<typeof import("../run-failure-report.js")>();
return { ...actual, reportRunFailure: vi.fn(async () => undefined) };
});
type Dependencies = HeartbeatRunCompletionDependencies;
function callbacks(db: Db) {
const state = createHeartbeatRunState(db);
const lifecycleDeps = {
...state, ...createHeartbeatRunPreparation(db),
issuesSvc: { addComment: vi.fn(), listReviewAttention: vi.fn() },
recovery: { escalateStrandedAssignedIssue: vi.fn() },
companySkills: { completeTestRunForIssue: vi.fn() },
budgets: { getInvocationBlock: vi.fn(async () => null) },
treeControlSvc: { getActivePauseHoldGate: vi.fn(async () => null) },
enqueueWakeup: vi.fn(),
getCurrentUserRedactionOptions: vi.fn<HeartbeatLifecycleDependencies["getCurrentUserRedactionOptions"]>(async () => ({ enabled: false })),
getAgentInvokability: vi.fn<HeartbeatLifecycleDependencies["getAgentInvokability"]>(async () => ({ invokable: true })),
emitTerminalAgentTaskRun: vi.fn(), budgetHooks: {},
} satisfies HeartbeatLifecycleDependencies;
const lifecycle = createHeartbeatLifecycle(db, lifecycleDeps);
return {
...state, ...lifecycle,
setRunStatusIfRunning: vi.fn(lifecycle.setRunStatusIfRunning),
setWakeupStatus: vi.fn(lifecycle.setWakeupStatus),
upsertTaskSession: vi.fn(state.upsertTaskSession),
clearTaskSessions: vi.fn(state.clearTaskSessions),
classifyAndPersistRunLiveness: vi.fn<Dependencies["classifyAndPersistRunLiveness"]>(async run => run),
completeSkillTestRunForHeartbeatOutcome: vi.fn<Dependencies["completeSkillTestRunForHeartbeatOutcome"]>(async () => null),
refreshContinuationSummaryForRun: vi.fn<Dependencies["refreshContinuationSummaryForRun"]>(async () => null),
findRunIssueComment: vi.fn<Dependencies["findRunIssueComment"]>(async () => null),
findLatestCompletedFinalAgentMessage: vi.fn<Dependencies["findLatestCompletedFinalAgentMessage"]>(async () => null),
finalizeIssueCommentPolicy: vi.fn<Dependencies["finalizeIssueCommentPolicy"]>(async () => ({ outcome: "not_applicable", queuedRun: null })),
handleIssueReviewPathDisposition: vi.fn<Dependencies["handleIssueReviewPathDisposition"]>(async () => undefined),
handleRunLivenessContinuation: vi.fn<Dependencies["handleRunLivenessContinuation"]>(),
handleSuccessfulRunHandoff: vi.fn<Dependencies["handleSuccessfulRunHandoff"]>(),
updateRuntimeState: vi.fn<Dependencies["updateRuntimeState"]>(),
scheduleBoundedRetryForRun: vi.fn<Dependencies["scheduleBoundedRetryForRun"]>(),
scheduleInteractionContinuationInfrastructureRetryIfEligible: vi.fn<Dependencies["scheduleInteractionContinuationInfrastructureRetryIfEligible"]>(async () => null),
timerClaimWasFirstHeartbeat: vi.fn<Dependencies["timerClaimWasFirstHeartbeat"]>(() => undefined),
releaseIssueExecutionAndPromote: vi.fn<Dependencies["releaseIssueExecutionAndPromote"]>(async () => undefined),
finalizeAgentStatus: vi.fn<Dependencies["finalizeAgentStatus"]>(async () => undefined),
enqueueWakeup: vi.fn<Dependencies["enqueueWakeup"]>(),
issuesSvc: { addComment: vi.fn<Dependencies["issuesSvc"]["addComment"]>() },
recovery: { reconcileLegacyContinuation: vi.fn<Dependencies["recovery"]["reconcileLegacyContinuation"]>(), reconcileResolvedDependencyWakeBackstop: vi.fn<Dependencies["recovery"]["reconcileResolvedDependencyWakeBackstop"]>() },
getCurrentUserRedactionOptions: lifecycleDeps.getCurrentUserRedactionOptions,
budgetHooks: {},
runLogStore: { finalize: vi.fn<Dependencies["runLogStore"]["finalize"]>(async () => ({ bytes: 123, sha256: "log-hash", compressed: true })) },
traceStore: { finalize: vi.fn<Dependencies["traceStore"]["finalize"]>() },
processRunCancellationSettlements: new Map<string, { settled: Promise<void>; failed: boolean }>(),
failedProcessRunCancellations: new Map<string, { settled: Promise<void>; failed: boolean }>(),
} satisfies Dependencies;
}
const support = await getEmbeddedPostgresTestSupport();
describe.skipIf(!support.supported && !process.env.PAPERCLIP_TEST_DATABASE_URL)("reviewed chat setup wait reporting", () => {
let database: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | undefined;
let db: Db;
beforeAll(async () => {
const external = process.env.PAPERCLIP_TEST_DATABASE_URL;
if (external) db = createDb(external);
else {
database = await startEmbeddedPostgresTestDatabase("paperclip-reviewed-chat-report");
db = createDb(database.connectionString);
}
await db.execute(sql`set client_min_messages = warning`);
}, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS);
afterAll(async () => { await db?.$client.end(); await database?.cleanup(); vi.restoreAllMocks(); });
beforeEach(async () => {
await db.execute(sql`truncate table companies restart identity cascade`);
vi.mocked(reportRunFailure).mockClear();
});
async function fixture(patch: Partial<typeof heartbeatRuns.$inferInsert> = {}) {
const [company] = await db.insert(companies).values({ name: "Completion", issuePrefix: "CMP" }).returning();
const [agent] = await db.insert(agents).values({ companyId: company.id, name: "Chat agent", adapterType: "process" }).returning();
const [wake] = await db.insert(agentWakeupRequests).values({ companyId: company.id, agentId: agent.id, source: "on_demand", status: "claimed" }).returning();
const [run] = await db.insert(heartbeatRuns).values({ companyId: company.id, agentId: agent.id, wakeupRequestId: wake.id, status: "running", runtimeMode: "legacy", ...patch }).returning();
const deps = callbacks(db);
const completion = createHeartbeatRunCompletion(db, deps);
const setup = (outerErr: unknown) => ({ run, runId: run.id, outerErr, signal: new AbortController().signal, providerDispatchStarted: false,
identityRedactor: createAgentIdentityRedactor(), readFailureReportSecrets: () => [] });
return { run, deps, completion, setup };
}
const read = (id: string) => db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)).then(rows => rows[0]!);
it.each(["scheduled", "not_scheduled", "scheduler_failed", "interaction_scheduled", "interaction_not_scheduled", "untrusted"] as const)(
"reports the wait only after its retry decision: %s", async scenario => {
const f = await fixture(scenario.startsWith("interaction_") ? { contextSnapshot: { source: "issue.interaction.respond", externalChatContinuation: true,
interactionId: "interaction-1", interactionStatus: "answered", interactionKind: "ask_user_questions",
mutation: "interaction", wakeReason: "issue_commented" } } : {});
const scheduled = { outcome: "scheduled" } as never;
if (scenario === "scheduler_failed") f.deps.scheduleBoundedRetryForRun.mockRejectedValueOnce(new Error("fixture scheduler failure"));
else if (scenario === "interaction_scheduled") f.deps.scheduleInteractionContinuationInfrastructureRetryIfEligible.mockResolvedValueOnce(scheduled);
else f.deps.scheduleBoundedRetryForRun.mockResolvedValueOnce(scenario === "not_scheduled"
? { outcome: "not_scheduled", reason: "Fixture scheduler boundary", issueId: null } : scheduled);
const error = scenario === "untrusted" ? new Error("reviewed_chat_execution_binding_not_ready") : new ReviewedChatBindingNotReadyError();
await f.completion.failRunSetup(f.setup(error));
const write = f.deps.setRunStatusIfRunning.mock.calls.find(call => call[1] === "failed");
if (scenario === "untrusted") {
// An ordinary setup failure keeps its report on the failed-status write.
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "setup_failed" });
expect(write?.[3]).toEqual(expect.not.objectContaining({ reviewedChatRetry: expect.anything() }));
expect(reportRunFailure).not.toHaveBeenCalled();
return;
}
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "reviewed_chat_execution_binding_not_ready" });
expect(write?.[3]).toMatchObject({ phase: "setup", reviewedChatRetry: "pending" });
expect(reportRunFailure).toHaveBeenCalledOnce();
expect(reportRunFailure).toHaveBeenCalledWith(db,
expect.objectContaining({ id: f.run.id, status: "failed", errorCode: "reviewed_chat_execution_binding_not_ready" }),
expect.objectContaining({ phase: "setup", error,
reviewedChatRetry: scenario === "scheduled" || scenario === "interaction_scheduled" ? "scheduled" : "not_scheduled" }));
});
});
@@ -27,6 +27,7 @@ import { preserveWorkspaceRestoreRecoveryMetadataSql } from "../legacy-workspace
import { cancellationResultJson, controllerLeaseLossCancellation, readRunCancellation } from "../run-cancellation.js";
import { CONTROLLER_LEASE_LOST_FAILURE_CODE, LegacyControllerLeaseLostError } from "../legacy-controller-lease.js";
import { REVIEWED_CHAT_BINDING_NOT_READY, ReviewedChatBindingNotReadyError, reviewedChatBindingDenialResultJson } from "../reviewed-chat-binding-diagnostics.js";
import { reportRunFailure } from "../run-failure-report.js";
import { accountRunCost } from "../run-cost-accounting.js";
import { isConversation, settleConversationTurn } from "../agent-conversations.js";
import { legacyExecutionNeedsReconciliationWithEvidence } from "../legacy-execution-recovery.js";
@@ -1528,7 +1529,11 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC
: setupFailureResultJson
? { resultJson: setupFailureResultJson }
: {}),
}, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets() }, { setupFailure: true }).catch(() => ({ run: null, updated: false as const }));
}, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets(),
// The Sentry report waits for the bounded retry decision below.
...(reviewedChatBindingNotReady ? { reviewedChatRetry: "pending" as const } : {}),
}, { setupFailure: true }).catch(() => ({ run: null, updated: false as const }));
let reviewedChatRetryScheduled = false;
if (!setupFailureWrite.updated) {
logger.info(
{
@@ -1614,7 +1619,7 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC
|| livenessRun.errorCode === REPOSITORY_CATALOG_UNAVAILABLE_CODE
|| livenessRun.errorCode === REVIEWED_CHAT_BINDING_NOT_READY)
&& isResolvedInteractionContinuationWakeContext(livenessRun.contextSnapshot);
await (isTransientWorkspacePreparationCode(livenessRun.errorCode) && !interactionOwnsRetry
const retry = await (isTransientWorkspacePreparationCode(livenessRun.errorCode) && !interactionOwnsRetry
? livenessRun.errorCode === RUNNER_REVISION_MISMATCH_CODE
? scheduleBoundedRetryForRun(livenessRun, failedAgent, RUNNER_REVISION_MISMATCH_RETRY)
: scheduleBoundedRetryForRun(livenessRun, failedAgent)
@@ -1624,7 +1629,9 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC
{ err: retryError, runId: livenessRun.id },
"failed to schedule interaction continuation retry after setup failure",
);
return null;
});
reviewedChatRetryScheduled = retry?.outcome === "scheduled";
}
}
await releaseIssueExecutionAndPromote(livenessRun, {
@@ -1650,6 +1657,13 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC
},
);
}
// This path owned the failed-status write, which deferred the report.
const reviewedChatReportRun = reviewedChatBindingNotReady && setupFailureWrite.updated
? failedRun ?? setupFailureWrite.run : null;
if (reviewedChatReportRun) {
void reportRunFailure(db, reviewedChatReportRun, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets(),
reviewedChatRetry: reviewedChatRetryScheduled ? "scheduled" : "not_scheduled" });
}
// Ensure the agent is not left stuck in "running" if the setup-failure
// path owned the terminal transition. If another path already finalized
// the run, keep that terminal outcome authoritative.
@@ -40,6 +40,12 @@ export interface RunFailureReportOptions {
* read, as closed labels and counts; its message and stack are never copied.
*/
nativeCloseFailure?: unknown;
/**
* The bounded retry decision for a reviewed chat setup wait. The setup path
* writes the failed status while `pending`, then reports again with the
* decision; a scheduled retry owns recovery and reports its own outcome.
*/
reviewedChatRetry?: "pending" | "scheduled" | "not_scheduled";
}
export interface RunFailureException {
+14
View File
@@ -20,6 +20,7 @@ import { RESTRICTED_WORKSPACE_SOURCE_REASON } from "./workspace-source-restricti
import { PLUGIN_RUNNER_AI_CONNECTION_REQUIRED } from "./plugin-runner-ai-connection.js";
import { NATIVE_PROVIDER_OVERLOADED_CODE } from "./native-runtime/native-provider-failure.js";
import { PROJECT_ACCESS_DENIED } from "./project-access-denial.js";
import { REVIEWED_CHAT_BINDING_NOT_READY } from "./reviewed-chat-binding-diagnostics.js";
type HeartbeatRun = typeof heartbeatRuns.$inferSelect;
@@ -289,6 +290,16 @@ async function isScheduledNativeCapacityRetry(db: Db, run: HeartbeatRun, options
return retry !== undefined;
}
/**
* A reviewed chat attestation exhausted its short lock or delivery wait before
* provider dispatch, and the setup path scheduled the bounded retry. The retry
* owns recovery; an exhausted or unscheduled wait stays reportable.
*/
function isScheduledReviewedChatRetry(run: HeartbeatRun, options: RunFailureReportOptions): boolean {
return run.status === "failed" && run.errorCode === REVIEWED_CHAT_BINDING_NOT_READY &&
options.reviewedChatRetry === "scheduled";
}
const providerAuthErrorCodes = new Set(["claude_auth_required", "acpx_auth_required"]);
/**
@@ -342,6 +353,8 @@ export function reportRunFailure(db: Db, run: HeartbeatRun, options: RunFailureR
if (run.status === "cancelled" && !isUnexpectedRunCancellation(run)) return Promise.resolve();
// The terminal write that ends the retry reports instead (`isNewTerminalRunFailure`).
if (isPendingNativeRetry(run)) return Promise.resolve();
// The setup path reports this run again once it has decided the retry.
if (options.reviewedChatRetry === "pending") return Promise.resolve();
if (mode === "unexpected" && (
isMissingSecretConfigurationBlocker(run, options) ||
isAiConnectionSelectionBlocker(run, options) ||
@@ -353,6 +366,7 @@ export function reportRunFailure(db: Db, run: HeartbeatRun, options: RunFailureR
isProviderQuotaFailure(run, options) ||
isCodexAcpModelCapacityFailure(run, options) ||
isAcpProviderAccessFailure(run, options) ||
isScheduledReviewedChatRetry(run, options) ||
isRestartInterruptedSetup(run)
)) return Promise.resolve();
const runStatus = run.status;