diff --git a/doc/execution-semantics.md b/doc/execution-semantics.md index 054872f8515..13f907f61f0 100644 --- a/doc/execution-semantics.md +++ b/doc/execution-semantics.md @@ -1996,6 +1996,24 @@ That is the execution contract Paperclip should present to operators. ### Cancellation during native startup +Core supports verified cleanup for explicitly recorded startup obligations. This +support does not create startup contexts, advertise transport support, or capture +a transport binding. Existing callers retain their legacy payloads and startup +budgets. This support alone makes no startup-latency claim. + +Restart recovery uses the claim breadcrumb only while the current run has no +first session checkpoint and the prior controller and context deadlines have +expired. A later preparation breadcrumb requires the stronger preparation-stop +proof. A failed cleanup-intent write retains the original typed failure and +rearms the existing restart retry after 30 seconds; the running run continues to +block idle sleep. Recovery queues cleanup rather than replaying a provider. A completed result +or a newer owner wins. The existing adopted-authentication and chat-workspace +ownership holds retain their separate behavior. The startup budget does not bound +the duration of remote cleanup. Existing Stop receipts and process cleanup still gate +destructive lifecycle or binding changes. Operator plugin restarts and external +machine changes can still interrupt startup. + + Cancellation records a preparation fence while holding the run row lock. Native runtime selection checks that fence, the running status, and the current startup controller lease in the same transaction that creates the native coordinator. @@ -2034,6 +2052,15 @@ preserving history, unknown action outcomes, and attempt counts. Pauses, approva budgets, task ownership, and terminal task status still gate admission. No automatic provider replay is authorized by a cancelled startup. +A failed cleanup attempt saves its next retry time in the existing control-work +deadlines. The startup marker retains the original admission deadline. Both +candidate batches use stable deadline order, and pending cleanup cannot enter +ordinary forced finalization. A late replacement-task reply remains owned until +its resource identity is durable. It is queued for cleanup instead of attached +after cancellation. The old task's Stop receipt cannot settle cleanup of a new +replacement task. A lost reply with no known resource identity remains unresolved +until provider inspection or operator reconciliation establishes its outcome. + ### Delivering queued messages after a legacy run stops The legacy queued-message Interrupt action accepts a null `targetRunId` when diff --git a/server/src/__tests__/environment-cleanup-work.test.ts b/server/src/__tests__/environment-cleanup-work.test.ts index 29dbf953aae..bd9419fa970 100644 --- a/server/src/__tests__/environment-cleanup-work.test.ts +++ b/server/src/__tests__/environment-cleanup-work.test.ts @@ -1,5 +1,5 @@ import { readIdleSleepSafety } from "../services/idle-sleep-safety.js"; -import { createOwnedSandbox } from "../services/sandbox-creation-operations.js"; +import { createOwnedSandbox, recordSandboxCreationResource } from "../services/sandbox-creation-operations.js"; import { mkdtemp, writeFile, rm } from "node:fs/promises"; import { tmpdir } from "node:os"; import { join } from "node:path"; @@ -116,15 +116,18 @@ describe.skipIf(!support.supported)("environment cleanup scheduling", () => { ])); await quiet(); }); - it("settles a deleted-company creation as manual history across restart without idle polling", async () => { + it.each([false, true])("settles a deleted-company creation as manual history across restart without idle polling (contextual=%s)", async contextual => { await start(); await quiet(); - await createOwnedSandbox(db, { companyId, environmentId, provider: "fixture", driverKey: "fixture", config: {}, metadata: {} }, + const created = await createOwnedSandbox(db, { companyId, environmentId, provider: "fixture", driverKey: "fixture", config: {}, + metadata: contextual ? { runnerTaskLease: true, runnerTaskCreationContextId: randomUUID() } : {} }, async () => ({ providerLeaseId: "fixture-deleted-company" })); await db.delete(companies).where(eq(companies.id, companyId)); await settle(31 * 60_000); await vi.waitFor(async () => expect(await db.select().from(sandboxCreationOperations)).toEqual([ expect.objectContaining({ state: "needs_reconciliation", metadata: expect.objectContaining({ creationReconciliationReason: "company_deleted" }) }), ])); + if (contextual) await recordSandboxCreationResource(db, { id: String(created.metadata!.creationOperationId), companyId, environmentId, + providerLeaseId: created.providerLeaseId }); await quiet(); worker!.stop(); await coordinator!.stop(); await start(); await quiet(); diff --git a/server/src/__tests__/environment-task-authority.integration.test.ts b/server/src/__tests__/environment-task-authority.integration.test.ts index d01611e1972..9e89c49901c 100644 --- a/server/src/__tests__/environment-task-authority.integration.test.ts +++ b/server/src/__tests__/environment-task-authority.integration.test.ts @@ -1,11 +1,12 @@ import { randomUUID } from "node:crypto"; -import { afterAll, beforeAll, describe, expect, it } from "vitest"; +import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; import { eq } from "drizzle-orm"; -import { agents, companies, createDb, environmentLeases, environments, heartbeatRuns, plugins } from "@paperclipai/db"; +import { agents, companies, createDb, environmentLeases, environments, heartbeatRuns, plugins, sandboxCreationOperations } from "@paperclipai/db"; import { resolvePluginTaskResume } from "../services/environment-task-runtime.js"; import { remoteTerminationReceipt } from "../services/remote-execution-termination.js"; import { environmentRuntimeService } from "../services/environment-runtime.js"; import type { PluginWorkerManager } from "../services/plugin-worker-manager.js"; +import { NativeExecutionContext } from "../services/native-runtime/native-execution-context.js"; import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "./helpers/embedded-postgres.js"; const support = await getEmbeddedPostgresTestSupport(); @@ -20,6 +21,108 @@ databaseSuite("environment task lease authority", () => { }); afterAll(async () => { await stopDb?.(); }); + it("replaces a stopped warm candidate within its tracked startup context", async () => { + const companyId = randomUUID(), agentId = randomUUID(), environmentId = randomUUID(), pluginId = randomUUID(), runId = randomUUID(), leaseId = randomUUID(); + await db.insert(companies).values({ id: companyId, name: "Warm candidate", issuePrefix: `T${companyId.slice(0, 7).replace(/-/g, "").toUpperCase()}` }); + await db.insert(agents).values({ id: agentId, companyId, name: "Fixture", adapterType: "paperclip_runner" }); + await db.insert(plugins).values({ id: pluginId, pluginKey: pluginId, packageName: "fixture-warm-replacement", version: "1", status: "ready", + manifestJson: { capabilities: ["environment.drivers.register"], environmentDrivers: [{ driverKey: "tasks", supportsTasks: true }] } as never }); + await db.insert(environments).values({ id: environmentId, companyId, name: `Fixture ${environmentId}`, driver: "plugin", + config: { pluginKey: pluginId, driverKey: "tasks", driverConfig: {} } }); + await db.insert(heartbeatRuns).values({ id: runId, companyId, agentId, invocationSource: "manual", status: "running" }); + await db.insert(environmentLeases).values({ id: leaseId, companyId, environmentId, heartbeatRunId: runId, + provider: "plugin:fixture:tasks", providerLeaseId: "stopped-task", status: "active", leasePolicy: "reuse_by_environment", + metadata: { driver: "plugin", pluginId, pluginKey: pluginId, driverKey: "tasks", runnerTaskLease: true, runnerTaskReused: true } }); + const calls: string[] = []; + const workers = { getWorker: () => ({ supportedMethods: ["environmentTask", "environmentAcquireLease"] }), + call: async (_plugin: string, method: string, params: any, _timeout?: number, _sink?: unknown, settled?: () => void) => { + calls.push(method === "environmentTask" ? params.operation.kind : method); + try { + if (method === "environmentAcquireLease") return { providerLeaseId: "replacement-task" }; + if (params.operation.kind === "status") return { kind: "status", taskId: params.taskId, phase: "completed", executionStopped: true }; + if (params.operation.kind === "describe") return { kind: "description", taskId: params.taskId, + runner: { version: "fixture", digest: `sha256:${"a".repeat(64)}` }, executionContextVersion: 1 }; + return { kind: "accepted", taskId: params.taskId }; + } finally { settled?.(); } + }, + } as unknown as PluginWorkerManager; + const context = new NativeExecutionContext({ binding: { companyId, agentId, runId } } as never, 1_000); + try { + await expect(environmentRuntimeService(db, { pluginWorkerManager: workers }).task({ companyId, leaseId, + operation: { kind: "describe" }, executionContext: context })).resolves.toMatchObject({ kind: "description", taskId: "replacement-task" }); + expect(calls).toEqual(["status", "status", "complete", "environmentAcquireLease", "describe"]); + expect(context.pending).toBe(false); + const [lease] = await db.select().from(environmentLeases).where(eq(environmentLeases.id, leaseId)); + expect(lease.providerLeaseId).toBe("replacement-task"); + expect(lease.metadata?.runnerTaskReused).toBe(false); + expect(JSON.stringify(lease.metadata)).not.toContain(context.id); + } finally { context.finish(); } + }); + + it.each(["late", "post-result", "retiring"])("queues a replacement instead of attaching after %s startup cancellation", async mode => { + const companyId = randomUUID(), agentId = randomUUID(), environmentId = randomUUID(), pluginId = randomUUID(), runId = randomUUID(), leaseId = randomUUID(); + await db.insert(companies).values({ id: companyId, name: "Warm candidate", issuePrefix: `T${companyId.slice(0, 7).replace(/-/g, "").toUpperCase()}` }); + await db.insert(agents).values({ id: agentId, companyId, name: "Fixture", adapterType: "paperclip_runner" }); + await db.insert(plugins).values({ id: pluginId, pluginKey: pluginId, packageName: "fixture-warm-replacement", version: "1", status: "ready", + manifestJson: { capabilities: ["environment.drivers.register"], environmentDrivers: [{ driverKey: "tasks", supportsTasks: true }] } as never }); + await db.insert(environments).values({ id: environmentId, companyId, name: `Fixture ${environmentId}`, driver: "plugin", + config: { pluginKey: pluginId, driverKey: "tasks", driverConfig: {} } }); + await db.insert(heartbeatRuns).values({ id: runId, companyId, agentId, invocationSource: "manual", status: "running" }); + await db.insert(environmentLeases).values({ id: leaseId, companyId, environmentId, heartbeatRunId: runId, + provider: "plugin:fixture:tasks", providerLeaseId: "stopped-task", status: "active", leasePolicy: "reuse_by_environment", + metadata: { driver: "plugin", pluginId, pluginKey: pluginId, driverKey: "tasks", runnerTaskLease: true, runnerTaskReused: true } }); + const calls: string[] = []; + let reply!: () => Promise, acquiring!: () => void; + const entered = new Promise(resolve => { acquiring = resolve; }); + const workers = { getWorker: () => ({ supportedMethods: ["environmentTask", "environmentAcquireLease"] }), + call: async (_plugin: string, method: string, params: any, _timeout?: number, _sink?: unknown, settled?: () => void, _contextId?: string, observe?: (result: any) => Promise) => { + calls.push(method === "environmentTask" ? params.operation.kind : method); + try { + if (method === "environmentAcquireLease") return await new Promise(resolve => { + reply = async () => { const result = { providerLeaseId: "replacement-task", metadata: { binding: "fresh" } }; + await observe?.(result); + if (mode === "retiring") await db.update(environmentLeases).set({ metadata: { driver: "plugin", pluginId, driverKey: "tasks", runnerTaskRetiring: true } }).where(eq(environmentLeases.id, leaseId)); + resolve(result); }; + acquiring(); + }); + if (params.operation.kind === "status") return { kind: "status", taskId: params.taskId, phase: "completed", executionStopped: true }; + if (params.operation.kind === "describe") return { kind: "description", taskId: params.taskId, + runner: { version: "fixture", digest: `sha256:${"a".repeat(64)}` }, executionContextVersion: 1 }; + return { kind: "accepted", taskId: params.taskId }; + } finally { settled?.(); } + }, + } as unknown as PluginWorkerManager; + const context = new NativeExecutionContext({ binding: { companyId, agentId, runId } } as never, 1_000); + if (mode === "post-result") { + const wait = context.wait.bind(context); + vi.spyOn(context, "wait").mockImplementation(operation => wait(async () => { + const value = await operation(); context.abort(new Error("Cancelled after recording")); return value; + })); + } + try { + const request = environmentRuntimeService(db, { pluginWorkerManager: workers }).task({ companyId, leaseId, + operation: { kind: "describe" }, executionContext: context }); + const rejected = expect(request).rejects.toThrow("operation unavailable"); + await entered; + if (mode === "late") { + context.abort(new Error("Startup cancelled")); + await rejected; + expect(context.pending).toBe(true); + } + await reply(); await rejected; + expect(context.pending).toBe(false); + const [lease] = await db.select().from(environmentLeases).where(eq(environmentLeases.id, leaseId)); + expect(lease.providerLeaseId).toBe("stopped-task"); + const [creation] = await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.runId, runId)); + expect(creation.state).toBe("cleanup_pending"); + expect(creation.metadata.runnerTaskCreationContextId).toBe(context.id); + const [cleanup] = await db.select().from(environmentLeases).where(eq(environmentLeases.id, creation.leaseId!)); + expect(cleanup).toMatchObject({ heartbeatRunId: runId, providerLeaseId: "replacement-task", status: "pending_cleanup" }); + expect(cleanup.metadata).toMatchObject({ runnerTaskLease: true, providerMetadata: { binding: "fresh" } }); + expect(calls).not.toContain("describe"); + } finally { context.finish(); } + }); + it("authorizes a new task lease only after scoped prior execution has stopped", async () => { const companyId = randomUUID(), agentId = randomUUID(), environmentId = randomUUID(), pluginId = randomUUID(); const oldRunId = randomUUID(), nextRunId = randomUUID(), oldLeaseId = randomUUID(), nextLeaseId = randomUUID(); diff --git a/server/src/__tests__/environment-task-runtime.test.ts b/server/src/__tests__/environment-task-runtime.test.ts index 15c8dcb7b62..96126fc6df8 100644 --- a/server/src/__tests__/environment-task-runtime.test.ts +++ b/server/src/__tests__/environment-task-runtime.test.ts @@ -2,14 +2,16 @@ import { beforeEach, describe, expect, it, vi } from "vitest"; import { PgDialect } from "drizzle-orm/pg-core"; import { executionWorkspaces, environmentLeases, type Db } from "@paperclipai/db"; import { environmentTaskOperationSchema, parseEnvironmentTaskResult } from "@paperclipai/plugin-sdk"; -import { executeEnvironmentTask } from "../services/environment-task-runtime.js"; +import { executeEnvironmentTask, settleDispatchedEnvironmentTask } from "../services/environment-task-runtime.js"; +import { NativeExecutionContext } from "../services/native-runtime/native-execution-context.js"; -const state = vi.hoisted(() => ({ plugin: {} as any, release: vi.fn() })); +const state = vi.hoisted(() => ({ plugin: {} as any, release: vi.fn(), identity: vi.fn(), config: vi.fn() })); vi.mock("../services/provider-fresh-workspace.js", () => ({ stageProviderFreshWorkspace: async (input: { existing: unknown }) => input.existing, releaseProviderRecoveryTransfers: state.release, })); -vi.mock("../services/plugin-registry.js", () => ({ pluginRegistryService: () => ({ getById: vi.fn(async () => state.plugin) }) })); +vi.mock("../services/plugin-registry.js", () => ({ pluginRegistryService: () => ({ getById: vi.fn(async () => state.plugin), getConfig: state.config }) })); +vi.mock("../services/plugin-agent-runtime-state.js", () => ({ pluginAgentRuntimeIdentity: state.identity })); const leaseId = "10000000-0000-4000-8000-000000000001"; const projectId = "10000000-0000-4000-8000-000000000002"; const secondProjectId = "10000000-0000-4000-8000-000000000003"; @@ -25,7 +27,7 @@ function database(value: ReturnType | null = row(), projectRows = [{ const query: any = { from: (table: unknown) => { selectedRows = table === executionWorkspaces ? workspaceRows : table === environmentLeases ? ownerRows : projectRows; return query; }, leftJoin: () => query, where: vi.fn(() => query), limit: () => Promise.resolve(results.shift()), then: (resolve: (rows: typeof projectRows) => unknown) => Promise.resolve(selectedRows).then(resolve as (rows: unknown[]) => unknown) }; const sets: Record[] = []; const update: any = { set: (value: Record) => { sets.push(value); return update; }, where: () => update, - returning: async () => [{ id: leaseId }], then: (resolve: (value: unknown) => unknown) => Promise.resolve([]).then(resolve) }; + returning: async () => [{ id: leaseId, metadata: value?.lease.metadata, heartbeatRunId: value?.lease.heartbeatRunId }], then: (resolve: (value: unknown) => unknown) => Promise.resolve([]).then(resolve) }; const db = { select: () => query, update: () => update, transaction: vi.fn(async (write: (tx: Db) => Promise) => write(db as unknown as Db)) }; return { db: db as unknown as Db, query, sets, transaction: db.transaction }; @@ -37,9 +39,65 @@ const submit = { kind: "submit" as const, preparedLaunchId: "configuration", pro beforeEach(() => { state.release.mockReset(); + state.identity.mockReset().mockResolvedValue({ instanceSecrets: { launcher: "synthetic-transient-binding" } }); + state.config.mockReset().mockResolvedValue({ configJson: { endpoint: "synthetic" } }); state.plugin = { id: "original", pluginKey: "test.provider", status: "ready", manifestJson: { capabilities: ["environment.drivers.register"], environmentDrivers: [{ driverKey: "tasks", supportsTasks: true }] } }; }); describe("plugin-provided Runner execution", () => { + it.each([false, true])("retires an undispatched warm task only with required preparation proof (%s)", async preparationStopped => { + const value = row(); + Object.assign(value.lease.metadata, { runnerTaskDispatched: false, + runnerTaskStartupCleanup: { contextId: "startup", requiresPreparationStop: true } }); + const fixture = database(value), workers = worker(); + fixture.db.select = ((...args: unknown[]) => (database(value).db.select as (...values: unknown[]) => unknown)(...args)) as Db["select"]; + let release!: () => void; + const drain = new Promise(resolve => { release = resolve; }); + const drainStartup = vi.fn(() => drain); + Object.assign(workers, { drainStartup }); + const operations: string[] = []; + workers.call.mockImplementation(async (...args: any[]) => { + const operation = args[2].operation.kind; operations.push(operation); + return operation === "status" ? { kind: "status", taskId: "attempt-1", phase: "cancelled", executionStopped: true, preparationStopped } + : { kind: "accepted", taskId: "attempt-1" }; + }); + const retiring = settleDispatchedEnvironmentTask(fixture.db, workers as never, { companyId: "company", id: leaseId }); + const checked = retiring.then(value => ({ value, error: null }), error => ({ value: false, error })); + await vi.waitFor(() => expect(operations).toContain("stop")); + await vi.waitFor(() => expect(operations).toContain("status")); + expect(drainStartup).toHaveBeenCalledWith("startup"); + expect(operations).not.toContain("complete"); + release(); + const result = await checked; + if (preparationStopped) { expect(result).toEqual({ value: true, error: null }); expect(operations).toEqual(["stop", "status", "complete"]); } + else { expect(result.error?.message).toContain("termination is unconfirmed"); expect(fixture.sets).toContainEqual(expect.objectContaining({ status: "pending_cleanup", cleanupStatus: "failed" })); } + }); + it("keeps legacy payloads passive without capability or transport activation", async () => { + const context = new NativeExecutionContext({ binding: { companyId: "company", agentId: "agent", runId: "run" } } as never, 1_000); + const workers = worker(); + workers.call.mockImplementation(async (...args: any[]) => { args[5]?.(); return { kind: "description", taskId: "attempt-1", runner: { version: "fixture", digest: `sha256:${"a".repeat(64)}` } }; }); + try { + for (const executionContext of [undefined, context]) { + await executeEnvironmentTask(database().db, workers as never, { companyId: "company", leaseId, + operation: { kind: "describe" }, ...(executionContext ? { executionContext } : {}) }); + const sent = workers.call.mock.calls.at(-1) as unknown as any[]; + expect(sent[2]).not.toHaveProperty("executionContextSupported"); + expect(sent[2]).not.toHaveProperty("executionContext"); + if (!executionContext) expect(sent).toHaveLength(4); + } + expect(state.identity).not.toHaveBeenCalled(); + expect(state.config).not.toHaveBeenCalled(); + expect(context.pending).toBe(false); + } finally { context.finish(); } + }); + it.each(["json", "wrong-run"])("rejects a %s context before the worker", async mode => { + const context = new NativeExecutionContext({ binding: { companyId: "company", agentId: "agent", runId: mode === "wrong-run" ? "other" : "run" } } as never, 1_000); + const workers = worker(); + try { + await expect(executeEnvironmentTask(database().db, workers as never, { companyId: "company", leaseId, operation: { kind: "describe" }, + executionContext: mode === "json" ? JSON.parse(JSON.stringify(context)) : context })).rejects.toThrow("native_execution_context"); + expect(workers.call).not.toHaveBeenCalled(); + } finally { context.finish(); } + }); it("forwards a retained fresh directory intent on later launch calls and checks provider support", async () => { const value = row(); value.lease.metadata.runnerTaskProjectAuthValidation.projectIds = []; diff --git a/server/src/__tests__/heartbeat-native-cleanup-admission.test.ts b/server/src/__tests__/heartbeat-native-cleanup-admission.test.ts index b6544447a68..86f4e8452c9 100644 --- a/server/src/__tests__/heartbeat-native-cleanup-admission.test.ts +++ b/server/src/__tests__/heartbeat-native-cleanup-admission.test.ts @@ -1,10 +1,15 @@ import { EMBEDDED_POSTGRES_TEST_TIMEOUT_MS } from "@paperclipai/db"; import { randomUUID } from "node:crypto"; -import { eq } from "drizzle-orm"; +import { eq, sql } from "drizzle-orm"; import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; -import { agents, authUsers, companies, companyMemberships, createDb, heartbeatRuns, issues } from "@paperclipai/db"; +import { agents, authUsers, companies, companyMemberships, createDb, environmentLeases, environments, heartbeatRuns, issues, nativeRunFinalizations } from "@paperclipai/db"; import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "./helpers/embedded-postgres.js"; import { heartbeatService } from "../services/heartbeat.js"; +import { NativeStartupCleanupPendingError, readNativeStartupCleanup } from "../services/native-runtime/native-startup-cleanup.js"; +import { prepareNativeHeartbeatRun } from "../services/native-runtime/prepare-native-run.js"; +import { environmentService } from "../services/environments.js"; +import { remoteTerminationReceipt } from "../services/remote-execution-termination.js"; +import { createIsolatedTestHome } from "./helpers/isolated-test-home.js"; const execute = vi.hoisted(() => vi.fn()); vi.mock("../adapters/index.js", async () => { @@ -70,4 +75,108 @@ suite("native terminal-run cleanup admission", () => { expect((await heartbeat.getRun(nextId))?.status).toBe("succeeded"); expect(execute).toHaveBeenCalledTimes(3); }, 30_000); + + it("retries a failed startup intent through timer failure and drain before verified cancellation", async () => { + const home = createIsolatedTestHome(), originalHome = process.env.PAPERCLIP_HOME; + process.env.PAPERCLIP_HOME = home.home; + const companyId = randomUUID(), agentId = randomUUID(), issueId = randomUUID(), leaseId = randomUUID(); + const contextId = randomUUID(), leaseOwner = randomUUID(), taskId = randomUUID(), deadlineAtMs = Date.now() - 1; + const originalSetTimeout = globalThis.setTimeout; + const retries: Array<{ timer: ReturnType; fire(): void }> = []; + const timeout = vi.spyOn(globalThis, "setTimeout").mockImplementation(((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { + if (typeof delay === "number" && delay <= 30_000 && new Error().stack?.includes("scheduleNativeSessionResumeDispatch")) { + const timer = originalSetTimeout(() => {}, 3_600_000); + retries.push({ timer, fire() { clearTimeout(timer); callback(...args); } }); + return timer; + } + return originalSetTimeout(callback, delay, ...args); + }) as typeof setTimeout); + let failSuppression = false, runId = ""; + const runtimeEnv = new Proxy>({}, { get(_target, key) { + if (key === "PAPERCLIP_DATABASE_RESTORE_IN_PROGRESS" && failSuppression) { + failSuppression = false; + throw new Error("Scheduling dependency unavailable"); + } + return undefined; + } }); + const heartbeat = heartbeatService(db, { runtimeEnv }); + try { + await db.insert(companies).values({ id: companyId, name: "Intent retry", issuePrefix: "CIR", defaultResponsibleUserId: "owner" }); + await db.insert(authUsers).values({ id: "owner", name: "Fixture user", email: "owner@example.test", createdAt: new Date(), updatedAt: new Date() }).onConflictDoNothing(); + await db.insert(companyMemberships).values({ companyId, principalType: "user", principalId: "owner", status: "active", membershipRole: "member" }); + await db.insert(agents).values({ id: agentId, companyId, name: "Worker", role: "engineer", status: "idle", adapterType: "process", + adapterConfig: {}, permissions: {}, runtimeConfig: { heartbeat: { enabled: false, wakeOnDemand: true } } }); + await db.insert(issues).values({ id: issueId, companyId, title: "Recover startup", status: "todo", assigneeAgentId: agentId, responsibleUserId: "owner" }); + const [environment] = await db.insert(environments).values({ companyId, name: "Controlled provider", driver: "plugin", config: {} }).returning(); + await db.execute(sql`create table test_cleanup_intent_fault (enabled boolean not null)`); + await db.execute(sql`insert into test_cleanup_intent_fault values (true)`); + await db.execute(sql`create sequence test_cleanup_intent_attempts`); + await db.execute(sql.raw(`create function test_reject_cleanup_intent() returns trigger language plpgsql as $$ begin + if new.company_id = '${companyId}'::uuid and new.error_code = 'native_startup_cleanup_pending' + and exists (select 1 from test_cleanup_intent_fault where enabled) then + perform nextval('test_cleanup_intent_attempts'); raise exception 'Cleanup intent write unavailable'; + end if; return new; end $$`)); + await db.execute(sql`create trigger test_cleanup_intent_fault before update on heartbeat_runs for each row execute function test_reject_cleanup_intent()`); + execute.mockReset(); + execute.mockImplementation(async (context: { runId: string }) => { + runId = context.runId; + const [run] = await db.update(heartbeatRuns).set({ runtimeMode: "native", runtimeModeResolvedAt: null }).where(eq(heartbeatRuns.id, runId)).returning(); + await prepareNativeHeartbeatRun({ db, run, issue: { id: issueId, title: "Recover startup", description: null }, environmentLeaseId: leaseId }); + await db.update(agents).set({ adapterType: "paperclip_runner", adapterConfig: { provider: "codex" } }).where(eq(agents.id, agentId)); + await db.update(issues).set({ executionRunId: runId }).where(eq(issues.id, issueId)); + await db.insert(nativeRunFinalizations).values({ runId, companyId, issueId, phase: "observed", attempt: 1, + controllerGeneration: 1, leaseOwner, leaseExpiresAt: new Date(Date.now() - 1_000) }); + await db.insert(environmentLeases).values({ id: leaseId, companyId, environmentId: environment.id, heartbeatRunId: runId, + issueId, status: "active", provider: "plugin", providerLeaseId: taskId, leasePolicy: "reuse_by_environment", metadata: { runnerTaskLease: true } }); + await db.update(heartbeatRuns).set({ runnerProfileJson: sql`coalesce(${heartbeatRuns.runnerProfileJson}, '{}'::jsonb) || ${JSON.stringify({ + nativeStartupContext: { schema: "paperclip.native-startup-context.v1", companyId, agentId, runId, + contextId, deadlineAtMs, leaseId, leaseOwner, controllerGeneration: 1, attempt: 1 }, + })}::jsonb` }).where(eq(heartbeatRuns.id, runId)); + throw new NativeStartupCleanupPendingError(contextId, deadlineAtMs, leaseOwner, false, leaseId); + }); + await heartbeat.invoke(agentId, "on_demand", { issueId }, "manual"); + await heartbeat.drainActiveRunExecutions(); + const owner = () => db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, runId)).then(rows => rows[0]!); + const lease = () => db.select().from(environmentLeases).where(eq(environmentLeases.id, leaseId)).then(rows => rows[0]!); + expect((await db.execute<{ last_value: string }>(sql`select last_value from test_cleanup_intent_attempts`))[0].last_value).toBe("2"); + expect(await heartbeat.getRun(runId)).toMatchObject({ status: "running", errorCode: null }); + expect((await owner()).leaseOwner).toBe(leaseOwner); + expect(await lease()).toMatchObject({ status: "active", cleanupStatus: null }); + expect(readNativeStartupCleanup((await heartbeat.getRun(runId))!)).toBeNull(); + const drainedRetries = retries.length; + expect(drainedRetries).toBeGreaterThan(0); + await heartbeat.resumeQueuedRunsAfterDrain(); + expect(retries.length).toBeGreaterThan(drainedRetries); + const resumedRetries = retries.length; + failSuppression = true; + retries.at(-1)!.fire(); + await vi.waitFor(() => expect(retries.length).toBeGreaterThan(resumedRetries)); + expect((await owner()).leaseOwner).toBe(leaseOwner); + expect((await heartbeat.getRun(runId))?.status).toBe("running"); + await db.execute(sql`update test_cleanup_intent_fault set enabled = false`); + retries.at(-1)!.fire(); + await vi.waitFor(async () => expect(readNativeStartupCleanup((await heartbeat.getRun(runId))!)?.state).toBe("pending")); + await vi.waitFor(async () => expect((await heartbeat.listEvents(runId)).some(event => event.eventType === "native.recovery.transition")).toBe(true)); + const current = await lease(); + await environmentService(db).releaseLease(leaseId, "released", { cleanupStatus: "success", + remoteExecutionTermination: remoteTerminationReceipt(current, { providerLeaseId: taskId, state: "stopped" }) }); + await heartbeat.cancelRun(runId, "Startup cleanup retry completed"); + expect(await heartbeat.getRun(runId)).toMatchObject({ status: "cancelled" }); + expect(readNativeStartupCleanup((await heartbeat.getRun(runId))!)?.state).toBe("complete"); + expect(await owner()).toMatchObject({ leaseOwner: null, controlDeadlineAt: null }); + expect(execute).toHaveBeenCalledOnce(); + } finally { + await heartbeat.drainActiveRunExecutions(); + timeout.mockRestore(); + for (const retry of retries) clearTimeout(retry.timer); + await db.execute(sql`drop trigger if exists test_cleanup_intent_fault on heartbeat_runs`); + await db.execute(sql`drop function if exists test_reject_cleanup_intent()`); + await db.execute(sql`drop table if exists test_cleanup_intent_fault`); + await db.execute(sql`drop sequence if exists test_cleanup_intent_attempts`); + if (originalHome === undefined) delete process.env.PAPERCLIP_HOME; + else process.env.PAPERCLIP_HOME = originalHome; + home.cleanup(); + } + }, 30_000); + }); diff --git a/server/src/__tests__/idle-sleep-safety.test.ts b/server/src/__tests__/idle-sleep-safety.test.ts index 187ff3d32e2..40a93b09794 100644 --- a/server/src/__tests__/idle-sleep-safety.test.ts +++ b/server/src/__tests__/idle-sleep-safety.test.ts @@ -204,6 +204,19 @@ if (!support.supported) console.warn(`Skipping idle sleep Postgres tests: ${supp } }); + it("keeps a failed startup intent awake after its local worker counter settles", async () => { + const f = await seed(); + expect(await read()).toEqual(none); + const finish = beginIdleTrackedWork(); + await db.update(heartbeatRuns).set({ status: "running", runtimeMode: "native", nativePhase: "observed", + runnerProfileJson: { nativeStartupContext: { contextId: randomUUID(), deadlineAtMs: now - 1 } } }).where(eq(heartbeatRuns.id, f.runId)); + finish(); + expect(idleWorkSnapshot().active).toBe(0); + expect(await read()).toEqual(present); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.runId)); + expect(await read()).toEqual(none); + }); + it("retains committed budget stop intent until its exact generation is delivered", async () => { const f = await seed(); const [policy] = await db.insert(budgetPolicies).values({ companyId: f.companyId, scopeType: "company", scopeId: f.companyId, diff --git a/server/src/__tests__/native-startup-cleanup-recovery.test.ts b/server/src/__tests__/native-startup-cleanup-recovery.test.ts new file mode 100644 index 00000000000..4e05e3db5bb --- /dev/null +++ b/server/src/__tests__/native-startup-cleanup-recovery.test.ts @@ -0,0 +1,729 @@ +import { randomUUID } from "node:crypto"; +import { databaseWorkPending } from "@paperclipai/db/work-signals"; +import { DELIVERY_QUEUES } from "../services/delivery-work-notifications.js"; +import { writeFile } from "node:fs/promises"; +import path from "node:path"; +import type { PluginEnvironmentTaskOperation } from "@paperclipai/plugin-sdk"; +import type { PaperclipPluginManifestV1 } from "@paperclipai/shared"; +import { and, eq, sql } from "drizzle-orm"; +import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; +import { + activityLog, agents, companies, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, environmentLeases, + environments, heartbeatRuns, issues, nativeRunFinalizations, nativeRunResults, plugins, sandboxCreationOperations, +} from "@paperclipai/db"; +import { recoveryPostgresSupport, startRecoveryPostgres } from "./helpers/recovery-postgres.js"; +import { createIsolatedTestHome } from "./helpers/isolated-test-home.js"; +import { prepareNativeHeartbeatRun } from "../services/native-runtime/prepare-native-run.js"; +import { + acknowledgeNativeStartupCleanup, NATIVE_STARTUP_CLEANUP_PENDING, readNativeStartupCleanup, + requestNativeStartupCleanup, verifyNativeStartupCleanup, clearNativeStartupContext, +} from "../services/native-runtime/native-startup-cleanup.js"; +import { isNativeRunnerOwnershipHeld } from "../services/native-runtime/native-runner-ownership.js"; +import { cancelNativeSession } from "../services/native-runtime/native-session-executor.js"; +import * as nativeSessionExecutor from "../services/native-runtime/native-session-executor.js"; +import { NativeExecutionContext } from "../services/native-runtime/native-execution-context.js"; +import type { NativeExecutionInput } from "../vendor/paperclip-runner/index.js"; +import { callbacks } from "../services/heartbeat/__tests__/run-control-fixtures.js"; +import { createHeartbeatRunControl } from "../services/heartbeat/run-control.js"; +import { nextEnvironmentCleanupAt } from "../services/environment-cleanup-state.js"; +import { executionControlSchedule } from "../services/execution-control-work.js"; +import { claimNativeRestartRecoveries } from "../services/native-runtime/native-restart-recovery.js"; +import { reconcileAbandonedExecutionControl } from "../services/execution-control-reconciliation.js"; +import { createPluginWorkerManager, type PluginWorkerManager } from "../services/plugin-worker-manager.js"; +import { hasRemoteTerminationReceipt, remoteTerminationReceipt } from "../services/remote-execution-termination.js"; + +import { createOwnedSandbox, queueSandboxCreationCleanup, recordSandboxCreationResource, recoverSandboxCreations } from "../services/sandbox-creation-operations.js"; +import { environmentService } from "../services/environments.js"; +import { environmentRuntimeService } from "../services/environment-runtime.js"; +import { createHeartbeatRecovery, type HeartbeatRecoveryDependencies } from "../services/heartbeat/recovery.js"; + +const describePostgres = recoveryPostgresSupport.supported ? describe : describe.skip; + +describePostgres("durable cleanup after a native startup timeout", () => { + let temporary: Awaited>; + let db: ReturnType; + let home: ReturnType; + const originalHome = process.env.PAPERCLIP_HOME; + const companyId = randomUUID(), agentId = randomUUID(); + + beforeAll(async () => { + home = createIsolatedTestHome(); + process.env.PAPERCLIP_HOME = home.home; + temporary = await startRecoveryPostgres("native-startup-cleanup-"); + db = createDb(temporary.connectionString); + await db.insert(companies).values({ id: companyId, name: "Startup cleanup", issuePrefix: "NSC" }); + await db.insert(agents).values({ id: agentId, companyId, name: "Runner", role: "engineer", status: "running", + adapterType: "paperclip_runner", adapterConfig: { provider: "codex" }, runtimeConfig: {}, permissions: {} }); + }, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS); + + afterAll(async () => { + await temporary?.cleanup(); + home?.cleanup(); + if (originalHome === undefined) delete process.env.PAPERCLIP_HOME; + else process.env.PAPERCLIP_HOME = originalHome; + }); + + async function fixture(requiresPreparationStop = false) { + const runId = randomUUID(), issueId = randomUUID(), leaseId = randomUUID(), taskId = randomUUID(); + const contextId = randomUUID(), leaseOwner = randomUUID(); + await db.insert(issues).values({ id: issueId, companyId, identifier: `NSC-${issueId}`, title: "Timed out startup", + status: "in_progress", priority: "medium", assigneeAgentId: agentId }); + const [run] = await db.insert(heartbeatRuns).values({ id: runId, companyId, agentId, status: "running", + runtimeMode: "native", nativeIssueId: issueId, invocationSource: "manual", contextSnapshot: { issueId } }).returning(); + await db.update(issues).set({ executionRunId: runId }).where(eq(issues.id, issueId)); + await prepareNativeHeartbeatRun({ db, run, issue: { id: issueId, title: "Timed out startup", description: null }, environmentLeaseId: leaseId }); + await db.insert(nativeRunFinalizations).values({ runId, companyId, issueId, phase: "observed", attempt: 1, + controllerGeneration: 1, controllerBootId: randomUUID(), controllerPid: process.pid, + controllerProcessStartedAt: new Date(), leaseOwner, leaseExpiresAt: new Date(Date.now() + 60_000) }); + const [environment] = await db.insert(environments).values({ name: `Cleanup ${runId}`, driver: "plugin", status: "active", config: {} }).returning(); + await db.insert(environmentLeases).values({ id: leaseId, companyId, environmentId: environment.id, heartbeatRunId: runId, + issueId, status: "active", provider: "plugin", providerLeaseId: taskId, leasePolicy: "reuse_by_environment", + metadata: { runnerTaskLease: true, runnerTaskReused: true } }); + const request = { companyId, agentId, runId, contextId, leaseOwner, deadlineAtMs: Date.now() - 1, requiresPreparationStop }; + const reload = () => db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, runId)).then(rows => rows[0]!); + const owner = () => db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, runId)).then(rows => rows[0]!); + const lease = () => db.select().from(environmentLeases).where(eq(environmentLeases.id, leaseId)).then(rows => rows[0]!); + const stopReceipt = async (override: Record = {}, preparationStopped = false) => { + const current = await lease(); + const receipt = remoteTerminationReceipt(current, { providerLeaseId: taskId, state: "stopped" }); + await db.update(environmentLeases).set({ status: "released", releasedAt: new Date(), cleanupStatus: "success", + metadata: { ...current.metadata, ...(preparationStopped ? { runnerTaskPreparationStopped: true } : {}), remoteExecutionTermination: { ...receipt, ...override } } }).where(eq(environmentLeases.id, leaseId)); + }; + const acceptedResult = async () => { + const current = await reload(), resultId = randomUUID(); + await db.insert(nativeRunResults).values({ id: resultId, companyId, issueId, runId, + completionContractId: current.completionContractId!, serverFingerprint: resultId, schemaStatus: "accepted", + resultJson: { schema: "paperclip.run_result.v1", reportedWorkDisposition: "done", summary: "Completed work" }, canonicalSha256: "a".repeat(64) }); + await db.update(nativeRunFinalizations).set({ resultId, phase: "workspace_finalizing" }).where(eq(nativeRunFinalizations.runId, runId)); + return resultId; + }; + return { request, reload, owner, lease, stopReceipt, acceptedResult }; + } + + async function saveEarlyContext(f: Awaited>) { + const run = await f.reload(), owner = await f.owner(), lease = await f.lease(); + const context = { schema: "paperclip.native-startup-context.v1", companyId, agentId, runId: run.id, + contextId: f.request.contextId, deadlineAtMs: f.request.deadlineAtMs, leaseId: lease.id, + leaseOwner: owner.leaseOwner, controllerGeneration: owner.controllerGeneration, attempt: owner.attempt }; + await db.update(heartbeatRuns).set({ runnerProfileJson: { ...run.runnerProfileJson, nativeStartupContext: context } }).where(eq(heartbeatRuns.id, run.id)); + return context; + } + + it.each(["pending", "needs_reconciliation"])("keeps ownership until a %s replacement queued after the first teardown snapshot is verified stopped", async state => { + const f = await fixture(true), original = await f.lease(); + let reply!: (result: { providerLeaseId: string }) => void, creating!: () => void; + const entered = new Promise(resolve => { creating = resolve; }); + const acquiring = createOwnedSandbox(db, { companyId, environmentId: original.environmentId!, heartbeatRunId: f.request.runId, + issueId: original.issueId, provider: original.provider!, driverKey: "tasks", config: {}, requestKey: original.providerLeaseId!, + metadata: { runnerTaskLease: true, runnerTaskCreationContextId: f.request.contextId } }, async () => new Promise(resolve => { reply = resolve; creating(); })); + await entered; + await requestNativeStartupCleanup(db, f.request); + await f.stopReceipt({}, true); + await expect(verifyNativeStartupCleanup(db, await f.reload(), async () => {})).rejects.toThrow("cleanup is still pending"); + const [pending] = await db.select().from(sandboxCreationOperations).where(and( + eq(sandboxCreationOperations.runId, f.request.runId), eq(sandboxCreationOperations.requestKey, original.providerLeaseId!))); + if (state === "needs_reconciliation") { + await db.update(sandboxCreationOperations).set({ nextAttemptAt: new Date(0) }).where(eq(sandboxCreationOperations.id, pending.id)); + await recoverSandboxCreations(db, async () => null); + expect((await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, pending.id)))[0].state).toBe(state); + const inspect = vi.fn(async () => null); + await recoverSandboxCreations(db, inspect); + expect(inspect).not.toHaveBeenCalled(); + await expect(queueSandboxCreationCleanup(db, { id: pending.id, companyId, environmentId: original.environmentId!, + providerLeaseId: "unproven-task" })).rejects.toThrow("ownership changed"); + } + reply({ providerLeaseId: "late-replacement" }); + const fresh = await acquiring; + await recordSandboxCreationResource(db, { id: String(fresh.metadata!.creationOperationId), companyId, + environmentId: original.environmentId!, providerLeaseId: fresh.providerLeaseId, providerMetadata: { binding: "actual" } }); + if (state === "pending") await db.update(sandboxCreationOperations).set({ nextAttemptAt: new Date(0) }) + .where(eq(sandboxCreationOperations.id, String(fresh.metadata!.creationOperationId))); + expect(await nextEnvironmentCleanupAt(db)).not.toBeNull(); + const restarted = createDb(temporary.connectionString); + try { await recoverSandboxCreations(restarted, async () => { throw new Error("A recorded task identity needs no new provider inspection"); }); } + finally { await restarted.$client.end(); } + const [creation] = await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, String(fresh.metadata!.creationOperationId))); + await expect(verifyNativeStartupCleanup(db, await f.reload(), async () => {})).rejects.toThrow("cleanup is still pending"); + const replacement = (await environmentService(db).getLeaseById(creation.leaseId!))!; + await queueSandboxCreationCleanup(db, { id: creation.id, companyId, environmentId: original.environmentId!, providerLeaseId: fresh.providerLeaseId }); + expect((await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, creation.id)))[0].leaseId).toBe(replacement.id); + await expect(queueSandboxCreationCleanup(db, { id: creation.id, companyId, environmentId: original.environmentId!, providerLeaseId: "foreign-task" })).rejects.toThrow("ownership changed"); + await environmentService(db).releaseLease(replacement.id, "released", { cleanupStatus: "success", + remoteExecutionTermination: remoteTerminationReceipt(replacement, { providerLeaseId: replacement.providerLeaseId, state: "stopped" }) }); + expect((await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, creation.id)))[0].state).toBe("resolved"); + await queueSandboxCreationCleanup(db, { id: creation.id, companyId, environmentId: original.environmentId!, providerLeaseId: fresh.providerLeaseId }); + expect((await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, creation.id)))[0]) + .toMatchObject({ state: "resolved", leaseId: replacement.id }); + await verifyNativeStartupCleanup(db, await f.reload(), async () => {}); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await acknowledgeNativeStartupCleanup(db, f.request); + expect((await f.owner()).leaseOwner).toBeNull(); + }); + + it.each(["before_inventory", "before_write", "complete_before_write", "ordinary"])("preserves startup cleanup through orphan recovery: %s", async phase => { + const f = await fixture(), deps = callbacks(db); + await db.update(nativeRunFinalizations).set({ phase: "terminal_failure", leaseExpiresAt: new Date(0) }) + .where(eq(nativeRunFinalizations.runId, f.request.runId)); + if (phase === "before_inventory") await requestNativeStartupCleanup(db, f.request); + const write = deps.setRunStatusFromLive.getMockImplementation()!; + deps.setRunStatusFromLive.mockImplementation(async (...args) => { + if (phase === "before_write" || phase === "complete_before_write") { + await requestNativeStartupCleanup(db, f.request); + if (phase === "complete_before_write") await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt()); + } + return write(...args); + }); + const recovery = createHeartbeatRecovery(db, { ...deps, environmentRuntime: environmentRuntimeService(db), + environmentsSvc: environmentService(db), runtimeEnv: {}, activeRunExecutionPromises: new Set>(), + mergeRunStopMetadataForAgent: (_agent: unknown, _status: unknown, options: { resultJson?: object }) => options?.resultJson, + classifyAndPersistRunLiveness: async (run: unknown) => run, releaseEnvironmentLeasesForRun: vi.fn(), + releaseIssueExecutionAndPromote: vi.fn(), scheduleInteractionContinuationInfrastructureRetryIfEligible: async () => null, + } as unknown as HeartbeatRecoveryDependencies); + await recovery.recoverActiveExecutions({ runId: f.request.runId }, { staleThresholdMs: 0 }); + expect((await f.reload()).status).toBe(phase === "ordinary" ? "failed" : "running"); + if (phase === "ordinary") return; + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + deps.verifyStartupCleanup = run => verifyNativeStartupCleanup(db, run, () => f.stopReceipt()); + expect(await createHeartbeatRunControl(db, deps).cancelRunInternal(f.request.runId, "Startup cleanup retry")) + .toMatchObject({ status: "cancelled" }); + expect((await f.owner()).leaseOwner).toBeNull(); + }); + + it.each(["request", "acknowledge"])("registers queue intent before cleanup %s writes", async phase => { + const f = await fixture(true); + const writes: boolean[][] = []; + const observe = async (queues: string[], work: () => Promise) => { + const transaction = db.transaction.bind(db); + const spy = vi.spyOn(db, "transaction").mockImplementation(((callback: (tx: typeof db) => Promise) => transaction(async tx => { + const update = tx.update.bind(tx); + tx.update = ((table: unknown) => { + if ([heartbeatRuns, nativeRunFinalizations, environmentLeases].includes(table as never)) { + writes.push(queues.map(queue => databaseWorkPending(db, queue))); + } + return update(table as never); + }) as typeof tx.update; + return callback(tx as unknown as typeof db); + })) as typeof db.transaction); + try { await work(); } finally { spy.mockRestore(); } + }; + if (phase === "request") { + await observe([DELIVERY_QUEUES.executionFinalization, DELIVERY_QUEUES.environmentCleanup], () => requestNativeStartupCleanup(db, f.request)); + expect(writes).toEqual([[true, true], [true, true], [true, true]]); + await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt({}, true)); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await acknowledgeNativeStartupCleanup(db, f.request); + } else { + await requestNativeStartupCleanup(db, f.request); + await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt({}, true)); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await observe([DELIVERY_QUEUES.agentLifecycle, DELIVERY_QUEUES.environmentCleanup], () => acknowledgeNativeStartupCleanup(db, f.request)); + expect(writes).toEqual([[true, true]]); + } + }); + + it("returns the deadline queue to quiet and wakes again for the next startup failure", async () => { + const schedule = executionControlSchedule(db); + expect(await schedule.finalization()).toBeNull(); + for (let failure = 0; failure < 2; failure += 1) { + const f = await fixture(true); + await requestNativeStartupCleanup(db, f.request); + expect(await schedule.finalization()).not.toBeNull(); + const deps = callbacks(db); + deps.verifyStartupCleanup = run => verifyNativeStartupCleanup(db, run, () => f.stopReceipt({}, true)); + const control = createHeartbeatRunControl(db, deps); + await reconcileAbandonedExecutionControl(db, new Date(Date.now() + 1_000), { startupCleanup: async scope => { + if (scope.runId !== f.request.runId) return; + await control.cancelRunInternal(scope.runId, "Startup cleanup retry"); + await acknowledgeNativeStartupCleanup(db, scope); + } }); + expect((await f.reload()).status).toBe("cancelled"); + expect(await f.owner()).toMatchObject({ leaseOwner: null, controlDeadlineAt: null }); + expect(await schedule.finalization()).toBeNull(); + } + }); + + it("discovers a crash after warm prepare dispatch but before a cleanup intent was recorded", async () => { + const f = await fixture(true), lease = await f.lease(); + await db.update(environmentLeases).set({ metadata: { ...lease.metadata, runnerTaskStartup: { + contextId: f.request.contextId, deadlineAtMs: f.request.deadlineAtMs, runId: f.request.runId, + } } }).where(eq(environmentLeases.id, lease.id)); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() - 1_000) }) + .where(eq(nativeRunFinalizations.runId, f.request.runId)); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + const onClaim = vi.fn(); + const result = await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() }, onClaim }); + expect(result).toEqual([{ kind: "blocked", runId: f.request.runId, reason: NATIVE_STARTUP_CLEANUP_PENDING }]); + expect(onClaim).not.toHaveBeenCalled(); + expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ contextId: f.request.contextId, + state: "pending", requiresPreparationStop: true }); + expect(isNativeRunnerOwnershipHeld(await f.reload())).toBe(false); + }); + + it.each(["wrong_run", "future_deadline", "live_owner", "checkpointed", "missing_marker"])( + "does not infer a timed-out startup from %s", async variant => { + const f = await fixture(true), lease = await f.lease(); + if (variant !== "missing_marker") await db.update(environmentLeases).set({ metadata: { ...lease.metadata, + runnerTaskStartup: { contextId: f.request.contextId, runId: variant === "wrong_run" ? randomUUID() : f.request.runId, + deadlineAtMs: variant === "future_deadline" ? Date.now() + 60_000 : f.request.deadlineAtMs }, + } }).where(eq(environmentLeases.id, lease.id)); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() + (variant === "live_owner" ? 60_000 : -1_000)) }) + .where(eq(nativeRunFinalizations.runId, f.request.runId)); + if (variant === "checkpointed") await db.update(heartbeatRuns).set({ sessionIdAfter: "current-run-checkpoint" }) + .where(eq(heartbeatRuns.id, f.request.runId)); + await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() } }); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + }); + + it("persists an audited cancellation intent that a new database handle can recover without a generic hold", async () => { + const f = await fixture(); + expect(await requestNativeStartupCleanup(db, f.request)).toBe(true); + const run = await f.reload(), marker = readNativeStartupCleanup(run)!; + expect(marker).toMatchObject({ state: "pending", contextId: f.request.contextId, leaseOwner: f.request.leaseOwner, + controllerGeneration: 1, attempt: 1, taskId: (await f.lease()).providerLeaseId }); + expect(run).toMatchObject({ status: "running", errorCode: NATIVE_STARTUP_CLEANUP_PENDING }); + expect(run.resultJson?.startupCancellation).toMatchObject({ requestedAt: expect.any(String) }); + expect(isNativeRunnerOwnershipHeld(run)).toBe(false); + expect(await db.select({ id: activityLog.id }).from(activityLog).where(and(eq(activityLog.id, marker.auditId), + eq(activityLog.companyId, companyId), eq(activityLog.action, "native.startup_cleanup_requested")))).toHaveLength(1); + const restarted = createDb(temporary.connectionString), release = vi.fn(f.stopReceipt); + await verifyNativeStartupCleanup(restarted, await f.reload(), release); + await verifyNativeStartupCleanup(restarted, await f.reload(), release); + expect(release).toHaveBeenCalledOnce(); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + await acknowledgeNativeStartupCleanup(restarted, { companyId, runId: run.id }); + expect((await f.owner()).controlDeadlineAt).not.toBeNull(); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, run.id)); + await acknowledgeNativeStartupCleanup(restarted, { companyId, runId: run.id }); + expect(await f.owner()).toMatchObject({ leaseOwner: null, leaseExpiresAt: null, controlDeadlineAt: null, recoveryState: null }); + }); + + it("keeps cleanup bound to the explicit current lease when a released alias belongs to the same run", async () => { + const f = await fixture(true), current = await f.lease(); + const aliasId = randomUUID(); + await db.insert(environmentLeases).values({ ...current, id: aliasId, providerLeaseId: randomUUID(), + status: "released", releasedAt: new Date(), cleanupStatus: "success" }); + expect(await requestNativeStartupCleanup(db, { ...f.request, leaseId: current.id })).toBe(true); + expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ leaseId: current.id, taskId: current.providerLeaseId }); + expect((await db.select().from(environmentLeases).where(eq(environmentLeases.id, aliasId)))[0]?.metadata?.runnerTaskStartupCleanup).toBeUndefined(); + }); + + it("recovers an exact Stop receipt committed before Core records completion", async () => { + const f = await fixture(); + await requestNativeStartupCleanup(db, f.request); + await f.stopReceipt(); + const release = vi.fn(async () => { throw new Error("Already retired task must not be released twice"); }); + await verifyNativeStartupCleanup(createDb(temporary.connectionString), await f.reload(), release); + expect(release).not.toHaveBeenCalled(); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + }); + + it("keeps accelerated preparation pending when only the provider has stopped", async () => { + const f = await fixture(true); + await requestNativeStartupCleanup(db, f.request); + await expect(verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt())).rejects.toThrow(/pending|preparation/i); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + }); + + it("automatically finishes pending cleanup after a late real worker reply and exact preparation Stop proof", async () => { + const f = await fixture(true), lease = await f.lease(); + const entrypointPath = path.join(home.home, `cleanup-worker-${f.request.runId}.cjs`); + await writeFile(entrypointPath, ` +const rl=require("node:readline").createInterface({input:process.stdin,crlfDelay:Infinity}); +const held=[];let stopped=false; +const send=(id,result)=>process.stdout.write(JSON.stringify({jsonrpc:"2.0",id,result})+"\\n"); +rl.on("line",line=>{const m=JSON.parse(line); + if(m.method==="initialize")send(m.id,{ok:true,supportedMethods:["environmentTask","configChanged"]}); + else if(m.method==="environmentTask"){ + const kind=m.params.operation.kind; + if(kind==="prepare")held.push(m.id); + else if(kind==="status")send(m.id,{kind:"status",taskId:m.params.taskId,phase:stopped?"cancelled":"running",executionStopped:stopped,preparationStopped:stopped&&held.length===0}); + else {if(kind==="stop")stopped=true;send(m.id,{kind:"accepted",taskId:m.params.taskId});} + }else if(m.method==="configChanged"){for(const id of held.splice(0))send(id,{});send(m.id,{});} + else if(m.method==="shutdown"){send(m.id,{});setImmediate(()=>process.exit(0));} +}); +`, { mode: 0o600 }); + const manifest: PaperclipPluginManifestV1 = { id: "test.startup-cleanup", apiVersion: 1, version: "1.0.0", + displayName: "Cleanup fixture", description: "Cleanup fixture", author: "Paperclip", categories: ["automation"], + capabilities: [], entrypoints: { worker: "worker.cjs" } }; + const manager = createPluginWorkerManager(); + await manager.startWorker(manifest.id, { entrypointPath, manifest, config: {}, + instanceInfo: { instanceId: "cleanup", hostVersion: "1.0.0" }, apiVersion: 1, hostHandlers: {} }); + const context = new NativeExecutionContext({ binding: { companyId, agentId, runId: f.request.runId } } as NativeExecutionInput, 100); + const params = { companyId, agentId, runId: f.request.runId, environmentId: lease.environmentId, issueId: lease.issueId, + driverKey: "tasks", taskId: lease.providerLeaseId!, config: {}, projectIds: [], lease: { providerLeaseId: lease.providerLeaseId! } }; + const operation = { kind: "prepare", projectIds: [], requirements: { schema: "paperclip.runner.launch-requirements.v1", + identity: { runnerInstanceId: "fixture", environmentLeaseId: lease.id, runId: f.request.runId, + normalizedSessionId: "session", turnId: "turn", itemId: "item" }, provider: "codex", model: null, + instructions: "Synthetic", runtimeContext: null, settings: {}, approvalPolicy: "never", readOnly: false, + preparedConversation: false, includeCollaborationModeInstructions: false } } as PluginEnvironmentTaskOperation; + const release = async () => { + await manager.call(manifest.id, "environmentTask", { ...params, operation: { kind: "stop" } }); + const status = await manager.call(manifest.id, "environmentTask", { ...params, operation: { kind: "status" } }); + if (status.kind === "status" && status.executionStopped && status.preparationStopped) { + await manager.call(manifest.id, "environmentTask", { ...params, operation: { kind: "complete" } }); + await f.stopReceipt({}, true); + } + }; + try { + await expect(manager.call(manifest.id, "environmentTask", { ...params, operation }, 10, undefined, context.trackWorker())).rejects.toThrow("timed out"); + if (!context.signal.aborted) await new Promise(resolve => context.signal.addEventListener("abort", () => resolve(), { once: true })); + expect(context.pending).toBe(true); + expect(await requestNativeStartupCleanup(db, { ...f.request, contextId: context.id, deadlineAtMs: context.deadlineAtMs })).toBe(true); + expect(isNativeRunnerOwnershipHeld(await f.reload())).toBe(false); + await expect(cancelNativeSession(f.request.runId, "Startup timeout", { db, scope: "run" })).resolves.toMatchObject({ auditId: expect.any(String) }); + await expect(verifyNativeStartupCleanup(db, await f.reload(), release)).rejects.toThrow("pending"); + expect((await f.reload()).status).toBe("running"); + await manager.call(manifest.id, "configChanged", { companyId, config: { release: true } }); + expect(context.pending).toBe(false); + await verifyNativeStartupCleanup(createDb(temporary.connectionString), await f.reload(), release); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + expect((await f.lease()).metadata?.runnerTaskPreparationStopped).toBe(true); + } finally { context.finish(); await manager.stopAll(); } + }); + + it.each([false, true])("verifies an abandoned ephemeral startup without an inactive-owner acknowledgement (receipt=%s)", async stopped => { + const prior = process.env.PAPERCLIP_EPHEMERAL_SERVER; + process.env.PAPERCLIP_EPHEMERAL_SERVER = "true"; + try { + const f = await fixture(true); + await requestNativeStartupCleanup(db, f.request); + const deps = callbacks(db); + deps.verifyStartupCleanup = vi.fn(run => verifyNativeStartupCleanup(db, run, async () => { if (stopped) await f.stopReceipt({}, true); })); + const control = createHeartbeatRunControl(db, deps); + if (stopped) { + expect(await control.cancelRunInternal(f.request.runId, "Startup timeout")).toMatchObject({ status: "cancelled" }); + expect((await f.owner()).leaseOwner).toBeNull(); + } else { + await expect(control.cancelRunInternal(f.request.runId, "Startup timeout")).rejects.toThrow("Task cleanup is still pending"); + expect((await f.reload()).status).toBe("running"); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + } + expect(deps.verifyStartupCleanup).toHaveBeenCalled(); + } finally { + if (prior === undefined) delete process.env.PAPERCLIP_EPHEMERAL_SERVER; + else process.env.PAPERCLIP_EPHEMERAL_SERVER = prior; + } + }, 30_000); + + it("terminalizes through assembled run control only after verified cleanup succeeds", async () => { + const f = await fixture(true); + await requestNativeStartupCleanup(db, f.request); + let drained = false; + const deps = callbacks(db); + deps.verifyStartupCleanup = run => verifyNativeStartupCleanup(db, run, () => f.stopReceipt({}, drained)); + const control = createHeartbeatRunControl(db, deps); + await expect(control.cancelRunInternal(f.request.runId, "Startup timeout")).rejects.toThrow("pending"); + expect(await f.reload()).toMatchObject({ status: "running", errorCode: NATIVE_STARTUP_CLEANUP_PENDING }); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + drained = true; + const result = await control.cancelRunInternal(f.request.runId, "Startup timeout"); + expect(result).toMatchObject({ status: "cancelled" }); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + expect(await f.owner()).toMatchObject({ leaseOwner: null, leaseExpiresAt: null, controlDeadlineAt: null }); + }); + + it("joins cleanup recorded while an operator Stop waits for native startup", async () => { + const f = await fixture(true); + let entered!: () => void, resume!: () => void; + const waiting = new Promise(resolve => { entered = resolve; }); + const settled = new Promise(resolve => { resume = resolve; }); + const cancel = nativeSessionExecutor.cancelNativeSession; + const spy = vi.spyOn(nativeSessionExecutor, "cancelNativeSession").mockImplementation(async (...args) => { + const result = await cancel(...args); + if (args[0] === f.request.runId) { entered(); await settled; } + return result; + }); + let drained = false; + const deps = callbacks(db); + deps.verifyStartupCleanup = vi.fn(run => verifyNativeStartupCleanup(db, run, () => f.stopReceipt({}, drained))); + const control = createHeartbeatRunControl(db, deps); + try { + const stopping = control.cancelRunInternal(f.request.runId, "Operator Stop"); + const outcome = stopping.then(value => ({ value }), error => ({ error })); + await waiting; + expect(await requestNativeStartupCleanup(db, f.request)).toBe(true); + resume(); + expect(await outcome).toMatchObject({ error: expect.objectContaining({ message: "Task cleanup is still pending" }) }); + expect(deps.verifyStartupCleanup).toHaveBeenCalledOnce(); + expect((await f.reload()).status).toBe("running"); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + drained = true; + expect(await control.cancelRunInternal(f.request.runId, "Operator Stop")).toMatchObject({ status: "cancelled" }); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + expect((await f.owner()).leaseOwner).toBeNull(); + } finally { resume(); spy.mockRestore(); } + }); + + it("rejects a cancellation commit when cleanup arrives after its final read", async () => { + const f = await fixture(true); + const deps = callbacks(db), commit = deps.setRunStatusFromLive.getMockImplementation()!; + deps.setRunStatusFromLive.mockImplementationOnce(async (...args) => { + expect(await requestNativeStartupCleanup(db, f.request)).toBe(true); + return commit(...args); + }); + deps.verifyStartupCleanup = vi.fn(run => verifyNativeStartupCleanup(db, run, () => f.stopReceipt({}, true))); + const control = createHeartbeatRunControl(db, deps); + expect(await control.cancelRunInternal(f.request.runId, "Operator Stop")).toMatchObject({ status: "running" }); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + expect(deps.startNextQueuedRunForAgent).not.toHaveBeenCalled(); + expect(await control.cancelRunInternal(f.request.runId, "Operator Stop")).toMatchObject({ status: "cancelled" }); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + expect((await f.owner()).leaseOwner).toBeNull(); + }); + + it("restarts the real cancellation flow after remote Stop committed before Core acknowledgement", async () => { + const f = await fixture(true); + await requestNativeStartupCleanup(db, f.request); + await f.stopReceipt({}, true); + const restarted = createDb(temporary.connectionString), release = vi.fn(async () => { throw new Error("Stop receipt already persisted"); }); + const deps = callbacks(restarted); + deps.verifyStartupCleanup = run => verifyNativeStartupCleanup(restarted, run, release); + const control = createHeartbeatRunControl(restarted, deps); + const reconcile = vi.fn(async (scope: { companyId: string; runId: string }) => { + if (scope.runId !== f.request.runId) return; + expect(scope.companyId).toBe(companyId); + await control.cancelRunInternal(scope.runId, "Startup timeout recovered after restart"); + await acknowledgeNativeStartupCleanup(restarted, scope); + }); + await reconcileAbandonedExecutionControl(restarted, new Date(Date.now() + 1_000), { startupCleanup: reconcile }); + expect(reconcile.mock.calls.some(([scope]) => scope.runId === f.request.runId)).toBe(true); + expect(release).not.toHaveBeenCalled(); + expect((await f.reload()).status).toBe("cancelled"); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("complete"); + expect(await f.owner()).toMatchObject({ leaseOwner: null, leaseExpiresAt: null, controlDeadlineAt: null }); + }); + + it.each(["providerLeaseId", "runId", "leaseId"])("rejects a Stop receipt for another %s", async field => { + const f = await fixture(); + await requestNativeStartupCleanup(db, f.request); + await expect(verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt({ [field]: randomUUID() }))).rejects.toThrow("pending"); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + }); + + it("does not issue a Stop against a newer controller generation", async () => { + const f = await fixture(); + await requestNativeStartupCleanup(db, f.request); + await db.update(nativeRunFinalizations).set({ controllerGeneration: 2 }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + const release = vi.fn(f.stopReceipt); + await expect(verifyNativeStartupCleanup(db, await f.reload(), release)).rejects.toThrow("ownership changed"); + expect(release).not.toHaveBeenCalled(); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + }); + + it("rejects a stale generation that changes while Stop is in flight", async () => { + const f = await fixture(); + await requestNativeStartupCleanup(db, f.request); + await expect(verifyNativeStartupCleanup(db, await f.reload(), async () => { + await f.stopReceipt(); + await db.update(nativeRunFinalizations).set({ controllerGeneration: 2 }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + })).rejects.toThrow("ownership changed"); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + }); + + it("preserves a final result that wins while verified cleanup is in flight", async () => { + const f = await fixture(); + await requestNativeStartupCleanup(db, f.request); + let resultId: string; + await expect(verifyNativeStartupCleanup(db, await f.reload(), async () => { + await f.stopReceipt(); + resultId = await f.acceptedResult(); + })).rejects.toThrow("ownership changed"); + expect(await f.owner()).toMatchObject({ resultId: resultId!, phase: "workspace_finalizing" }); + expect(readNativeStartupCleanup(await f.reload())?.state).toBe("pending"); + }); + + it.each(["native_adopted_runner_authentication_timeout", "native_execution_ownership_unverified"])("preserves the existing %s hold", async errorCode => { + const f = await fixture(); + await db.update(heartbeatRuns).set({ errorCode, nativePhase: "terminal_failure" }).where(eq(heartbeatRuns.id, f.request.runId)); + expect(await requestNativeStartupCleanup(db, f.request)).toBe(false); + const current = await f.reload(); + expect(current).toMatchObject({ status: "running", errorCode, nativePhase: "terminal_failure" }); + expect(readNativeStartupCleanup(current)).toBeNull(); + }); + + it("does not replace a final result with a timeout intent", async () => { + const f = await fixture(); + const resultId = await f.acceptedResult(); + expect(await requestNativeStartupCleanup(db, f.request)).toBe(false); + expect((await f.owner()).resultId).toBe(resultId); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + }); + it("promotes a pre-capability context before an ordinary deadline after the audited intent write fails", async () => { + const f = await fixture(); + await saveEarlyContext(f); + await db.execute(sql`create function reject_startup_intent() returns trigger language plpgsql as $$ begin + if new.action = 'native.startup_cleanup_requested' then raise exception 'Startup intent write unavailable'; end if; return new; end $$`); + await db.execute(sql`create trigger reject_startup_intent before insert on activity_log for each row execute function reject_startup_intent()`); + try { await expect(requestNativeStartupCleanup(db, f.request)).rejects.toThrow(); } + finally { await db.execute(sql`drop trigger reject_startup_intent on activity_log`); await db.execute(sql`drop function reject_startup_intent()`); } + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() - 1_000) }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + await db.update(heartbeatRuns).set({ executionControlDeadlineAt: new Date(Date.now() - 1_000) }).where(eq(heartbeatRuns.id, f.request.runId)); + await reconcileAbandonedExecutionControl(db); + expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ contextId: f.request.contextId, requiresPreparationStop: false, state: "pending" }); + expect((await f.reload()).status).toBe("running"); + expect((await f.owner()).leaseOwner).toBe(f.request.leaseOwner); + await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt()); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await acknowledgeNativeStartupCleanup(db, f.request); + }); + + it.each([false, true])("recovers an early context without replacing stronger preparation proof (prepared=%s)", async prepared => { + const f = await fixture(); + await saveEarlyContext(f); + if (prepared) { const lease = await f.lease(); await db.update(environmentLeases).set({ metadata: { ...lease.metadata, + runnerTaskStartup: { contextId: f.request.contextId, deadlineAtMs: f.request.deadlineAtMs, runId: f.request.runId } } }).where(eq(environmentLeases.id, lease.id)); } + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() - 1_000) }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + const onClaim = vi.fn(); + const result = await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() }, onClaim }); + expect(result).toEqual([{ kind: "blocked", runId: f.request.runId, reason: NATIVE_STARTUP_CLEANUP_PENDING }]); + expect(onClaim).not.toHaveBeenCalled(); + expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ requiresPreparationStop: prepared, state: "pending" }); + await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt({}, prepared)); + await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await acknowledgeNativeStartupCleanup(db, f.request); + }); + + it.each([false, true])("defers an early context to a concrete owner deadline (locally active=%s)", async active => { + const f = await fixture(); + await saveEarlyContext(f); + const owner = await f.owner(); + const result = await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + liveRunExecutions: active ? new Set([f.request.runId]) : undefined, + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() } }); + expect(result).toMatchObject([{ kind: "awaiting_evidence", runId: f.request.runId, retryAt: owner.leaseExpiresAt }]); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + }); + + it("does not turn an early context into cleanup after the current-run checkpoint", async () => { + const f = await fixture(); + await saveEarlyContext(f); + await db.update(heartbeatRuns).set({ sessionIdAfter: "current-checkpoint" }).where(eq(heartbeatRuns.id, f.request.runId)); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() - 1_000) }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() } }); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + }); + + + it("locks the selected lease before choosing the stronger preparation proof", async () => { + const f = await fixture(), lease = await f.lease(); + let changed!: () => void, commit!: () => void; + const written = new Promise(resolve => { changed = resolve; }); + const release = new Promise(resolve => { commit = resolve; }); + const preparing = db.transaction(async tx => { + await tx.update(environmentLeases).set({ metadata: { ...lease.metadata, runnerTaskStartup: { + contextId: f.request.contextId, deadlineAtMs: f.request.deadlineAtMs, runId: f.request.runId, + } } }).where(eq(environmentLeases.id, lease.id)); + changed(); + await release; + }); + await written; + const requesting = requestNativeStartupCleanup(db, f.request); + try { + await vi.waitFor(async () => { + const rows = await db.execute(sql`select query from pg_stat_activity where wait_event_type = 'Lock' + and query like 'select%from "environment_leases"%'`); + expect(rows.length).toBeGreaterThan(0); + }); + } finally { commit(); } + await preparing; + await requesting; + expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ requiresPreparationStop: true }); + await expect(verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt())).rejects.toThrow("pending"); + await verifyNativeStartupCleanup(db, await f.reload(), () => f.stopReceipt({}, true)); + }); + + it("clears only its owned startup context before fallback and leaves no expired cleanup authority", async () => { + const f = await fixture(); + await saveEarlyContext(f); + const scope = { companyId, runId: f.request.runId, contextId: f.request.contextId, + leaseOwner: f.request.leaseOwner, controllerGeneration: 1 }; + await expect(clearNativeStartupContext(db, { ...scope, controllerGeneration: 2 })).rejects.toThrow("lost authority"); + expect((await f.reload()).runnerProfileJson?.nativeStartupContext).toBeDefined(); + await clearNativeStartupContext(db, scope); + expect((await f.reload()).runnerProfileJson?.nativeStartupContext).toBeUndefined(); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: new Date(Date.now() - 1_000) }).where(eq(nativeRunFinalizations.runId, f.request.runId)); + await claimNativeRestartRecoveries({ db, restartKind: "hard", runIds: [f.request.runId], + controller: { bootId: randomUUID(), pid: process.pid, processStartedAt: new Date() } }); + expect(readNativeStartupCleanup(await f.reload())).toBeNull(); + }); + + it.each(["cleanup", "terminal"])("does not clear the startup breadcrumb after %s wins", async winner => { + const f = await fixture(); + await saveEarlyContext(f); + if (winner === "cleanup") await requestNativeStartupCleanup(db, f.request); + else await db.update(heartbeatRuns).set({ status: "cancelled" }).where(eq(heartbeatRuns.id, f.request.runId)); + await expect(clearNativeStartupContext(db, { companyId, runId: f.request.runId, contextId: f.request.contextId, + leaseOwner: f.request.leaseOwner, controllerGeneration: 1 })).rejects.toThrow("lost authority"); + expect((await f.reload()).runnerProfileJson?.nativeStartupContext).toBeDefined(); + if (winner === "cleanup") expect(readNativeStartupCleanup(await f.reload())).toMatchObject({ state: "pending" }); + }); + + it("requires exact task Stop proof when retrying cleanup of a never-dispatched replacement", async () => { + const f = await fixture(true), original = await f.lease(), pluginId = randomUUID(); + await db.insert(plugins).values({ id: pluginId, pluginKey: pluginId, packageName: "fixture-abandoned-task", version: "1", status: "ready", + manifestJson: { capabilities: ["environment.drivers.register"], environmentDrivers: [{ driverKey: "tasks", supportsTasks: true }] } as never }); + await db.update(environments).set({ companyId, config: { pluginKey: pluginId, driverKey: "tasks", driverConfig: {} } }) + .where(eq(environments.id, original.environmentId!)); + const fresh = await createOwnedSandbox(db, { companyId, environmentId: original.environmentId!, heartbeatRunId: f.request.runId, + issueId: original.issueId, provider: original.provider!, pluginId, driverKey: "tasks", config: {}, requestKey: original.providerLeaseId!, + metadata: { driver: "plugin", pluginId, pluginKey: pluginId, driverKey: "tasks", runnerTaskLease: true, agentId, + runnerTaskCreationContextId: f.request.contextId } }, async () => ({ providerLeaseId: "late-never-dispatched" })); + await queueSandboxCreationCleanup(db, { id: String(fresh.metadata!.creationOperationId), companyId, + environmentId: original.environmentId!, providerLeaseId: fresh.providerLeaseId }); + const creation = async () => (await db.select().from(sandboxCreationOperations).where(eq(sandboxCreationOperations.id, String(fresh.metadata!.creationOperationId))))[0]!; + const replacement = async () => (await environmentService(db).getLeaseById((await creation()).leaseId!))!; + expect((await replacement()).metadata?.runnerTaskDispatched).not.toBe(true); + await requestNativeStartupCleanup(db, { ...f.request, leaseId: original.id }); + await f.stopReceipt({}, true); + let proof: "void" | "running" | "foreign" | "exact" = "void"; + const calls: string[] = []; + const workers = { isRunning: () => true, getWorker: () => ({ supportedMethods: ["environmentTask", "environmentReleaseLease"] }), + drainStartup: vi.fn(async () => undefined), + call: async (_plugin: string, method: string, params: any) => { + calls.push(method === "environmentTask" ? params.operation.kind : method); + if (method === "environmentReleaseLease") return undefined; + if (params.operation.kind === "status") return proof === "void" ? undefined : { + kind: "status", taskId: proof === "foreign" ? "another-task" : params.taskId, + phase: proof === "running" ? "running" : "cancelled", executionStopped: proof !== "running", + }; + return { kind: "accepted", taskId: params.taskId }; + }, + } as unknown as PluginWorkerManager; + const runtime = environmentRuntimeService(db, { pluginWorkerManager: workers }); + const recovery = createHeartbeatRecovery(db, { ...callbacks(db), environmentRuntime: runtime, + environmentsSvc: environmentService(db), runtimeEnv: {}, activeRunExecutionPromises: new Set>(), + acknowledgeRemoteStop: async () => undefined, resumeRemoteStopComments: async () => undefined, + } as unknown as HeartbeatRecoveryDependencies); + const stopDeps = callbacks(db); + stopDeps.verifyStartupCleanup = run => verifyNativeStartupCleanup(db, run, async () => {}); + const control = createHeartbeatRunControl(db, stopDeps); + for (const missing of ["void", "running", "foreign"] as const) { + proof = missing; + const swept = await recovery.sweepPendingCleanupLeases({ explicitRetry: { companyId, runId: f.request.runId, actorId: "operator" } }); + const cancelled = await control.cancelRunInternal(f.request.runId, "Startup cleanup retry").then(() => true, () => false); + const lease = await replacement(); + expect({ destroyed: swept.destroyed, status: lease.status, verifiedReceipt: hasRemoteTerminationReceipt(lease), + creationState: (await creation()).state, cancelled, leaseOwner: (await f.owner()).leaseOwner }).toEqual({ + destroyed: 0, status: "pending_cleanup", verifiedReceipt: false, creationState: "cleanup_pending", cancelled: false, leaseOwner: f.request.leaseOwner, + }); + } + proof = "exact"; + expect((await recovery.sweepPendingCleanupLeases({ explicitRetry: { companyId, runId: f.request.runId, actorId: "operator" } })).destroyed).toBe(1); + expect(calls).toContain("stop"); + expect(calls).toContain("status"); + expect(calls).toContain("complete"); + expect(workers!.drainStartup).toHaveBeenCalledWith(f.request.contextId); + expect(hasRemoteTerminationReceipt(await replacement())).toBe(true); + expect((await creation()).state).toBe("resolved"); + expect(await control.cancelRunInternal(f.request.runId, "Startup cleanup retry")).toMatchObject({ status: "cancelled" }); + expect((await f.owner()).leaseOwner).toBeNull(); + }); + +}); diff --git a/server/src/index.ts b/server/src/index.ts index ffc3b2d9009..ce02001ecf9 100644 --- a/server/src/index.ts +++ b/server/src/index.ts @@ -81,6 +81,7 @@ import { deliverExecutionStatuses } from "./services/execution-status-delivery.j import { deliverReconciledExecutions, settleUnrecoverableExecutions } from "./services/execution-recovery-resolution.js"; import { reconcileSafeNativeReplacements } from "./services/native-runtime/native-safe-replacement.js"; import { reconcileAbandonedExecutionControl } from "./services/execution-control-reconciliation.js"; +import { acknowledgeNativeStartupCleanup } from "./services/native-runtime/native-startup-cleanup.js"; import { executionControlSchedule, registerExecutionControlWork } from "./services/execution-control-work.js"; import { connectionIntentDeliveryService } from "./services/connection-intent-delivery.js"; import { existsSync, readFileSync, rmSync } from "node:fs"; @@ -1376,7 +1377,12 @@ async function startServerWithDatabaseTeardown( const unsubscribeLocalLoginCleanup = localLoginCleanup.subscribeCleanupReady(localLoginCleanupWork.wake); server.on("close", unsubscribeLocalLoginCleanup); registerExecutionControlWork(deliveryWork, [ - { queue: DELIVERY_QUEUES.executionFinalization, run: () => reconcileAbandonedExecutionControl(db), next: executionSchedule.finalization }, + { queue: DELIVERY_QUEUES.executionFinalization, run: () => reconcileAbandonedExecutionControl(db, new Date(), { + startupCleanup: async scope => { + await accountingHeartbeat.cancelRun(scope.runId, "Native startup timed out; cancelling and verifying cleanup"); + await acknowledgeNativeStartupCleanup(db, scope); + }, + }), next: executionSchedule.finalization }, { queue: DELIVERY_QUEUES.executionStatus, run: () => deliverExecutionStatuses(db), next: executionSchedule.status }, { queue: DELIVERY_QUEUES.executionDisposition, run: () => settleUnrecoverableExecutions(db), next: executionSchedule.disposition }, ...(heartbeat ? [ diff --git a/server/src/services/environment-cleanup-state.ts b/server/src/services/environment-cleanup-state.ts index eae1d13fb4e..e9d1fa6bf5f 100644 --- a/server/src/services/environment-cleanup-state.ts +++ b/server/src/services/environment-cleanup-state.ts @@ -1,9 +1,19 @@ -import { eq, sql } from "drizzle-orm"; +import { and, eq, or, sql } from "drizzle-orm"; import { environmentLeases, sandboxCreationOperations, type Db } from "@paperclipai/db"; import { hasDeferredEnvironmentCleanup } from "./environment-cleanup-notifications.js"; export const ENVIRONMENT_CLEANUP_RETRY_MS = 5 * 60_000; +export function recoverableSandboxCreationCondition() { + return or(eq(sandboxCreationOperations.state, "pending"), and( + eq(sandboxCreationOperations.state, "needs_reconciliation"), + sql`coalesce(${sandboxCreationOperations.metadata}->>'creationReconciliationReason', '') <> 'company_deleted'`, + sql`${sandboxCreationOperations.metadata}->>'runnerTaskLease' = 'true'`, + sql`jsonb_typeof(${sandboxCreationOperations.metadata}->'runnerTaskCreationContextId') = 'string' and ${sandboxCreationOperations.metadata}->>'runnerTaskCreationContextId' <> ''`, + sql`jsonb_typeof(${sandboxCreationOperations.metadata}->'creationProviderLeaseId') = 'string' and ${sandboxCreationOperations.metadata}->>'creationProviderLeaseId' <> ''`, + )); +} + export function pendingCleanupDeadlineSql(now = Date.now()) { const deadline = sql`case when ${environmentLeases.metadata}->>'pendingCleanupInFlight' = 'true' @@ -21,7 +31,7 @@ export async function nextEnvironmentCleanupAt(db: Db, backoffMs = ENVIRONMENT_C extract(epoch from ${environmentLeases.updatedAt}) * 1000 + ${backoffMs}, ${pendingCleanupDeadlineSql()}))` }).from(environmentLeases).where(eq(environmentLeases.status, "pending_cleanup")); const [creation] = await db.select({ next: sql`min(extract(epoch from ${sandboxCreationOperations.nextAttemptAt}) * 1000)` }) - .from(sandboxCreationOperations).where(eq(sandboxCreationOperations.state, "pending")); + .from(sandboxCreationOperations).where(recoverableSandboxCreationCondition()); const deadlines = [row?.next, creation?.next].filter((value): value is string => value != null).map(Number); const saved = deadlines.length ? Math.min(...deadlines) : null; const buffered = hasDeferredEnvironmentCleanup(db) ? Date.now() + backoffMs : null; diff --git a/server/src/services/environment-runtime.ts b/server/src/services/environment-runtime.ts index 30acbbe1db5..7ffdb2c379a 100644 --- a/server/src/services/environment-runtime.ts +++ b/server/src/services/environment-runtime.ts @@ -3382,7 +3382,7 @@ function createPluginEnvironmentDriver( async releaseRunLease(input) { await db.update(environmentLeases).set({ metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || '{"pluginLeaseCleanupMethod":"release"}'::jsonb` }).where(and(eq(environmentLeases.id, input.lease.id), eq(environmentLeases.companyId, input.lease.companyId))); const taskStopped = await settleDispatchedEnvironmentTask(db, workerManager, input.lease) || - (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true); + (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true && !input.lease.metadata?.runnerTaskStartup && !input.lease.metadata?.runnerTaskStartupCleanup); const { plugin, driverKey, driverConfig } = await resolvePluginDriverForRelease(input); await workerManager.call(plugin.id, "environmentReleaseLease", { driverKey, @@ -3425,7 +3425,7 @@ function createPluginEnvironmentDriver( async destroyRunLease(input) { await db.update(environmentLeases).set({ metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || '{"pluginLeaseCleanupMethod":"destroy"}'::jsonb` }).where(and(eq(environmentLeases.id, input.lease.id), eq(environmentLeases.companyId, input.lease.companyId))); const taskStopped = await settleDispatchedEnvironmentTask(db, workerManager, input.lease) || - (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true); + (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true && !input.lease.metadata?.runnerTaskStartup && !input.lease.metadata?.runnerTaskStartupCleanup); const { pluginKey, driverKey, driverConfig } = await resolvePluginDriverForRelease(input); await destroyPluginEnvironmentLease({ db, @@ -3462,7 +3462,7 @@ function createPluginEnvironmentDriver( async retryPendingSandboxTeardown(input) { const taskStopped = await settleDispatchedEnvironmentTask(db, workerManager, input.lease) || - (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true); + (input.lease.metadata?.runnerTaskLease === true && input.lease.metadata?.runnerTaskDispatched !== true && !input.lease.metadata?.runnerTaskStartup && !input.lease.metadata?.runnerTaskStartupCleanup); const { plugin, driverKey, driverConfig } = await resolvePluginDriverForRelease(input); const environmentId = input.environment?.id ?? readString(input.lease.metadata?.environmentId); if (!environmentId) throw new Error("Plugin lease cleanup has no saved environment identity"); @@ -3778,7 +3778,7 @@ export function environmentRuntimeService( }, /** Dispatch plugin-provided Runner execution, including resource preparation and task lifecycle. */ - async task(input: { companyId: string; leaseId: string; operation: PluginEnvironmentTaskOperation }) { + async task(input: { companyId: string; leaseId: string; operation: PluginEnvironmentTaskOperation; executionContext?: unknown }) { if (!options.pluginWorkerManager) throw new Error("Plugin-provided Runner execution worker manager unavailable"); return executeEnvironmentTask(db, options.pluginWorkerManager, input); }, diff --git a/server/src/services/environment-task-runtime.ts b/server/src/services/environment-task-runtime.ts index 3595d00b430..1ef71b839d2 100644 --- a/server/src/services/environment-task-runtime.ts +++ b/server/src/services/environment-task-runtime.ts @@ -1,15 +1,17 @@ import { attachSandboxCreation, environmentService } from "./environments.js"; -import { createOwnedSandbox, recordSandboxCreationResource } from "./sandbox-creation-operations.js"; +import { createOwnedSandbox, queueSandboxCreationCleanup, recordSandboxCreationResource } from "./sandbox-creation-operations.js"; import { writeEnvironmentCleanup } from "./environment-cleanup-notifications.js"; import { releaseProviderRecoveryTransfers, stageProviderFreshWorkspace } from "./provider-fresh-workspace.js"; import { readWorkspaceProviderBinding } from "@paperclipai/shared"; import { settlePluginTaskCredentialHandoff } from "./plugin-task-credential-writeback.js"; import { and, eq, inArray, or, sql } from "drizzle-orm"; import { environmentLeases, executionWorkspaces, environments, heartbeatRuns, issues, projects, type Db } from "@paperclipai/db"; -import { freshWorkspaceSchema, environmentTaskOperationSchema, parseEnvironmentTaskResult, type PluginEnvironmentTaskOperation } from "@paperclipai/plugin-sdk"; +import { freshWorkspaceSchema, environmentTaskOperationSchema, parseEnvironmentTaskResult, + type HostToWorkerMethodName, type HostToWorkerMethods, type PluginEnvironmentTaskOperation } from "@paperclipai/plugin-sdk"; import { pluginRegistryService } from "./plugin-registry.js"; import { hasRemoteTerminationReceipt, remoteExecutionHasStopped, remoteTerminationReceipt } from "./remote-execution-termination.js"; import type { PluginWorkerManager } from "./plugin-worker-manager.js"; +import { NativeExecutionContext } from "./native-runtime/native-execution-context.js"; export async function pluginEnvironmentSupportsTasks(db: Db, workers: PluginWorkerManager, lease: { companyId: string; metadata: Record | null }) { const metadata = lease.metadata ?? {}; @@ -31,6 +33,7 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage companyId: string; leaseId: string; operation: PluginEnvironmentTaskOperation; + executionContext?: unknown; }) { const operation = environmentTaskOperationSchema.parse(input.operation); const [row] = await db.select({ lease: environmentLeases, environment: environments, run: heartbeatRuns }) @@ -40,6 +43,13 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage .where(and(eq(environmentLeases.id, input.leaseId), eq(environmentLeases.companyId, input.companyId))).limit(1); if (!row || !row.lease.providerLeaseId) throw new Error("Plugin-provided Runner execution lease unavailable"); const { lease, environment, run } = row; + const context = input.executionContext; + if (context !== undefined) { + if (!(context instanceof NativeExecutionContext) || !run) { + throw new Error("native_execution_context_unavailable"); + } + context.assertScope({ companyId: input.companyId, agentId: run.agentId, runId: run.id }); + } const taskId = row.lease.providerLeaseId; const metadata = lease.metadata ?? {}; const probe = metadata.runnerTaskProbe as { runId?: unknown; sessionId?: unknown; expiresAtMs?: unknown } | undefined; @@ -128,6 +138,19 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage !workers.getWorker(plugin.id)?.supportedMethods.includes("environmentTask")) { throw new Error("Plugin-provided Runner execution provider unavailable"); } + const callWorker = async (method: M, params: HostToWorkerMethods[M][0], timeout?: number): Promise => { + if (!context) { + const cleanup = metadata.runnerTaskStartupCleanup as { contextId?: unknown; requiresPreparationStop?: unknown } | undefined; + if (["stop", "status", "complete", "credentials"].includes(operation.kind) && typeof cleanup?.contextId === "string" && typeof cleanup.requiresPreparationStop === "boolean") { + return workers.call(plugin.id, method, params, timeout, undefined, undefined, cleanup.contextId); + } + return timeout === undefined ? workers.call(plugin.id, method, params) : workers.call(plugin.id, method, params, timeout); + } + const settled = context.trackWorker(); + const result = await workers.call(plugin.id, method, params, Math.max(1, Math.min(timeout ?? 15_000, context.deadlineAtMs - Date.now())), undefined, settled, context.id); + context.assertOpen(); + return result; + }; const issue = scopesProjects && lease.issueId ? await db.select({ id: issues.id }).from(issues) .where(and(eq(issues.id, lease.issueId), eq(issues.companyId, input.companyId))).limit(1).then(rows => rows[0]) : null; if (scopesProjects && lease.issueId && !issue) throw new Error("Plugin-provided Runner execution issue unavailable"); @@ -219,7 +242,7 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage } try { if (operation.kind === "describe" && metadata.runnerTaskReused === true) { - const state = parseEnvironmentTaskResult({kind:"status"}, taskId, await workers.call(plugin.id, "environmentTask", { + const state = parseEnvironmentTaskResult({kind:"status"}, taskId, await callWorker("environmentTask", { driverKey: metadata.driverKey, companyId: input.companyId, environmentId: environment?.id ?? null, issueId: lease.issueId, config: driverConfig, taskId, runId: run?.id ?? null, agentId: run?.agentId ?? null, projectIds, lease: {providerLeaseId: taskId, metadata}, operation:{kind:"status"}, @@ -233,37 +256,74 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage runnerTaskSessionRetained:state.sessionStateAvailable === true})}::jsonb`, }).where(and(eq(environmentLeases.id, metadata.runnerTaskPreviousLeaseId), eq(environmentLeases.companyId, input.companyId))); const replacementDriverKey = metadata.driverKey; + let abandoned = false; const fresh = await createOwnedSandbox(db, { companyId: input.companyId, environmentId: environment!.id, heartbeatRunId: lease.heartbeatRunId, issueId: lease.issueId, executionWorkspaceId: lease.executionWorkspaceId, provider: lease.provider!, pluginId: plugin.id, driverKey: metadata.driverKey, config: {}, requestKey: taskId, - metadata: { driver: "plugin", pluginId: plugin.id, pluginKey: plugin.pluginKey, driverKey: metadata.driverKey, runnerTaskLease: true }, - }, identity => workers.call(plugin.id, "environmentAcquireLease", {driverKey:replacementDriverKey, - companyId:input.companyId,environmentId:environment!.id,issueId:lease.issueId,config:driverConfig, - runId:identity.runId,creationOperationId:identity.id,agentId:run!.agentId,adapterType:"paperclip_runner", - ...(typeof metadata.runnerTaskRequestedExpiresAt === "string" ? {requestedExpiresAt:metadata.runnerTaskRequestedExpiresAt} : {})})); + metadata: { driver: "plugin", pluginId: plugin.id, pluginKey: plugin.pluginKey, driverKey: metadata.driverKey, + runnerTaskLease: true, agentId: run!.agentId, + ...(context ? { runnerTaskCreationContextId: context.id } : {}) }, + }, async identity => { + const params = { driverKey: replacementDriverKey, companyId: input.companyId, environmentId: environment!.id, + issueId: lease.issueId, config: driverConfig, runId: identity.runId, creationOperationId: identity.id, + agentId: run!.agentId, adapterType: "paperclip_runner", + ...(typeof metadata.runnerTaskRequestedExpiresAt === "string" ? { requestedExpiresAt: metadata.runnerTaskRequestedExpiresAt } : {}) }; + if (!context) return workers.call(plugin.id, "environmentAcquireLease", params, 30_000); + const settled = context.trackWorker(); + let observedResource: Parameters[1] | undefined; + let dispatched = false; + try { + return await context.wait(() => { + dispatched = true; + return workers.call(plugin.id, "environmentAcquireLease", params, 30_000, undefined, settled, context.id, + async result => { + if (!result.providerLeaseId || result.providerLeaseId === taskId) throw new Error("Plugin replacement task identity unavailable"); + const resource = { id: identity.id, companyId: input.companyId, environmentId: environment!.id, + providerLeaseId: result.providerLeaseId, providerMetadata: result.metadata }; + await recordSandboxCreationResource(db, resource); + observedResource = resource; + if (abandoned || !context.active || context.signal.aborted || Date.now() >= context.deadlineAtMs) { + await queueSandboxCreationCleanup(db, resource); + } + }); + }); + } catch (error) { + if (!dispatched) settled(); + abandoned = true; + if (observedResource) await queueSandboxCreationCleanup(db, observedResource); + throw error; + } + }); if (!fresh.providerLeaseId || fresh.providerLeaseId === taskId) throw new Error("Plugin replacement task identity unavailable"); - await recordSandboxCreationResource(db, { id: String(fresh.metadata!.creationOperationId), companyId: input.companyId, - environmentId: environment!.id, providerLeaseId: fresh.providerLeaseId }); const {runnerTaskIdentity:_identity,runnerTaskPriorIdentity:_prior,runnerTaskCredentialHandoff:_handoff, runnerTaskResumeFrom:_resume,runnerTaskPreviousLeaseId:_previous,...rest}=metadata; const replacementMetadata={...rest,providerMetadata:fresh.metadata ?? {},runnerTaskReused:false,runnerTaskDispatched:false, runnerTaskExecutionStopped:false,runnerTaskSessionRetained:false}; - { + try { + context?.assertOpen(); + if (!context) await recordSandboxCreationResource(db, { id: String(fresh.metadata!.creationOperationId), companyId: input.companyId, + environmentId: environment!.id, providerLeaseId: fresh.providerLeaseId }); const expiresAt=fresh.expiresAt ? new Date(fresh.expiresAt) : null; const deadline=typeof metadata.runnerTaskRequestedExpiresAt === "string" ? Date.parse(metadata.runnerTaskRequestedExpiresAt) : null; if ((expiresAt && (!Number.isFinite(expiresAt.getTime()) || expiresAt.getTime() <= Date.now())) || (deadline !== null && (!Number.isFinite(deadline) || !expiresAt || expiresAt.getTime() > deadline))) throw new Error("Plugin replacement task expiry is not bounded"); await attachSandboxCreation(db, String(fresh.metadata!.creationOperationId), { companyId: input.companyId, environmentId: environment!.id, heartbeatRunId: lease.heartbeatRunId }, async tx => { + context?.assertOpen(); const [updated] = await tx.update(environmentLeases).set({providerLeaseId:fresh.providerLeaseId,expiresAt, metadata:{...replacementMetadata,creationOperationId:fresh.metadata!.creationOperationId}, }).where(and(eq(environmentLeases.id,lease.id),eq(environmentLeases.providerLeaseId,taskId), - eq(environmentLeases.status,"active"))).returning({id:environmentLeases.id}); + eq(environmentLeases.status,"active"), sql`coalesce(${environmentLeases.metadata}->>'runnerTaskRetiring', 'false') != 'true'`)).returning({id:environmentLeases.id}); if (!updated) throw new Error("Plugin task replacement ownership changed"); - return (await environmentService(tx).getLeaseById(updated.id))!; + const attached = (await environmentService(tx).getLeaseById(updated.id))!; + context?.assertOpen(); + return attached; }); - + } catch (error) { + if (context) await queueSandboxCreationCleanup(db, { id: String(fresh.metadata!.creationOperationId), companyId: input.companyId, + environmentId: environment!.id, providerLeaseId: fresh.providerLeaseId, providerMetadata: fresh.metadata }); + throw error; } return executeEnvironmentTask(db, workers, input); } @@ -275,14 +335,17 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage return snapshot.credential; }); } - const result = await workers.call(plugin.id, "environmentTask", { + const params = { driverKey: metadata.driverKey, companyId: input.companyId, environmentId: environment?.id ?? null, issueId: lease.issueId, config: driverConfig, taskId, runId: run?.id ?? (activeProbe ? String(probe.runId) : null), agentId: run?.agentId ?? null, projectIds, lease: { providerLeaseId: lease.providerLeaseId, metadata: lease.metadata ?? undefined }, ...(workspaceBinding ? { workspace: workspaceBinding } : {}), ...(freshWorkspace && scopesProjects ? { fresh: freshWorkspace } : {}), operation, - }, operation.kind === "copilot_metadata" ? Math.max(1, Math.min(40_000, Number(probe?.expiresAtMs) - Date.now())) : 15_000); + }; + const timeout = operation.kind === "copilot_metadata" ? Math.max(1, Math.min(40_000, Number(probe?.expiresAtMs) - Date.now())) + : 15_000; + const result = await callWorker("environmentTask", params, timeout); const parsed = parseEnvironmentTaskResult(operation, taskId, result); if (operation.kind === "read_file") { const [current] = await db.select({ lease: environmentLeases, run: heartbeatRuns }).from(environmentLeases) @@ -316,7 +379,9 @@ export async function executeEnvironmentTask(db: Db, workers: PluginWorkerManage } if ((parsed.kind === "status" || parsed.kind === "copilot_metadata") && parsed.executionStopped === true) { await db.update(environmentLeases).set({ - metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || ${JSON.stringify({ runnerTaskExecutionStopped: true, runnerTaskSessionRetained: parsed.kind === "status" && parsed.sessionStateAvailable === true })}::jsonb`, + metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || ${JSON.stringify({ runnerTaskExecutionStopped: true, + runnerTaskSessionRetained: parsed.kind === "status" && parsed.sessionStateAvailable === true, + ...(parsed.kind === "status" && parsed.preparationStopped === true ? { runnerTaskPreparationStopped: true } : {}) })}::jsonb`, }).where(and(eq(environmentLeases.id, lease.id), eq(environmentLeases.companyId, input.companyId))); } if (operation.kind === "complete") { @@ -353,16 +418,22 @@ export async function settleDispatchedEnvironmentTask(db: Db, workers: PluginWor metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || '{"runnerTaskRetiring":true}'::jsonb`, }).where(and(eq(environmentLeases.id, lease.id), eq(environmentLeases.companyId, lease.companyId))) .returning({ metadata: environmentLeases.metadata, heartbeatRunId: environmentLeases.heartbeatRunId }); - if (current?.metadata?.runnerTaskDispatched !== true) { + const startup = current?.metadata?.runnerTaskStartup; + const startupCleanup = current?.metadata?.runnerTaskStartupCleanup as { requiresPreparationStop?: boolean } | undefined; + if (current?.metadata?.runnerTaskDispatched !== true && !startup && !startupCleanup) { if (current?.metadata) await settlePluginTaskCredentialHandoff(db, { companyId: lease.companyId, leaseId: lease.id }, current.metadata, async () => { throw new Error("Undispatched task must not request credentials"); }); return current?.metadata?.runnerTaskExecutionStopped === true; } const scope = { companyId: lease.companyId, leaseId: lease.id }; try { + const contextId = (startupCleanup as { contextId?: unknown } | undefined)?.contextId ?? (startup as { contextId?: unknown } | undefined)?.contextId; + const draining = typeof contextId === "string" ? workers.drainStartup?.(contextId) : undefined; + void draining?.catch(() => undefined); await executeEnvironmentTask(db, workers, { ...scope, operation: { kind: "stop" } }); const state = await executeEnvironmentTask(db, workers, { ...scope, operation: { kind: "status" } }); - if (state.kind !== "status" || state.executionStopped !== true) throw new Error("Plugin Runner termination is unconfirmed"); + if (state.kind !== "status" || state.executionStopped !== true || ((startup || startupCleanup?.requiresPreparationStop) && state.preparationStopped !== true)) throw new Error("Plugin Runner termination is unconfirmed"); + await draining; await executeEnvironmentTask(db, workers, { ...scope, operation: { kind: "complete" } }); return true; } catch { diff --git a/server/src/services/execution-control-reconciliation.test.ts b/server/src/services/execution-control-reconciliation.test.ts index 10923cd5bc1..1cd52611df5 100644 --- a/server/src/services/execution-control-reconciliation.test.ts +++ b/server/src/services/execution-control-reconciliation.test.ts @@ -1,7 +1,7 @@ import { resolveExternalTestDatabaseUrl } from "../__tests__/helpers/external-test-database.js"; import { enableRunFailureReporting } from "../__tests__/helpers/run-failure-reporting.js"; import { randomUUID } from "node:crypto"; -import { eq } from "drizzle-orm"; +import { eq, inArray } from "drizzle-orm"; import { afterAll, beforeAll, describe, expect, it, vi } from "vitest"; import { agents, companies, completionContracts, createDb, environmentLeases, environments, heartbeatRuns, issues, issueRecoveryActions, issueThreadInteractions, nativeRunFinalizations, nativeRunResults, statusDecisions, workAssessments } from "@paperclipai/db"; import { @@ -78,6 +78,55 @@ describeEmbeddedPostgres("reconcileAbandonedExecutionControl reports a genuine f return { companyId, agentId, issueId, runId }; } + it("recognizes pending cleanup selected only by the run deadline batch", async () => { + const f = await seedAbandonedRunFixture(), now = new Date(); + const cleanupIds = Array.from({ length: 51 }, () => randomUUID()); + const hidden = cleanupIds[50]!; + await db.insert(heartbeatRuns).values(cleanupIds.map(id => ({ id, companyId: f.companyId, agentId: f.agentId, + nativeIssueId: f.issueId, runtimeMode: "native", status: "running", + executionControlDeadlineAt: id === hidden ? new Date(now.getTime() - 120_000) : null }))); + await db.insert(nativeRunFinalizations).values(cleanupIds.map(runId => ({ runId, companyId: f.companyId, + issueId: f.issueId, phase: "terminal_failure", failureCode: "native_startup_cleanup_pending", + controlDeadlineAt: new Date(now.getTime() - (runId === hidden ? 60_000 : 120_000)) }))); + const attempted: string[] = []; + try { + await reconcileAbandonedExecutionControl(db, now, { startupCleanup: async ({ runId }) => { attempted.push(runId); throw new Error("Provider unavailable"); } }); + expect(attempted).toContain(hidden); + expect((await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, hidden)))[0].status).toBe("running"); + expect((await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, hidden)))[0].controlDeadlineAt! > now).toBe(true); + } finally { + await db.update(nativeRunFinalizations).set({ controlDeadlineAt: null }).where(inArray(nativeRunFinalizations.runId, cleanupIds)); + await db.update(heartbeatRuns).set({ executionControlDeadlineAt: null }).where(inArray(heartbeatRuns.id, cleanupIds)); + } + }); + + it("moves failed startup cleanup retries behind later expired runs", async () => { + const f = await seedAbandonedRunFixture(); + const now = new Date(); + const cleanupIds = Array.from({ length: 50 }, () => randomUUID()); + const firstDeadline = new Date(now.getTime() - 120_000); + await db.insert(heartbeatRuns).values(cleanupIds.map(id => ({ id, companyId: f.companyId, agentId: f.agentId, + nativeIssueId: f.issueId, runtimeMode: "native", status: "running", executionControlDeadlineAt: firstDeadline, + contextSnapshot: { issueId: f.issueId } }))); + await db.insert(nativeRunFinalizations).values(cleanupIds.map(runId => ({ runId, companyId: f.companyId, + issueId: f.issueId, phase: "terminal_failure", failureCode: "native_startup_cleanup_pending", controlDeadlineAt: firstDeadline }))); + const attempted: string[] = []; + const startupCleanup = async ({ runId }: { runId: string }) => { attempted.push(runId); throw new Error("Provider unavailable"); }; + try { + await reconcileAbandonedExecutionControl(db, now, { startupCleanup }); + await reconcileAbandonedExecutionControl(db, now, { startupCleanup }); + expect(new Set(attempted)).toEqual(new Set(cleanupIds)); + expect(attempted).toHaveLength(50); + const [later] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, f.runId)); + expect(later?.status).toBe("failed"); + const retries = await db.select().from(nativeRunFinalizations).where(inArray(nativeRunFinalizations.runId, cleanupIds)); + expect(retries.every(row => row.controlDeadlineAt && row.controlDeadlineAt > now)).toBe(true); + } finally { + await db.update(nativeRunFinalizations).set({ controlDeadlineAt: null }).where(inArray(nativeRunFinalizations.runId, cleanupIds)); + await db.update(heartbeatRuns).set({ executionControlDeadlineAt: null }).where(inArray(heartbeatRuns.id, cleanupIds)); + } + }); + it("reports exactly one Sentry event for a genuine finalization-deadline failure", async () => { const { runId } = await seedAbandonedRunFixture(); const captureCallsBefore = mockCaptureRunFailure.mock.calls.length; diff --git a/server/src/services/execution-control-reconciliation.ts b/server/src/services/execution-control-reconciliation.ts index 621fd210cfc..0133f215d27 100644 --- a/server/src/services/execution-control-reconciliation.ts +++ b/server/src/services/execution-control-reconciliation.ts @@ -8,7 +8,7 @@ import { notifyInstructionCollection } from "./instruction-collection-notificati import { notifyExecutionRunWork } from "./execution-control-notifications.js"; import { randomUUID } from "node:crypto"; import { logger } from "../middleware/logger.js"; -import { and, eq, isNotNull, lte, sql } from "drizzle-orm"; +import { and, asc, eq, isNotNull, lte, sql } from "drizzle-orm"; import { agents, heartbeatRuns, @@ -22,17 +22,25 @@ import { hasLiveLegacyController } from "./legacy-controller-lease.js"; import { reportRunFailure } from "./run-failure-report.js"; import { getNativeReviewAssignment, readNativeReviewAssignmentContext } from "./native-runtime/native-review-participant.js"; import { preserveNativeFailedWorkspace } from "./native-runtime/native-failed-workspace-recovery.js"; +import { EXECUTION_RECONCILIATION_INTERVAL_MS } from "./execution-control-deadline.js"; +import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js"; +import { NATIVE_STARTUP_CLEANUP_PENDING, readNativeStartupContext, promoteNativeStartupCleanup } from "./native-runtime/native-startup-cleanup.js"; /** Only newly recorded control deadlines are eligible. Upgrades never replay ambiguous historical runs. */ export async function reconcileAbandonedExecutionControl( db: Db, now = new Date(), + options: { startupCleanup?: (scope: { companyId: string; runId: string }) => Promise } = {}, ) { const nativeDue = await db .select({ runId: nativeRunFinalizations.runId, issueId: nativeRunFinalizations.issueId, companyId: nativeRunFinalizations.companyId, + failureCode: nativeRunFinalizations.failureCode, + leaseOwner: nativeRunFinalizations.leaseOwner, + controllerGeneration: nativeRunFinalizations.controllerGeneration, + attempt: nativeRunFinalizations.attempt, }) .from(nativeRunFinalizations) .where( @@ -41,20 +49,28 @@ export async function reconcileAbandonedExecutionControl( lte(nativeRunFinalizations.controlDeadlineAt, now), ), ) + .orderBy(asc(nativeRunFinalizations.controlDeadlineAt), asc(nativeRunFinalizations.runId)) .limit(50); const controlDue = await db .select({ runId: heartbeatRuns.id, companyId: heartbeatRuns.companyId, context: heartbeatRuns.contextSnapshot, + nativeIssueId: nativeRunFinalizations.issueId, + failureCode: nativeRunFinalizations.failureCode, + leaseOwner: nativeRunFinalizations.leaseOwner, + controllerGeneration: nativeRunFinalizations.controllerGeneration, + attempt: nativeRunFinalizations.attempt, }) .from(heartbeatRuns) + .leftJoin(nativeRunFinalizations, eq(nativeRunFinalizations.runId, heartbeatRuns.id)) .where( and( isNotNull(heartbeatRuns.executionControlDeadlineAt), lte(heartbeatRuns.executionControlDeadlineAt, now), ), ) + .orderBy(asc(heartbeatRuns.executionControlDeadlineAt), asc(heartbeatRuns.id)) .limit(50); const due = [ ...new Map( @@ -62,10 +78,10 @@ export async function reconcileAbandonedExecutionControl( ...nativeDue, ...controlDue.map((row) => ({ ...row, - issueId: + issueId: row.nativeIssueId ?? ( typeof row.context?.issueId === "string" ? row.context.issueId - : null, + : null), })), ].map((row) => [row.runId, row]), ).values(), @@ -78,6 +94,25 @@ export async function reconcileAbandonedExecutionControl( while (nextCandidate < due.length) { const candidate = due[nextCandidate++]!; try { + if (candidate.failureCode === NATIVE_STARTUP_CLEANUP_PENDING) { + if (!options.startupCleanup) continue; + try { + await options.startupCleanup({ companyId: candidate.companyId, runId: candidate.runId }); + } finally { + await db.transaction(async tx => { + if (candidate.issueId) await tx.select({ id: issues.id }).from(issues).where(eq(issues.id, candidate.issueId)).for("update"); + const [owner] = await tx.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, candidate.runId)).for("update"); + if (owner?.failureCode !== NATIVE_STARTUP_CLEANUP_PENDING || !owner.controlDeadlineAt || owner.controlDeadlineAt > now || + owner.leaseOwner !== candidate.leaseOwner || owner.controllerGeneration !== candidate.controllerGeneration || owner.attempt !== candidate.attempt) return; + const cleanupRetryAt = new Date(Math.max(now.getTime(), Date.now()) + EXECUTION_RECONCILIATION_INTERVAL_MS); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.executionFinalization); + await tx.update(nativeRunFinalizations).set({ controlDeadlineAt: cleanupRetryAt }).where(eq(nativeRunFinalizations.runId, candidate.runId)); + await tx.update(heartbeatRuns).set({ executionControlDeadlineAt: cleanupRetryAt }).where(and(eq(heartbeatRuns.id, candidate.runId), + isNotNull(heartbeatRuns.executionControlDeadlineAt), lte(heartbeatRuns.executionControlDeadlineAt, now))); + }); + } + continue; + } // Set inside the transaction only when the write below genuinely // transitions the run into "failed". Read after the transaction // commits, so a rolled-back write never reports a false failure. @@ -128,6 +163,18 @@ export async function reconcileAbandonedExecutionControl( ].some((deadline) => deadline && deadline <= now) ) return false; + if (coordinator?.failureCode === NATIVE_STARTUP_CLEANUP_PENDING) return false; + const startupContext = coordinator && readNativeStartupContext(run, coordinator); + if (startupContext) { + if (!await promoteNativeStartupCleanup(tx as unknown as Db, run, coordinator!, now)) { + const retryAt = new Date(Math.max(now.getTime() + EXECUTION_RECONCILIATION_INTERVAL_MS, + startupContext.deadlineAtMs, coordinator!.leaseExpiresAt?.getTime() ?? 0)); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.executionFinalization); + await tx.update(nativeRunFinalizations).set({ controlDeadlineAt: retryAt }).where(eq(nativeRunFinalizations.runId, run.id)); + await tx.update(heartbeatRuns).set({ executionControlDeadlineAt: retryAt }).where(eq(heartbeatRuns.id, run.id)); + } + return false; + } await tx .update(heartbeatRuns) .set({ executionControlDeadlineAt: null }) diff --git a/server/src/services/heartbeat.ts b/server/src/services/heartbeat.ts index 9212fc686c8..b9878f8ae20 100644 --- a/server/src/services/heartbeat.ts +++ b/server/src/services/heartbeat.ts @@ -398,6 +398,7 @@ import { isNativeRunnerOwnershipHeld, NATIVE_OWNERSHIP_UNVERIFIED_ERROR_CODE, } from "./native-runtime/native-runner-ownership.js"; +import { NativeStartupCleanupPendingError, requestNativeStartupCleanup, verifyNativeStartupCleanup, readNativeStartupCleanup } from "./native-runtime/native-startup-cleanup.js"; import { emitAgentTaskRun, emitAgentTaskRunById, @@ -1436,6 +1437,14 @@ export function heartbeatService( } const runControl = createHeartbeatRunControl(db, { + verifyStartupCleanup: async run => { + await verifyNativeStartupCleanup(db, run, () => envOrchestrator.releaseForRun({ + heartbeatRunId: run.id, companyId: run.companyId, agentId: run.agentId, status: "expired", + cancelActiveWork: true, providerResourceDisposition: "destroy", + })); + const marker = readNativeStartupCleanup(run)!; + await options.pluginWorkerManager?.retireStartup?.(marker.contextId); + }, getRun, getRunCleanupState, getRunExecutionWait, @@ -1759,7 +1768,7 @@ export function heartbeatService( }, }); })().catch((error) => { - if (!nativeRecoveryDeadlines.has(runId)) { + if (!nativeRecoveryDeadlines.has(runId) || nativeRecoveryDeadlines.get(runId) === pending) { scheduleNativeSessionResumeDispatch(runId, new Date(Date.now() + 30_000), mode); } logger.error( @@ -1956,6 +1965,19 @@ export function heartbeatService( Parameters[0] | null = null; let nativeSessionResumeScheduled = false; let nativeOwnershipHeld = false; + let nativeStartupCleanupScheduled = false; + let nativeStartupCleanupError: NativeStartupCleanupPendingError | undefined; + const requestStartupCleanup = async (error: NativeStartupCleanupPendingError) => { + nativeStartupCleanupError = error; + try { + nativeStartupCleanupScheduled = await requestNativeStartupCleanup(db, { companyId: run.companyId, agentId: run.agentId, runId: run.id, + contextId: error.contextId, deadlineAtMs: error.deadlineAtMs, leaseOwner: error.leaseOwner, + leaseId: error.leaseId, requiresPreparationStop: error.requiresPreparationStop }); + } catch (writeError) { + scheduleNativeSessionResumeDispatch(run.id, new Date(Date.now() + 30_000), "restart"); + throw writeError; + } + }; let instructionWorkingCopy: ReturnType | null = null; let nativeDispatchStarted = false; let nativeWorkspaceFinalizeScheduled = false; @@ -3527,6 +3549,10 @@ export function heartbeatService( })); } catch (err) { await persistUsageCaptureFailure?.(); + if (err instanceof NativeStartupCleanupPendingError) { + await requestStartupCleanup(err); + return; + } if (err instanceof NativeControllerDetachedForRestartError) { nativeSessionResumeScheduled = true; return; @@ -3659,7 +3685,12 @@ export function heartbeatService( }); } } catch (outerErr) { - if ( + if (nativeStartupCleanupScheduled || nativeStartupCleanupError || outerErr instanceof NativeStartupCleanupPendingError) { + const pending = outerErr instanceof NativeStartupCleanupPendingError ? outerErr : nativeStartupCleanupError; + if (!nativeStartupCleanupScheduled && pending) await requestStartupCleanup(pending).catch(error => { + logger.warn({ err: error, runId: run.id }, "Native startup cleanup intent will retry through owned recovery"); + }); + } else if ( nativeOwnershipHeld || outerErr instanceof NativeRunnerOwnershipUnverifiedError ) { @@ -3696,7 +3727,7 @@ export function heartbeatService( ); } else { await preserveNativeWorkspaceOnFailure(); - if (!nativeOwnershipHeld) await runCompletion.failRunSetup({ + if (!nativeOwnershipHeld && !nativeStartupCleanupScheduled && !nativeStartupCleanupError) await runCompletion.failRunSetup({ run, runId, outerErr, signal: executionControl.controller.signal, providerDispatchStarted: legacyAdapterEntered || nativeDispatchStarted, identityRedactor, readFailureReportSecrets, @@ -3746,7 +3777,7 @@ export function heartbeatService( latestRun && !nativeSessionResumeScheduled && !nativeWorkspaceFinalizeScheduled && - !nativeOwnershipHeld + !nativeOwnershipHeld && !nativeStartupCleanupScheduled && !nativeStartupCleanupError ) { latestRun = await terminalizeRunOnLeaseRelease(latestRun).catch( (terminalizeErr) => { @@ -3772,7 +3803,7 @@ export function heartbeatService( if ( !nativeSessionResumeScheduled && !nativeWorkspaceFinalizeScheduled && - !nativeOwnershipHeld + !nativeOwnershipHeld && !nativeStartupCleanupScheduled && !nativeStartupCleanupError ) { // Keep launchers during same-run recovery. At a terminal boundary all // operations have settled; clean before the remote lease can be stopped. @@ -3895,7 +3926,7 @@ export function heartbeatService( }).where(and(eq(heartbeatRuns.id, run.id), eq(heartbeatRuns.status, "cancelled"))); } if (latestRun?.runtimeMode === "native" && isHeartbeatRunTerminalStatus(latestRun.status) && - !nativeSessionResumeScheduled && !nativeWorkspaceFinalizeScheduled && !nativeOwnershipHeld) { + !nativeSessionResumeScheduled && !nativeWorkspaceFinalizeScheduled && !nativeOwnershipHeld && !nativeStartupCleanupScheduled && !nativeStartupCleanupError) { await settleNativeRunProcess(db, run.id).catch(error => { logger.warn({ err: error, runId: run.id }, "failed to release settled native process identity"); }); @@ -3932,7 +3963,7 @@ export function heartbeatService( caseHandoffCleanupSettled = hasStoppedLocalProcessTree(latestRun); } if (caseHandoffCleanupSettled && latestRun && !nativeSessionResumeScheduled && !nativeWorkspaceFinalizeScheduled && - !nativeOwnershipHeld && isHeartbeatRunTerminalStatus(latestRun.status)) { + !nativeOwnershipHeld && !nativeStartupCleanupScheduled && !nativeStartupCleanupError && isHeartbeatRunTerminalStatus(latestRun.status)) { const handoff = await pendingCaseHandoffForRun(db, run.id); if (handoff) await recordCaseHandoffExecutionReleased(db, run.id, handoff.issueId); } diff --git a/server/src/services/heartbeat/recovery.test.ts b/server/src/services/heartbeat/recovery.test.ts index 1573f3bdd49..73a665bb53d 100644 --- a/server/src/services/heartbeat/recovery.test.ts +++ b/server/src/services/heartbeat/recovery.test.ts @@ -168,13 +168,13 @@ describe("heartbeat recovery module callbacks", () => { expect(database.access).not.toHaveBeenCalled(); }); - it("persists an authentication ownership hold before its event without terminating or retrying", async () => { + it.each(["adopted_runner_authentication_timeout"] as const)("persists a %s ownership hold before its event without terminating or retrying", async reason => { const database = guardedDatabase(); const deps = callbacks(database.db); const run = { id: "run", runtimeMode: "native", status: "running" } as Run; const blocked = { ...run, nativePhase: "terminal_failure", errorCode: NATIVE_OWNERSHIP_UNVERIFIED_ERROR_CODE }; deps.setRunStatusFromLive.mockResolvedValue({ updated: true, run: blocked }); - expect(await createHeartbeatRecovery(database.db, deps).markNativeOwnershipUnverified(run, { reason: "adopted_runner_authentication_timeout" })).toBe(blocked); + expect(await createHeartbeatRecovery(database.db, deps).markNativeOwnershipUnverified(run, { reason })).toBe(blocked); expect(deps.setRunStatusFromLive).toHaveBeenCalledWith("run", "running", ["running"], expect.objectContaining({ nativePhase: "terminal_failure" })); expect(deps.appendRunEvent).toHaveBeenCalledAfter(deps.setRunStatusFromLive); expect(deps.cancelHeartbeatNativeRun).not.toHaveBeenCalled(); @@ -207,6 +207,42 @@ describePostgres("heartbeat recovery module ownership", () => { return (await db.insert(heartbeatRuns).values({ id: runId, companyId, agentId, issueId, invocationSource: "automation", status: "running", runtimeMode: "legacy" }).returning())[0]; } + it("routes an expired pre-capability startup to cleanup before generic orphan ownership holds", async () => { + const run = await seedRun(), leaseId = randomUUID(), environmentId = randomUUID(), leaseOwner = randomUUID(); + const deadlineAtMs = Date.now() - 1_000, contextId = randomUUID(); + await db.update(agents).set({ adapterType: "paperclip_runner" }).where(eq(agents.id, run.agentId)); + await db.update(issues).set({ executionRunId: run.id }).where(eq(issues.id, run.issueId!)); + await db.update(heartbeatRuns).set({ runtimeMode: "native", nativeIssueId: run.issueId, nativePhase: "observed", + runnerInstanceId: randomUUID(), nativeSessionId: randomUUID(), runnerProfileJson: { nativeStartupContext: { + schema: "paperclip.native-startup-context.v1", companyId: run.companyId, agentId: run.agentId, runId: run.id, + contextId, deadlineAtMs, leaseId, leaseOwner, controllerGeneration: 1, attempt: 1 } } }).where(eq(heartbeatRuns.id, run.id)); + await db.insert(nativeRunFinalizations).values({ runId: run.id, companyId: run.companyId, issueId: run.issueId!, + phase: "observed", attempt: 1, leaseOwner, controllerGeneration: 1, leaseExpiresAt: new Date(Date.now() - 1_000), + controllerBootId: randomUUID(), controllerPid: process.pid, controllerProcessStartedAt: new Date() }); + await db.insert(environments).values({ id: environmentId, name: environmentId, driver: "plugin", config: {} }); + await db.insert(environmentLeases).values({ id: leaseId, companyId: run.companyId, environmentId, heartbeatRunId: run.id, + issueId: run.issueId, provider: "plugin", providerLeaseId: "early-task", status: "active", metadata: { runnerTaskLease: true } }); + const deps = callbacks(db); + deps.getRun.mockImplementation(async id => (await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)))[0] ?? null); + native.claims.mockImplementationOnce(claimNativeRestartRecoveries); + try { + await createHeartbeatRecovery(db, deps).recoverActiveExecutions({ runId: run.id }); + expect(native.claims).toHaveBeenCalledWith(expect.objectContaining({ runIds: [run.id] })); + const [current] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, run.id)); + expect(current).toMatchObject({ status: "running", errorCode: "native_startup_cleanup_pending", + resultJson: { nativeStartupCleanup: { contextId, state: "pending" } } }); + expect(deps.executeRun).not.toHaveBeenCalled(); + expect(deps.setRunStatusFromLive).not.toHaveBeenCalled(); + } finally { + await db.delete(environmentLeases).where(eq(environmentLeases.id, leaseId)); + await db.delete(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, run.id)); + await db.delete(heartbeatRunEvents).where(eq(heartbeatRunEvents.runId, run.id)); + await db.delete(activityLog).where(eq(activityLog.runId, run.id)); + await db.update(issues).set({ executionRunId: null }).where(eq(issues.id, run.issueId!)); + await db.delete(heartbeatRuns).where(eq(heartbeatRuns.id, run.id)); + } + }); + async function ownedProcess() { const child = spawn(process.execPath, ["-e", "setInterval(() => {}, 1000)", `paperclip-recovery-${randomUUID()}`], { stdio: "ignore", detached: true, env: { PATH: process.env.PATH }, diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index c72ff89214b..48d1a532c27 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -1,3 +1,4 @@ +import { readNativeStartupCleanup, readNativeStartupContext } from "../native-runtime/native-startup-cleanup.js"; import { pendingFailedNativeRetryCancellationCondition } from "../native-runtime/native-cancellation-request.js"; import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import { registerLiveRecoveryWork } from "./live-recovery-work.js"; @@ -1038,7 +1039,9 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD ? "Native restart recovery is waiting for safe ownership evidence" : disposition.kind === "already_finalized" ? "Native restart recovery found an already-finalized result" - : "Native restart recovery blocked ambiguous or conflicting ownership", + : disposition.reason === "native_startup_cleanup_pending" + ? "Native startup timed out; cancellation and verified cleanup are queued" + : "Native restart recovery blocked ambiguous or conflicting ownership", payload: { restartKind: isClaim ? disposition.restartKind : restartKind, recoveryRequestId: isClaim @@ -2251,6 +2254,10 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD nativeControllerProcessStartedAt: nativeRunFinalizations.controllerProcessStartedAt, nativeControllerLeaseExpiresAt: nativeRunFinalizations.leaseExpiresAt, + nativeLeaseOwner: nativeRunFinalizations.leaseOwner, + nativeControllerGeneration: nativeRunFinalizations.controllerGeneration, + nativeAttempt: nativeRunFinalizations.attempt, + nativeResultId: nativeRunFinalizations.resultId, nativeWorkspaceFinalizationPending: pendingNativeWorkspaceFinalizationCondition(db), }) .from(heartbeatRuns) @@ -2271,7 +2278,10 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD && !isNativeRunnerOwnershipHeld(run) && !activeRunExecutions.has(run.id) && !runningProcesses.has(run.id), ).map(({ run }) => run.id); - const remoteRecoveryRunIds = new Set(await listExpiredNativeRunnerAuthorities(db, now, expiredNativeRunIds)); + const earlyStartupRunIds = activeRuns.filter(row => expiredNativeRunIds.includes(row.run.id) && + readNativeStartupContext(row.run, { leaseOwner: row.nativeLeaseOwner, controllerGeneration: row.nativeControllerGeneration ?? 0, + attempt: row.nativeAttempt ?? 0, resultId: row.nativeResultId })).map(row => row.run.id); + const remoteRecoveryRunIds = new Set([...earlyStartupRunIds, ...await listExpiredNativeRunnerAuthorities(db, now, expiredNativeRunIds)]); if (remoteRecoveryRunIds.size) { const recovery = await recoverNativeRunsAfterRestart(now, [...remoteRecoveryRunIds]); for (const claim of recovery.claims) resumedRunIds.add(claim.runId); @@ -2321,6 +2331,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD nativeControllerLeaseExpiresAt, nativeWorkspaceFinalizationPending, } of activeRuns) { + if (run.runtimeMode === "native" && readNativeStartupCleanup(run)) continue; if (parseObject(run.contextSnapshot).nativeQuestionCancellation) continue; // Native recovery owns these dispositions. Its writes happened after this // inventory was read; do not reap or overwrite them using the old row. diff --git a/server/src/services/heartbeat/run-control.ts b/server/src/services/heartbeat/run-control.ts index 4b1c7c7af69..835ac1fa078 100644 --- a/server/src/services/heartbeat/run-control.ts +++ b/server/src/services/heartbeat/run-control.ts @@ -123,7 +123,8 @@ import { } from "../native-runtime/index.js"; import { runningProcesses } from "../../adapters/index.js"; import { parseObject } from "../../adapters/utils.js"; -import { isNativeRunnerOwnershipHeld } from "../native-runtime/native-runner-ownership.js"; +import { isNativeRunnerOwnershipHeld, nativeRunnerOwnershipNotHeldCondition } from "../native-runtime/native-runner-ownership.js"; +import { readNativeStartupCleanup, acknowledgeNativeStartupCleanup } from "../native-runtime/native-startup-cleanup.js"; import { withCurrentBudgetEnforcement, type BudgetEnforcementScope, @@ -177,6 +178,7 @@ export interface HeartbeatRunControlDependencies extends Pick, "mergeRunStopMetadataForAgent" | "setRunStatusFromLive" | "setRunStatus" | "setWakeupStatus" | "appendRunEvent">, Pick { + verifyStartupCleanup?: (run: typeof heartbeatRuns.$inferSelect) => Promise; options: { closeWarmNativeSessionsForRun?: (input: { runId: string; @@ -1399,13 +1401,19 @@ export function createHeartbeatRunControl(db: Db, dependencies: HeartbeatRunCont } let terminationSettled = false; try { - await cancelHeartbeatNativeRun({ - db, - runId: run.id, - reason, - runtimeMode: run.runtimeMode, - ...(options.cancellationRequestId ? { cancellationRequestId: options.cancellationRequestId } : {}), - }); + const startupCleanupRun = run.runtimeMode === "native" ? await getRun(run.id) : null; + if (startupCleanupRun && readNativeStartupCleanup(startupCleanupRun) && !control && !running && !activeRunExecutions.has(run.id)) { + 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 } : {}), + }); + } if (running) { await terminateHeartbeatRunProcess({ pid: running.child.pid, @@ -1466,12 +1474,13 @@ export function createHeartbeatRunControl(db: Db, dependencies: HeartbeatRunCont } const finishedAt = new Date(); - const persistedCancellationResult = - run.runtimeMode === "native" - ? await getRun(run.id).then((current) => - parseObject(current?.resultJson), - ) - : {}; + let persistedCancellationRun = run.runtimeMode === "native" ? await getRun(run.id) : null; + if (persistedCancellationRun && readNativeStartupCleanup(persistedCancellationRun)) { + if (!dependencies.verifyStartupCleanup) throw conflict("Native startup cleanup worker unavailable"); + await dependencies.verifyStartupCleanup(persistedCancellationRun); + persistedCancellationRun = await getRun(run.id); + } + const persistedCancellationResult = parseObject(persistedCancellationRun?.resultJson); return await setRunStatusFromLive( run.id, "cancelled", @@ -1520,12 +1529,18 @@ export function createHeartbeatRunControl(db: Db, dependencies: HeartbeatRunCont persistedCancellationResult.nativeCancellation, } : {}), + ...(Object.hasOwn(persistedCancellationResult, "nativeStartupCleanup") + ? { nativeStartupCleanup: persistedCancellationResult.nativeStartupCleanup } : {}), }, } : {}), }, undefined, - pendingNativeRetry ? nativeRetryCancellationCommitCondition(persistedCancellationResult) : undefined, + and(pendingNativeRetry ? nativeRetryCancellationCommitCondition(persistedCancellationResult) + : persistedCancellationRun && readNativeStartupCleanup(persistedCancellationRun) ? and(nativeRunnerOwnershipNotHeldCondition(), + sql`not exists (select 1 from ${nativeRunFinalizations} where ${nativeRunFinalizations.runId} = ${run.id} and ${nativeRunFinalizations.resultId} is not null)`) + : undefined, + run.runtimeMode === "native" ? sql`coalesce(${heartbeatRuns.resultJson}->'nativeStartupCleanup'->>'state', '') <> 'pending'` : undefined), ); } catch (error) { if (processCancellationSettlement) { @@ -1557,6 +1572,7 @@ export function createHeartbeatRunControl(db: Db, dependencies: HeartbeatRunCont const cancelled = cancellation.run; if (cancellation.updated && cancelled) { + if (readNativeStartupCleanup(cancelled)) await acknowledgeNativeStartupCleanup(db, { companyId: cancelled.companyId, runId: cancelled.id }); await setWakeupStatus(run.wakeupRequestId, "cancelled", { finishedAt: cancelled.finishedAt ?? new Date(), error: reason, diff --git a/server/src/services/heartbeat/run-lifecycle.ts b/server/src/services/heartbeat/run-lifecycle.ts index 8f4c0dc7595..5cf432a9134 100644 --- a/server/src/services/heartbeat/run-lifecycle.ts +++ b/server/src/services/heartbeat/run-lifecycle.ts @@ -1,3 +1,4 @@ +import { readNativeStartupCleanup } from "../native-runtime/native-startup-cleanup.js"; import { notifyStrandedAgentStatus } from "../live-run-recovery-notifications.js"; import { notifyRunDispatch } from "../run-dispatch-notifications.js"; import { preserveAcceptedRunUsageProjectionSql } from "../usage-receipts.js"; @@ -1159,6 +1160,9 @@ export function createHeartbeatLifecycle(db: Db, dependencies: HeartbeatLifecycl .where(eq(heartbeatRuns.id, runId)) .then((rows) => rows[0] ?? null); const previousStatus = previous?.run ?? null; + if (status === "failed" && patch?.errorCode === "process_lost" && previousStatus?.runtimeMode === "native" && readNativeStartupCleanup(previousStatus)) { + return { updated: false, run: previousStatus }; + } if (previousStatus && (status === "cancelled" || status === "interrupted")) { patch = { ...patch, resultJson: cancellationResultJson(previousStatus, status, patch?.resultJson, patch?.errorCode, patch?.error) }; diff --git a/server/src/services/heartbeat/runtime-execution.ts b/server/src/services/heartbeat/runtime-execution.ts index 1ec069325c1..268ebf4aa41 100644 --- a/server/src/services/heartbeat/runtime-execution.ts +++ b/server/src/services/heartbeat/runtime-execution.ts @@ -1,3 +1,4 @@ +import { NativeStartupCleanupPendingError } from "../native-runtime/native-startup-cleanup.js"; import { NativeControllerRecoveryWaitingError } from "../native-runtime/native-controller-recovery.js"; import { usesNativeUsageDelivery } from "../native-runtime/native-usage-accounting.js"; @@ -1072,15 +1073,21 @@ export async function executeHeartbeatRuntime(db: Db, input: HeartbeatRuntimeExe && !(nativeExecution && "access" in nativeExecution.workspace && nativeExecution.workspace.access === "none")) { input.effects.onProviderResourceDisposition("stop_and_retain"); } - await writeExecutionControl(db, DELIVERY_QUEUES.executionFinalization, tx => tx - .update(heartbeatRuns) - .set({ executionControlDeadlineAt: new Date(Date.now() + 60_000) }) - .where( - and( - eq(heartbeatRuns.id, run.id), - eq(heartbeatRuns.status, "running"), - ), - ), { companyId: run.companyId }); + try { + await writeExecutionControl(db, DELIVERY_QUEUES.executionFinalization, tx => tx + .update(heartbeatRuns) + .set({ executionControlDeadlineAt: new Date(Date.now() + 60_000) }) + .where( + and( + eq(heartbeatRuns.id, run.id), + eq(heartbeatRuns.status, "running"), + ), + ), { companyId: run.companyId }); + } catch (writeError) { + if (adapterErr instanceof NativeStartupCleanupPendingError) throw adapterErr; + throw writeError; + } + if (adapterErr instanceof NativeStartupCleanupPendingError) throw adapterErr; if ( issueRef && context.resumeSessionGoalHeartbeat === true && diff --git a/server/src/services/native-runtime/native-execution-context-worker.test.ts b/server/src/services/native-runtime/native-execution-context-worker.test.ts index 3fb4d77d8bc..2c511ce108f 100644 --- a/server/src/services/native-runtime/native-execution-context-worker.test.ts +++ b/server/src/services/native-runtime/native-execution-context-worker.test.ts @@ -32,8 +32,8 @@ const invocations = []; const send = (id, result) => process.stdout.write(JSON.stringify({jsonrpc:"2.0",id,result})+"\\n"); readline.createInterface({input:process.stdin,crlfDelay:Infinity}).on("line", line => { const message = JSON.parse(line); - if (message.method === "initialize") send(message.id, {ok:true,supportedMethods:["environmentTask","configChanged","health"]}); - else if (message.method === "environmentTask" || message.method === "environmentDestroyLease") { + if (message.method === "initialize") send(message.id, {ok:true,supportedMethods:["environmentTask","environmentAcquireLease","configChanged","health"]}); + else if (message.method === "environmentTask" || message.method === "environmentDestroyLease" || message.method === "environmentAcquireLease") { held.push(message.id); invocations.push(message.paperclipInvocation?.id); if (message.params.config.hostWrite) process.stdout.write(JSON.stringify({jsonrpc:"2.0",id:"host-"+message.id,method:"companies.get",params:{companyId:"company"},paperclipInvocationId:message.paperclipInvocation.id})+"\\n"); @@ -43,7 +43,7 @@ readline.createInterface({input:process.stdin,crlfDelay:Infinity}).on("line", li else if (message.method === "configChanged") { if (message.params.config.exit) process.exit(1); if (message.params.config.hostAfter) process.stdout.write(JSON.stringify({jsonrpc:"2.0",id:"late-host",method:"companies.get",params:{companyId:"company"},paperclipInvocationId:invocations.at(-1)})+"\\n"); - if (message.params.config.release) for (const id of held.splice(0)) send(id, {kind:"description",taskId:"task"}); + if (message.params.config.release) for (const id of held.splice(0)) { send(id, {providerLeaseId:"late-task",kind:"description",taskId:"task"}); if (message.params.config.duplicate) send(id, {providerLeaseId:"late-task",kind:"description",taskId:"task"}); } send(message.id, {}); } else if (message.method === "shutdown") {send(message.id, {});setImmediate(()=>process.exit(0));} }); @@ -59,6 +59,70 @@ async function startWorker(hostHandlers: Record = {}) { } describe("Core startup responsibility across real worker IPC", () => { + it("drops only a dead acquisition reply placeholder while retaining real writes until verified retirement", async () => { + let release!: () => void, writing!: () => void; + const gate = new Promise(resolve => { release = resolve; }), entered = new Promise(resolve => { writing = resolve; }); + const manager = await startWorker({ "companies.get": async () => { writing(); await gate; return {}; } }); + const settled = vi.fn(), observe = vi.fn(async () => {}); + try { + const acquisition = manager.call(manifest.id, "environmentAcquireLease", { companyId: "company", environmentId: "environment", + driverKey: "tasks", config: { hostWrite: true }, runId: "run", agentId: "agent", adapterType: "paperclip_runner" }, + 10, undefined, settled, "dead-acquire", observe); + const rejected = expect(acquisition).rejects.toThrow("timed out"); + await entered; await rejected; + await manager.stopWorker(manifest.id); + let drained = false; + const draining = manager.drainStartup!("dead-acquire").then(() => { drained = true; }); + await new Promise(resolve => setImmediate(resolve)); + expect(drained).toBe(false); + expect(settled).not.toHaveBeenCalled(); + release(); await draining; + expect(observe).not.toHaveBeenCalled(); + expect(settled).not.toHaveBeenCalled(); + await manager.retireStartup!("dead-acquire"); + expect(settled).toHaveBeenCalledOnce(); + } finally { release(); await manager.stopAll(); } + }, 25_000); + + it.each([false, true])("retains a received acquisition reply through failed recording and retirement (worker exits=%s)", async workerExits => { + const manager = await startWorker(), settled = vi.fn(); + let release!: () => void, recording!: () => void; + const gate = new Promise(resolve => { release = resolve; }), started = new Promise(resolve => { recording = resolve; }); + let unavailable = true; + const observe = vi.fn(async (result: unknown) => { + expect(result).toMatchObject({ providerLeaseId: "late-task" }); + if (unavailable) throw new Error("Database unavailable"); + recording(); await gate; + }); + try { + const acquire = manager.call(manifest.id, "environmentAcquireLease", { companyId: "company", environmentId: "environment", + driverKey: "tasks", config: {}, runId: "run", agentId: "agent", adapterType: "paperclip_runner" }, 10, undefined, settled, "late-acquire", observe); + await expect(acquire).rejects.toThrow("timed out"); + await manager.call(manifest.id, "configChanged", { config: { release: true, duplicate: true } }); + await vi.waitFor(() => expect(observe).toHaveBeenCalledOnce()); + await new Promise(resolve => setImmediate(resolve)); + expect(settled).not.toHaveBeenCalled(); + if (workerExits) await manager.stopWorker(manifest.id); + unavailable = false; + vi.useFakeTimers(); + const failed = manager.retireStartup!("late-acquire").catch(error => error.message); + await started; + expect(observe).toHaveBeenCalledTimes(2); + await vi.advanceTimersByTimeAsync(15_000); + expect(await failed).toBe("Task cleanup is still pending"); + expect(settled).not.toHaveBeenCalled(); + vi.useRealTimers(); + let retired = false; + const retiring = manager.retireStartup!("late-acquire").then(() => { retired = true; }); + await new Promise(resolve => setImmediate(resolve)); + expect(retired).toBe(false); + release(); await retiring; + expect(settled).toHaveBeenCalledOnce(); + await manager.retireStartup!("late-acquire"); + expect(observe).toHaveBeenCalledTimes(2); + } finally { vi.useRealTimers(); release(); await manager.stopAll(); } + }); + it.each(["stop", "replace", "stopAll"])("keeps stopped startup work reachable through %s until verified retirement", async mode => { let release!: () => void, entered!: () => void; const gate = new Promise(resolve => { release = resolve; }), started = new Promise(resolve => { entered = resolve; }); diff --git a/server/src/services/native-runtime/native-restart-recovery.ts b/server/src/services/native-runtime/native-restart-recovery.ts index a27af96ac3b..635808df5ef 100644 --- a/server/src/services/native-runtime/native-restart-recovery.ts +++ b/server/src/services/native-runtime/native-restart-recovery.ts @@ -38,6 +38,7 @@ import { isNewTerminalRunFailure, reportRunFailure } from "../run-failure-report import { isNativeRunnerOwnershipHeld } from "./native-runner-ownership.js"; import { nativeRestartInterruptedTurnId, type PersistedNativeSession } from "../../vendor/paperclip-runner/index.js"; import { retireSupersededNativeRetry } from "./native-superseded-retry.js"; +import { requestNativeStartupCleanup, readNativeStartupContext, promoteNativeStartupCleanup } from "./native-startup-cleanup.js"; export type NativeControllerIdentity = { bootId: string; @@ -623,22 +624,41 @@ export async function claimNativeRestartRecoveries(input: { } as const; } + const startupContext = readNativeStartupContext(row.run, row.coordinator); + const startupRetryAt = startupContext ? new Date(Math.max(now.getTime() + 30_000, + startupContext.deadlineAtMs, row.coordinator.leaseExpiresAt?.getTime() ?? 0)) : undefined; if (input.liveRunExecutions?.has(row.run.id)) { return { kind: "awaiting_evidence", runId: row.run.id, reason: "current_controller_preparing", + ...(startupRetryAt ? { retryAt: startupRetryAt } : {}), } as const; } + if (startupContext) { + if (await promoteNativeStartupCleanup(tx as unknown as Db, row.run, row.coordinator, now)) { + return { kind: "blocked", runId: row.run.id, reason: "native_startup_cleanup_pending" } as const; + } + return { kind: "awaiting_evidence", runId: row.run.id, reason: "native_startup_cleanup_pending", retryAt: startupRetryAt } as const; + } const profile = row.run.runnerProfileJson ?? {}; const storedRemoteWorkspace = remoteWorkspaceRunReferenceSchema.safeParse(profile.remoteWorkspace); const remoteWorkspace = readNativeWorkspaceSyncReference(profile.nativeWorkspaceSync) ?? (storedRemoteWorkspace.success ? storedRemoteWorkspace.data : null); - const [pluginTask] = await tx.select({ id: environmentLeases.id }).from(environmentLeases).where(and( + const [pluginTask] = await tx.select({ id: environmentLeases.id, metadata: environmentLeases.metadata }).from(environmentLeases).where(and( eq(environmentLeases.companyId, row.run.companyId), eq(environmentLeases.heartbeatRunId, row.run.id), sql`${environmentLeases.metadata}->>'runnerTaskLease' = 'true'`, )).orderBy(desc(environmentLeases.createdAt)).limit(1); + const startup = pluginTask?.metadata?.runnerTaskStartup as { contextId?: unknown; deadlineAtMs?: unknown; runId?: unknown } | undefined; + if (startup?.runId === row.run.id && typeof startup.contextId === "string" && + Number.isSafeInteger(startup.deadlineAtMs) && Number(startup.deadlineAtMs) <= now.getTime() && + !row.run.sessionIdAfter && row.coordinator.leaseOwner && row.coordinator.leaseExpiresAt && row.coordinator.leaseExpiresAt <= now) { + await requestNativeStartupCleanup(tx as unknown as Db, { companyId: row.run.companyId, agentId: row.run.agentId, + runId: row.run.id, contextId: startup.contextId, deadlineAtMs: Number(startup.deadlineAtMs), + leaseOwner: row.coordinator.leaseOwner, requiresPreparationStop: true, leaseId: pluginTask!.id }, { publish: false }); + return { kind: "blocked", runId: row.run.id, reason: "native_startup_cleanup_pending" } as const; + } const remoteSandbox = profile.nativeWorkspaceSync != null || profile.remoteWorkspace != null; const remoteProcess = remoteSandbox || !!pluginTask; const durableAuthority = (remoteWorkspace || pluginTask) && await hasNativeRunnerCheckpoint(tx, { diff --git a/server/src/services/native-runtime/native-startup-cleanup.ts b/server/src/services/native-runtime/native-startup-cleanup.ts new file mode 100644 index 00000000000..e6b80230c2d --- /dev/null +++ b/server/src/services/native-runtime/native-startup-cleanup.ts @@ -0,0 +1,208 @@ +import { and, eq, isNull, sql } from "drizzle-orm"; +import { environmentLeases, heartbeatRuns, issues, nativeRunFinalizations, sandboxCreationOperations, type Db } from "@paperclipai/db"; +import { conflict } from "../../errors.js"; +import { persistActivity, publishActivity } from "../activity-log.js"; +import { DELIVERY_QUEUES, notifyDeliveryWork } from "../delivery-work-notifications.js"; +import { hasRemoteTerminationReceipt } from "../remote-execution-termination.js"; +import { isNativeRunnerOwnershipHeld } from "./native-runner-ownership.js"; + +export const NATIVE_STARTUP_CLEANUP_PENDING = "native_startup_cleanup_pending"; + +export class NativeStartupCleanupPendingError extends Error { + constructor(readonly contextId: string, readonly deadlineAtMs: number, readonly leaseOwner: string, + readonly requiresPreparationStop: boolean, readonly leaseId?: string) { + super(NATIVE_STARTUP_CLEANUP_PENDING); + this.name = "NativeStartupCleanupPendingError"; + } +} + +type Run = typeof heartbeatRuns.$inferSelect; +export interface NativeStartupCleanup { + schema: "paperclip.native-startup-cleanup.v1"; + companyId: string; agentId: string; runId: string; + contextId: string; deadlineAtMs: number; leaseOwner: string; + controllerGeneration: number; attempt: number; leaseId: string; taskId: string; + requiresPreparationStop: boolean; state: "pending" | "complete"; auditId: string; +} + +export function readNativeStartupCleanup(run: Pick): NativeStartupCleanup | null { + const marker = run.resultJson?.nativeStartupCleanup as NativeStartupCleanup | undefined; + return marker?.schema === "paperclip.native-startup-cleanup.v1" && marker.companyId === run.companyId && + marker.runId === run.id && marker.agentId === run.agentId && ["contextId", "leaseOwner", "leaseId", "taskId", "auditId"].every(key => + typeof marker[key as keyof NativeStartupCleanup] === "string" && String(marker[key as keyof NativeStartupCleanup]).length > 0) && + Number.isSafeInteger(marker.deadlineAtMs) && Number.isSafeInteger(marker.controllerGeneration) && marker.controllerGeneration > 0 && + Number.isSafeInteger(marker.attempt) && marker.attempt > 0 && typeof marker.requiresPreparationStop === "boolean" && + ["pending", "complete"].includes(marker.state) ? marker : null; +} + +export function readNativeStartupContext(run: Run, + owner: { leaseOwner: string | null; controllerGeneration: number; attempt: number; resultId: string | null }) { + const value = run.runnerProfileJson?.nativeStartupContext as { schema?: unknown; companyId?: unknown; agentId?: unknown; runId?: unknown; + contextId?: unknown; deadlineAtMs?: unknown; leaseId?: unknown; leaseOwner?: unknown; controllerGeneration?: unknown; attempt?: unknown } | undefined; + if (run.runtimeMode !== "native" || run.status !== "running" || run.sessionIdAfter || owner.resultId || isNativeRunnerOwnershipHeld(run) || + !owner.leaseOwner || owner.controllerGeneration < 1 || owner.attempt < 1 || value?.schema !== "paperclip.native-startup-context.v1" || + value.companyId !== run.companyId || value.agentId !== run.agentId || value.runId !== run.id || value.leaseOwner !== owner.leaseOwner || + value.controllerGeneration !== owner.controllerGeneration || value.attempt !== owner.attempt || + typeof value.contextId !== "string" || !value.contextId || typeof value.leaseId !== "string" || !value.leaseId || + !Number.isSafeInteger(value.deadlineAtMs)) return null; + return { contextId: value.contextId, leaseId: value.leaseId, deadlineAtMs: Number(value.deadlineAtMs) }; +} + +export async function clearNativeStartupContext(db: Db, input: { + companyId: string; runId: string; contextId: string; leaseOwner: string; controllerGeneration: number; +}): Promise { + const cleared = await db.update(heartbeatRuns).set({ + runnerProfileJson: sql`${heartbeatRuns.runnerProfileJson} - 'nativeStartupContext'`, + }).where(and(eq(heartbeatRuns.companyId, input.companyId), eq(heartbeatRuns.id, input.runId), + eq(heartbeatRuns.status, "running"), + sql`coalesce(${heartbeatRuns.resultJson}->'nativeStartupCleanup'->>'state', '') != 'pending'`, + sql`${heartbeatRuns.runnerProfileJson}->'nativeStartupContext'->>'contextId' = ${input.contextId}`, + sql`${heartbeatRuns.runnerProfileJson}->'nativeStartupContext'->>'leaseOwner' = ${input.leaseOwner}`, + sql`${heartbeatRuns.runnerProfileJson}->'nativeStartupContext'->>'controllerGeneration' = ${String(input.controllerGeneration)}`, + sql`exists (select 1 from ${nativeRunFinalizations} where ${nativeRunFinalizations.runId} = ${input.runId} + and ${nativeRunFinalizations.leaseOwner} = ${input.leaseOwner} + and ${nativeRunFinalizations.controllerGeneration} = ${input.controllerGeneration})`, + )).returning({ id: heartbeatRuns.id }); + if (cleared.length !== 1) throw new Error("Native startup fallback lost authority"); +} + +export async function promoteNativeStartupCleanup(db: Db, run: Run, + owner: { leaseOwner: string | null; leaseExpiresAt: Date | null; controllerGeneration: number; attempt: number; resultId: string | null }, + now: Date): Promise { + const startup = readNativeStartupContext(run, owner); + if (!startup || startup.deadlineAtMs > now.getTime() || !owner.leaseOwner || !owner.leaseExpiresAt || owner.leaseExpiresAt > now || isNativeRunnerOwnershipHeld(run)) return false; + const [lease] = await db.select().from(environmentLeases).where(and(eq(environmentLeases.id, startup.leaseId), + eq(environmentLeases.companyId, run.companyId), eq(environmentLeases.heartbeatRunId, run.id), + sql`${environmentLeases.metadata}->>'runnerTaskLease' = 'true'`)); + if (!lease) return false; + const prepared = lease.metadata?.runnerTaskStartup as { contextId?: unknown; runId?: unknown } | undefined; + return requestNativeStartupCleanup(db, { companyId: run.companyId, agentId: run.agentId, runId: run.id, + ...startup, leaseOwner: owner.leaseOwner, + requiresPreparationStop: prepared?.contextId === startup.contextId && prepared.runId === run.id }, { publish: false }); +} + +export async function requestNativeStartupCleanup(db: Db, input: { + companyId: string; agentId: string; runId: string; contextId: string; deadlineAtMs: number; leaseOwner: string; + requiresPreparationStop: boolean; + leaseId?: string; +}, options: { publish?: boolean } = {}): Promise { + let publication: Parameters[0] | null = null; + const [binding] = await db.select({ issueId: nativeRunFinalizations.issueId }).from(nativeRunFinalizations).where(and( + eq(nativeRunFinalizations.companyId, input.companyId), eq(nativeRunFinalizations.runId, input.runId))); + if (!binding) return false; + const requested = await db.transaction(async tx => { + await tx.select({ id: issues.id }).from(issues).where(and(eq(issues.companyId, input.companyId), eq(issues.id, binding.issueId))).for("update"); + const [coordinator] = await tx.select().from(nativeRunFinalizations).where(and( + eq(nativeRunFinalizations.companyId, input.companyId), eq(nativeRunFinalizations.runId, input.runId))).for("update"); + const [run] = await tx.select().from(heartbeatRuns).where(and(eq(heartbeatRuns.companyId, input.companyId), + eq(heartbeatRuns.id, input.runId), eq(heartbeatRuns.agentId, input.agentId))).for("update"); + if (!run || !coordinator || run.runtimeMode !== "native" || run.status !== "running" || run.sessionIdAfter || coordinator.resultId || + isNativeRunnerOwnershipHeld(run)) return false; + const existing = readNativeStartupCleanup(run); + if (existing) return existing.contextId === input.contextId; + if (coordinator.leaseOwner !== input.leaseOwner) return false; + const leases = await tx.select().from(environmentLeases).where(and(eq(environmentLeases.companyId, input.companyId), + eq(environmentLeases.heartbeatRunId, input.runId), input.leaseId ? eq(environmentLeases.id, input.leaseId) : undefined, + sql`${environmentLeases.metadata}->>'runnerTaskLease' = 'true'`)).for("update"); + if (leases.length !== 1 || !leases[0]!.providerLeaseId) throw new Error("Native startup cleanup lease unavailable"); + const lease = leases[0]!; + const activity = await persistActivity(tx as unknown as Db, { companyId: input.companyId, actorType: "system", + actorId: "native-startup-cleanup", action: "native.startup_cleanup_requested", entityType: "heartbeat_run", entityId: run.id, + agentId: run.agentId, runId: run.id, issueId: run.nativeIssueId ?? undefined, + details: { contextId: input.contextId, deadlineAtMs: input.deadlineAtMs, leaseId: lease.id, + controllerGeneration: coordinator.controllerGeneration, reason: "startup_worker_unsettled" } }); + if (!activity.activity?.id) throw new Error("Native startup cleanup audit unavailable"); + publication = activity.publication; + const preparation = lease.metadata?.runnerTaskStartup as { contextId?: unknown; runId?: unknown } | undefined; + const marker: NativeStartupCleanup = { schema: "paperclip.native-startup-cleanup.v1", companyId: run.companyId, agentId: run.agentId, + runId: run.id, contextId: input.contextId, deadlineAtMs: input.deadlineAtMs, leaseOwner: input.leaseOwner, + controllerGeneration: coordinator.controllerGeneration, attempt: coordinator.attempt, leaseId: lease.id, + taskId: lease.providerLeaseId!, requiresPreparationStop: input.requiresPreparationStop || + (preparation?.contextId === input.contextId && preparation.runId === run.id), state: "pending", auditId: activity.activity.id }; + await notifyDeliveryWork(tx, DELIVERY_QUEUES.executionFinalization); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.environmentCleanup); + await tx.update(heartbeatRuns).set({ errorCode: NATIVE_STARTUP_CLEANUP_PENDING, + error: "Native startup timed out. Cancellation and verified cleanup are pending.", + resultJson: sql`coalesce(${heartbeatRuns.resultJson}, '{}'::jsonb) || ${JSON.stringify({ nativeStartupCleanup: marker, + startupCancellation: { ...run.resultJson?.startupCancellation as object, requestedAt: new Date().toISOString() } })}::jsonb`, + updatedAt: new Date() }).where(eq(heartbeatRuns.id, run.id)); + await tx.update(nativeRunFinalizations).set({ phase: "terminal_failure", failureCode: NATIVE_STARTUP_CLEANUP_PENDING, + nextAttemptAt: null, controlDeadlineAt: new Date(), recoveryState: "blocked", updatedAt: new Date() }) + .where(eq(nativeRunFinalizations.runId, run.id)); + await tx.update(environmentLeases).set({ metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || ${JSON.stringify({ + runnerTaskRetiring: true, runnerTaskStartupCleanup: { contextId: marker.contextId, requiresPreparationStop: marker.requiresPreparationStop }, + })}::jsonb`, updatedAt: new Date() }).where(eq(environmentLeases.id, lease.id)); + return true; + }); + if (publication && options.publish !== false) publishActivity(publication); + return requested; +} + +async function assertStartupCreationsStopped(db: Db, marker: NativeStartupCleanup): Promise { + const creations = await db.select({ creation: sandboxCreationOperations, lease: environmentLeases }).from(sandboxCreationOperations) + .leftJoin(environmentLeases, eq(environmentLeases.id, sandboxCreationOperations.leaseId)).where(and( + eq(sandboxCreationOperations.companyId, marker.companyId), eq(sandboxCreationOperations.runId, marker.runId), + sql`${sandboxCreationOperations.metadata}->>'runnerTaskLease' = 'true'`)); + if (creations.some(({ creation, lease }) => creation.state !== "attached" && + (!["cleanup_pending", "resolved"].includes(creation.state) || !lease || lease.companyId !== marker.companyId || lease.heartbeatRunId !== marker.runId || + lease.providerLeaseId !== creation.metadata.creationProviderLeaseId || lease.cleanupStatus !== "success" || !hasRemoteTerminationReceipt(lease)))) { + throw conflict("Task cleanup is still pending", { code: NATIVE_STARTUP_CLEANUP_PENDING }); + } +} + +export async function verifyNativeStartupCleanup(db: Db, run: Run, release: () => Promise): Promise { + const marker = readNativeStartupCleanup(run); + if (!marker || isNativeRunnerOwnershipHeld(run) || !["running", "cancelled"].includes(run.status)) throw conflict("Native startup cleanup intent unavailable"); + const read = async () => { + const [lease] = await db.select().from(environmentLeases).where(and(eq(environmentLeases.companyId, run.companyId), eq(environmentLeases.id, marker.leaseId))); + if (!lease || lease.heartbeatRunId !== run.id || lease.providerLeaseId !== marker.taskId) throw conflict("Native startup cleanup target changed"); + return lease; + }; + const [owner] = await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, run.id)); + if (!owner || owner.controllerGeneration !== marker.controllerGeneration || owner.attempt !== marker.attempt || + owner.leaseOwner !== marker.leaseOwner || owner.resultId) throw conflict("Native startup cleanup ownership changed"); + let lease = await read(); + const stopped = (value: typeof lease) => hasRemoteTerminationReceipt(value) && value.cleanupStatus === "success" && + (!marker.requiresPreparationStop || value.metadata?.runnerTaskPreparationStopped === true); + if (!stopped(lease)) { await release(); lease = await read(); } + if (!stopped(lease)) throw conflict("Task cleanup is still pending", { code: NATIVE_STARTUP_CLEANUP_PENDING }); + await assertStartupCreationsStopped(db, marker); + await db.transaction(async tx => { + await tx.select({ id: issues.id }).from(issues).where(and(eq(issues.companyId, run.companyId), eq(issues.id, run.nativeIssueId!))).for("update"); + const [coordinator] = await tx.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, run.id)).for("update"); + const [current] = await tx.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, run.id)).for("update"); + const observed = current && readNativeStartupCleanup(current); + const [receipt] = await tx.select().from(environmentLeases).where(eq(environmentLeases.id, marker.leaseId)).for("update"); + if (!coordinator || !current || isNativeRunnerOwnershipHeld(current) || coordinator.resultId || coordinator.controllerGeneration !== marker.controllerGeneration || + coordinator.attempt !== marker.attempt || coordinator.leaseOwner !== marker.leaseOwner || observed?.contextId !== marker.contextId || + !receipt || receipt.providerLeaseId !== marker.taskId || receipt.heartbeatRunId !== run.id || !stopped(receipt)) { + throw conflict("Native startup cleanup ownership changed"); + } + await assertStartupCreationsStopped(tx as unknown as Db, marker); + await tx.update(heartbeatRuns).set({ resultJson: sql`jsonb_set(${heartbeatRuns.resultJson}, '{nativeStartupCleanup,state}', '"complete"'::jsonb)`, updatedAt: new Date() }) + .where(eq(heartbeatRuns.id, run.id)); + }); +} + +export async function acknowledgeNativeStartupCleanup(db: Db, input: { companyId: string; runId: string }): Promise { + const [binding] = await db.select({ issueId: nativeRunFinalizations.issueId }).from(nativeRunFinalizations).where(and( + eq(nativeRunFinalizations.companyId, input.companyId), eq(nativeRunFinalizations.runId, input.runId))); + if (!binding) return; + await db.transaction(async tx => { + await tx.select({ id: issues.id }).from(issues).where(and(eq(issues.companyId, input.companyId), eq(issues.id, binding.issueId))).for("update"); + const [owner] = await tx.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, input.runId)).for("update"); + const [run] = await tx.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, input.runId)).for("update"); + const marker = run && readNativeStartupCleanup(run); + if (!owner || !run || run.status !== "cancelled" || !marker || marker.state !== "complete" || owner.resultId || + owner.failureCode !== NATIVE_STARTUP_CLEANUP_PENDING || owner.controllerGeneration !== marker.controllerGeneration || + owner.attempt !== marker.attempt || owner.leaseOwner !== marker.leaseOwner) return; + const [lease] = await tx.select().from(environmentLeases).where(eq(environmentLeases.id, marker.leaseId)).for("update"); + if (!lease || lease.heartbeatRunId !== run.id || lease.providerLeaseId !== marker.taskId || !hasRemoteTerminationReceipt(lease) || + (marker.requiresPreparationStop && lease.metadata?.runnerTaskPreparationStopped !== true)) return; + await assertStartupCreationsStopped(tx as unknown as Db, marker); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentLifecycle); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.environmentCleanup); + await tx.update(nativeRunFinalizations).set({ leaseOwner: null, leaseExpiresAt: null, controlDeadlineAt: null, recoveryState: null, + failureCode: "native_retry_cancelled", updatedAt: new Date() }).where(and(eq(nativeRunFinalizations.runId, input.runId), isNull(nativeRunFinalizations.resultId))); + }); +} diff --git a/server/src/services/plugin-worker-manager.ts b/server/src/services/plugin-worker-manager.ts index 363d15c065c..2fa59b62573 100644 --- a/server/src/services/plugin-worker-manager.ts +++ b/server/src/services/plugin-worker-manager.ts @@ -725,6 +725,7 @@ export interface PluginWorkerHandle { executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise; /** @@ -865,6 +866,7 @@ export interface PluginWorkerManager { executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise; /** @@ -914,6 +916,10 @@ export function createPluginWorkerHandle( // Unlike RPC promises, these survive timeouts. A late response is the // completion receipt. A worker crash cannot manufacture one. const unsettledCalls = new Map void>(); + const observedResults = new Map; + observe: (result: unknown) => Promise; finish: () => void; + }>(); const startupCalls = new Map void>>(); const startupRetirements = new Map>(); const startupHostHandlers = new Map>>(); @@ -1156,24 +1162,50 @@ export function createPluginWorkerHandle( /** * Handle a JSON-RPC response from the worker (matching a pending request). */ + function settleResponse(response: JsonRpcResponse): void { + const id = response.id!; + unsettledCalls.get(id)?.(); + unsettledCalls.delete(id); + const pending = pendingRequests.get(id); + if (!pending) { log.warn({ id }, "received response for unknown request id"); return; } + clearTimeout(pending.timer); + pendingRequests.delete(id); + pending.resolve(response); + } + + function processObservedResult(id: string | number): Promise { + const observer = observedResults.get(id); + if (!observer?.response) return Promise.resolve(); + if (observer.running) return observer.running; + const response = observer.response; + const processing = (async () => { + if (isJsonRpcSuccessResponse(response)) await observer.observe(response.result); + observedResults.delete(id); + observer.finish(); + settleResponse(response); + })(); + observer.running = processing; + void processing.catch(() => { + const pending = pendingRequests.get(id); + pending?.resolve(createErrorResponse(id, JSONRPC_ERROR_CODES.INTERNAL_ERROR, "Plugin result could not be recorded")); + }).finally(() => { if (observer.running === processing) observer.running = undefined; }); + return processing; + } + function handleResponse(response: JsonRpcResponse): void { const id = response.id; if (id === null || id === undefined) { log.warn("received response with null/undefined id"); return; } - - unsettledCalls.get(id)?.(); - unsettledCalls.delete(id); - const pending = pendingRequests.get(id); - if (!pending) { - log.warn({ id }, "received response for unknown request id"); + const observer = observedResults.get(id); + if (observer) { + if (observer.response) return; + observer.response = response; + void processObservedResult(id).catch(() => log.warn({ id }, "plugin result recording will retry during cleanup")); return; } - - clearTimeout(pending.timer); - pendingRequests.delete(id); - pending.resolve(response); + settleResponse(response); } function readNonEmptyString(value: unknown): string | null { @@ -3087,6 +3119,11 @@ export function createPluginWorkerHandle( // Read-only requests cannot continue in an exited worker. Do not infer // completion for execute/cleanup calls, whose provider work may outlive it. for (const finish of [...unsettledInspections]) finish(); + for (const [id, observer] of observedResults) { + if (observer.response) continue; + observedResults.delete(id); + observer.finish(); + } // Close the one login pseudo-terminal route with a fixed non-secret exit and // clear the route one time. The pending pseudo-terminal calls @@ -3423,8 +3460,9 @@ export function createPluginWorkerHandle( executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise { - const dispatched = measureRunPhase("execution.plugin_dispatch", () => callInternalRaw(method, params, timeoutMs, executeLogSink, onWorkerSettled, startupContextId)); + const dispatched = measureRunPhase("execution.plugin_dispatch", () => callInternalRaw(method, params, timeoutMs, executeLogSink, onWorkerSettled, startupContextId, observeResult)); // Tracing wraps the RPC in a new promise. Guard the promise handed to the // caller as well, without swallowing its eventual rejection for that caller. void dispatched.catch(() => undefined); @@ -3438,6 +3476,7 @@ export function createPluginWorkerHandle( executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise { const rpcPromise = new Promise((resolve, reject) => { if (startupContextId && startupRetirements.has(startupContextId)) { @@ -3484,6 +3523,19 @@ export function createPluginWorkerHandle( } if (method === "environmentInspectLease") unsettledInspections.add(finish); } + if (observeResult && startupContextId) { + let finish!: () => void; + const processing = new Promise(resolve => { finish = resolve; }); + let handlers = startupHostHandlers.get(startupContextId); + if (!handlers) { handlers = new Set(); startupHostHandlers.set(startupContextId, handlers); } + handlers.add(processing); + observedResults.set(id, { contextId: startupContextId, observe: observeResult as (result: unknown) => Promise, finish: () => { + startupHostHandlers.get(startupContextId)?.delete(processing); + if (startupHostHandlers.get(startupContextId)?.size === 0) startupHostHandlers.delete(startupContextId); + finish(); + onStartupWorkChanged?.(); + } }); + } const timeout = resolveRpcCallTimeoutMs(timeoutMs, rpcTimeoutMs); const invocationScope = deriveInvocationScope(method, params); const invocation = invocationScope ? registerInvocation(invocationScope) : null; @@ -3550,6 +3602,8 @@ export function createPluginWorkerHandle( } catch (err) { clearTimeout(timer); pendingRequests.delete(id); + observedResults.get(id)?.finish(); + observedResults.delete(id); unsettledCalls.get(id)?.(); unsettledCalls.delete(id); clearInvocation(invocation); @@ -3637,6 +3691,7 @@ export function createPluginWorkerHandle( hasStartupWork() { return startupCalls.size > 0 || startupHostHandlers.size > 0 || startupRetirements.size > 0; }, async drainStartup(contextId: string) { revokeStartupInvocations(contextId); + for (const [id, observer] of observedResults) if (observer.contextId === contextId) void processObservedResult(id).catch(() => undefined); await waitForStartupHandlers(contextId); }, async retireStartup(contextId: string) { @@ -3644,6 +3699,7 @@ export function createPluginWorkerHandle( if (current) return current; const retiring = (async () => { revokeStartupInvocations(contextId); + for (const [id, observer] of observedResults) if (observer.contextId === contextId) void processObservedResult(id).catch(() => undefined); await waitForStartupHandlers(contextId); for (const finish of [...startupCalls.get(contextId) ?? []]) finish(); })(); @@ -3662,6 +3718,7 @@ export function createPluginWorkerHandle( executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise { if (status !== "running" && status !== "starting") { onWorkerSettled?.(); @@ -3671,7 +3728,7 @@ export function createPluginWorkerHandle( ), ); } - return callInternal(method, params, timeoutMs, executeLogSink, onWorkerSettled, startupContextId); + return callInternal(method, params, timeoutMs, executeLogSink, onWorkerSettled, startupContextId, observeResult); }, openLoginPtySession(input: LoginPtyOpenInput) { @@ -4032,6 +4089,7 @@ export function createPluginWorkerManager( executeLogSink?: ExecuteLogSink, onWorkerSettled?: () => void, startupContextId?: string, + observeResult?: (result: HostToWorkerMethods[M][1]) => Promise, ): Promise { const handle = workers.get(pluginId); if (!startupContextId && ["environmentReleaseLease", "environmentDestroyLease"].includes(method)) { @@ -4057,7 +4115,7 @@ export function createPluginWorkerManager( // A caller timeout is not worker completion. Inspection capacity is // released only by its actual reply, send failure, or worker exit. const finish = onWorkerSettled ? () => { finishInspection?.(); onWorkerSettled(); } : finishInspection; - const result = handle.call(method, params, timeoutMs, executeLogSink, finish, startupContextId); + const result = handle.call(method, params, timeoutMs, executeLogSink, finish, startupContextId, observeResult); if (method === "configChanged") void result.then(() => { for (const listener of configApplied) { try { listener(); } diff --git a/server/src/services/sandbox-creation-operations.ts b/server/src/services/sandbox-creation-operations.ts index a56c6615284..7fab2432fe6 100644 --- a/server/src/services/sandbox-creation-operations.ts +++ b/server/src/services/sandbox-creation-operations.ts @@ -4,9 +4,9 @@ import { and, eq, lte, or, sql } from "drizzle-orm"; import { companies, environments, sandboxCreationOperations, type Db } from "@paperclipai/db"; import { readEnvironmentCreationCleanupError, type PluginEnvironmentLease, type PluginEnvironmentLeaseObservation } from "@paperclipai/plugin-sdk"; import { assertEnvironmentCompanyBinding, environmentService } from "./environments.js"; -import { ENVIRONMENT_CLEANUP_RETRY_MS } from "./environment-cleanup-state.js"; +import { ENVIRONMENT_CLEANUP_RETRY_MS, recoverableSandboxCreationCondition } from "./environment-cleanup-state.js"; import { logger } from "../middleware/logger.js"; -import { notifyEnvironmentCleanup } from "./environment-cleanup-notifications.js"; +import { notifyEnvironmentCleanup, writeEnvironmentCleanup } from "./environment-cleanup-notifications.js"; export type SandboxCreationOperation = typeof sandboxCreationOperations.$inferSelect; @@ -78,26 +78,69 @@ export async function createOwnedSandbox( * This enriches the existing owner; it never transfers or reopens ownership. */ export async function recordSandboxCreationResource(db: Db, input: { id: string; companyId: string; environmentId: string; providerLeaseId: string; + providerMetadata?: Record; }): Promise { - const [recorded] = await db.update(sandboxCreationOperations).set({ - metadata: sql`coalesce(${sandboxCreationOperations.metadata}, '{}'::jsonb) || ${JSON.stringify({ creationProviderLeaseId: input.providerLeaseId })}::jsonb`, - updatedAt: new Date(), - }).where(and(eq(sandboxCreationOperations.id, input.id), eq(sandboxCreationOperations.companyId, input.companyId), - eq(sandboxCreationOperations.originalEnvironmentId, input.environmentId), - or(sql`${sandboxCreationOperations.metadata}->>'creationProviderLeaseId' is null`, - sql`${sandboxCreationOperations.metadata}->>'creationProviderLeaseId' = ${input.providerLeaseId}`), - )).returning({ id: sandboxCreationOperations.id }); - if (!recorded) throw new Error("Sandbox creation resource identity changed"); + await writeEnvironmentCleanup(db, async tx => { + const [recorded] = await tx.update(sandboxCreationOperations).set({ + nextAttemptAt: sql`case when ${sandboxCreationOperations.state} = 'needs_reconciliation' then clock_timestamp() else ${sandboxCreationOperations.nextAttemptAt} end`, + metadata: sql`coalesce(${sandboxCreationOperations.metadata}, '{}'::jsonb) || ${JSON.stringify({ creationProviderLeaseId: input.providerLeaseId, ...(input.providerMetadata ? { creationProviderMetadata: input.providerMetadata } : {}) })}::jsonb`, + updatedAt: new Date(), + }).where(and(eq(sandboxCreationOperations.id, input.id), eq(sandboxCreationOperations.companyId, input.companyId), + eq(sandboxCreationOperations.originalEnvironmentId, input.environmentId), + or(sql`${sandboxCreationOperations.metadata}->>'creationProviderLeaseId' is null`, + sql`${sandboxCreationOperations.metadata}->>'creationProviderLeaseId' = ${input.providerLeaseId}`), + )).returning({ id: sandboxCreationOperations.id }); + if (!recorded) throw new Error("Sandbox creation resource identity changed"); + }, { companyId: input.companyId }); +} + +export async function queueSandboxCreationCleanup(db: Db, input: { + id: string; companyId: string; environmentId: string; providerLeaseId: string; + providerMetadata?: Record; +}): Promise { + await db.transaction(async tx => { + await tx.select({ id: environments.id }).from(environments).where(eq(environments.id, input.environmentId)).for("update"); + const [operation] = await tx.select().from(sandboxCreationOperations).where(and(eq(sandboxCreationOperations.id, input.id), + eq(sandboxCreationOperations.companyId, input.companyId), eq(sandboxCreationOperations.originalEnvironmentId, input.environmentId))).for("update"); + if (!operation || (operation.metadata.creationProviderLeaseId && operation.metadata.creationProviderLeaseId !== input.providerLeaseId)) { + throw new Error("Sandbox creation cleanup ownership changed"); + } + if (["attached", "cleanup_pending", "resolved"].includes(operation.state)) return; + const contextId = operation.metadata.runnerTaskLease === true && typeof operation.metadata.runnerTaskCreationContextId === "string" + ? operation.metadata.runnerTaskCreationContextId : null; + if (operation.state !== "pending" && !(operation.state === "needs_reconciliation" && contextId && + operation.metadata.creationProviderLeaseId === input.providerLeaseId)) throw new Error("Sandbox creation cleanup ownership changed"); + await notifyEnvironmentCleanup(tx, { companyId: operation.companyId, runId: operation.runId }); + const lease = await environmentService(tx as unknown as Db).insertPendingCleanupLease({ + companyId: operation.companyId, environmentId: operation.originalEnvironmentId, + heartbeatRunId: operation.runId, issueId: operation.issueId, executionWorkspaceId: operation.executionWorkspaceId, + provider: operation.provider, providerLeaseId: input.providerLeaseId, + metadata: { ...operation.metadata, creationOperationId: operation.id, environmentId: operation.originalEnvironmentId, + providerMetadata: input.providerMetadata ?? operation.metadata.creationProviderMetadata ?? {}, runnerTaskRetiring: true, + ...(contextId ? { runnerTaskStartupCleanup: { contextId, requiresPreparationStop: false } } : {}) }, + failureReason: "interrupted_task_creation", + }); + await tx.update(sandboxCreationOperations).set({ state: "cleanup_pending", leaseId: lease.id, updatedAt: new Date(), + metadata: { ...operation.metadata, creationProviderLeaseId: input.providerLeaseId, + creationProviderMetadata: input.providerMetadata ?? operation.metadata.creationProviderMetadata ?? {} }, + }).where(eq(sandboxCreationOperations.id, operation.id)); + }); } export async function recoverSandboxCreations(db: Db, inspect: (operation: SandboxCreationOperation) => Promise, ): Promise { const due = await db.select().from(sandboxCreationOperations).where(and( - eq(sandboxCreationOperations.state, "pending"), lte(sandboxCreationOperations.nextAttemptAt, new Date()), + recoverableSandboxCreationCondition(), lte(sandboxCreationOperations.nextAttemptAt, new Date()), )).limit(100); for (const candidate of due) { try { + if (candidate.metadata.runnerTaskLease === true && typeof candidate.metadata.runnerTaskCreationContextId === "string" && + typeof candidate.metadata.creationProviderLeaseId === "string") { + await queueSandboxCreationCleanup(db, { id: candidate.id, companyId: candidate.companyId, + environmentId: candidate.originalEnvironmentId, providerLeaseId: candidate.metadata.creationProviderLeaseId }); + continue; + } const [existingCompany] = await db.select({ id: companies.id }).from(companies).where(eq(companies.id, candidate.companyId)).limit(1); const observation = existingCompany ? await inspect(candidate) : null; const cleanup = observation?.creationCleanup ? readEnvironmentCreationCleanupError({ data: { @@ -140,7 +183,7 @@ export async function recoverSandboxCreations(db: Db, ? { nextAttemptAt: new Date(Date.now() + ENVIRONMENT_CLEANUP_RETRY_MS), updatedAt: new Date() } : { state: "needs_reconciliation", updatedAt: new Date(), metadata: sql`coalesce(${sandboxCreationOperations.metadata}, '{}'::jsonb) || '{"creationReconciliationReason":"company_deleted"}'::jsonb` }) - .where(and(eq(sandboxCreationOperations.id, candidate.id), eq(sandboxCreationOperations.state, "pending"))); + .where(and(eq(sandboxCreationOperations.id, candidate.id), recoverableSandboxCreationCondition())); return Boolean(company); }); logger.warn({ errorKind: retry ? "sandbox_creation_recovery_failed" : "sandbox_creation_needs_reconciliation", operationId: candidate.id, companyId: candidate.companyId },