mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-08 01:57:31 +01:00
fix(native): record why finalization failed a run (#19063)
## Thinking Path
> - Paperclip is the open source app people use to manage AI agents for
work.
> - A native run finishes in two steps: the provider turn, then
finalization. Finalization saves the workspace and commits the result.
> - When finalization exhausts its retries, `recordRetryableFailure`
sets the run to `failed` and blocks the task.
> - That code writes the cause only to `resultJson.failureCode`. It does
not write the run's `errorCode` or `error`.
> - So the run list, inbox, and agent status show a failed run with no
reason. Operators cannot tell why the run failed.
> - This pull request writes the finalizer's terminal failure code and a
readable message to the run row when the finalizer fails the run.
> - The benefit is that every failed run now names its cause.
## Linked Issues or Issue Description
**What happened?**
A hosted instance had 11 assigned native runs with status `failed`,
`errorCode` null, and `error` null in one day. In each run, the provider
turn succeeded. The remote workspace copy-back then failed three times.
The finalizer set the run to `failed` and blocked the task. The run kept
no error code. `resultJson.failureCode` was
`native_workspace_sync_out_retry_exhausted`, but no screen shows that
field as the failure reason.
**Expected behavior**
A failed run has an `errorCode` and an `error`. The failure surfaces
show why the run failed.
**Steps to reproduce**
1. Create a native run with a finalization coordinator.
2. Call `recordNativeFinalizationFailure` three times with
`native_workspace_sync_out_failed` and `failureScope: "workspace"`.
3. Read the run. Its status is `failed`, and its `errorCode` and `error`
are null.
**Paperclip version or commit**
`master` at be20d4ad97.
## What Changed
- `recordRetryableFailure` in
`server/src/services/native-runtime/native-run-finalizer.ts` now sets
`errorCode` to the terminal failure code and `error` to a readable
message when it projects a run to `failed`. This covers
`native_workspace_sync_out_retry_exhausted`,
`native_workspace_sync_out_unrecoverable`, and
`native_finalization_retry_exhausted`.
- The update keeps an earlier root `errorCode` and `error` (`coalesce`).
- The update does not change a run that Stop already cancelled. It uses
the same row-level `case` as the status write.
- The update does not add an error when the finalizer projects the run
as `succeeded` or `cancelled`.
- New tests in `native-run-finalizer-telemetry.test.ts` cover the failed
projection, root-cause retention, concurrent cancellation, a retry that
remains, the provider-scope failure, and the provider-succeeded
projection.
## Verification
- `cd server && npx vitest run
src/services/native-runtime/native-run-finalizer-telemetry.test.ts`
- Before the fix, three tests failed because `errorCode` was null:
"bounds workspace-only retries…", "records the finalization error code
when provider-scope retries fail…", and "blocks immediately when the
sandbox… is gone".
- After the fix, all tests in the file pass.
- Related suites pass: `native-workspace-export-retry`,
`native-run-projection-work`, `explicit-native-continuation`,
`execution-control-work`, `native-status-arbiter-corpus`, and
`workspace-recovery` (971 tests). One `workspace-recovery` test timed
out at 30 s under the parallel load. It passes when run alone.
- Downstream checks: the export retry path
(`native-workspace-export-retry.ts`) and the success projection
(`native-run-projection.ts`) already clear `error` and `errorCode` when
they reopen or succeed a run. A later recovery therefore does not keep a
stale error.
## Risks
- Low risk. The change only writes two columns that were null for these
runs.
- `error` is now also the agent status reason and the lease failure
reason for these runs. Before, the agent reason fell back to
`native_workspace_sync_out_failed`.
- This change does not fix the first cause of the copy-back failures.
The remote capture reports only the generic
`remote_workspace_operation_failed`, because the capture output is
redacted. That cause needs separate work.
> 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`), used in Claude Code
with tool use (shell, file edit, read-only browser).
## 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: Claude Opus 5.5 <noreply@anthropic.com>
Co-authored-by: Paperclip <noreply@paperclip.ing>
This commit is contained in:
2 files changed
+180
-2
No files matched your search
@@ -2,7 +2,7 @@ import { resolveExternalTestDatabaseUrl } from "../../__tests__/helpers/external
|
||||
import { enableRunFailureReporting } from "../../__tests__/helpers/run-failure-reporting.js";
|
||||
import { randomUUID } from "node:crypto";
|
||||
import { verifyCommittedReplayPayloadReads } from "./__tests__/helpers/committed-replay.js";
|
||||
import { eq } from "drizzle-orm";
|
||||
import { eq, sql } from "drizzle-orm";
|
||||
import { afterAll, beforeAll, describe, expect, it, vi } from "vitest";
|
||||
import {
|
||||
agents,
|
||||
@@ -751,6 +751,151 @@ describeEmbeddedPostgres("native run finalizer / status decision committer — a
|
||||
.where(eq(heartbeatRuns.id, fixture.runId))
|
||||
.then((rows) => rows[0]?.status),
|
||||
).resolves.toBe("failed");
|
||||
// A failed run must say why it failed. The retry-exhausted code is the
|
||||
// terminal cause, so it is also the run's error code.
|
||||
const failedRun = await readRunError(fixture.runId);
|
||||
expect(failedRun).toMatchObject({
|
||||
status: "failed",
|
||||
errorCode: "native_workspace_sync_out_retry_exhausted",
|
||||
});
|
||||
expect(failedRun?.error).toMatch(/workspace/i);
|
||||
});
|
||||
|
||||
async function readRunError(runId: string) {
|
||||
return db
|
||||
.select({ status: heartbeatRuns.status, errorCode: heartbeatRuns.errorCode, error: heartbeatRuns.error })
|
||||
.from(heartbeatRuns)
|
||||
.where(eq(heartbeatRuns.id, runId))
|
||||
.then((rows) => rows[0]);
|
||||
}
|
||||
|
||||
async function exhaustWorkspaceRetries(runId: string, beforeLastAttempt?: () => Promise<unknown>) {
|
||||
for (let attempt = 1; attempt <= 3; attempt += 1) {
|
||||
if (attempt === 3) await beforeLastAttempt?.();
|
||||
await recordNativeFinalizationFailure({
|
||||
db, runId, error: new Error("native_workspace_sync_out_failed"),
|
||||
projectRunStatus: true, failureScope: "workspace",
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
it("keeps an earlier root error code when workspace retries are exhausted", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.update(heartbeatRuns)
|
||||
.set({ errorCode: "native_provider_terminal_failed", error: "Provider failed earlier." })
|
||||
.where(eq(heartbeatRuns.id, fixture.runId));
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 1,
|
||||
});
|
||||
await exhaustWorkspaceRetries(fixture.runId);
|
||||
await expect(readRunError(fixture.runId)).resolves.toEqual({
|
||||
status: "failed",
|
||||
errorCode: "native_provider_terminal_failed",
|
||||
error: "Provider failed earlier.",
|
||||
});
|
||||
});
|
||||
|
||||
it("does not record an error on a run cancelled before workspace retries were exhausted", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 1,
|
||||
});
|
||||
await exhaustWorkspaceRetries(fixture.runId, () => db.update(heartbeatRuns)
|
||||
.set({ status: "cancelled", finishedAt: new Date() })
|
||||
.where(eq(heartbeatRuns.id, fixture.runId)));
|
||||
await expect(readRunError(fixture.runId)).resolves.toEqual({ status: "cancelled", errorCode: null, error: null });
|
||||
});
|
||||
|
||||
it("does not record an error when Stop wins after the finalizer read the running run", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 1,
|
||||
});
|
||||
for (let attempt = 1; attempt <= 2; attempt += 1) {
|
||||
await recordNativeFinalizationFailure({
|
||||
db, runId: fixture.runId, error: new Error("native_workspace_sync_out_failed"),
|
||||
projectRunStatus: true, failureScope: "workspace",
|
||||
});
|
||||
}
|
||||
// Stop holds the run row. The finalizer reads the still-running run, then
|
||||
// its terminal UPDATE waits for that lock. Stop commits the cancellation,
|
||||
// and the UPDATE must evaluate the cancelled row, not its earlier read.
|
||||
let finalizer: Promise<unknown> | null = null;
|
||||
await db.transaction(async (stop) => {
|
||||
await stop.select({ id: heartbeatRuns.id }).from(heartbeatRuns)
|
||||
.where(eq(heartbeatRuns.id, fixture.runId)).for("update");
|
||||
finalizer = recordNativeFinalizationFailure({
|
||||
db, runId: fixture.runId, error: new Error("native_workspace_sync_out_failed"),
|
||||
projectRunStatus: true, failureScope: "workspace",
|
||||
});
|
||||
const deadline = Date.now() + 10_000;
|
||||
for (;;) {
|
||||
const [waiting] = await db.execute<{ count: number }>(
|
||||
sql`select count(*)::int as count from pg_locks where not granted and locktype in ('tuple', 'transactionid')`,
|
||||
);
|
||||
if (Number(waiting?.count) > 0) break;
|
||||
if (Date.now() > deadline) throw new Error("finalizer never waited for the Stop lock");
|
||||
await new Promise((resolve) => setTimeout(resolve, 20));
|
||||
}
|
||||
await stop.update(heartbeatRuns).set({ status: "cancelled", finishedAt: new Date() })
|
||||
.where(eq(heartbeatRuns.id, fixture.runId));
|
||||
});
|
||||
await finalizer;
|
||||
await expect(readRunError(fixture.runId)).resolves.toEqual({ status: "cancelled", errorCode: null, error: null });
|
||||
});
|
||||
|
||||
it("leaves a run without an error while workspace retries remain", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 1,
|
||||
});
|
||||
await recordNativeFinalizationFailure({
|
||||
db, runId: fixture.runId, error: new Error("native_workspace_sync_out_failed"),
|
||||
projectRunStatus: true, failureScope: "workspace",
|
||||
});
|
||||
await expect(readRunError(fixture.runId)).resolves.toEqual({ status: "running", errorCode: null, error: null });
|
||||
});
|
||||
|
||||
it("records the finalization error code when provider-scope retries fail an unsucceeded run", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 3,
|
||||
});
|
||||
await recordNativeFinalizationFailure({
|
||||
db, runId: fixture.runId, error: new Error("native_finalization_invalid"), projectRunStatus: true,
|
||||
});
|
||||
const run = await readRunError(fixture.runId);
|
||||
expect(run).toMatchObject({ status: "failed", errorCode: "native_finalization_retry_exhausted" });
|
||||
expect(run?.error).toBeTruthy();
|
||||
});
|
||||
|
||||
it("fails a provider-succeeded run with an error code when workspace retries are exhausted", async () => {
|
||||
// The reported case: the provider turn succeeded, then the workspace
|
||||
// copy-back failed three times. Workspace scope fails the run regardless
|
||||
// of the provider outcome, so the run must name the cause.
|
||||
const fixture = await seedNativeRun();
|
||||
await db.update(heartbeatRuns).set({ resultJson: { prpRunTerminalState: "succeeded" } })
|
||||
.where(eq(heartbeatRuns.id, fixture.runId));
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 1,
|
||||
});
|
||||
await exhaustWorkspaceRetries(fixture.runId);
|
||||
const run = await readRunError(fixture.runId);
|
||||
expect(run).toMatchObject({ status: "failed", errorCode: "native_workspace_sync_out_retry_exhausted" });
|
||||
expect(run?.error).toMatch(/recovery action/);
|
||||
});
|
||||
|
||||
it("does not attach a finalization error to a provider-succeeded run when provider retries are exhausted", async () => {
|
||||
const fixture = await seedNativeRun();
|
||||
await db.update(heartbeatRuns).set({ resultJson: { prpRunTerminalState: "succeeded" } })
|
||||
.where(eq(heartbeatRuns.id, fixture.runId));
|
||||
await db.insert(nativeRunFinalizations).values({
|
||||
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "observed", attempt: 3,
|
||||
});
|
||||
await recordNativeFinalizationFailure({
|
||||
db, runId: fixture.runId, error: new Error("native_finalization_invalid"), projectRunStatus: true,
|
||||
});
|
||||
await expect(readRunError(fixture.runId)).resolves.toEqual({ status: "succeeded", errorCode: null, error: null });
|
||||
});
|
||||
|
||||
it("blocks immediately when the sandbox with unexported changes is gone", async () => {
|
||||
@@ -786,6 +931,13 @@ describeEmbeddedPostgres("native run finalizer / status decision committer — a
|
||||
.where(eq(heartbeatRuns.id, fixture.runId))
|
||||
.then((rows) => rows[0]?.status),
|
||||
).resolves.toBe("failed");
|
||||
await expect(
|
||||
db
|
||||
.select({ errorCode: heartbeatRuns.errorCode })
|
||||
.from(heartbeatRuns)
|
||||
.where(eq(heartbeatRuns.id, fixture.runId))
|
||||
.then((rows) => rows[0]?.errorCode),
|
||||
).resolves.toBe("native_workspace_sync_out_unrecoverable");
|
||||
await expect(
|
||||
db
|
||||
.select({ status: issues.status })
|
||||
|
||||
@@ -260,6 +260,23 @@ async function claimCoordinator(input: {
|
||||
return claimed;
|
||||
}
|
||||
|
||||
function terminalFinalizationFailureMessage(failureCode: string, failureScope: "provider" | "workspace" | undefined) {
|
||||
if (failureCode === "native_workspace_sync_out_retry_exhausted") {
|
||||
// This code also covers local-directory and plugin workspaces, so the
|
||||
// message stays general and defers to the recovery action's next step.
|
||||
return "Saving the workspace failed after 3 attempts. The agent's result is kept; follow the run's recovery action to repair the workspace.";
|
||||
}
|
||||
if (failureCode === "native_workspace_sync_out_unrecoverable") {
|
||||
return "The sandbox holding unexported workspace changes is unavailable, so its files could not be saved.";
|
||||
}
|
||||
if (failureCode === "native_finalization_retry_exhausted") {
|
||||
return "Native run finalization failed after 3 attempts.";
|
||||
}
|
||||
return failureScope === "workspace"
|
||||
? `Native workspace finalization failed (${failureCode}).`
|
||||
: `Native run finalization failed (${failureCode}).`;
|
||||
}
|
||||
|
||||
async function recordRetryableFailure(input: {
|
||||
db: Db;
|
||||
run: typeof heartbeatRuns.$inferSelect;
|
||||
@@ -437,6 +454,7 @@ async function recordRetryableFailure(input: {
|
||||
if (projectsTerminalStatus) await notifyInstructionCollection(tx, { companyId: input.run.companyId, runId: input.run.id });
|
||||
if (projectsTerminalStatus) await notifyCancelledWorkspacePreservation(tx, { companyId: input.run.companyId, runId: input.run.id });
|
||||
if (projectsTerminalStatus) await notifyUnsafeWorkspaceExportRunChange(tx, input.run);
|
||||
const terminalRunStatus = input.failureScope === "workspace" ? "failed" : exhaustedRunStatus;
|
||||
const [updatedRun] = await tx
|
||||
.update(heartbeatRuns)
|
||||
.set({
|
||||
@@ -446,9 +464,17 @@ async function recordRetryableFailure(input: {
|
||||
// Stop can win after the failure's admission snapshot. The
|
||||
// UPDATE locks and evaluates the current row, not that snapshot.
|
||||
status: sql`case when ${heartbeatRuns.status} = 'cancelled' then ${heartbeatRuns.status}
|
||||
else ${input.failureScope === "workspace" ? "failed" : exhaustedRunStatus} end`,
|
||||
else ${terminalRunStatus} end`,
|
||||
finishedAt: sql`case when ${heartbeatRuns.status} = 'cancelled' then ${heartbeatRuns.finishedAt}
|
||||
else coalesce(${heartbeatRuns.finishedAt}, ${now.toISOString()}::timestamptz) end`,
|
||||
// A failed run names its cause. Keep an earlier root cause, and
|
||||
// leave a run that Stop already cancelled without a failure.
|
||||
...(terminalRunStatus === "failed"
|
||||
? explainFailedRun({
|
||||
errorCode: failureCode,
|
||||
error: terminalFinalizationFailureMessage(failureCode, input.failureScope),
|
||||
})
|
||||
: {}),
|
||||
}
|
||||
: {}),
|
||||
nativePhase: phase,
|
||||
|
||||
Reference in new issue
Block a user