diff --git a/server/src/__tests__/heartbeat-process-recovery.test.ts b/server/src/__tests__/heartbeat-process-recovery.test.ts index ea30fdea2c4..46c9e3de558 100644 --- a/server/src/__tests__/heartbeat-process-recovery.test.ts +++ b/server/src/__tests__/heartbeat-process-recovery.test.ts @@ -3250,6 +3250,72 @@ describeEmbeddedPostgres("heartbeat orphaned process recovery", () => { expect(retries).toHaveLength(0); }); + // A hard restart can kill the server after it claimed a legacy run but before + // the adapter dispatch renewal, leaving an expired lease from another boot. + async function seedRestartOrphanedLegacySetup(executionStage: "preparing" | "dispatching") { + const fixture = await seedRunFixture({ + adapterType: "paperclip_runner", + agentStatus: "idle", + runtimeMode: "legacy", + }); + await db.update(heartbeatRuns).set({ + controllerBootId: randomUUID(), + controllerLeaseExpiresAt: sql`clock_timestamp() - interval '1 second'`, + executionStage, + }).where(eq(heartbeatRuns.id, fixture.runId)); + return fixture; + } + + it("retries a legacy run that a restart stopped before adapter dispatch", async () => { + const { companyId, runId, issueId } = await seedRestartOrphanedLegacySetup("preparing"); + + const heartbeat = heartbeatService(db); + const result = await heartbeat.reapOrphanedRuns(); + + expect(result).toEqual({ reaped: 1, runIds: [runId] }); + const [reaped] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, runId)); + expect(reaped).toMatchObject({ + status: "failed", + errorCode: "process_lost", + error: "Process lost -- server may have restarted; retrying once", + }); + expect(reaped?.resultJson).toMatchObject({ + executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + processLossDiagnostic: { localCheck: "no_identifiers", retryEligible: true, runPredatesObserver: true }, + }); + const retries = await db.select().from(heartbeatRuns).where(and( + eq(heartbeatRuns.companyId, companyId), + eq(heartbeatRuns.retryOfRunId, runId), + )); + expect(retries).toEqual([expect.objectContaining({ status: "scheduled_retry" })]); + expect(await db.select().from(issueRecoveryActions) + .where(eq(issueRecoveryActions.sourceIssueId, issueId))).toEqual([]); + expect(mockAdapterExecute).not.toHaveBeenCalled(); + }); + + it("keeps an orphaned legacy run that reached adapter dispatch held for reconciliation", async () => { + const { companyId, runId, issueId } = await seedRestartOrphanedLegacySetup("dispatching"); + + const heartbeat = heartbeatService(db); + await heartbeat.reapOrphanedRuns(); + + const [reaped] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, runId)); + expect(reaped).toMatchObject({ + status: "failed", + errorCode: "process_lost", + error: "Process lost -- server may have restarted", + }); + expect(reaped?.resultJson).not.toHaveProperty("executionRecovery"); + expect(await db.select().from(heartbeatRuns).where(and( + eq(heartbeatRuns.companyId, companyId), + eq(heartbeatRuns.retryOfRunId, runId), + ))).toEqual([]); + expect(await db.select().from(issueRecoveryActions) + .where(eq(issueRecoveryActions.sourceIssueId, issueId))).toEqual([ + expect.objectContaining({ cause: "legacy_execution_requires_reconciliation" }), + ]); + }); + async function withTempPaperclipHome( fn: (home: string) => Promise, ): Promise { diff --git a/server/src/services/__tests__/run-failure-report.test.ts b/server/src/services/__tests__/run-failure-report.test.ts index 0914b1a2e3d..038f2b6fd32 100644 --- a/server/src/services/__tests__/run-failure-report.test.ts +++ b/server/src/services/__tests__/run-failure-report.test.ts @@ -393,6 +393,52 @@ describeEmbeddedPostgres("reportRunFailure", () => { expect(mockCaptureRunFailure).toHaveBeenCalledOnce(); }); + function restartInterruptedSetupRun(overrides: Partial = {}) { + return buildRun({ + error: "Process lost -- server may have restarted; retrying once", + runtimeMode: "legacy", executionStage: "preparing", processPid: null, processGroupId: null, + resultJson: { + executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + processLossDiagnostic: { + pidRecorded: false, groupRecorded: false, localCheck: "no_identifiers", + retryEligible: true, runPredatesObserver: true, + }, + }, + ...overrides, + }); + } + + it("keeps a retried restart interruption of legacy setup local", async () => { + await seedCompanyAndAgent({ adapterType: "paperclip_runner" }); + await reportRunFailure(db, restartInterruptedSetupRun()); + expect(mockCaptureRunFailure).not.toHaveBeenCalled(); + }); + + it("reports a retried restart interruption of legacy setup in all mode", async () => { + vi.stubEnv("PAPERCLIP_SENTRY_RUN_FAILURES", "all"); + await seedCompanyAndAgent({ adapterType: "paperclip_runner" }); + await reportRunFailure(db, restartInterruptedSetupRun()); + expect(mockCaptureRunFailure).toHaveBeenCalledOnce(); + }); + + it.each([ + { executionStage: "dispatching" }, { runtimeMode: "native" }, { processPid: 4242 }, + { errorCode: "adapter_failed" }, + { resultJson: { processLossDiagnostic: { localCheck: "no_identifiers", retryEligible: true, runPredatesObserver: true } } }, + { resultJson: { + executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + processLossDiagnostic: { localCheck: "no_identifiers", retryEligible: false, runPredatesObserver: true }, + } }, + { resultJson: { + executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + processLossDiagnostic: { localCheck: "no_identifiers", retryEligible: true, runPredatesObserver: false }, + } }, + ])("reports process loss without restart-before-dispatch evidence: %j", async (overrides) => { + await seedCompanyAndAgent({ adapterType: "paperclip_runner" }); + await reportRunFailure(db, restartInterruptedSetupRun(overrides)); + expect(mockCaptureRunFailure).toHaveBeenCalledOnce(); + }); + async function expiredGrokOffer(input: { wakes: Array<{ status: "rejected" | "accepted" | "acknowledged" | "unknown"; httpStatus: number | null }>; acceptedAt?: Date | null; diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index 4a6db618b5a..27ac5659e84 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -9,7 +9,7 @@ import { recordNativeLocalProcessStop } from "../native-local-process-stop.js"; import { legacyControllerBootId, hasLiveLegacyController, - revokeExpiredLegacyController, + revokeExpiredLegacyControllerWithState, } from "../legacy-controller-lease.js"; import { remoteTerminationReceipt } from "../remote-execution-termination.js"; import { runUsedConversationAdapter } from "../conversation-continuation.js"; @@ -2314,12 +2314,27 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD readNonEmptyString(runContext.wakeReason) === "issue_monitor_due" && monitorNextCheckAt !== undefined && (!monitorNextCheckAt || monitorNextCheckAt.getTime() <= now.getTime()); + const revokedState = await revokeExpiredLegacyControllerWithState(db, run); + if (!revokedState) continue; + // A legacy controller persists "dispatching" in the same lease renewal + // that admits the adapter. An expired lease from another boot that is + // still "preparing" proves a restart stopped setup before provider work. + // Use the state committed with the revocation, not the earlier snapshot: + // the old controller may have dispatched before its lease expired. + // The revocation matched the snapshot's boot ID before replacing it. + const restartInterruptedBeforeDispatch = + run.runtimeMode === "legacy" && + revokedState.executionStage === "preparing" && + !!run.controllerBootId && + run.controllerBootId !== legacyControllerBootId && + !revokedState.processPid && + !revokedState.processGroupId; const shouldRetry = (run.processLossRetryCount ?? 0) < 1 && ((tracksLegacyLocalChild && (!!run.processPid || !!run.processGroupId)) || + restartInterruptedBeforeDispatch || monitorDispatchLostWithoutFutureWake); - if (!(await revokeExpiredLegacyController(db, run))) continue; const baseMessage = buildProcessLossMessage(run); const processLossDiagnostic = buildProcessLossDiagnostic({ run, @@ -2344,7 +2359,13 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD "failed", { conversationContinuationEligible, - resultJson: { ...parseObject(run.resultJson), processLossDiagnostic }, + resultJson: { + ...parseObject(run.resultJson), + processLossDiagnostic, + ...(restartInterruptedBeforeDispatch + ? { executionRecovery: { kind: "bootstrap", providerWorkStarted: false } } + : {}), + }, errorCode: "process_lost", errorMessage: shouldRetry ? `${baseMessage}; retrying once` diff --git a/server/src/services/legacy-controller-lease.test.ts b/server/src/services/legacy-controller-lease.test.ts index d2e4b2e2c40..2280f70dd0e 100644 --- a/server/src/services/legacy-controller-lease.test.ts +++ b/server/src/services/legacy-controller-lease.test.ts @@ -5,7 +5,8 @@ import { agents, companies, createDb, heartbeatRuns } from "@paperclipai/db"; import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../__tests__/helpers/embedded-postgres.js"; import { heartbeatService } from "./heartbeat.js"; import { hasLiveLegacyController, LEGACY_CONTROLLER_RENEW_MS, legacyControllerBootId, legacyControllerClaim, LegacyControllerLeaseLostError, - renewLegacyControllerLease, revokeExpiredLegacyController, watchLegacyControllerLease } from "./legacy-controller-lease.js"; + renewLegacyControllerLease, revokeExpiredLegacyController, revokeExpiredLegacyControllerWithState, + watchLegacyControllerLease } from "./legacy-controller-lease.js"; const support = await getEmbeddedPostgresTestSupport(); (support.supported ? describe : describe.skip)("durable legacy controller ownership", () => { @@ -79,6 +80,16 @@ const support = await getEmbeddedPostgresTestSupport(); expect(attempts.filter(Boolean)).toHaveLength(1); expect(await renewLegacyControllerLease(db, run)).toBe(false); }); + it("revocation reports the committed dispatch boundary instead of the caller's stale snapshot", async () => { + const stale = await seed(); + expect(await renewLegacyControllerLease(db, stale, "dispatching")).toBe(true); + await expire(stale.id); + expect(stale.executionStage).toBe("preparing"); + expect(await revokeExpiredLegacyControllerWithState(db, stale)).toEqual({ + executionStage: "dispatching", processPid: null, processGroupId: null, + }); + expect(await revokeExpiredLegacyControllerWithState(db, stale)).toBeNull(); + }); it("a crash after revocation permits a later recovery claim", async () => { const run = await seed(); await expire(run.id); diff --git a/server/src/services/legacy-controller-lease.ts b/server/src/services/legacy-controller-lease.ts index f8ec824002c..e13e2ee2308 100644 --- a/server/src/services/legacy-controller-lease.ts +++ b/server/src/services/legacy-controller-lease.ts @@ -55,10 +55,20 @@ export async function hasLiveLegacyController(db: Db, run: Run): Promise; + /** Atomically revoke an expired controller. Renewal and revocation serialize on - * the run row. Expiry permits cleanup, never dispatch of a replacement agent. */ -export async function revokeExpiredLegacyController(db: Db, run: Run): Promise { - if (run.runtimeMode === "native" || !run.controllerBootId) return true; + * the run row. Expiry permits cleanup, never dispatch of a replacement agent. + * Returns the stage and process identifiers committed with the revocation, or + * null when another writer owns the row. They cannot advance afterwards, + * because renewal requires the replaced boot ID. */ +export async function revokeExpiredLegacyControllerWithState( + db: Db, + run: Run, +): Promise { + if (run.runtimeMode === "native" || !run.controllerBootId) { + return { executionStage: run.executionStage, processPid: run.processPid, processGroupId: run.processGroupId }; + } const [revoked] = await db.update(heartbeatRuns).set({ controllerBootId: randomUUID(), controllerLeaseExpiresAt: sql`clock_timestamp() + interval '60 seconds'`, @@ -67,8 +77,16 @@ export async function revokeExpiredLegacyController(db: Db, run: Run): Promise { + return (await revokeExpiredLegacyControllerWithState(db, run)) !== null; } /** Abort the adapter if the controller cannot renew. Bound each check by the diff --git a/server/src/services/run-failure-report.ts b/server/src/services/run-failure-report.ts index abf0152adf3..0fe6b277688 100644 --- a/server/src/services/run-failure-report.ts +++ b/server/src/services/run-failure-report.ts @@ -166,6 +166,23 @@ function isHermesConnectionFailure(run: HeartbeatRun, options: RunFailureReportO (connection.reason === "remote_unavailable" && code === "hermes_gateway_upstream_error"); } +/** + * The orphan reaper proved a server restart stopped legacy setup before + * dispatch and made the run eligible for its bounded retry. Only that reaper + * branch pairs process loss with bootstrap evidence. + */ +function isRestartInterruptedSetup(run: HeartbeatRun): boolean { + if ( + run.status !== "failed" || run.errorCode !== "process_lost" || run.runtimeMode !== "legacy" || + run.executionStage !== "preparing" || run.processPid != null || run.processGroupId != null + ) return false; + const recovery = asRecord(run.resultJson?.executionRecovery); + const processLoss = asRecord(run.resultJson?.processLossDiagnostic); + return recovery?.kind === "bootstrap" && recovery.providerWorkStarted === false && + processLoss?.retryEligible === true && processLoss.runPredatesObserver === true && + processLoss.localCheck === "no_identifiers"; +} + /** * The adapter proved the user's provider account is out of quota, and recovery * waits for its reset. Both fields come from the adapter's own classifier. @@ -218,7 +235,8 @@ export function reportRunFailure(db: Db, run: HeartbeatRun, options: RunFailureR isAiConnectionSelectionBlocker(run, options) || isLocalPathWorkspaceConfigurationBlocker(run, options) || isGitConnectionFailure(run, options) || - isProviderQuotaFailure(run, options) + isProviderQuotaFailure(run, options) || + isRestartInterruptedSetup(run) )) return Promise.resolve(); const runStatus = run.status; const report = captureTerminalRunFailure(db, run, runStatus, options, mode);