diff --git a/doc/observability.md b/doc/observability.md index bdfce422305..4fa47a5547a 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -673,6 +673,23 @@ at detection; it does not claim that a retry was queued or succeeded. This data contains no process IDs, task text, paths, or credentials and changes no recovery or ownership decisions. +When a native session fails because close could not prove durable runner +suspension (`provider_transport_failed: runner did not durably suspend before +checkpoint`), `run_execution` records which barrier was unproven: +`closeRunnerSuspended`, `closeProviderDrained`, `closeSuspendCommandStatus` +(a runner command status, or `not_queued`), `closeRunnerLifecycle` (`ready`, +`suspended`, `closed`, `recoverable_failure`, or `unobserved`), +`closeRunnerIdentityMatches`, `closeProviderState` (`settled`, `unsettled`, +`unreadable`, or `not_local`), `closeProviderPendingEventCount`, +`closeProviderTurnActive`, `closeSemanticResultPersistenceFailed`, and the counts +`closeSemanticToolsPending`, `closeSemanticToolDeliveriesOpen`, and +`closeSemanticResultFailures`. Fields absent from the runner's settlement are +omitted. Tool call, operation, command and event identities, input digests and +provider turn IDs stay in the instance run log. The report reads the caught error +only for these labels; its text and stack are not copied, because they bypass the +executor's identity redaction. These observations do not change close, quarantine +or recovery behavior. + ACP turns record `acpLastEventAgeMs`, `acpObservedEventCount`, `acpPendingToolCount`, and `acpToolInventoryComplete` at finalization, before usage reads, error logging, and cleanup. The age measures time since the last diff --git a/server/src/services/__tests__/run-failure-diagnostics.test.ts b/server/src/services/__tests__/run-failure-diagnostics.test.ts index e75e043311c..1a2fe4cc708 100644 --- a/server/src/services/__tests__/run-failure-diagnostics.test.ts +++ b/server/src/services/__tests__/run-failure-diagnostics.test.ts @@ -176,6 +176,61 @@ describe("run failure diagnostics", () => { } }); + it("exports which native close barrier failed without tool identities or provider text", () => { + const closeFailure = (settlement: unknown) => Object.assign( + new Error("provider_transport_failed: runner did not durably suspend before checkpoint"), + { code: "native_session_close_unrecoverable", settlement }, + ); + const settlement = { + runnerSuspended: false, + providerDrained: true, + suspensionState: { commandStatus: "pending", runnerLifecycle: "ready", runnerIdentityMatches: true }, + semanticTools: { + persistenceFailed: false, + failures: [{ callId: "private-call", operationId: "private-operation", stage: "persist", code: "private-code" }], + pending: [{ sourceEventId: "private-event", callId: "private-call", inputDigest: "private-digest" }], + deliveries: [{ commandId: "private-command", status: "pending" }, { commandId: "private-command-2", status: "indeterminate" }], + }, + finalProviderState: { pendingEventCount: 128, activeProviderTurnId: "private-turn", providerSettled: false }, + }; + const result = sanitizeRunFailureDiagnostics(collectRunFailureDiagnostics(run(), { nativeCloseFailure: closeFailure(settlement) })); + expect(result.execution).toEqual({ + closeRunnerSuspended: false, closeProviderDrained: true, + closeSuspendCommandStatus: "pending", closeRunnerLifecycle: "ready", closeRunnerIdentityMatches: true, + closeProviderState: "unsettled", closeProviderPendingEventCount: 128, closeProviderTurnActive: true, + closeSemanticResultPersistenceFailed: false, + closeSemanticToolsPending: 1, closeSemanticToolDeliveriesOpen: 2, closeSemanticResultFailures: 1, + }); + expect(result.exceptions).toEqual([]); + expect(JSON.stringify(result)).not.toContain("private"); + expect(JSON.stringify(result)).not.toContain("durably suspend"); + + const unobserved = collectRunFailureDiagnostics(run(), { nativeCloseFailure: new Error("wrapped", { cause: closeFailure({ + runnerSuspended: true, providerDrained: false, suspensionState: null, finalProviderState: null, + }) }) }).execution; + expect(unobserved).toEqual({ closeRunnerSuspended: true, closeProviderDrained: false, closeProviderState: "not_local" }); + expect(collectRunFailureDiagnostics(run(), { nativeCloseFailure: closeFailure({ + suspensionState: { commandStatus: null, runnerLifecycle: null, runnerIdentityMatches: null }, + finalProviderState: "unreadable", + }) }).execution).toEqual({ closeSuspendCommandStatus: "not_queued", closeRunnerLifecycle: "unobserved", closeProviderState: "unreadable" }); + }); + + it("ignores unrelated errors and unknown or hostile native close settlement values", () => { + expect(collectRunFailureDiagnostics(run(), { nativeCloseFailure: Object.assign(new Error("x"), { + code: "provider_transport_failed", settlement: { runnerSuspended: false }, + }) }).execution).toEqual({}); + const hostile = Object.assign(new Error("x"), { code: "native_session_close_unrecoverable", settlement: { + runnerSuspended: "private", providerDrained: 1, + suspensionState: { commandStatus: "private-status", runnerLifecycle: "private-lifecycle", runnerIdentityMatches: "yes" }, + finalProviderState: { pendingEventCount: -1, activeProviderTurnId: 7, providerSettled: "private" }, + semanticTools: Object.defineProperty({ pending: Number.POSITIVE_INFINITY }, "persistenceFailed", { get() { throw new Error("private"); } }), + } }); + expect(collectRunFailureDiagnostics(run(), { nativeCloseFailure: hostile }).execution).toEqual({}); + expect(collectRunFailureDiagnostics(run(), { nativeCloseFailure: Object.assign(new Error("x"), { + code: "native_session_close_unrecoverable", + }) }).execution).toEqual({}); + }); + it("selects bounded lock-owner evidence from a caught timeout cause", () => { const error = new Error("outer", { cause: Object.assign(new Error("lock timeout"), { code: "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT", diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index 2e98d755fc6..6729158c6c7 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -9418,7 +9418,9 @@ async function executePaperclipNativeSessionWithinScope( recoveryProjection.supersedeOnIdentityChange, }); }); - if (terminalRunToReport) void reportRunFailure(input.db, terminalRunToReport); + // Pass the raw error only for closed settlement labels: its text bypasses + // the identity redactor applied to the persisted message above. + if (terminalRunToReport) void reportRunFailure(input.db, terminalRunToReport, { nativeCloseFailure: error }); await boundedExecutionCleanup(async () => { await stoppedLeaseRenewal; await attemptFailureStep(() => diff --git a/server/src/services/run-failure-diagnostics.ts b/server/src/services/run-failure-diagnostics.ts index f277481cc70..ef88dc994ca 100644 --- a/server/src/services/run-failure-diagnostics.ts +++ b/server/src/services/run-failure-diagnostics.ts @@ -23,6 +23,11 @@ export interface RunFailureReportOptions { phase?: "setup" | "execute"; /** Runtime-only values to redact; never included in the captured event. */ secretValues?: readonly string[]; + /** + * The caught native session error. Only an unrecoverable-close settlement is + * read, as closed labels and counts; its message and stack are never copied. + */ + nativeCloseFailure?: unknown; } export interface RunFailureException { @@ -60,6 +65,65 @@ function read(value: unknown, key: string): unknown { } } +const NATIVE_CLOSE_COMMAND_STATUSES: ReadonlySet = new Set(["pending", "completed", "failed", "rejected", "indeterminate"]); +const NATIVE_CLOSE_RUNNER_LIFECYCLES: ReadonlySet = new Set(["ready", "suspended", "closed", "recoverable_failure"]); + +function boundedCount(value: unknown): number | undefined { + if (Array.isArray(value)) return value.length; + return typeof value === "number" && Number.isSafeInteger(value) && value >= 0 ? value : undefined; +} + +/** + * Which close-barrier condition failed. Tool identities, digests and provider + * turn ids stay in the run log; only booleans, fixed labels and counts leave. + */ +function readNativeCloseSettlement(error: unknown): Context | null { + let candidate = error; + for (let depth = 0; depth < 4 && candidate && typeof candidate === "object"; depth++) { + if (read(candidate, "code") === "native_session_close_unrecoverable") break; + candidate = read(candidate, "cause"); + } + if (read(candidate, "code") !== "native_session_close_unrecoverable") return null; + const settlement = read(candidate, "settlement"); + const result: Context = {}; + for (const [field, key] of [["runnerSuspended", "closeRunnerSuspended"], ["providerDrained", "closeProviderDrained"]] as const) { + const value = read(settlement, field); + if (typeof value === "boolean") result[key] = value; + } + const suspension = read(settlement, "suspensionState"); + const commandStatus = read(suspension, "commandStatus"); + if (NATIVE_CLOSE_COMMAND_STATUSES.has(commandStatus)) result.closeSuspendCommandStatus = commandStatus as string; + else if (suspension && commandStatus === null) result.closeSuspendCommandStatus = "not_queued"; + const lifecycle = read(suspension, "runnerLifecycle"); + if (NATIVE_CLOSE_RUNNER_LIFECYCLES.has(lifecycle)) result.closeRunnerLifecycle = lifecycle as string; + else if (suspension && lifecycle === null) result.closeRunnerLifecycle = "unobserved"; + const identityMatches = read(suspension, "runnerIdentityMatches"); + if (typeof identityMatches === "boolean") result.closeRunnerIdentityMatches = identityMatches; + const provider = read(settlement, "finalProviderState"); + if (provider === null) result.closeProviderState = "not_local"; + else if (provider === "unreadable") result.closeProviderState = "unreadable"; + else if (provider && typeof provider === "object") { + const settled = read(provider, "providerSettled"); + if (typeof settled === "boolean") result.closeProviderState = settled ? "settled" : "unsettled"; + const pending = boundedCount(read(provider, "pendingEventCount")); + if (pending !== undefined) result.closeProviderPendingEventCount = pending; + const activeTurn = read(provider, "activeProviderTurnId"); + if (activeTurn === null || typeof activeTurn === "string") result.closeProviderTurnActive = activeTurn !== null; + } + const tools = read(settlement, "semanticTools"); + const persistenceFailed = read(tools, "persistenceFailed"); + if (typeof persistenceFailed === "boolean") result.closeSemanticResultPersistenceFailed = persistenceFailed; + for (const [field, key] of [ + ["pending", "closeSemanticToolsPending"], + ["deliveries", "closeSemanticToolDeliveriesOpen"], + ["failures", "closeSemanticResultFailures"], + ] as const) { + const count = boundedCount(read(tools, field)); + if (count !== undefined) result[key] = count; + } + return result; +} + function scalars(value: unknown, fields: readonly string[]): Context { const result: Context = {}; for (const field of fields) { @@ -216,6 +280,8 @@ export function collectRunFailureDiagnostics(run: Run, options: RunFailureReport const value = read(result, field); if (typeof value === "number" && Number.isSafeInteger(value) && value >= 0) execution[field] = value; } + const closeSettlement = readNativeCloseSettlement(options.nativeCloseFailure); + if (closeSettlement) Object.assign(execution, closeSettlement); const pendingToolKinds = readAcpPendingToolKinds(read(result, "acpPendingToolKinds")); if (pendingToolKinds) execution.acpPendingToolKinds = pendingToolKinds; const toolInventoryComplete = read(result, "acpToolInventoryComplete");