From 2141efc0970b778c9950eecad9f9b296945b960f Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Wed, 4 Nov 2026 23:30:45 -0600 Subject: [PATCH] fix(native): answer Stop during slow native startup with 409 and settle it as cancelled (#19189) 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 > - Operators stop a running agent run with `POST /api/heartbeat-runs/:runId/cancel` > - For a native run, Stop waits up to 30 seconds for the native session to open before it can deliver the cancel > - A remote native session can take longer than 30 seconds to open. Then the wait fails with `native_cancellation_pending_recovery`, and the route answers HTTP 500 > - The Stop intent was already saved. The startup owner fenced the late session in memory only, so the run ended as a provider failure, not as a cancellation > - This pull request maps that outcome to a clear 409 and makes the late session acknowledge the saved Stop intent > - The benefit is a consistent cancel result and a run that ends as `cancelled` when an operator stops it during a slow startup ## Linked Issues or Issue Description **What happened?** An operator stopped a native run about 40 seconds after it started. The run was still opening its remote provider session (session startup took about 105 seconds). The cancel request waited 30 seconds for the startup handle, then returned HTTP 500 `{"error":"Internal server error"}`. The run record showed `executionCancellation.state = "requested"` and `nativeCancellation.dispatchState = "pending"`. When the session opened, the executor fenced it and threw `native_finalization_missing: session returned no semantic result`. The run ended `failed` with `native_session_interrupted`, and the pending Stop intent was never acknowledged. **Expected behavior** The cancel route returns a clear result and never an internal error. If the Stop is saved but the session is still starting, the route returns 409 with code `native_stop_pending`. When the late session opens, it acknowledges the saved Stop, and the run settles as an operator cancellation. **Steps to reproduce** 1. Start a native run whose provider session takes more than 30 seconds to open. 2. Stop the run from the board while the session is still opening. 3. See HTTP 500 from the cancel route, and see the run end `failed` instead of `cancelled`. ## What Changed - `server/src/services/heartbeat/run-control.ts`: the cancel path catches `native_cancellation_pending_recovery` from native dispatch. It throws `409 native_stop_pending` instead. The run stays `running` and keeps its saved Stop intent. No terminal transition or release happens. - `server/src/services/native-runtime/native-session-executor.ts`: when a late startup handle opens after a Stop caller timed out, the executor reads the run. If a run-scope Stop intent is still `pending`, it calls the durable `cancelNativeSession(..., { db, scope: "run" })` against the published handle. This records the audited acknowledgement (`dispatched: true`). The existing in-memory fence still runs. If the acknowledgement fails, the executor logs a warning and keeps the previous behavior. - New regression `server/src/services/heartbeat/native-stop-pending.test.ts` (real Postgres): startup-wait timeout and remote-ack timeout both give 409 `native_stop_pending`. The run stays `running` with its Stop intent. Other native Stop errors stay unchanged. - New regression in `native-session-executor.test.ts`: a Stop that times out on startup gets its saved intent acknowledged when the late handle opens. The provider session is cancelled once, and no turn is submitted. ## Verification - Red before the fix: `native-stop-pending.test.ts` failed (raw `NativeCancellationPendingRecoveryError` / `Error`, not `HttpError`). The executor regression failed (no acknowledgement write). - Green after the fix: `cd server && npx vitest run src/services/heartbeat/native-stop-pending.test.ts` - `cd server && npx vitest run src/services/native-runtime/native-session-executor.test.ts -t "late startup"` - Related suites: `src/services/native-runtime/native-session-executor.test.ts`, `src/services/heartbeat/`, `src/services/native-runtime/native-stop-accounting.integration.test.ts`, `src/__tests__/agent-live-run-routes.test.ts`. - Evidence: the incident run had cancellation recorded at 01:12:01Z and the 500 at 01:12:32Z. This matches the 30-second `waitForNativeSessionStartup` deadline. Its final error matched the startup-stop branch in the executor. ## Risks - Low to medium. The 409 only replaces an error that was already a failure. The caller still sees "not stopped yet", and the run is not marked cancelled. - The late acknowledgement runs only when a run-scope intent is `pending` and the handle is published. It uses the same durable cancel path that the reattach branch already uses. It can commit the normal Stop status decision for the issue. That is the same effect a timely Stop has. - If the acknowledgement fails, the code falls back to the previous in-memory fence. A Stop never gives a second executor: no provider turn is submitted after the handle opens. ## 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 - [x] All Paperclip CI gates are green - [x] 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 --- .../heartbeat/native-stop-pending.test.ts | 64 +++++++++++++++++++ server/src/services/heartbeat/run-control.ts | 26 ++++++-- .../native-session-executor.test.ts | 47 ++++++++++++++ .../native-runtime/native-session-executor.ts | 18 ++++++ 4 files changed, 148 insertions(+), 7 deletions(-) create mode 100644 server/src/services/heartbeat/native-stop-pending.test.ts diff --git a/server/src/services/heartbeat/native-stop-pending.test.ts b/server/src/services/heartbeat/native-stop-pending.test.ts new file mode 100644 index 00000000000..258eafd144a --- /dev/null +++ b/server/src/services/heartbeat/native-stop-pending.test.ts @@ -0,0 +1,64 @@ +import type { Db } from "@paperclipai/db"; +import { heartbeatRuns } from "@paperclipai/db"; +import { describe, expect, it, vi } from "vitest"; +import { HttpError } from "../../errors.js"; +import { cancelNativeSession, NativeCancellationPendingRecoveryError } from "../native-runtime/index.js"; +import { createHeartbeatRunControl } from "./run-control.js"; +import { callbacks, runControlPostgresSupport, setupRunControlDatabase } from "./__tests__/run-control-fixtures.js"; + +vi.mock("../live-events.js", () => ({ publishLiveEvent: vi.fn() })); +vi.mock("../local-service-supervisor.js", async (importOriginal) => ({ + ...await importOriginal(), + terminateLocalService: vi.fn(async () => undefined), +})); +vi.mock("../native-runtime/index.js", async (importOriginal) => ({ + ...await importOriginal(), + cancelNativeSession: vi.fn(), +})); + +describe.skipIf(!runControlPostgresSupport.supported)("native Stop while the provider session is still starting", () => { + let db: Db; + const { fixture } = setupRunControlDatabase("paperclip-heartbeat-native-stop-pending", value => { db = value; }); + + async function startingNativeRun() { + const { company, agent } = await fixture(); + const [run] = await db.insert(heartbeatRuns).values({ + companyId: company.id, agentId: agent.id, status: "running", runtimeMode: "native", runtimeModeResolvedAt: new Date(), + }).returning(); + return run; + } + + // Staging: an operator Stop arrived while a remote native session took longer + // than the 30s startup wait to open. The Stop was durably recorded and later + // honored by the startup owner, but the request answered HTTP 500. + it.each([ + ["startup wait timed out", () => new NativeCancellationPendingRecoveryError()], + ["remote owner acknowledgement timed out", () => new Error("native_cancellation_pending_recovery")], + ])("answers a recorded but unacknowledged Stop (%s) with a pending conflict", async (_label, failure) => { + const run = await startingNativeRun(); + const deps = callbacks(db); + vi.mocked(cancelNativeSession).mockRejectedValueOnce(failure()); + const error = await createHeartbeatRunControl(db, deps) + .cancelRunInternal(run.id, "Cancelled by a board operator", { resultJson: { cancelledByActorType: "user", cancelledByUserId: "user-1" } }) + .catch((err: unknown) => err); + expect(error).toBeInstanceOf(HttpError); + expect(error).toMatchObject({ status: 409, details: { code: "native_stop_pending", runId: run.id } }); + // Pending is not a cancellation receipt: no terminal transition or release. + expect(deps.setRunStatusFromLive).not.toHaveBeenCalled(); + expect(deps.finalizeAgentStatus).not.toHaveBeenCalled(); + expect(deps.startNextQueuedRunForAgent).not.toHaveBeenCalled(); + const current = await deps.getRun(run.id); + expect(current?.status).toBe("running"); + // The Stop intent itself stays recorded for the startup owner to honor. + expect(current?.resultJson).toMatchObject({ cancellation: expect.any(Object), startupCancellation: expect.any(Object) }); + }); + + it("keeps other native Stop failures unchanged", async () => { + const run = await startingNativeRun(); + const deps = callbacks(db); + const failure = new Error("native_cancellation_intent_conflict"); + vi.mocked(cancelNativeSession).mockRejectedValueOnce(failure); + await expect(createHeartbeatRunControl(db, deps).cancelRunInternal(run.id)).rejects.toBe(failure); + expect(deps.setRunStatusFromLive).not.toHaveBeenCalled(); + }); +}); diff --git a/server/src/services/heartbeat/run-control.ts b/server/src/services/heartbeat/run-control.ts index 11f25b30457..9f609e40432 100644 --- a/server/src/services/heartbeat/run-control.ts +++ b/server/src/services/heartbeat/run-control.ts @@ -1462,13 +1462,25 @@ export function createHeartbeatRunControl(db: Db, dependencies: HeartbeatRunCont if (!dependencies.verifyStartupCleanup) throw conflict("Native startup cleanup worker unavailable"); await dependencies.verifyStartupCleanup(startupCleanupRun); } else { - await cancelHeartbeatNativeRun({ - db, - runId: run.id, - reason, - runtimeMode: run.runtimeMode, - ...(options.cancellationRequestId ? { cancellationRequestId: options.cancellationRequestId } : {}), - }); + try { + await cancelHeartbeatNativeRun({ + db, + runId: run.id, + reason, + runtimeMode: run.runtimeMode, + ...(options.cancellationRequestId ? { cancellationRequestId: options.cancellationRequestId } : {}), + }); + } catch (error) { + // The durable Stop intent is recorded, but its owner (a native + // session still opening, or a remote controller) has not yet + // acknowledged it. The owner honors it later; answer honestly + // instead of reporting an internal failure. + if (error instanceof Error && error.message === "native_cancellation_pending_recovery") { + throw conflict("Stop is recorded; the native session is still starting and will stop when it opens.", + { code: "native_stop_pending", runId: run.id }); + } + throw error; + } } if (running) { await terminateHeartbeatRunProcess({ diff --git a/server/src/services/native-runtime/native-session-executor.test.ts b/server/src/services/native-runtime/native-session-executor.test.ts index 39a403fe553..9f1898dea66 100644 --- a/server/src/services/native-runtime/native-session-executor.test.ts +++ b/server/src/services/native-runtime/native-session-executor.test.ts @@ -8374,6 +8374,53 @@ describe("native session cancellation", () => { } }); + it("acknowledges a timed-out Stop's durable intent when the late startup handle opens", async () => { + const root = await mkdtemp(join(tmpdir(), "native-late-startup-ack-")); + const previous = process.env.PAPERCLIP_RUNNER_STATE_DIR; + process.env.PAPERCLIP_RUNNER_STATE_DIR = root; + let open!: () => void, started!: () => void; + const opening = new Promise(resolve => { open = resolve; }); + const admitted = new Promise(resolve => { started = resolve; }); + const submitTurn = vi.fn(); + state.cancel.mockClear(); + state.execute.mockReset().mockImplementationOnce(async (options) => { + started(); await opening; + await options.onSession({ cancel: state.cancel }); + submitTurn(); + throw new Error("a stopped startup must not reach prompt submission"); + }); + const runResultJson: Record = {}; + const updates: Array<{ table: unknown; values: Record }> = []; + const outcome = executePaperclipNativeSession({ db: leaseDb(execution, {}, runResultJson, updates), execution, runnerInstanceId: "runner" }) + .catch(error => error); + const persistence = cancellationDb(); + try { + await admitted; + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const stopping = cancelNativeSession(execution.binding.runId, "operator Stop", { db: persistence.db, scope: "run" }).catch(error => error); + await new Promise(resolve => setImmediate(resolve)); + await vi.advanceTimersByTimeAsync(30_000); + expect(await stopping).toMatchObject({ name: "NativeCancellationPendingRecoveryError" }); + vi.useRealTimers(); + // The startup owner reads the same durable run row the Stop caller wrote. + Object.assign(runResultJson, persistence.getResultJson()); + expect(runResultJson.nativeCancellation).toMatchObject({ dispatchState: "pending", scope: "run" }); + open(); await outcome; + expect(state.cancel).toHaveBeenCalledOnce(); + expect(submitTurn).not.toHaveBeenCalled(); + const acknowledgement = updates.find(update => update.table === heartbeatRuns && + (update.values.resultJson as Record | undefined)?.nativeCancellation?.dispatchState === "acknowledged"); + expect(acknowledgement?.values.resultJson).toMatchObject({ + nativeCancellation: { intentId: (runResultJson.nativeCancellation as Record).intentId, dispatched: true }, + }); + } finally { + vi.useRealTimers(); open(); await outcome; + if (previous === undefined) delete process.env.PAPERCLIP_RUNNER_STATE_DIR; + else process.env.PAPERCLIP_RUNNER_STATE_DIR = previous; + await rm(root, { recursive: true, force: true }); + } + }); + it("routes control-plane cancellation to the active normalized session and removes the handle", async () => { const running = executePaperclipNativeSession({ db: leaseDb(), diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index da9b82fbb41..a70335eb7b0 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -10353,6 +10353,24 @@ async function executePaperclipNativeSessionWithinScope( await startup.cancellationSettled; // If startup exceeded the caller's deadline, its late handle // must still be cancelled instead of escaping the Stop fence. + // The caller left its durable run Stop pending; acknowledge it + // against this exact published handle so the run settles as an + // operator cancellation rather than a provider failure. + try { + const [stopRun] = await input.db.select({ resultJson: heartbeatRuns.resultJson }).from(heartbeatRuns).where(and( + eq(heartbeatRuns.id, input.execution.binding.runId), + eq(heartbeatRuns.companyId, input.execution.binding.companyId), + )).limit(1); + const pendingStop = record(record(stopRun?.resultJson).nativeCancellation); + if (pendingStop.scope === "run" && pendingStop.dispatchState === "pending") { + await cancelNativeSession(input.execution.binding.runId, "Stop requested during native startup", { db: input.db, scope: "run" }); + } + } catch (error) { + // Best effort: the in-memory Stop below still fences this + // handle; the intent stays pending for cancellation recovery. + logger.warn({ runId: input.execution.binding.runId, err: error }, + "Late native startup Stop could not acknowledge its durable intent"); + } await cancelNativeSession(input.execution.binding.runId, "Stop requested during native startup"); throw new Error("native_finalization_missing: session returned no semantic result"); }