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 },