diff --git a/doc/run-log-events.md b/doc/run-log-events.md index 9641c092e7..9c13110010 100644 --- a/doc/run-log-events.md +++ b/doc/run-log-events.md @@ -58,6 +58,17 @@ and incomplete result-delivery command IDs and statuses. If execution and cleanup both fail, execution retains its original error identity and cleanup is attached as `cleanupError`. +Warm retirement failures emit `native_session.retirement_diagnostic` on the +persistent run log, including after the turn's output stream closes. The payload +contains a closed retirement phase, close state (`not_started`, `pending`, +`completed`, or `failed`), a closed failure code, and the bound run, native +session, runner, optional preparing run, and computer-owner IDs/generation. +The retirement attempt snapshots its owner and observer before awaiting. A close that +rejects after the retirement grace can emit a later diagnostic. Arbitrary +exception text, paths, and caller-supplied retirement reasons are excluded. +These observations do not change retirement, quarantine, or replay authority; +logging failure cannot alter the cleanup result. + Semantic settlement also includes up to 20 content-free failure records, with the call ID, operation ID, stage (`dispatch` or `persist_result`), and cause. Causes distinguish an oversized command, a full command journal, known storage diff --git a/server/src/services/native-runtime/native-session-executor.test.ts b/server/src/services/native-runtime/native-session-executor.test.ts index ec8617a551..1c3affd002 100644 --- a/server/src/services/native-runtime/native-session-executor.test.ts +++ b/server/src/services/native-runtime/native-session-executor.test.ts @@ -1,4 +1,4 @@ -import { compareAndSealRetiredComputerCheckpoint, retiredComputerCheckpointIsSettled, retiredComputerCheckpointUnsettledReason, retireUnlaunchedComputerAttempt, nativeSessionBootstrapTimeoutMs } from "./native-session-executor.js"; +import { closeWarmNativeSession, compareAndSealRetiredComputerCheckpoint, retiredComputerCheckpointIsSettled, retiredComputerCheckpointUnsettledReason, retireUnlaunchedComputerAttempt, nativeSessionBootstrapTimeoutMs } from "./native-session-executor.js"; import { prepareHeartbeatGitHubLaunchers } from "../heartbeat-github-launchers.js"; import { RemoteProviderPackVerificationError } from "./remote-provider-pack-cache.js"; import { gunzipSync } from "node:zlib"; @@ -14157,6 +14157,41 @@ describe("computer idle authority transition", () => { }); describe("computer graceful idle reservation", () => { + it("attributes preparation retirement to the actual advanced computer generation", async () => { + const name = "computer-retirement-diagnostic-generation"; + const current = { ...execution, binding: { ...execution.binding, runId: `${name}-one`, agentId: name }, + session: { ...execution.session, normalizedSessionId: name, lifecyclePolicy: { mode: "warm", idleTimeoutMs: 60_000 } } } as NativeExecutionInputV1; + const onEvent = vi.fn(async () => undefined); + const close = vi.fn(async () => undefined); + const retire = vi.fn(async () => true); + const nextRetire = vi.fn(async () => true); + const target = { kind: "remote", transport: "computer", environmentId: name, remoteCwd: "/remote/agent", + resourceAuthority: { kind: "computer-owner", computerId: name, ownerId: name, generation: 1 }, + retainWarm: async () => undefined, retire }; + state.execute.mockReset().mockImplementationOnce(async options => { await options.onSession?.({ close }); + return { result: { summary: "completed" }, terminal: { runTerminalState: "succeeded" }, turnId: name, + normalizedSessionId: name, providerSessionId: name, driverKind: "test", driverVersion: "1", nativeEventCount: 1, + highestContiguousSourceSeq: 1, usage: null }; }); + await executePaperclipNativeSession({ db: leaseDb(current), execution: current, runnerInstanceId: name, onEvent, + runnerExecutionTarget: target as never, + instructionWorkingCopy: { runId: current.binding.runId, root: "/remote/agent", hasChanges: async () => false, + checkpointWarm: async () => true, collectStopped: async () => undefined } }); + try { + await expect(reserveWarmNativeInstructionDirectory({ companyId: current.binding.companyId, agentId: name, + previousRunId: current.binding.runId, runId: `${name}-two`, canReuse: async () => false, + target: { ...target, resourceAuthority: { ...target.resourceAuthority, generation: 2 }, retire: nextRetire } as never, + })).rejects.toThrow("prior session cleanup requires operator recovery"); + await vi.waitFor(() => expect(onEvent).toHaveBeenCalledWith(expect.objectContaining({ + eventType: "native_session.retirement_diagnostic", payload: expect.objectContaining({ + runId: current.binding.runId, preparingRunId: `${name}-two`, ownerId: name, ownerGeneration: 2, closeState: "not_started", + }), + }))); + expect(retire).not.toHaveBeenCalled(); + expect(nextRetire).toHaveBeenCalledOnce(); + expect(close).not.toHaveBeenCalled(); + } finally { await closeWarmNativeSessionsForRun({ runId: current.binding.runId, reason: "fixture cleanup" }); } + }); + it.each(["codex", "acpx"])("suspends %s before retiring descendants and admits the next idle turn", async kind => { const name = `graceful-idle-${kind}`; const current = { ...execution, binding: { ...execution.binding, runId: `${name}-one`, agentId: name }, @@ -14195,7 +14230,8 @@ describe("computer graceful idle reservation", () => { const name = `graceful-${condition}`; const current = { ...execution, binding: { ...execution.binding, runId: name, agentId: name }, session: { ...execution.session, normalizedSessionId: name, lifecyclePolicy: { mode: "warm", idleTimeoutMs: 60_000 } } } as NativeExecutionInputV1; - const close = vi.fn(async () => { throw new Error("protocol close failed"); }); + const close = vi.fn(async () => { throw new Error("PRIVATE-CANARY protocol close failed /private/home?token=secret"); }); + const onEvent = vi.fn(async () => undefined); const detach = vi.fn(async () => undefined); let retired = false; const retire = vi.fn(async (options?: { beforeStop?: () => Promise }) => { @@ -14208,12 +14244,20 @@ describe("computer graceful idle reservation", () => { return { result: { summary: "completed" }, terminal: { runTerminalState: "succeeded" }, turnId: name, normalizedSessionId: name, providerSessionId: name, driverKind: "test", driverVersion: "1", nativeEventCount: 1, highestContiguousSourceSeq: 1, usage: null }; }); - await executePaperclipNativeSession({ db: leaseDb(current), execution: current, runnerInstanceId: name, + await executePaperclipNativeSession({ db: leaseDb(current), execution: current, runnerInstanceId: name, onEvent, runnerExecutionTarget: { kind: "remote", transport: "computer", environmentId: name, remoteCwd: "/remote/agent", resourceAuthority: { kind: "computer-owner", computerId: name, ownerId: name, generation: 1 }, retainWarm: async () => undefined, retire } as never }); const result = await closeWarmNativeSessionsForRun({ runId: name, reason: "cancel exact task" }); expect(result.failed).toBe(1); + await vi.waitFor(() => expect(onEvent).toHaveBeenCalledWith(expect.objectContaining({ + eventType: "native_session.retirement_diagnostic", + payload: expect.objectContaining({ runId: name, normalizedSessionId: name, runnerInstanceId: name, + computerId: name, ownerId: name, ownerGeneration: 1, + closeState: condition === "failed-close" ? "failed" : "not_started", + phase: condition === "superseded" ? "computer_retirement" : "session_close" }), + }))); + expect(JSON.stringify(onEvent.mock.calls)).not.toContain("PRIVATE-CANARY"); expect(retired).toBe(condition !== "superseded"); if (condition === "superseded") { expect(close).not.toHaveBeenCalled(); expect(detach).not.toHaveBeenCalled(); } else expect(detach).toHaveBeenCalledOnce(); @@ -14295,3 +14339,67 @@ describe("computer managed context snapshots", () => { else { expect(launch).toHaveBeenCalledOnce(); expect(inspectProcess).not.toHaveBeenCalled(); expect(retire).not.toHaveBeenCalled(); } }); }); + + +describe("warm native retirement diagnostics", () => { + it.each(["not_started", "pending", "failed", "superseded", "retirement_failed", "collection_failed"] as const)("records a closed diagnostic without changing retirement (%s)", async mode => { + const secret = "PRIVATE-CANARY /private/provider/home?token=secret"; + const failure = new Error(secret); + const diagnostic = vi.fn(); + const collect = vi.fn(async () => { if (mode === "collection_failed") throw failure; }); + const detach = vi.fn(async () => undefined); + let rejectClose: ((error: Error) => void) | undefined; + const close = vi.fn(async () => { + if (mode === "failed") throw failure; + if (mode === "pending") await new Promise((_, reject) => { rejectClose = reject; }); + }); + let lateClose: Promise | undefined; + const retire = vi.fn(async ({ beforeStop }: { beforeStop: () => Promise }) => { + if (mode === "superseded") return false; + if (mode === "retirement_failed") throw failure; + if (mode === "pending") { lateClose = beforeStop(); void lateClose.catch(() => undefined); } + if (mode === "failed" || mode === "collection_failed") await beforeStop().catch(() => undefined); + return true; + }); + const entry = { session: { close, detachControllerForRestart: detach }, computerTarget: { retire }, + instructionWorkingCopy: { collectStopped: collect }, onRetirementDiagnostic: diagnostic } as unknown as Parameters[0]; + if (["failed", "retirement_failed", "collection_failed"].includes(mode)) + await expect(closeWarmNativeSession(entry, secret)).rejects.toBe(failure); + else await expect(closeWarmNativeSession(entry, secret)).rejects.toThrow(mode === "superseded" ? "computer_owner_retirement_superseded" : "prior session cleanup requires operator recovery"); + expect(diagnostic).toHaveBeenLastCalledWith({ + phase: ["superseded", "retirement_failed"].includes(mode) ? "computer_retirement" : mode === "collection_failed" ? "instruction_collection" : "session_close", + closeState: ["superseded", "retirement_failed", "not_started"].includes(mode) ? "not_started" : mode === "collection_failed" ? "completed" : mode, + failureCode: mode === "superseded" ? "computer_owner_retirement_superseded" : ["not_started", "pending"].includes(mode) ? "native_session_cleanup_quarantined" : "native_session_interrupted", + }); + if (mode !== "collection_failed") expect(collect).not.toHaveBeenCalled(); + if (["not_started", "superseded", "retirement_failed"].includes(mode)) expect(close).not.toHaveBeenCalled(); + if (mode === "pending") { + const successorObserver = vi.fn(); + entry.onRetirementDiagnostic = successorObserver; + rejectClose!(failure); + await expect(lateClose).rejects.toBe(failure); + expect(successorObserver).not.toHaveBeenCalled(); + expect(diagnostic).toHaveBeenLastCalledWith({ phase: "session_close", closeState: "failed", failureCode: "native_session_interrupted" }); + } + expect(JSON.stringify(diagnostic.mock.calls)).not.toContain(secret); + expect(retire).toHaveBeenCalledOnce(); + }); + + it("retains the known close settlement failure code without its payload", async () => { + const failure = Object.assign(new Error("PRIVATE-CANARY"), { code: "native_session_close_unrecoverable", settlement: { privatePath: "/private/canary" } }); + const diagnostic = vi.fn(); + const entry = { session: { close: async () => { throw failure; } }, + onRetirementDiagnostic: diagnostic } as unknown as Parameters[0]; + await expect(closeWarmNativeSession(entry, "test")).rejects.toBe(failure); + expect(diagnostic).toHaveBeenLastCalledWith({ phase: "session_close", closeState: "failed", failureCode: "native_session_close_unrecoverable" }); + expect(JSON.stringify(diagnostic.mock.calls)).not.toContain("CANARY"); + expect(JSON.stringify(diagnostic.mock.calls)).not.toContain("privatePath"); + }); + + it("does not let an observer failure change a failed close", async () => { + const failure = new Error("original close failure"); + const entry = { session: { close: async () => { throw failure; } }, + onRetirementDiagnostic: () => { throw new Error("observer failure"); } } as unknown as Parameters[0]; + await expect(closeWarmNativeSession(entry, "test")).rejects.toBe(failure); + }); +}); diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index e6463f11a9..79ac8f8a3a 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -445,7 +445,18 @@ export type NativeInstructionWorkingCopy = { retirementFailed?: () => Promise; }; +type WarmRetirementDiagnostic = { + computerId?: string; + ownerId?: string; + ownerGeneration?: number; + preparingRunId?: string; + phase: "computer_retirement" | "session_close" | "controller_detach" | "instruction_collection" | "access_cleanup"; + closeState: "not_started" | "pending" | "completed" | "failed"; + failureCode: ReturnType | "computer_owner_retirement_superseded" | "native_session_close_unrecoverable"; +}; + type WarmNativeSession = { + onRetirementDiagnostic?: (diagnostic: WarmRetirementDiagnostic) => void; computerTarget?: AdapterComputerExecutionTarget; runId: string; instructionWorkingCopy?: NativeInstructionWorkingCopy; @@ -490,35 +501,70 @@ class ComputerOwnerSupersededError extends Error { constructor() { super("computer_owner_retirement_superseded"); } } -async function closeWarmNativeSession(entry: WarmNativeSession, reason: string, preserveInstructionsForRunId?: string) { +export async function closeWarmNativeSession(entry: WarmNativeSession, reason: string, preserveInstructionsForRunId?: string) { let closeFailure: unknown; let closeCompleted = false; - const close = async () => { - try { await entry.session.close({ reason }); closeCompleted = true; } - catch (error) { closeFailure = error; throw error; } - }; - // Reserve the exact generation before protocol close. A winning admission - // must never receive a stale controller's suspend/kill command. The module - // always hard-retires descendants after the bounded graceful window. - if (entry.computerTarget && !(await entry.computerTarget.retire({ beforeStop: close }))) { - throw new ComputerOwnerSupersededError(); - } - const stopping = entry.githubAccess?.stop(); - try { + let closeState: WarmRetirementDiagnostic["closeState"] = "not_started"; + let phase: WarmRetirementDiagnostic["phase"] = "computer_retirement"; + const observer = entry.onRetirementDiagnostic; + const computer = entry.computerTarget?.resourceAuthority; + const context = { ...(computer ? { computerId: computer.computerId, ownerId: computer.ownerId, ownerGeneration: computer.generation } : {}), + ...(entry.preparingRunId ? { preparingRunId: entry.preparingRunId } : {}) }; + const report = (error: unknown, failedPhase = phase) => { try { - if (!entry.computerTarget) await close(); - if (closeFailure || !closeCompleted) { - await entry.session.detachControllerForRestart?.(); - throw closeFailure ?? new NativeSessionCleanupQuarantinedError(); - } - } catch (error) { - try { await entry.instructionWorkingCopy?.retirementFailed?.(); } - catch (receiptError) { throw new AggregateError([error, receiptError], "Warm instruction retirement and receipt both failed"); } + observer?.({ ...context, phase: failedPhase, closeState, + failureCode: error instanceof ComputerOwnerSupersededError + ? "computer_owner_retirement_superseded" + : error instanceof Error && "code" in error && error.code === "native_session_close_unrecoverable" + ? "native_session_close_unrecoverable" : nativeSessionFailureSourceCode(error) }); + } catch { /* Diagnostics never own retirement or alter its result. */ } + }; + const close = async () => { + closeState = "pending"; + try { await entry.session.close({ reason }); closeCompleted = true; closeState = "completed"; } + catch (error) { + closeFailure = error; + closeState = "failed"; + // Graceful retirement can finish its bounded wait before close rejects. + // Preserve that late initiating failure without exposing arbitrary text. + report(error, "session_close"); throw error; } - await entry.instructionWorkingCopy?.collectStopped(); - if (entry.instructionCopy?.runId !== preserveInstructionsForRunId) await entry.instructionCopy?.collectStopped(); - } finally { await stopping; } + }; + try { + // Reserve the exact generation before protocol close. A winning admission + // must never receive a stale controller's suspend/kill command. The module + // always hard-retires descendants after the bounded graceful window. + if (entry.computerTarget && !(await entry.computerTarget.retire({ beforeStop: close }))) { + throw new ComputerOwnerSupersededError(); + } + const stopping = entry.githubAccess?.stop(); + try { + try { + phase = "session_close"; + if (!entry.computerTarget) await close(); + if (closeFailure || !closeCompleted) { + phase = "controller_detach"; + await entry.session.detachControllerForRestart?.(); + phase = "session_close"; + throw closeFailure ?? new NativeSessionCleanupQuarantinedError(); + } + } catch (error) { + try { await entry.instructionWorkingCopy?.retirementFailed?.(); } + catch (receiptError) { throw new AggregateError([error, receiptError], "Warm instruction retirement and receipt both failed"); } + throw error; + } + phase = "instruction_collection"; + await entry.instructionWorkingCopy?.collectStopped(); + if (entry.instructionCopy?.runId !== preserveInstructionsForRunId) await entry.instructionCopy?.collectStopped(); + } finally { + try { await stopping; } + catch (error) { phase = "access_cleanup"; throw error; } + } + } catch (error) { + report(error); + throw error; + } } const warmNativeSessions = new Map(); @@ -8622,6 +8668,16 @@ async function executePaperclipNativeSessionWithinScope( const configuredEnvironmentDigest = createHash("sha256") .update(JSON.stringify(configuredEnvironment(input.runnerEnvironment))) .digest("hex"); + const onRetirementDiagnostic = (diagnostic: WarmRetirementDiagnostic) => { + // Use the persistent run log even after the turn's output stream is closed. + // The payload contains only closed enums and this execution's bound IDs. + void Promise.resolve().then(() => input.onEvent?.({ + eventType: "native_session.retirement_diagnostic", stream: "system", level: "warn", + message: "Native session retirement did not complete.", + payload: { ...diagnostic, runId: input.execution.binding.runId, + normalizedSessionId: nativeSessionKey(input.execution), runnerInstanceId: effectiveRunnerInstanceId }, + })).catch(() => undefined); + }; const warmSessionOwnerToken = Symbol( `native-warm-session:${input.execution.binding.runId}`, ); @@ -8695,6 +8751,7 @@ async function executePaperclipNativeSessionWithinScope( entry.instructionWorkingCopy = input.instructionWorkingCopy?.checkpointWarm ? undefined : input.instructionWorkingCopy; entry.busy = true; entry.runId = input.execution.binding.runId; + entry.onRetirementDiagnostic = onRetirementDiagnostic; entry.computerTarget = input.runnerExecutionTarget?.kind === "remote" && input.runnerExecutionTarget.transport === "computer" ? input.runnerExecutionTarget : undefined; entry.ownerToken = warmSessionOwnerToken; entry.environmentId = @@ -9069,6 +9126,7 @@ async function executePaperclipNativeSessionWithinScope( : undefined, session, runId: input.execution.binding.runId, + onRetirementDiagnostic, computerTarget: input.runnerExecutionTarget?.kind === "remote" && input.runnerExecutionTarget.transport === "computer" ? input.runnerExecutionTarget : undefined, ownerToken: warmSessionOwnerToken, configDigest: warmConfigDigest, @@ -9086,6 +9144,7 @@ async function executePaperclipNativeSessionWithinScope( const owner = warmNativeSessions.get(warmSessionId); if (owner) { owner.runId = input.execution.binding.runId; + owner.onRetirementDiagnostic = onRetirementDiagnostic; owner.computerTarget = input.runnerExecutionTarget?.kind === "remote" && input.runnerExecutionTarget.transport === "computer" ? input.runnerExecutionTarget : undefined; } if (owner && input.instructionWorkingCopy?.runId && input.instructionWorkingCopy.checkpointWarm) owner.instructionCopy = {