mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-13 07:12:00 +01:00
test(native): cover a turn.start timeout that loses the remote Runner, end to end (#21041)
## Thinking Path
> - Paperclip is the open source app people use to manage AI agents for
work
> - Native runs on a remote sandbox (Daytona) use a detached
`paperclip-runnerd`. After a recoverable failure, the same run
reattaches to that Runner
> - On staging, 31 tasks that a person retried are blocked. Their last
run failed with `runner_remote_process_identity_unavailable` /
`native_continuation_requires_reconciliation`
> - In each run, the `turn.start` PRP command timed out. The close then
killed the Runner. The same-run reattachment found the Runner gone
(`process_not_running`, `providerTurnIssued: false`), and the task
waited for a Retry
> - #21023 and #21039 fix this sequence. Neither one is deployed yet. No
test reproduces this exact sequence, so a later change could break it
without a signal
> - This pull request adds two tests. One reproduces the turn start
timeout with a real `paperclip-runnerd`. The other reproduces the
staging failure record of a person's Retry
> - The benefit is that a regression of this failure class fails CI
before it reaches staging
## Linked Issues or Issue Description
Refs #21023, #21039, #20923, #20853
**What happened?**
A person retried a blocked task that runs Codex on Daytona. The Retry
started a fresh provider session and submitted a turn. The `turn.start`
PRP command timed out (`provider_transport_failed: PRP command
turn.start timed out`). The run closed. The run log shows `runner did
not prove durable suspension before checkpoint`, `runner shutdown
failed: Error: Durable recovery runner timed out.`, and then
`runner_remote_process_exited lifecycle=ready`. The log does not show
`remote runner left alive unsettled for same-run reattachment`. The
same-run retry tried to reattach 50 s later. It recorded
`native.remote_runner_recovery_failed` with `stage:
process_verification`, `reason: process_not_running`, `runnerSettled:
false`, `providerTurnIssued: false`, and an empty Runner stderr. The run
failed with `runner_remote_process_identity_unavailable`, and the task
waited for a person.
**Expected behavior**
A turn start timeout does not kill the Runner, so the same-run
reattachment adopts it. If the Runner is gone anyway, the run continues
once by itself in a fresh provider session and does not replay the turn.
**Steps to reproduce**
1. Start a remote native Codex run on a release before #21023.
2. Make the provider not answer `turn/start`, so the `turn.start` PRP
command times out.
3. The runtime cancels the session as failure cleanup. The close treats
that as a Stop and kills `paperclip-runnerd`.
4. The same-run reattachment finds `process_not_running`. Before #21039,
the completion hook refuses an automatic Retry with
`provider_turn_unsettled`.
**Paperclip version or commit**
Staging runs 8cefbe9977. That build has neither #21023 nor #21039. This
pull request is based on master after both.
**Deployment mode**
Hosted staging cloud workspace. Native runtime with a remote Daytona
sandbox.
**Agent adapter(s) involved**
Codex (native `codex_app_server` driver through `paperclip-runnerd`).
## What Changed
-
`packages/paperclip-runner/src/live/runnerd-turn-start-timeout-retention.test.ts`
(new): runs `executeNativeSession` over a real `paperclip-runnerd` with
a launcher-owned (remote-shaped) process. The fake Codex never answers
`turn/start`, so the `turn.start` PRP command times out. The test checks
that the run fails with that exact error, that the Runner process is
still alive after the close, and that its journal is `ready` for the
same-run reattachment.
- `server/src/services/runner-lost-mid-turn-continuation.test.ts`: a new
case with the staging failure record. A person's Retry (`task_retry`, a
user intent with a non-hook key, `forceFreshSession`) has only
`turn.submitted`. Its refusal has `runnerSettled: false` and
`providerTurnIssued: false`. The completion hook requests one automatic
Retry. The test checks one unknown-outcome event with `replayed: false`,
an idempotent second call, saved-work recovery first, and one queued
fresh-session successor. The fixture gets small optional inputs for the
wake, the events, and the refusal payload. Other cases are unchanged.
- No production code changes.
## Verification
- `cd packages/paperclip-runner && npx vitest run
src/live/runnerd-turn-start-timeout-retention.test.ts
src/live/runnerd-codex-transport-remote-retention.test.ts`: 6 of 6 pass.
The new test passed 4 runs in a row.
- Red without #21023: with `native-session-runtime.ts`,
`harness-driver-backend.ts`, and `native-session-backend.ts` from before
#21023, the new runner test fails with `expected 'gone' to be 'alive'`.
That is the staging failure.
- `cd server && npx vitest run
src/services/runner-lost-mid-turn-continuation.test.ts`: 9 of 9 pass.
- Red without #21039: with `restart-interrupted-turn.ts` from before
#21039, the new server case fails with `{ requested: false, reason:
"provider_turn_unsettled" }`.
- `npx tsc --noEmit` passes for `server` and
`packages/paperclip-runner`.
- `pnpm verify` exits 2 because the new runner test file is outside the
resolved test graphs. CI supplies that coverage.
- Staging evidence: read-only GET of the failed run's events and log.
- Not run: a live Daytona run. #21023 and #21039 are not deployed yet.
## Risks
- Low. Tests only. No production code changes.
- The runner test starts a real `paperclip-runnerd` and the fake Codex.
It kills both processes and removes its temporary directory in
`finally`.
> For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and
discuss it in `#dev` before opening the PR. Feature PRs that overlap
with planned core work may need to be redirected — check the roadmap
first. See `CONTRIBUTING.md`.
## Model Used
- Claude Opus 5.5 (`claude-opus-5-5`), via Claude Code with tool use
(shell, file edits, test runs, read-only staging API reads).
## 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
148d2b629c
commit
b2cb8f8f56
2 files changed
+139
-8
No files matched your search
@@ -0,0 +1,102 @@
|
||||
import { execFileSync, spawn } from "node:child_process";
|
||||
import { mkdtemp, readFile, rm, writeFile } from "node:fs/promises";
|
||||
import { tmpdir } from "node:os";
|
||||
import { join } from "node:path";
|
||||
import { expect, it, vi } from "vitest";
|
||||
import { createRunnerdNativeSessionBackend } from "../backends/codex-native-backend.js";
|
||||
import type { NativeExecutionInputV1 } from "../contracts/native-execution.js";
|
||||
import type * as durableControlPlane from "../control-plane/durable-prp-control-plane.js";
|
||||
import type { PrpEvent } from "../protocol/replay-contract.js";
|
||||
import { executeNativeSession } from "../native-session-runtime.js";
|
||||
import { createCapabilityRunnerdCodexTransport } from "./runnerd-codex-transport.js";
|
||||
import { defaultCapabilityRunnerdBinary, fakeCodex, fakeCodexArgs } from "../../test/support/runnerd-transport.js";
|
||||
|
||||
function processState(pid: number): "alive" | "gone" {
|
||||
try { process.kill(pid, 0); } catch { return "gone"; }
|
||||
try {
|
||||
return execFileSync("ps", ["-o", "stat=", "-p", String(pid)], { encoding: "utf8" }).trim().startsWith("Z") ? "gone" : "alive";
|
||||
} catch { return "gone"; }
|
||||
}
|
||||
|
||||
const kill = (pid: number | null | undefined) => {
|
||||
if (!pid) return;
|
||||
try { process.kill(pid, "SIGKILL"); } catch (error) { if (!["ESRCH", "EPERM"].includes(String((error as NodeJS.ErrnoException).code))) throw error; }
|
||||
};
|
||||
|
||||
it("keeps the remote Runner alive for the same-run reattachment when the turn.start command times out", async () => {
|
||||
const root = await mkdtemp(join(tmpdir(), "runnerd-turn-start-timeout-"));
|
||||
const hangPath = join(root, "hang-turn-start");
|
||||
const identity = { runId: "run-start-timeout", sessionId: "session-start-timeout", companyId: "company-start-timeout",
|
||||
issueId: "issue-start-timeout", agentId: "agent-start-timeout" };
|
||||
const execution: NativeExecutionInputV1 = {
|
||||
schema: "paperclip.native-execution-input.v1",
|
||||
binding: { runId: identity.runId, companyId: identity.companyId, issueId: identity.issueId, agentId: identity.agentId,
|
||||
executionWorkspaceId: "workspace-start-timeout" },
|
||||
session: { normalizedSessionId: identity.sessionId, driverKind: "codex_app_server", protocolVersion: 1,
|
||||
lifecyclePolicy: { mode: "per_turn", idleTimeoutMs: null } },
|
||||
task: { identifier: "TEST-8", title: "Write the brief", description: null, prompt: "Write the brief.", workMode: "standard" },
|
||||
workspace: { cwd: root, repoUrl: null, repoRef: null, branchName: null },
|
||||
provider: { kind: "codex", model: null },
|
||||
completionContract: { id: "contract-start-timeout", sha256: "digest", schemaVersion: "paperclip.completion-contract.v1", contract: {
|
||||
revision: "1", objective: "Write the brief", criteria: [{ id: "brief", requirement: "Write the brief" }],
|
||||
} },
|
||||
interactionResponses: [], credentialBindings: [],
|
||||
};
|
||||
const children: ReturnType<typeof spawn>[] = [];
|
||||
const launch = vi.fn((spec: durableControlPlane.RunnerProcessLaunchSpec) => {
|
||||
const child = spawn(spec.command, [...spec.args], { cwd: spec.cwd, env: spec.environment, stdio: "ignore" });
|
||||
children.push(child);
|
||||
return {
|
||||
child,
|
||||
completion: new Promise<durableControlPlane.RunnerProcessResult>((resolveExit, rejectExit) => {
|
||||
child.once("error", rejectExit);
|
||||
child.once("exit", (code, exitSignal) => resolveExit({ code, signal: exitSignal, stdout: "", stderr: "" }));
|
||||
}),
|
||||
isExitConfirmed: () => child.exitCode !== null || child.signalCode !== null,
|
||||
};
|
||||
});
|
||||
const bundle = createCapabilityRunnerdCodexTransport({
|
||||
runnerBinary: defaultCapabilityRunnerdBinary(), codexCommand: fakeCodex,
|
||||
codexArgs: fakeCodexArgs(root, "--hang-turn-start", hangPath), stateDirectory: root,
|
||||
runnerReconnectGraceMs: 60_000, runnerProcessLauncher: launch, closeGraceMs: 600, turnStartTimeoutMs: 2_000,
|
||||
prpIdentity: { runnerInstanceId: "runner-start-timeout", environmentLeaseId: "lease-start-timeout", runId: identity.runId,
|
||||
normalizedSessionId: identity.sessionId, turnId: "turn-start-timeout", itemId: "item-start-timeout" },
|
||||
});
|
||||
const events: PrpEvent[] = [];
|
||||
try {
|
||||
await writeFile(hangPath, "before");
|
||||
const backend = createRunnerdNativeSessionBackend(execution, { runnerInstanceId: "runner-start-timeout",
|
||||
transportFactory: () => bundle.transport });
|
||||
const executing = executeNativeSession({
|
||||
input: execution, backend, runnerInstanceId: "runner-start-timeout", controlPlaneInstanceId: "controller-start-timeout",
|
||||
timeoutMs: 20_000, requireSessionCloseBeforeReturn: true,
|
||||
controlPlane: {
|
||||
async openRun() {},
|
||||
async checkpointSession() {},
|
||||
async appendEvent(event) {
|
||||
if (!("sourceSeq" in event)) throw new Error("Expected a durable PRP event");
|
||||
events.push(event);
|
||||
return { cursor: events.length, highestContiguousSourceSeq: event.sourceSeq, disposition: "committed" };
|
||||
},
|
||||
async replayEvents(request) {
|
||||
const source = events.filter(event => event.sourceInstanceId === request.sourceInstanceId);
|
||||
return { events: source.filter(event => event.sourceSeq > request.afterSourceSeq),
|
||||
highestContiguousSourceSeq: source.at(-1)?.sourceSeq ?? 0 };
|
||||
},
|
||||
async completeRun() {},
|
||||
},
|
||||
});
|
||||
await expect(executing).rejects.toThrow("provider_transport_failed: PRP command turn.start timed out");
|
||||
expect(launch).toHaveBeenCalledTimes(1);
|
||||
const runner = children[0]!;
|
||||
await new Promise(resolveWait => setTimeout(resolveWait, 1_000));
|
||||
expect(processState(runner.pid!)).toBe("alive");
|
||||
const journal = JSON.parse(await readFile(join(root, "runner", "runner-state.json"), "utf8")) as Record<string, unknown>;
|
||||
expect(journal.lifecycle).toBe("ready");
|
||||
} finally {
|
||||
await rm(hangPath, { force: true });
|
||||
for (const child of children) kill(child.pid);
|
||||
kill(bundle.evidence().codexPid);
|
||||
await rm(root, { recursive: true, force: true });
|
||||
}
|
||||
}, 60_000);
|
||||
@@ -31,12 +31,18 @@ const stagingRefusal = (reason: "process_not_running" | "process_identity_change
|
||||
describe("a remote Runner that died in the middle of a provider turn", () => {
|
||||
useWorkspaceRecoveryFixture(targets);
|
||||
|
||||
async function runnerLostMidTurn(input: { wake: "user" | "system_retry" | "system_monitor";
|
||||
refusal?: "process_not_running" | "process_identity_changed" | null }) {
|
||||
async function runnerLostMidTurn(input: { wake: "user" | "user_retry" | "system_retry" | "system_monitor";
|
||||
refusal?: "process_not_running" | "process_identity_changed" | null;
|
||||
events?: string[]; refusalPayload?: Record<string, unknown> }) {
|
||||
const f = await seed("native");
|
||||
const original = await run(f.runId);
|
||||
const system = input.wake !== "user";
|
||||
const reason = input.wake === "user" ? "issue_assigned" : input.wake === "system_retry" ? "transient_failure_retry" : "issue_monitor_due";
|
||||
const system = input.wake !== "user" && input.wake !== "user_retry";
|
||||
const reason = input.wake === "user" ? "issue_assigned" : input.wake === "user_retry" ? "task_retry"
|
||||
: input.wake === "system_retry" ? "transient_failure_retry" : "issue_monitor_due";
|
||||
const [retryIntent] = input.wake === "user_retry" ? await db.insert(agentWakeupRequests).values({ companyId: f.companyId,
|
||||
agentId: original.agentId, source: "on_demand", triggerDetail: "manual", reason: "task_retry", status: "completed",
|
||||
idempotencyKey: `task-retry:${randomUUID()}`, requestedByActorType: "user", requestedByActorId: "local-board",
|
||||
payload: { issueId: f.issueId } }).returning() : [];
|
||||
const [predecessor] = input.wake === "system_retry" ? await db.insert(heartbeatRuns).values({ companyId: f.companyId,
|
||||
agentId: original.agentId, issueId: f.issueId, status: "failed", createdAt: new Date(Date.now() - 60 * 60_000),
|
||||
finishedAt: new Date(Date.now() - 50 * 60_000),
|
||||
@@ -48,23 +54,24 @@ describe("a remote Runner that died in the middle of a provider turn", () => {
|
||||
await db.update(heartbeatRuns).set({ errorCode: "native_continuation_requires_reconciliation",
|
||||
error: "runner_remote_process_identity_unavailable", wakeupRequestId: wake.id, responsibleUserId: "local-board",
|
||||
retryOfRunId: predecessor?.id ?? null, startedAt: new Date(Date.now() - 45 * 60_000),
|
||||
contextSnapshot: { issueId: f.issueId, wakeReason: reason, ...(predecessor ? { retryOfRunId: predecessor.id,
|
||||
contextSnapshot: { issueId: f.issueId, wakeReason: reason, ...(retryIntent ? { taskRetryRequestId: retryIntent.id,
|
||||
forceFreshSession: true } : {}), ...(predecessor ? { retryOfRunId: predecessor.id,
|
||||
retryReason: "transient_failure", scheduledRetryAttempt: 1 } : {}) },
|
||||
}).where(eq(heartbeatRuns.id, f.runId));
|
||||
for (const eventType of ["turn.submitted", "turn.started", "tool.execution.started", "turn.accepted", "tool.execution.completed"])
|
||||
for (const eventType of input.events ?? ["turn.submitted", "turn.started", "tool.execution.started", "turn.accepted", "tool.execution.completed"])
|
||||
await appendHeartbeatRunEvent(db, { companyId: f.companyId, runId: f.runId, agentId: original.agentId,
|
||||
eventType, stream: "system", level: "info", message: eventType,
|
||||
payload: { prpEvent: { eventType, turnId: TURN_ID, payload: {} } } });
|
||||
if (input.refusal !== null) await appendHeartbeatRunEvent(db, { companyId: f.companyId, runId: f.runId,
|
||||
agentId: original.agentId, eventType: "native.remote_runner_recovery_failed", stream: "system", level: "error",
|
||||
message: "Could not verify the existing remote runner.", payload: stagingRefusal(input.refusal) });
|
||||
message: "Could not verify the existing remote runner.", payload: input.refusalPayload ?? stagingRefusal(input.refusal) });
|
||||
const claim = { kind: "reattach_remote_runner" as const, runId: f.runId, leaseOwner: `boot:2:${randomUUID()}`,
|
||||
controllerGeneration: 2, providerAttempt: 1, restartKind: "hard" as const, recoveryRequestId: null,
|
||||
remote: { providerLeaseId: f.providerLeaseId, remoteCwd: f.remote } };
|
||||
const service = heartbeatService(db, { environmentRuntime: f.environmentRuntime });
|
||||
// Keep the agent's only slot busy so a successor stays observable as queued.
|
||||
await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: original.agentId, status: "running" });
|
||||
return { ...f, agentId: original.agentId, claim, service };
|
||||
return { ...f, agentId: original.agentId, claim, service, retryIntent };
|
||||
}
|
||||
const queued = async (companyId: string) => db.select().from(heartbeatRuns)
|
||||
.where(and(eq(heartbeatRuns.companyId, companyId), eq(heartbeatRuns.status, "queued")));
|
||||
@@ -101,6 +108,28 @@ describe("a remote Runner that died in the middle of a provider turn", () => {
|
||||
idempotencyKey: `task-retry:restart-interrupted-turn:${f.runId}`, requestedByActorType: "user", requestedByActorId: "local-board" })]);
|
||||
}, 30_000);
|
||||
|
||||
it("continues a person's Retry whose turn start timed out and whose Runner was gone at the same-run reattachment", async () => {
|
||||
const f = await runnerLostMidTurn({ wake: "user_retry", events: ["turn.submitted"], refusalPayload: {
|
||||
remoteRunnerRecovery: { stage: "process_verification", reason: "process_not_running", runnerSettled: false,
|
||||
runnerLifecycle: "ready", runnerDiagnostics: ["WebSocket peer closed the connection"], providerTurnIssued: false,
|
||||
runnerExitEvidence: "== runnerd.process-stderr.log" } } });
|
||||
expect(await requestInterruptedNativeTurnRetry(db, f.runId)).toEqual({ requested: true, requestId: expect.any(String) });
|
||||
expect(await requestInterruptedNativeTurnRetry(db, f.runId)).toMatchObject({ requested: true });
|
||||
expect(await unknownOutcomeEvents(f.runId)).toEqual([expect.objectContaining({ payload: expect.objectContaining({
|
||||
lastTurnEvent: "turn.submitted", replayed: false }) })]);
|
||||
await vi.waitFor(async () => {
|
||||
await Promise.all(await reconcileRetainedWorkspaces(db, f.environmentRuntime, current => f.service.resumeRemoteStopComments(current)) ?? []);
|
||||
expect(readSystemRecovery((await action(f.actionId)).evidence)?.state).toBe("complete");
|
||||
}, { timeout: 10_000, interval: 10 });
|
||||
await vi.waitFor(async () => expect(await queued(f.companyId)).toHaveLength(1), { timeout: 10_000, interval: 50 });
|
||||
const [successor] = await queued(f.companyId);
|
||||
expect(successor.contextSnapshot).toMatchObject({ previousRunId: f.runId, wakeReason: "task_retry", forceFreshSession: true });
|
||||
const retries = await db.select().from(agentWakeupRequests).where(and(eq(agentWakeupRequests.companyId, f.companyId),
|
||||
eq(agentWakeupRequests.reason, "task_retry")));
|
||||
expect(retries.filter(retry => retry.id !== f.retryIntent!.id && retry.idempotencyKey?.startsWith("task-retry:"))).toEqual([
|
||||
expect.objectContaining({ idempotencyKey: `task-retry:restart-interrupted-turn:${f.runId}`, requestedByActorId: "local-board" })]);
|
||||
}, 30_000);
|
||||
|
||||
it.each([
|
||||
{ title: "inherits the hook's Retry intent", inherit: true },
|
||||
{ title: "reaches the hook's Retry run through its retry chain", inherit: false },
|
||||
|
||||
Reference in new issue
Block a user