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