mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-13 07:12:00 +01:00
fix(native): continue the interrupted turn after a relaunch that failed before its runner existed (#20944)
## 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 <runId>`, 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 <runId>` 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 <noreply@anthropic.com>
This commit is contained in:
1 parent
d9d5958d09
commit
e01ba16bfd
5 files changed
+73
-7
No files matched your search
@@ -346,6 +346,19 @@ export async function withReleasedNativeRunProcess<T extends {
|
||||
}
|
||||
|
||||
/** Recover the exact stopped identity after the mutable run fields were cleared. */
|
||||
export async function readUnidentifiedLocalRunnerStop(db: Db, companyId: string, runId: string): Promise<boolean> {
|
||||
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)
|
||||
|
||||
+31
-2
@@ -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<string, unknown>; stopRecorded: boolean; viaReconciler?: boolean }) {
|
||||
async function resumeOnce(options: { failureDetail: Record<string, unknown>; 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<number>`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<boolean | undefined> = [];
|
||||
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]);
|
||||
|
||||
@@ -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<string, unknown> | 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
|
||||
|
||||
@@ -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<string, unknown> | 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 } });
|
||||
}
|
||||
@@ -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`).
|
||||
|
||||
Reference in new issue
Block a user