From 36e4c6657f808fc4438da0f4d2c64c358a89ff71 Mon Sep 17 00:00:00 2001 From: Devin Foley Date: Mon, 19 Oct 2026 09:29:50 -0700 Subject: [PATCH] fix(sentry): report a native retry failure only when the retry ends (#16865) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - The server sends a Sentry `run_failure` event when an agent run reaches a terminal failure. > - A native run that waits for a same-run retry is stored as `failed` with `nativePhase: "retryable_failure"`. That state is not terminal. > - `reportRunFailure` reported that pending state. Runs that later recovered, for example after a workspace copy-back retry, still sent a run failure event. > - These events make one catch-all Sentry group noisy and hide the real terminal failures in it. > - This pull request skips the pending retry state and reports once when the retry ends as a terminal failure. > - The benefit is that run failure events match runs that really failed. ## Linked Issues or Issue Description **What happened?** Two staging runs had a workspace copy-back failure during settlement (`Daytona syncOut tar command failed ... No space left on device`). The executor stored each run as `failed` with `nativePhase: "retryable_failure"` and `errorCode: native_session_interrupted`. Sentry received a `run_failure` event for each run. About two minutes later, the copy-back retry succeeded and both runs finished as `succeeded` with `workspaceFinalizeStatus: "succeeded"`. **Expected behavior** A run that waits for a same-run retry must not send a terminal run failure event. If the retry ends as a terminal failure, the server must send one event at that time. **Steps to reproduce** 1. Set `PAPERCLIP_SENTRY_RUN_FAILURES=unexpected`. 2. Start a native run that fails retryably. For example, make the workspace copy-back fail once. 3. See the `run_failure` event in Sentry, and then see the run finish as `succeeded` after the retry. ## What Changed - `reportRunFailure` returns without a report for a native run that is `failed` with `nativePhase: "retryable_failure"`. - New `isNewTerminalRunFailure(before, after)`: a status change counts as before. A failed run that leaves the pending retry state but stays `failed` also counts. - Three terminal writers can keep the status `failed` → `failed`. They now use `isNewTerminalRunFailure`, so they still report once: - the resume reconciler's ambiguous-state write; - the restart recovery `blocked` write; - the committed-result projection (`projectCommittedRun`). - Result-less retries already reset the run to `running` before they start, so their terminal write still reports through the existing status-change guard. - `doc/observability.md` describes the new rule. ## Verification - `pnpm exec vitest run src/services/__tests__/run-failure-report.test.ts src/__tests__/run-failure-sentry.test.ts src/__tests__/native-session-resumption.test.ts src/services/native-runtime/native-run-finalizer-telemetry.test.ts src/services/native-runtime/native-runner-restart-recovery.integration.test.ts src/__tests__/heartbeat-status-preserving-telemetry.test.ts src/services/execution-control-reconciliation.test.ts` (from `server/`): 7 files, 363 passed, 9 skipped. - New tests: - `run-failure-report.test.ts`: a pending native retry does not report, and a `terminal_failure` run does. Unit cases cover `isNewTerminalRunFailure`. - `native-session-resumption.test.ts`: a sweep that ends an unreported pending retry sends one event. - `native-run-finalizer-telemetry.test.ts`: a committed failure for a pending-retry row sends one event, and a replay sends none. - `native-runner-restart-recovery.integration.test.ts`: a restart recovery `blocked` write for a pending-retry row sends one event. - I removed each of the three writer changes one at a time. The matching new test failed each time (`expected [] to have a length of 1` / `to deeply equal [ [ ObjectContaining{…} ] ]`). - I did not run the full server `tsc --noEmit` locally. The local container has a 4 GiB memory limit, and the process was killed (exit 137). CI runs the typecheck. ## Risks - A run that stays in the pending retry state and never resumes no longer sends a run failure event. The run stays visible on the board as failed with a scheduled retry. A later terminal write still reports it. - The finalizer's `failed` + `retryable_failure` write for a failed provider result also stops reporting. The terminal write that ends that retry reports instead: retry exhaustion in `recordRetryableFailure` reports unconditionally, and commit goes through `finalizeNativeRun` or `projectCommittedRun`. - A run that was reported in the pending state before this change can report once more when it becomes terminal after deploy. This affects only runs in flight during the upgrade. - There are no schema, migration, or API changes. Run status, retries, and recovery do not change. > For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and discuss it in `#dev` before opening the PR. Feature PRs that overlap with planned core work may need to be redirected — check the roadmap first. See `CONTRIBUTING.md`. ## Model Used - Anthropic Claude Opus 5.5 (`claude-opus-5-5`) in Claude Code, with tool use (shell, code search, test runs) and a read-only code exploration subagent. Context window: the standard window for that model. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [ ] All Paperclip CI gates are green - [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-authored-by: devinfoley <139239+devinfoley@users.noreply.github.com> Co-authored-by: Claude Opus 5.5 --- doc/observability.md | 4 +- .../native-session-resumption.test.ts | 40 +++++++++++++++++++ .../__tests__/run-failure-report.test.ts | 22 +++++++++- .../native-finalization-reconciler.ts | 7 ++-- .../native-runtime/native-restart-recovery.ts | 4 +- .../native-run-finalizer-telemetry.test.ts | 29 ++++++++++++++ .../native-runtime/native-run-finalizer.ts | 7 +++- ...unner-restart-recovery.integration.test.ts | 26 ++++++++++++ server/src/services/run-failure-report.ts | 26 +++++++++++- 9 files changed, 155 insertions(+), 10 deletions(-) diff --git a/doc/observability.md b/doc/observability.md index 4ce7e94d8af..d842247b315 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -715,7 +715,9 @@ backend Sentry DSN and the audited SDK. Set `PAPERCLIP_SENTRY_RUN_FAILURES` to: Missing, blank, or unrecognized values keep run reporting off. Expected operator stops, shutdown interruptions, successful runs, and queued work do not report in -either enabled mode. The mode does not change run status, retries, recovery, +either enabled mode. A native run that is `failed` while it waits for a same-run +retry (`nativePhase` `retryable_failure`) does not report either. It reports once +if a later write ends the retry as a terminal failure. The mode does not change run status, retries, recovery, Telemetry, or OpenTelemetry export. It is process-wide, so an operator can enable it on one staging instance without enabling it on other deployments. Restart the server after changing deployment environment variables. diff --git a/server/src/__tests__/native-session-resumption.test.ts b/server/src/__tests__/native-session-resumption.test.ts index 89f1cbb2441..270a3b26fef 100644 --- a/server/src/__tests__/native-session-resumption.test.ts +++ b/server/src/__tests__/native-session-resumption.test.ts @@ -622,6 +622,46 @@ describe("P6-25 pre-result native session recovery", () => { expect(mockCaptureRunFailure.mock.calls.slice(captureCallsBefore)).toHaveLength(0); }); + + it("sends one Sentry event when a sweep ends an unreported pending retry", async () => { + const freshRunId = "79000000-0000-4000-8000-000000000103"; + await db.insert(issues).values({ id: freshRunId, companyId, title: "Independent failure report", + status: "in_progress", assigneeAgentId: agentId }); + // The executor stores a scheduled same-run retry as failed + retryable_failure, + // and reportRunFailure skips that write. The sweep's terminal write reports it. + await db.insert(heartbeatRuns).values({ + id: freshRunId, + companyId, + agentId, + nativeIssueId: freshRunId, + status: "failed", + nativePhase: "retryable_failure", + runtimeMode: "native", + runtimeModeResolvedAt: new Date(), + runnerProfileJson: { + nativeExecutionInput: { + ...persistedProfile.nativeExecutionInput, + binding: { runId: freshRunId }, + }, + }, + contextSnapshot: { issueId: freshRunId }, + }); + await db.insert(nativeRunFinalizations).values({ + runId: freshRunId, + companyId, + issueId: freshRunId, + phase: "retryable_failure", + attempt: 1, + }); + const captureCallsBefore = mockCaptureRunFailure.mock.calls.length; + + await claimNativeSessionResumptions({ db, runnerInstanceId: "reaper", runIds: [freshRunId] }); + await waitForPendingRunFailureReports(); + + const newCaptures = mockCaptureRunFailure.mock.calls.slice(captureCallsBefore); + expect(newCaptures).toHaveLength(1); + expect(newCaptures[0]?.[0]).toMatchObject({ runId: freshRunId, runStatus: "failed" }); + }); }); describe.each(["unchanged", "newer_active", "stale_idle"] as const)( diff --git a/server/src/services/__tests__/run-failure-report.test.ts b/server/src/services/__tests__/run-failure-report.test.ts index e8fab6b1fe3..f2c833557d1 100644 --- a/server/src/services/__tests__/run-failure-report.test.ts +++ b/server/src/services/__tests__/run-failure-report.test.ts @@ -29,7 +29,7 @@ vi.mock("../../log-redaction.js", async (importOriginal) => { return { ...actual, redactCurrentUserText: mockRedactCurrentUserText }; }); -import { reportRunFailure, waitForPendingRunFailureReports } from "../run-failure-report.js"; +import { isNewTerminalRunFailure, reportRunFailure, waitForPendingRunFailureReports } from "../run-failure-report.js"; import { controllerLeaseLossCancellation } from "../run-cancellation.js"; import { REDACTED_EVENT_VALUE } from "../../redaction.js"; @@ -981,6 +981,26 @@ describeEmbeddedPostgres("reportRunFailure", () => { .toBe(`the provider process exited with code ${REDACTED_EVENT_VALUE}`); }); + it("waits for the terminal write when a native run is failed pending a same-run retry", async () => { + await seedCompanyAndAgent(); + await reportRunFailure(db, buildRun({ runtimeMode: "native", nativePhase: "retryable_failure" })); + expect(mockCaptureRunFailure).not.toHaveBeenCalled(); + + await reportRunFailure(db, buildRun({ runtimeMode: "native", nativePhase: "terminal_failure" })); + expect(mockCaptureRunFailure).toHaveBeenCalledOnce(); + }); + + it("treats leaving a pending native retry as a new terminal failure", () => { + const pending = { status: "failed", runtimeMode: "native", nativePhase: "retryable_failure" } as const; + expect(isNewTerminalRunFailure({ ...pending, status: "running", nativePhase: "observed" }, pending)).toBe(true); + expect(isNewTerminalRunFailure(pending, { ...pending, nativePhase: "terminal_failure" })).toBe(true); + expect(isNewTerminalRunFailure(pending, { ...pending, nativePhase: "committed" })).toBe(true); + expect(isNewTerminalRunFailure(pending, pending)).toBe(false); + expect(isNewTerminalRunFailure({ ...pending, nativePhase: null }, { ...pending, nativePhase: "terminal_failure" })).toBe(false); + expect(isNewTerminalRunFailure({ ...pending, runtimeMode: "legacy" }, { ...pending, runtimeMode: "legacy", nativePhase: null })) + .toBe(false); + }); + it("captures nothing for succeeded, cancelled, and interrupted", async () => { await seedCompanyAndAgent(); for (const status of ["succeeded", "cancelled", "interrupted"] as const) { diff --git a/server/src/services/native-runtime/native-finalization-reconciler.ts b/server/src/services/native-runtime/native-finalization-reconciler.ts index afd9fac3c11..e0151725e64 100644 --- a/server/src/services/native-runtime/native-finalization-reconciler.ts +++ b/server/src/services/native-runtime/native-finalization-reconciler.ts @@ -35,7 +35,7 @@ import { import { issueRecoveryActionService } from "../issue-recovery-actions.js"; import { issueService } from "../issues.js"; import { emitAgentTaskRun } from "../agent-task-run-telemetry.js"; -import { reportRunFailure } from "../run-failure-report.js"; +import { isNewTerminalRunFailure, reportRunFailure } from "../run-failure-report.js"; import { resumeNativeWorkspaceFinalization } from "./native-workspace-finalizer.js"; import { dismissObsoleteNativePolicyReviews } from "./obsolete-policy-reviews.js"; import { @@ -519,9 +519,10 @@ export async function claimNativeSessionResumptions(input: { }).where(eq(heartbeatRuns.id, row.run.id)).returning(); // Only a genuine transition into "failed" is a new terminal failure. // A candidate that is already "failed" (the filter above admits - // both "running" and "failed") must not send a second Sentry event. + // both "running" and "failed") must not send a second Sentry event, + // unless that earlier write was an unreported pending retry. terminalRunToEmit = - updatedRun && updatedRun.status !== row.run.status ? updatedRun : null; + updatedRun && isNewTerminalRunFailure(row.run, updatedRun) ? updatedRun : null; await issueService(tx as unknown as Db).update( row.coordinator.issueId, { status: "blocked" }, diff --git a/server/src/services/native-runtime/native-restart-recovery.ts b/server/src/services/native-runtime/native-restart-recovery.ts index 3e4090e710f..fb05f82252a 100644 --- a/server/src/services/native-runtime/native-restart-recovery.ts +++ b/server/src/services/native-runtime/native-restart-recovery.ts @@ -19,7 +19,7 @@ import { readProcessStartedAt } from "../hot-restart.js"; import { getServerInfoSnapshot } from "../../server-info.js"; import { redactSensitiveText } from "../../redaction.js"; import { issueRecoveryActionService } from "../issue-recovery-actions.js"; -import { reportRunFailure } from "../run-failure-report.js"; +import { isNewTerminalRunFailure, reportRunFailure } from "../run-failure-report.js"; import { isNativeRunnerOwnershipHeld } from "./native-runner-ownership.js"; import { nativeRestartInterruptedTurnId, type PersistedNativeSession } from "../../vendor/paperclip-runner/index.js"; @@ -895,7 +895,7 @@ export async function claimNativeRestartRecoveries(input: { }) .where(eq(heartbeatRuns.id, row.run.id)) .returning(); - if (updatedRun && updatedRun.status !== row.run.status) { + if (updatedRun && isNewTerminalRunFailure(row.run, updatedRun)) { terminalRunToReport = updatedRun; } await tx diff --git a/server/src/services/native-runtime/native-run-finalizer-telemetry.test.ts b/server/src/services/native-runtime/native-run-finalizer-telemetry.test.ts index 3ad5e4163b1..e562b376924 100644 --- a/server/src/services/native-runtime/native-run-finalizer-telemetry.test.ts +++ b/server/src/services/native-runtime/native-run-finalizer-telemetry.test.ts @@ -58,6 +58,7 @@ import { restoreNativeWorkspaceBestEffort } from "./native-workspace-best-effort import { reconcileNativeFinalizations } from "./native-finalization-reconciler.js"; import { recoverLegacyUnsafeWorkspaceExports } from "./native-workspace-export-recovery.js"; import { finalizeNativeRun, recordNativeFinalizationFailure } from "./native-run-finalizer.js"; +import { waitForPendingRunFailureReports } from "../run-failure-report.js"; import { deliverExecutionStatuses } from "../execution-status-delivery.js"; import { commitNativeStatusDecision } from "./status-decision-committer.js"; import { NATIVE_STATUS_ARBITER_POLICY_VERSION, type NativeStatusDecision } from "./status-arbiter.js"; @@ -555,6 +556,34 @@ describeEmbeddedPostgres("native run finalizer / status decision committer — a expect(replayed).toEqual(repaired); }); + it("reports a committed failure once when the run row was an unreported pending retry", async () => { + const fixture = await seedNativeRun(); + await driveToCompleteResult(fixture, { + ...CONTROL_PLANE_CONFORMANCE_TERMINAL, + turnTerminalState: "failed", + runTerminalState: "failed", + }); + const finalize = () => finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true }); + await finalize(); + // The executor stores a scheduled same-run retry as failed + retryable_failure, + // and reportRunFailure skips that write. + await db.update(heartbeatRuns).set({ + nativePhase: "retryable_failure", + }).where(eq(heartbeatRuns.id, fixture.runId)); + await waitForPendingRunFailureReports(); + const captureCallsBefore = mockCaptureRunFailure.mock.calls.length; + + await finalize(); + await waitForPendingRunFailureReports(); + expect(captureRunFailureCallsFrom(captureCallsBefore)).toEqual([ + [expect.objectContaining({ runId: fixture.runId, runStatus: "failed" })], + ]); + + await finalize(); + await waitForPendingRunFailureReports(); + expect(captureRunFailureCallsFrom(captureCallsBefore)).toHaveLength(1); + }); + it("retires this run's scheduled finalization retry after successful commit", async () => { const fixture = await seedNativeRun(); await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL); diff --git a/server/src/services/native-runtime/native-run-finalizer.ts b/server/src/services/native-runtime/native-run-finalizer.ts index c8210435faa..441e0a4d34d 100644 --- a/server/src/services/native-runtime/native-run-finalizer.ts +++ b/server/src/services/native-runtime/native-run-finalizer.ts @@ -54,7 +54,7 @@ import { readNativeBoardResponseWaitSource, } from "./native-board-response-wait.js"; import { emitAgentTaskRun } from "../agent-task-run-telemetry.js"; -import { reportRunFailure } from "../run-failure-report.js"; +import { isNewTerminalRunFailure, reportRunFailure } from "../run-failure-report.js"; import { resolveExternalChatResponseWaitAuthorization } from "./chat-attachment-reuse.js"; import { authorizeNativeChatReviewPresentation, @@ -720,10 +720,13 @@ async function projectCommittedRun(input: { ) .returning(); // Metadata repairs can preserve the terminal status. Only a genuine status - // transition should emit another terminal event. + // transition should emit another terminal event. A failed run that leaves a + // pending retry still needs its first failure report. if (updatedRun && updatedRun.status !== input.run.status) { await emitAgentTaskRun(input.db, updatedRun); void reportRunFailure(input.db, updatedRun); + } else if (updatedRun && isNewTerminalRunFailure(input.run, updatedRun)) { + void reportRunFailure(input.db, updatedRun); } } diff --git a/server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts b/server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts index d949fba5d83..ee6d2ecb667 100644 --- a/server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts +++ b/server/src/services/native-runtime/native-runner-restart-recovery.integration.test.ts @@ -50,6 +50,7 @@ import { materializeAsset } from "./runtime-context.js"; import { createRunnerTestTlsTunnel, dockerCommandRunner } from "../../__tests__/helpers/docker-command-runner.js"; import { createIsolatedTestHome } from "../../__tests__/helpers/isolated-test-home.js"; import { finalizeNativeRun } from "./native-run-finalizer.js"; +import { waitForPendingRunFailureReports } from "../run-failure-report.js"; import { closeIdleWarmNativeSessionsForRestart, executePaperclipNativeSession, NativeControllerDetachedForRestartError } from "./native-session-executor.js"; const mockCaptureRunFailure = vi.hoisted(() => vi.fn()); @@ -1455,6 +1456,31 @@ describeEmbeddedPostgres("native runner restart recovery with real processes", ( expect(await fixture.db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId))).toHaveLength(1); }); + it("reports one event when it blocks a failed run that was an unreported pending retry", async () => { + const fixture = await seedRun("PENDING-RETRY-BLOCKED"); + // The executor stores a scheduled same-run retry as failed + retryable_failure, + // and reportRunFailure skips that write. The blocked write reports it. + await fixture.db.update(heartbeatRuns).set({ + status: "failed", + nativePhase: "retryable_failure", + runnerProfileJson: { sessionCheckpoint: { + terminal: { runTerminalState: "failed", turnTerminalState: "failed" }, + providerSessionId: "unusable-provider-session", + } }, + }).where(eq(heartbeatRuns.id, fixture.runId)); + await fixture.db.update(nativeRunFinalizations).set({ attempt: 3 }).where(eq(nativeRunFinalizations.runId, fixture.runId)); + const captureCallsBefore = mockCaptureRunFailure.mock.calls.length; + + expect(await claimNativeRestartRecoveries({ + db: fixture.db, controller: successor, restartKind: "hard", runIds: [fixture.runId], + })).toEqual([{ kind: "blocked", runId: fixture.runId, reason: "provider_checkpoint_permanently_failed" }]); + await waitForPendingRunFailureReports(); + + expect(mockCaptureRunFailure.mock.calls.slice(captureCallsBefore)).toEqual([ + [expect.objectContaining({ runId: fixture.runId, runStatus: "failed", errorCode: "native_restart_recovery_blocked" })], + ]); + }); + it("classifies every requested recovery candidate without an implicit 100-run cap", async () => { const db = createDb(temporary.connectionString); const fixtures: Array>> = []; diff --git a/server/src/services/run-failure-report.ts b/server/src/services/run-failure-report.ts index ad756c8c33b..46f3c090d5c 100644 --- a/server/src/services/run-failure-report.ts +++ b/server/src/services/run-failure-report.ts @@ -38,6 +38,27 @@ function isRunFailureStatus(status: string): status is RunFailureStatus { return status === "failed" || status === "timed_out" || status === "cancelled"; } +type RunFailureTransitionState = Pick; + +/** + * A native run that waits for a same-run retry is stored as `failed` with + * `nativePhase: "retryable_failure"`. That is not terminal: the retry or the + * workspace copy-back retry can still finish the run as succeeded. + */ +function isPendingNativeRetry(run: RunFailureTransitionState): boolean { + return run.status === "failed" && run.runtimeMode === "native" && run.nativePhase === "retryable_failure"; +} + +/** + * Whether a status write is a new terminal failure to pass to `reportRunFailure`. + * A status change counts. A run that leaves a pending native retry but stays + * `failed` also counts, because `reportRunFailure` skipped its earlier write. + */ +export function isNewTerminalRunFailure(before: RunFailureTransitionState, after: RunFailureTransitionState): boolean { + if (after.status !== before.status) return true; + return isPendingNativeRetry(before) && !isPendingNativeRetry(after); +} + function readTaskId(run: HeartbeatRun): string | null { if (run.issueId) return run.issueId; if (run.nativeIssueId) return run.nativeIssueId; @@ -238,7 +259,8 @@ async function isRejectedExternalBotWake(db: Db, run: HeartbeatRun): Promise