mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-20 06:02:18 +02:00
fix(native-runtime): report which close barrier failed (#16298)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - Native agent runs use the Paperclip runner. When a run ends, the controller closes the session. Close must prove that the runner durably suspended before the controller releases its checkpoint. > - If close cannot prove this, the run fails with `provider_transport_failed: runner did not durably suspend before checkpoint`. > - The runner knows which barrier was not proven. It writes that settlement only to the instance run log. > - The Sentry report for the failed run has no settlement evidence. Operators cannot tell a stuck suspend command from an undrained provider, an unreadable provider state, or unsettled tool results. > - This pull request sends that settlement to the run failure report as closed labels and counts. > - The benefit is that the next occurrence shows which barrier failed, so the root cause can be fixed instead of guessed. ## Linked Issues or Issue Description No public issue exists. This describes the bug. **What happened?** Hosted staging native Codex runs failed with `provider_transport_failed: runner did not durably suspend before checkpoint`. This happened on two runs, on 2026-09-30 and 2026-10-14. The second run used a release from 2026-10-14. The Sentry events contain only the error code, run phase, driver kind, and duration. They contain no stack and no settlement data. The native executor calls `reportRunFailure(db, run)` without the caught error, and the runner settlement is never read. **Expected behavior** A failed close report should tell an operator which barrier was not proven: runner suspension, provider drain, provider state, or semantic tool settlement. It must not expose tool identities, digests, provider turn IDs, or unredacted error text. **Steps to reproduce** 1. Run a native Codex session whose close cannot prove durable runner suspension. For example, the runner suspend command does not complete before the close deadline. 2. Observe the Sentry run failure event. Before this change, `run_execution` has no close settlement fields. ## What Changed - `collectRunFailureDiagnostics` accepts a new `nativeCloseFailure` option. It reads only a `native_session_close_unrecoverable` error, directly or up to four `cause` levels deep. - It adds closed labels and counts to `run_execution`: `closeRunnerSuspended`, `closeProviderDrained`, `closeSuspendCommandStatus`, `closeRunnerLifecycle`, `closeRunnerIdentityMatches`, `closeProviderState`, `closeProviderPendingEventCount`, `closeProviderTurnActive`, `closeSemanticResultPersistenceFailed`, `closeSemanticToolsPending`, `closeSemanticToolDeliveriesOpen`, and `closeSemanticResultFailures`. - Values outside the known vocabularies are dropped. Getters that throw are contained. - The native session executor passes the caught error as `nativeCloseFailure` when it reports a terminal run failure. It does not pass the error as `error`, because the raw error text and stack bypass the executor's identity redaction. - `doc/observability.md` documents the new fields and the privacy boundary. ## Verification - `cd server && npx vitest run src/services/__tests__/run-failure-diagnostics.test.ts src/__tests__/run-failure-sentry.test.ts`: 130 tests pass. - New tests check the full label set, a wrapped cause, null suspension and provider states, unrelated error codes, hostile and unknown values, and a missing settlement. They also check that no tool identity, digest, turn ID, or error text leaves the module. - Negative control: with the reader disabled, the new main test fails. - A scoped `tsc` run on `run-failure-diagnostics.ts`, its test, and `run-failure-report.ts` passes. The full server `tsc` and `pnpm build` were not run locally. The sandbox has a 4 GiB memory limit and no `cargo` for the runner binary. CI runs the full checks. ## Risks - Low risk. The change only adds Sentry context fields for one error code. Close, quarantine, retry, and recovery behavior do not change. - Sentry grouping does not change. The fingerprint stays `[errorCode, agentAdapter]`, and no exception chain is added. - The data path is Observability (Sentry error reporting, gated by the operator DSN). It does not change Telemetry. The fields contain only booleans, fixed labels, and counts. The DSN gate is unchanged. - These fields are observations. They do not prove a root cause by themselves. > For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and discuss it in `#dev` before opening the PR. Feature PRs that overlap with planned core work may need to be redirected — check the roadmap first. See `CONTRIBUTING.md`. ## Model Used - Anthropic Claude Opus 5.5 (`claude-opus-5-5`), run through Claude Code as an agent with tool use (shell, file edits, test execution, Sentry and GitHub connectors). Context window and reasoning mode are not exposed in this session. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [ ] All Paperclip CI gates are green - [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-authored-by: Devin Foley <139239+devinfoley@users.noreply.github.com> Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
4 files changed
+141
-1
No files matched your search
@@ -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
|
||||
|
||||
@@ -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",
|
||||
|
||||
@@ -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(() =>
|
||||
|
||||
@@ -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<unknown> = new Set(["pending", "completed", "failed", "rejected", "indeterminate"]);
|
||||
const NATIVE_CLOSE_RUNNER_LIFECYCLES: ReadonlySet<unknown> = 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");
|
||||
|
||||
Reference in new issue
Block a user