From fea4530a3090e8307cf02089fbddc5b79a291f0b Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Tue, 10 Nov 2026 06:48:43 -0600 Subject: [PATCH] fix(recovery): retry a preparation killed by a restart in the uncharged lane (#20534) 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 > - When the control plane restarts, an interrupted run must continue on its own. A user must not have to press Retry because a deploy or a crash happened > - A preparation that a restart stops before the provider starts spent no provider work. It is retried in the uncharged `interrupted_preparation` lane (12 retries), not the charged `transient_failure` lane (2 retries) > - #20496 made that work for a graceful drain (SIGTERM). A hard kill (SIGKILL) during workspace preparation still landed in the charged lane > - Two killed preparations in one chain then spent the failure budget, and the next interruption could not continue: the task needed a manual Retry > - This pull request lets restart recovery hand a killed preparation to the uncharged lane once the killed controller is proven gone > - The benefit is that a task survives any number of restarts during workspace preparation (up to the crash-loop cap) without a Retry click ## Linked Issues or Issue Description **Subsystem affected** Heartbeat restart recovery: the process-loss reaper in `server/src/services/heartbeat/recovery.ts`. **Problem or motivation** The restart-chaos harness on Daytona with `--storage s3 --storage-trigger snapshot-download` (seed 603, task t02, a codex C1 follow-up) kills the server while a workspace snapshot downloads. On builds that contain #20496, two replays still ended in `R3:retry_needed`. The run chain in replay `w-20261110T061107-s603-replay-t02-1794309789008`: 1. K1 SIGKILL during preparation: `process_lost`, then "Scheduled bounded retry 1/2 … transient_failure". 2. K2 drain during preparation: `interrupted_preparation` 1 (the #20496 path, correct). 3. K4 SIGKILL during preparation: `process_lost`, then "Scheduled bounded retry 2/2 … transient_failure". 4. K2 drain during preparation: the failure budget was spent (`failureRetries` 2), so the hold could not continue. The harness had to click Retry. **Root cause** The reaper does record the no-provider-work certificate (`executionRecovery: { kind: "bootstrap", providerWorkStarted: false }`) for a preparing run from another boot. But before it fails the run, `revokeExpiredLegacyControllerWithState` swaps in a random boot id with a 60 s lease, a tombstone that no controller holds. `scheduleBoundedRetryForRun` then asks `isInterruptedNativePreparation`, whose `preparerMayStillUnwind` check sees that live lease and says the old preparer may still be unwinding. The lane falls back to `transient_failure` and charges the failure budget. Every killed preparation is charged, whether or not its controller is provably gone. **Proposed solution** When the reaper has already proven the old controller's recorded process gone (`legacyControllerGone`, the shared owner prover that #20496 also uses) and the revoked state shows the run was still preparing with no process recorded (`restartInterruptedBeforeDispatch`), expire that tombstone lease in the same `process_lost` write. The lane decision then sees an expired lease and applies its existing checks (no coordinator, result or execution events; leases released with stop receipts; workspace repair when needed). Any evidence of provider work, or a controller that cannot be proven gone, keeps today's charged behaviour. **Alternatives considered** - Revoking with an already expired lease: the 60 s revocation lease fences other servers while this pass fails the run, so the expiry belongs in the terminal write. - Teaching `preparerMayStillUnwind` to ignore unstamped leases: that would also skip the wait for a lease of a live controller saved by an older release. ## What Changed - `server/src/services/heartbeat/recovery.ts`: the `process_lost` write sets `controllerLeaseExpiresAt` to now when `restartInterruptedBeforeDispatch && legacyControllerGone`. - `server/src/__tests__/heartbeat-process-recovery.test.ts`: - New: a chain whose preparation is killed twice (controllers proven gone) and then drained. Each kill schedules `interrupted_preparation` (attempts 1 and 2, `failureRetries` 0), and after the drain the restart settlement schedules `interrupted_preparation` 3 without a Retry. - New old-saved/new-resumed case: a preparing run saved by an older release without a controller process stamp keeps the charged `transient_failure` lane. - `doc/execution-semantics.md`: one additive sentence saying the lane also covers a hard kill once the killed controller is proven gone. ## Verification - Red/green: `npx vitest run src/__tests__/heartbeat-process-recovery.test.ts -t "killed twice"` fails on master (the first kill schedules `transient_failure`) and passes with the fix. - Related suites pass: `heartbeat-process-recovery`, `interrupted-preparation-hold-settle`, `execution-recovery-dead-controller`, `legacy-controller-lease` and `ownership-reconciliation-report` (5 files, 521 tests). - Live (Daytona, `--storage s3 --storage-trigger snapshot-download`, replay of `w-20261110T061107-s603/t02` with K1/K2/K4/K2, image `paperclip-daytona-runner@sha256:05a4a092…` whose runner content matches this branch): running; the result will be posted as a comment. ## Risks - Low. The change applies only when the shared owner prover returns `gone` for the exact recorded controller and the run was still preparing with no process recorded. The lease's boot id stays the random revocation id, so the old controller can still never renew it. Old rows without a controller stamp keep today's behaviour. - Previous-release story (upgrade-safe-run-state): no persisted shape changes. A run saved mid-preparation by an older release has no `controllerProcess` stamp, cannot be proven gone, and keeps the charged lane (covered by the new old-saved test). Retries an older release already scheduled in the charged lane keep their counters. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, with tool use and code execution in Claude Code. ## 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: Claude Opus 5.5 --- doc/execution-semantics.md | 2 +- .../heartbeat-process-recovery.test.ts | 63 ++++++++++++++++++- server/src/services/heartbeat/recovery.ts | 1 + 3 files changed, 64 insertions(+), 2 deletions(-) diff --git a/doc/execution-semantics.md b/doc/execution-semantics.md index fb76d65e902..9921801f589 100644 --- a/doc/execution-semantics.md +++ b/doc/execution-semantics.md @@ -2788,7 +2788,7 @@ replacement behavior. When a replacement does archive remote continuity state and the remote move fails, the local state is not moved, and the run error keeps the bounded, redacted exit status and output of that move. -Bootstrap retries, exact-checkpoint resumes, and fresh replacement sessions share three total provider attempts, including the original attempt. Linked run IDs, controller restarts, and duplicate wakes do not reset this budget. A resume after a graceful shutdown drain suspended the run for reattachment does not consume an attempt, because the run did not cause that restart. A crash restart (no drain record) consumes an attempt only when the attempt it interrupted spent provider work without progress. This is one rule over recorded outcomes, not over intents. The attempt counts as started only when the provider accepted a turn: a `turn.accepted` event or the provider's own `turn.started`. A startup still marked `beforeSpawn`, a runner that spawned but was never admitted, and a `turn.start` the provider did not accept are not charged. Progress means that an accepted turn then completed work: a tool execution or a completed item other than a usage report. An accepted turn with only usage, a failure, or no events is charged, so a resume that fails each time still uses up the budget. The first restart judges the original execution. Each later restart claim records the run's event-log position, and the next claim judges only the attempt recorded after it; a normal retry in between starts a new attempt (at its `native.process_start_requested`), so earlier work does not count for it. A reattachment adopts a provider that already started, so for it only progress counts. A resume that launches a new runner and that the controller died before starting used no provider work, so the next claim replaces it and the attempt ends at the attempt that resume was to run as. Uncharged restarts stop after 12 controller generations, so a crash loop that never starts the provider, or that makes progress and then crashes the controller each time, is still bounded. Legacy runs follow the same rule: a preparation interrupted before provider work started (`providerWorkStarted: false`) is retried in its own `interrupted_preparation` lane, which never spends the failure retry budget and is bounded at 12 retries. Exact-checkpoint resumes retain the 30-second delay. Replacement scheduling and predecessor lineage commit together, with one successor per predecessor and admission through the normal task locks, authorization, pause, approval, and budget gates. +Bootstrap retries, exact-checkpoint resumes, and fresh replacement sessions share three total provider attempts, including the original attempt. Linked run IDs, controller restarts, and duplicate wakes do not reset this budget. A resume after a graceful shutdown drain suspended the run for reattachment does not consume an attempt, because the run did not cause that restart. A crash restart (no drain record) consumes an attempt only when the attempt it interrupted spent provider work without progress. This is one rule over recorded outcomes, not over intents. The attempt counts as started only when the provider accepted a turn: a `turn.accepted` event or the provider's own `turn.started`. A startup still marked `beforeSpawn`, a runner that spawned but was never admitted, and a `turn.start` the provider did not accept are not charged. Progress means that an accepted turn then completed work: a tool execution or a completed item other than a usage report. An accepted turn with only usage, a failure, or no events is charged, so a resume that fails each time still uses up the budget. The first restart judges the original execution. Each later restart claim records the run's event-log position, and the next claim judges only the attempt recorded after it; a normal retry in between starts a new attempt (at its `native.process_start_requested`), so earlier work does not count for it. A reattachment adopts a provider that already started, so for it only progress counts. A resume that launches a new runner and that the controller died before starting used no provider work, so the next claim replaces it and the attempt ends at the attempt that resume was to run as. Uncharged restarts stop after 12 controller generations, so a crash loop that never starts the provider, or that makes progress and then crashes the controller each time, is still bounded. Legacy runs follow the same rule: a preparation interrupted before provider work started (`providerWorkStarted: false`) is retried in its own `interrupted_preparation` lane, which never spends the failure retry budget and is bounded at 12 retries. This holds for a hard kill as well as a graceful drain: once the killed controller's recorded process is proven gone, restart recovery fails the run as `process_lost` with the bootstrap certificate and schedules it in that lane. A run saved by an older release without a controller process stamp cannot be proven and stays in the charged lane. Exact-checkpoint resumes retain the 30-second delay. Replacement scheduling and predecessor lineage commit together, with one successor per predecessor and admission through the normal task locks, authorization, pause, approval, and budget gates. A due failed remote retry can retain its provider PID after heartbeat completion releases the task execution lock. Both remote workspace reference formats and diff --git a/server/src/__tests__/heartbeat-process-recovery.test.ts b/server/src/__tests__/heartbeat-process-recovery.test.ts index 0f4464cfb5a..74a0803bf67 100644 --- a/server/src/__tests__/heartbeat-process-recovery.test.ts +++ b/server/src/__tests__/heartbeat-process-recovery.test.ts @@ -31,7 +31,10 @@ import { JsonRpcCallError } from "@paperclipai/plugin-sdk"; import { taskInterruptionPresentation } from "../services/task-interruption-presentation.js"; import { requestTaskRetry } from "../services/task-retry.js"; import { adapterExecutionControls, createAdapterExecutionControl } from "../services/adapter-execution-control.js"; -import { execFileSync, spawn, type ChildProcess } from "node:child_process"; +import { execFileSync, spawn, spawnSync, type ChildProcess } from "node:child_process"; +import { currentControllerProcessStamp } from "../services/controller-process-identity.js"; +import { settleUnrecoverableExecutions } from "../services/execution-recovery-resolution.js"; +import { createOwnershipReportState, runOwnershipReconciliationPass } from "../services/recovery/ownership-invariant-report.js"; import fs from "node:fs/promises"; import os from "node:os"; import path from "node:path"; @@ -3554,6 +3557,64 @@ describeEmbeddedPostgres("heartbeat orphaned process recovery", () => { expect(mockAdapterExecute).not.toHaveBeenCalled(); }); + it("keeps a lost preparation from an older build without a controller stamp in the charged lane", async () => { + const { companyId, runId } = await seedRestartOrphanedLegacySetup("preparing"); + await db.update(heartbeatRuns).set({ runnerProfileJson: { adapterDispatch: { adapterType: "paperclip_runner" } } }) + .where(eq(heartbeatRuns.id, runId)); + + await heartbeatService(db).reapOrphanedRuns(); + + expect(await db.select().from(heartbeatRuns).where(and(eq(heartbeatRuns.companyId, companyId), + eq(heartbeatRuns.retryOfRunId, runId)))).toEqual([expect.objectContaining({ + status: "scheduled_retry", scheduledRetryReason: "transient_failure", scheduledRetryAttempt: 1 })]); + }); + + it("continues a chain whose preparations were killed twice and then interrupted again, without a Retry", async () => { + const { companyId, agentId, runId: firstRunId } = await seedRunFixture({ adapterType: "paperclip_runner", + agentStatus: "idle", runtimeMode: "legacy" }); + const preparing = async (runId: string, owner: "killed" | "current") => { + const live = currentControllerProcessStamp(); + const bootId = owner === "current" ? controllerLeases.legacyControllerBootId : randomUUID(); + const pid = Number(spawnSync(process.execPath, ["-e", "process.stdout.write(String(process.pid))"], + { encoding: "utf8" }).stdout); + await db.update(heartbeatRuns).set({ status: "running", startedAt: new Date(), executionStage: "preparing", + runnerProfileJson: { adapterDispatch: { adapterType: "paperclip_runner" } }, controllerBootId: bootId, + controllerProcess: owner === "current" ? live + : { bootId, pid, hostHash: live.hostHash, processStartedAt: new Date(Date.now() - 120_000).toISOString() }, + controllerLeaseExpiresAt: sql`clock_timestamp() + interval '45 seconds'` }).where(eq(heartbeatRuns.id, runId)); + await db.delete(heartbeatRunEvents).where(eq(heartbeatRunEvents.runId, runId)); + }; + const successorOf = async (runId: string) => (await db.select().from(heartbeatRuns).where(and( + eq(heartbeatRuns.companyId, companyId), eq(heartbeatRuns.retryOfRunId, runId))))[0]; + const heartbeat = heartbeatService(db); + + await preparing(firstRunId, "killed"); + await heartbeat.reapOrphanedRuns(); + const second = await successorOf(firstRunId); + expect(second).toMatchObject({ status: "scheduled_retry", scheduledRetryReason: "interrupted_preparation", + scheduledRetryAttempt: 1 }); + + await preparing(second!.id, "killed"); + await heartbeat.reapOrphanedRuns(); + const third = await successorOf(second!.id); + expect(third).toMatchObject({ status: "scheduled_retry", scheduledRetryReason: "interrupted_preparation", + scheduledRetryAttempt: 2 }); + expect(third!.contextSnapshot?.executionRetryAccounting).toMatchObject({ failureRetries: 0, interruptedPreparations: 2 }); + + await preparing(third!.id, "current"); + const drained = await heartbeat.drainRunningRunsForShutdown("SIGTERM"); + expect(drained.interruptedRunIds).toEqual([third!.id]); + const exited = randomUUID(); + await db.update(heartbeatRuns).set({ controllerBootId: exited, controllerProcess: { bootId: exited, + pid: Number(spawnSync(process.execPath, ["-e", "process.stdout.write(String(process.pid))"], { encoding: "utf8" }).stdout), + hostHash: currentControllerProcessStamp().hostHash, processStartedAt: new Date(Date.now() - 120_000).toISOString() } }) + .where(eq(heartbeatRuns.id, third!.id)); + await settleUnrecoverableExecutions(db); + await runOwnershipReconciliationPass(db, { state: createOwnershipReportState(), record: true }); + expect(await successorOf(third!.id)).toMatchObject({ agentId, status: "scheduled_retry", + scheduledRetryReason: "interrupted_preparation", scheduledRetryAttempt: 3 }); + }); + it("retries within the failure budget even when a legacy process-loss counter is set", async () => { const { companyId, runId } = await seedRestartOrphanedLegacySetup("preparing"); // Earlier releases wrote this counter; nothing writes it now. diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index 4eaef8c8842..a4dedbf0471 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -2699,6 +2699,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD error: shouldRetry ? `${baseMessage}; retrying once` : baseMessage, errorCode: "process_lost", finishedAt: now, + ...(restartInterruptedBeforeDispatch && legacyControllerGone ? { controllerLeaseExpiresAt: now } : {}), resultJson: (() => { const result = mergeRunStopMetadataForAgent( { adapterType, adapterConfig },