From e01ba16bfd86da2f1f5d3b03f4b2b770929c4a5d Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Wed, 11 Nov 2026 16:36:17 -0600 Subject: [PATCH] fix(native): continue the interrupted turn after a relaunch that failed before its runner existed (#20944) 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 > - Native agent runs survive a server restart: recovery verifies the old runner stopped, then resumes the same provider session and its interrupted turn > - Recovery is a chain of steps. When one step fails once, the next attempt must still be allowed to finish the work > - Here the first recovery step was correct, its runner spawn failed once (EAGAIN), and the next attempt refused to continue the interrupted turn. The run died and needed a manual Retry > - This pull request lets the scheduled same-run resume prove that the failed launch left nothing behind, and then continue the turn > - The benefit is that a single failed spawn during recovery no longer turns a recoverable lost turn into a terminal failure ## Linked Issues or Issue Description **What happened?** Restart-chaos wave `w-20261111T190113-s5303` (local, codex, A1, fault K1 with `--fail-recovery-step runnerd-start:1`) on master `683fd1e9a5`. Run timeline: 1. K1 killed the server mid-turn. Recovery recorded `native.local_process_stopped` for the dead runner and chose `resume_dead_runner`. 2. That attempt wrote `native.process_start_requested`, then the spawn failed with `spawn paperclip-runnerd EAGAIN`. The executor persisted a scheduled same-run resume (`recoveryMode: exact_checkpoint_resume`, `providerSessionEstablished: true`, `checkpointExists: true`, `recoverable: true`). 3. The scheduled attempt resumed the session. The runner reported `provider_turn_lost_on_restore` (recoverable). The run ended `native_provider_terminal_failed` with "Automatic recovery stopped", and the task needed Retry. The same seed with K1 and no injected step passes. Root cause: in `executePaperclipNativeSession` (`native-session-executor.ts`), `resumeInterruptedTurn` is `restartRecovery.kind === "resume_dead_runner" || scheduledResumeContinuation`. The second attempt is not a restart claim, so it depends on `scheduledResumeContinuationAllowed` (`scheduled-resume-continuation.ts`). That decision refused with `local_stop_unverified`: `readNativeLocalProcessStop` reads the newest launch event, and the newest one was the failed `process_start_requested` with no process identity and no stop receipt. The checkpoint evidence was correct; the stop evidence was the gap. The refusal was not logged. **Expected behavior** When a launch fails before its runner exists, a scheduled same-run resume proves on this host that no runner for the run exists and that the launch wrote no runner state, records that stop, and continues the interrupted turn. A live runner for the run still blocks it. **Steps to reproduce** `node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env local --adapters codex --workloads A1 --faults K1 --fail-recovery-step runnerd-start:1 --fault-after-seconds 10 --concurrency 1 --tasks 1 --seed 5303` ## What Changed - `scheduled-resume-continuation.ts`: when the decision refuses only for `local_stop_unverified` on a local target, `scheduledResumeContinuationAllowed` calls the existing `recordUnidentifiedLocalRunnerStop` (the same proof explicit continuations use). It requires that the newest event is this host's launch request, that no process carries `--run-id `, and that no runner state for the run changed after the launch request. On success it records `native.local_process_stopped` (`basis: unidentified_runner_absent`) in the claim transaction and decides again. All other checks (exact checkpoint, recoverable, session established, checkpoint exists, no replacement, admitted attempt) still apply first. - `native-session-executor.ts`: logs the refusal reason when a scheduled `exact_checkpoint_resume` will not continue the interrupted turn. - `native-scheduled-resume-continuation.integration.test.ts`: two cases. A failed relaunch after a verified stop now continues the turn (`resumeInterruptedTurn: true`, attempt 2). A failed relaunch while a process with `--run-id ` is alive still refuses. The fixture now advances `nextEventSeq` after inserting events directly. - `tests/restart-chaos/README.md`: records what the existing `runnerd-start:1` cell found and what now passes. ## Verification - RED on master: "continues the lost turn after a relaunch that failed before its runner existed" fails with `expected [ false ] to deeply equal [ true ]` (the runtime gets `resumeInterruptedTurn: false`, which is the path that produced `provider_turn_lost_on_restore` → `native_provider_terminal_failed`). - GREEN: `scheduled-resume-continuation`, `native-scheduled-resume-continuation.integration`, `native-exact-resume-failure`, `native-restart-recovery`, `native-runner-restart-recovery.integration`, `native-session-executor`, `native-session-resumption`, `heartbeat-native-restart-suspension` pass (1797 tests). `pnpm --filter @paperclipai/server typecheck` passes. - Chaos rerun of seed 5303 with `runnerd-start:1`: result is added in a comment on this PR. ## Risks - The proof is host-local: it only applies on the host that wrote the launch request, the same as explicit continuations. Remote targets and restart claims are unchanged. - Old saved state: a run already stuck in a scheduled resume after a failed spawn now continues on its next attempt instead of failing. That is the intended recovery; the checkpoint and attempt limits still bound it. - Sibling recovery steps (`teardown`, `directory-lock`) are Daytona-only. The saved waves that armed them (`s5311`, `s5312`) never reached the step, so this PR does not change or prove them. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, via Claude Code with tool use (shell, file edits, test runs). ## 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 --- .../src/services/native-local-process-stop.ts | 13 ++++++++ ...ed-resume-continuation.integration.test.ts | 33 +++++++++++++++++-- .../native-runtime/native-session-executor.ts | 9 +++-- .../scheduled-resume-continuation.ts | 17 ++++++++-- tests/restart-chaos/README.md | 8 +++++ 5 files changed, 73 insertions(+), 7 deletions(-) diff --git a/server/src/services/native-local-process-stop.ts b/server/src/services/native-local-process-stop.ts index d5df0a12fea..479d524c611 100644 --- a/server/src/services/native-local-process-stop.ts +++ b/server/src/services/native-local-process-stop.ts @@ -346,6 +346,19 @@ export async function withReleasedNativeRunProcess { + const [latest, launch] = await db.select({ eventType: heartbeatRunEvents.eventType, payload: heartbeatRunEvents.payload }) + .from(heartbeatRunEvents) + .where(and(eq(heartbeatRunEvents.companyId, companyId), eq(heartbeatRunEvents.runId, runId), + isNull(heartbeatRunEvents.sourceEventId), + inArray(heartbeatRunEvents.eventType, [PROCESS_START_REQUESTED, PROCESS_IDENTITY_RECORDED, LOCAL_PROCESS_STOPPED]))) + .orderBy(desc(heartbeatRunEvents.seq)).limit(2); + if (latest?.eventType !== LOCAL_PROCESS_STOPPED || latest.payload?.basis !== "unidentified_runner_absent" || + launch?.eventType !== PROCESS_START_REQUESTED || launch.payload?.hostname !== os.hostname()) return false; + const { noLocalRunnerProcessForRun } = await import("./native-runtime/native-session-executor.js"); + return noLocalRunnerProcessForRun(runId); +} + export async function readNativeLocalProcessStop(db: Db, companyId: string, runId: string) { const [event] = await db.select({ eventType: heartbeatRunEvents.eventType, payload: heartbeatRunEvents.payload }) .from(heartbeatRunEvents) diff --git a/server/src/services/native-runtime/native-scheduled-resume-continuation.integration.test.ts b/server/src/services/native-runtime/native-scheduled-resume-continuation.integration.test.ts index 22c96d48e3f..dd94207b60d 100644 --- a/server/src/services/native-runtime/native-scheduled-resume-continuation.integration.test.ts +++ b/server/src/services/native-runtime/native-scheduled-resume-continuation.integration.test.ts @@ -1,4 +1,7 @@ import { randomUUID } from "node:crypto"; +import { spawn } from "node:child_process"; +import { once } from "node:events"; +import { hostname } from "node:os"; import { eq, sql } from "drizzle-orm"; import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; import { agents, companies, completionContracts, createDb, heartbeatRunEvents, heartbeatRuns, issues, nativeRunFinalizations } from "@paperclipai/db"; @@ -36,7 +39,8 @@ describe("a scheduled same-run resume reaching the provider runtime", () => { const exactResume = { recoveryMode: "exact_checkpoint_resume", recoverable: true, providerSessionEstablished: true, checkpointExists: true, originalFailureCode: "native_session_recovery_failed" }; - async function resumeOnce(options: { failureDetail: Record; stopRecorded: boolean; viaReconciler?: boolean }) { + async function resumeOnce(options: { failureDetail: Record; stopRecorded: boolean; viaReconciler?: boolean; + failedRelaunch?: boolean; unidentifiedStopRecorded?: boolean; liveRunnerForRun?: boolean }) { const issueId = randomUUID(); const runId = randomUUID(); const [issue] = await db.insert(issues).values({ id: issueId, companyId, title: "Resume the lost turn", @@ -72,6 +76,10 @@ describe("a scheduled same-run resume reaching the provider runtime", () => { { eventType: "native.process_start_requested", payload: { providerAttempt: 1 } }, { eventType: "native.process_identity_recorded", payload: identity }, ...(options.stopRecorded ? [{ eventType: "native.local_process_stopped", payload: identity }] : []), + ...(options.failedRelaunch ? [{ eventType: "native.process_start_requested", + payload: { hostname: hostname(), providerAttempt: 1, requestedAt: new Date().toISOString() } }] : []), + ...(options.unidentifiedStopRecorded ? [{ eventType: "native.local_process_stopped", + payload: { processPid: null, processGroupId: null, processStartedAt: null, basis: "unidentified_runner_absent" } }] : []), ]; const [last] = await db.select({ seq: sql`coalesce(max(${heartbeatRunEvents.seq}), 0)::int` }) .from(heartbeatRunEvents).where(eq(heartbeatRunEvents.runId, runId)); @@ -81,11 +89,15 @@ describe("a scheduled same-run resume reaching the provider runtime", () => { await db.insert(heartbeatRunEvents).values({ companyId, runId, agentId, seq, eventType: event.eventType, stream: "system", level: "info", payload: event.payload }); } + await db.update(heartbeatRuns).set({ nextEventSeq: seq + 1 }).where(eq(heartbeatRuns.id, runId)); const passed: Array = []; provider.execute.mockReset().mockImplementation(async (input: { resumeInterruptedTurn?: boolean }) => { passed.push(input.resumeInterruptedTurn); throw new Error("scheduled_resume_fixture_stop"); }); + const liveRunner = options.liveRunnerForRun + ? spawn(process.execPath, ["-e", "setTimeout(() => {}, 60_000)", "--", "--run-id", runId], { stdio: "ignore" }) : null; + if (liveRunner) await once(liveRunner, "spawn"); let leaseOwner: string | undefined; if (options.viaReconciler) { const claims = await claimNativeSessionResumptions({ db, runnerInstanceId: native.runnerInstanceId, runIds: [runId] }); @@ -95,7 +107,7 @@ describe("a scheduled same-run resume reaching the provider runtime", () => { await executePaperclipNativeSession({ db, execution, runnerInstanceId: native.runnerInstanceId, leaseOwner, backend: { descriptor: async () => { throw new Error("Unexpected provider call"); }, openSession: async () => { throw new Error("Unexpected provider call"); }, - } }).catch(() => undefined); + } }).catch(() => undefined).finally(() => { liveRunner?.kill("SIGKILL"); }); const [coordinator] = await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, runId)); return { passed, coordinator: coordinator! }; } @@ -106,6 +118,23 @@ describe("a scheduled same-run resume reaching the provider runtime", () => { expect(coordinator.attempt).toBe(2); }); + it("continues the lost turn after a relaunch that failed before its runner existed", async () => { + const { passed, coordinator } = await resumeOnce({ failureDetail: exactResume, stopRecorded: true, failedRelaunch: true }); + expect(passed).toEqual([true]); + expect(coordinator.attempt).toBe(2); + }); + + it.each([false, true])("reuses the saved failed-relaunch stop on a later scheduled attempt (runner alive: %s)", async (liveRunnerForRun) => { + const { passed } = await resumeOnce({ failureDetail: exactResume, stopRecorded: true, failedRelaunch: true, + unidentifiedStopRecorded: true, liveRunnerForRun }); + expect(passed).toEqual([!liveRunnerForRun]); + }); + + it("keeps the lost turn failing after a failed relaunch while a runner for the run is still alive", async () => { + const { passed } = await resumeOnce({ failureDetail: exactResume, stopRecorded: true, failedRelaunch: true, liveRunnerForRun: true }); + expect(passed).toEqual([false]); + }); + it("keeps the lost turn failing when the reconciler claimed a resume without a stop receipt", async () => { const { passed } = await resumeOnce({ failureDetail: exactResume, stopRecorded: false, viaReconciler: true }); expect(passed).toEqual([false]); diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index 0d23246118f..418dca7eb98 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -10827,7 +10827,7 @@ async function executePaperclipNativeSessionAttempt( ); if (nextAttempt > 3) throw new Error("native_session_retry_exhausted"); - scheduledResumeContinuation = (await scheduledResumeContinuationAllowed(tx as unknown as Db, { + const scheduledResumeDecision = await scheduledResumeContinuationAllowed(tx as unknown as Db, { companyId: input.execution.binding.companyId, runId: input.execution.binding.runId, restartRecovery: Boolean(recovering), @@ -10838,7 +10838,12 @@ async function executePaperclipNativeSessionAttempt( ? (coordinator.recoveryHistory.at(-1) as Record | undefined) ?? null : null, controllerBootId: controller.bootId, admittedAttempt: nextAttempt, - })).allowed; + }); + scheduledResumeContinuation = scheduledResumeDecision.allowed; + if (!scheduledResumeDecision.allowed && coordinator.phase === "retryable_failure" + && record(coordinator.failureDetail).recoveryMode === "exact_checkpoint_resume") + logger.warn({ runId: input.execution.binding.runId, attempt: nextAttempt, reason: scheduledResumeDecision.reason }, + "scheduled same-run resume will not continue the interrupted provider turn"); const nextControllerGeneration = recovering ? recovering.controllerGeneration : coordinator.controllerBootId === controller.bootId diff --git a/server/src/services/native-runtime/scheduled-resume-continuation.ts b/server/src/services/native-runtime/scheduled-resume-continuation.ts index 215e540754a..94d40f37293 100644 --- a/server/src/services/native-runtime/scheduled-resume-continuation.ts +++ b/server/src/services/native-runtime/scheduled-resume-continuation.ts @@ -1,5 +1,7 @@ import type { Db } from "@paperclipai/db"; -import { readNativeLocalProcessStop } from "../native-local-process-stop.js"; +import { and, eq } from "drizzle-orm"; +import { heartbeatRuns } from "@paperclipai/db"; +import { readNativeLocalProcessStop, readUnidentifiedLocalRunnerStop, recordUnidentifiedLocalRunnerStop } from "../native-local-process-stop.js"; import { NATIVE_PROVIDER_RECOVERY_ATTEMPT_LIMIT } from "./native-restart-recovery.js"; export const SAME_RUN_RESUME_DISPOSITION = "same_run_resume"; @@ -44,7 +46,7 @@ export interface ScheduledResumeContinuationEvidence { resumeClaim?: Record | null; controllerBootId?: string; admittedAttempt: number; - localStop: { processPid: number } | null; + localStop: { processPid: number | null } | null; } export type ScheduledResumeContinuationDecision = @@ -79,5 +81,14 @@ export async function scheduledResumeContinuationAllowed( const { companyId, runId, ...evidence } = input; const localStop = evidence.restartRecovery || evidence.targetKind !== "local" ? null : await readNativeLocalProcessStop(db, companyId, runId); - return decideScheduledResumeContinuation({ ...evidence, localStop }); + const decision = decideScheduledResumeContinuation({ ...evidence, localStop }); + if (decision.allowed || decision.reason !== "local_stop_unverified") return decision; + if (await readUnidentifiedLocalRunnerStop(db, companyId, runId)) + return decideScheduledResumeContinuation({ ...evidence, localStop: { processPid: null } }); + const [run] = await db.select({ id: heartbeatRuns.id, companyId: heartbeatRuns.companyId, agentId: heartbeatRuns.agentId, + runtimeMode: heartbeatRuns.runtimeMode, processPid: heartbeatRuns.processPid, processGroupId: heartbeatRuns.processGroupId, + runnerProfileJson: heartbeatRuns.runnerProfileJson }) + .from(heartbeatRuns).where(and(eq(heartbeatRuns.id, runId), eq(heartbeatRuns.companyId, companyId))).limit(1); + if (!run || !await recordUnidentifiedLocalRunnerStop(db, run)) return decision; + return decideScheduledResumeContinuation({ ...evidence, localStop: { processPid: null } }); } diff --git a/tests/restart-chaos/README.md b/tests/restart-chaos/README.md index 8402bf5ccb6..2c4505b1687 100644 --- a/tests/restart-chaos/README.md +++ b/tests/restart-chaos/README.md @@ -1139,6 +1139,14 @@ only once is never reached with `nth` 2 or more, and the task fails `recovery_st 2026-11-11 an A1 task with K2 on Daytona never reached `directory-lock`: pick a workload whose recovery collects remote agent files. +`runnerd-start:1` with K1 (seed 5303) found the recovery-chain gap on 2026-11-11: the first recovery +attempt (`resume_dead_runner`) failed its spawn, which persisted a scheduled same-run resume. The second +attempt then refused to continue the interrupted turn (`local_stop_unverified`: the newest launch request +had no process identity and no stop receipt), so the restored session reported +`provider_turn_lost_on_restore` and the run ended `native_provider_terminal_failed`. A scheduled resume now +proves on this host that the failed launch left no runner and no runner state, records that stop, and +continues the turn. The cell passes only when the task finishes with no failed attempt. + Every task the armed fault crossed gets two more checks: `recovery_step_failed_once` (the receipt in `recovery-step-receipts.jsonl`; a step never reached tested nothing) and `no_failed_attempt`. The fault's receipt in `faults.json` names the armed step (`recoveryStep`).