Files
PaperClipAI/server/src/services/native-runtime/native-run-finalizer-telemetry.test.ts
T
36e4c6657f fix(sentry): report a native retry failure only when the retry ends (#16865)
## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work.
> - The server sends a Sentry `run_failure` event when an agent run
reaches a terminal failure.
> - A native run that waits for a same-run retry is stored as `failed`
with `nativePhase: "retryable_failure"`. That state is not terminal.
> - `reportRunFailure` reported that pending state. Runs that later
recovered, for example after a workspace copy-back retry, still sent a
run failure event.
> - These events make one catch-all Sentry group noisy and hide the real
terminal failures in it.
> - This pull request skips the pending retry state and reports once
when the retry ends as a terminal failure.
> - The benefit is that run failure events match runs that really
failed.

## Linked Issues or Issue Description

**What happened?**

Two staging runs had a workspace copy-back failure during settlement
(`Daytona syncOut tar command failed ... No space left on device`). The
executor stored each run as `failed` with `nativePhase:
"retryable_failure"` and `errorCode: native_session_interrupted`. Sentry
received a `run_failure` event for each run. About two minutes later,
the copy-back retry succeeded and both runs finished as `succeeded` with
`workspaceFinalizeStatus: "succeeded"`.

**Expected behavior**

A run that waits for a same-run retry must not send a terminal run
failure event. If the retry ends as a terminal failure, the server must
send one event at that time.

**Steps to reproduce**

1. Set `PAPERCLIP_SENTRY_RUN_FAILURES=unexpected`.
2. Start a native run that fails retryably. For example, make the
workspace copy-back fail once.
3. See the `run_failure` event in Sentry, and then see the run finish as
`succeeded` after the retry.

## What Changed

- `reportRunFailure` returns without a report for a native run that is
`failed` with `nativePhase: "retryable_failure"`.
- New `isNewTerminalRunFailure(before, after)`: a status change counts
as before. A failed run that leaves the pending retry state but stays
`failed` also counts.
- Three terminal writers can keep the status `failed` → `failed`. They
now use `isNewTerminalRunFailure`, so they still report once:
  - the resume reconciler's ambiguous-state write;
  - the restart recovery `blocked` write;
  - the committed-result projection (`projectCommittedRun`).
- Result-less retries already reset the run to `running` before they
start, so their terminal write still reports through the existing
status-change guard.
- `doc/observability.md` describes the new rule.

## Verification

- `pnpm exec vitest run
src/services/__tests__/run-failure-report.test.ts
src/__tests__/run-failure-sentry.test.ts
src/__tests__/native-session-resumption.test.ts
src/services/native-runtime/native-run-finalizer-telemetry.test.ts
src/services/native-runtime/native-runner-restart-recovery.integration.test.ts
src/__tests__/heartbeat-status-preserving-telemetry.test.ts
src/services/execution-control-reconciliation.test.ts` (from `server/`):
7 files, 363 passed, 9 skipped.
- New tests:
- `run-failure-report.test.ts`: a pending native retry does not report,
and a `terminal_failure` run does. Unit cases cover
`isNewTerminalRunFailure`.
- `native-session-resumption.test.ts`: a sweep that ends an unreported
pending retry sends one event.
- `native-run-finalizer-telemetry.test.ts`: a committed failure for a
pending-retry row sends one event, and a replay sends none.
- `native-runner-restart-recovery.integration.test.ts`: a restart
recovery `blocked` write for a pending-retry row sends one event.
- I removed each of the three writer changes one at a time. The matching
new test failed each time (`expected [] to have a length of 1` / `to
deeply equal [ [ ObjectContaining{…} ] ]`).
- I did not run the full server `tsc --noEmit` locally. The local
container has a 4 GiB memory limit, and the process was killed (exit
137). CI runs the typecheck.

## Risks

- A run that stays in the pending retry state and never resumes no
longer sends a run failure event. The run stays visible on the board as
failed with a scheduled retry. A later terminal write still reports it.
- The finalizer's `failed` + `retryable_failure` write for a failed
provider result also stops reporting. The terminal write that ends that
retry reports instead: retry exhaustion in `recordRetryableFailure`
reports unconditionally, and commit goes through `finalizeNativeRun` or
`projectCommittedRun`.
- A run that was reported in the pending state before this change can
report once more when it becomes terminal after deploy. This affects
only runs in flight during the upgrade.
- There are no schema, migration, or API changes. Run status, retries,
and recovery do not change.

> 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`) in Claude Code, with
tool use (shell, code search, test runs) and a read-only code
exploration subagent. Context window: the standard window for that
model.

## 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: devinfoley <139239+devinfoley@users.noreply.github.com>
Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-19 09:29:50 -07:00

953 lines
41 KiB
TypeScript

import { enableRunFailureReporting } from "../../__tests__/helpers/run-failure-reporting.js";
import { randomUUID } from "node:crypto";
import { eq } from "drizzle-orm";
import { afterAll, beforeAll, describe, expect, it, vi } from "vitest";
import {
agents,
companies,
completionContracts,
createDb,
heartbeatRuns,
heartbeatRunEvents,
issues,
nativeRunFinalizations,
nativeRunResults,
workAssessments,
statusDecisions,
issueRecoveryActions,
agentWakeupRequests,
workspaceOperations,
activityLog,
} from "@paperclipai/db";
import {
getEmbeddedPostgresTestSupport,
startEmbeddedPostgresTestDatabase,
} from "../../__tests__/helpers/embedded-postgres.js";
import {
CONTROL_PLANE_CONFORMANCE_RESULT,
CONTROL_PLANE_CONFORMANCE_TERMINAL,
} from "../../vendor/paperclip-runner/testing.js";
const mockTelemetryClient = vi.hoisted(() => ({
track: vi.fn(),
hashPrivateRef: vi.fn((value: string) => `hashed:${value}`),
}));
vi.mock("../../telemetry.ts", () => ({ getTelemetryClient: () => mockTelemetryClient }));
const mockCaptureRunFailure = vi.hoisted(() => vi.fn());
vi.mock("../../sentry.ts", async () => {
const actual = await vi.importActual<typeof import("../../sentry.ts")>("../../sentry.ts");
return {
...actual,
captureRunFailure: mockCaptureRunFailure,
};
});
function agentTaskRunCalls(fromIndex: number) {
return mockTelemetryClient.track.mock.calls
.slice(fromIndex)
.filter((call) => call[0] === "agent.task_run");
}
function captureRunFailureCallsFrom(fromIndex: number) {
return mockCaptureRunFailure.mock.calls.slice(fromIndex);
}
import { PaperclipControlPlanePort } from "./paperclip-control-plane-port.js";
import { restoreNativeWorkspaceBestEffort } from "./native-workspace-best-effort.js";
import { reconcileNativeFinalizations } from "./native-finalization-reconciler.js";
import { recoverLegacyUnsafeWorkspaceExports } from "./native-workspace-export-recovery.js";
import { finalizeNativeRun, recordNativeFinalizationFailure } from "./native-run-finalizer.js";
import { waitForPendingRunFailureReports } from "../run-failure-report.js";
import { deliverExecutionStatuses } from "../execution-status-delivery.js";
import { commitNativeStatusDecision } from "./status-decision-committer.js";
import { NATIVE_STATUS_ARBITER_POLICY_VERSION, type NativeStatusDecision } from "./status-arbiter.js";
const embeddedPostgresSupport = await getEmbeddedPostgresTestSupport();
const describeEmbeddedPostgres = embeddedPostgresSupport.supported ? describe : describe.skip;
if (!embeddedPostgresSupport.supported) {
console.warn(
`Skipping embedded Postgres native-finalizer telemetry tests on this host: ${
embeddedPostgresSupport.reason ?? "unsupported environment"
}`,
);
}
describeEmbeddedPostgres("native run finalizer / status decision committer — agent.task_run emission", () => {
let db!: ReturnType<typeof createDb>;
let tempDb: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | null = null;
let companyId: string;
let agentId: string;
beforeAll(async () => {
tempDb = await startEmbeddedPostgresTestDatabase("paperclip-native-finalizer-telemetry-");
db = createDb(tempDb.connectionString);
companyId = randomUUID();
agentId = randomUUID();
await db.insert(companies).values({ id: companyId, name: "Telemetry", issuePrefix: "TLM" });
await db.insert(agents).values({
id: agentId,
companyId,
name: "Native worker",
adapterType: "codex_local",
status: "running",
});
}, 30_000);
afterAll(async () => {
await tempDb?.cleanup();
});
async function seedNativeRun() {
const issueId = randomUUID();
const contractId = randomUUID();
const runId = randomUUID();
const sessionId = randomUUID();
const runnerInstanceId = randomUUID();
const contractSha256 = `contract-${contractId}`;
await db.insert(issues).values({
id: issueId,
companyId,
title: "Native telemetry fixture",
status: "in_progress",
assigneeAgentId: agentId,
workMode: "standard",
});
await db.insert(completionContracts).values({
id: contractId,
companyId,
issueId,
revision: 1,
schemaVersion: "paperclip.completion-contract.v1",
policyVersion: "telemetry-v1",
risk: "standard",
completionAuthority: "server_arbiter",
incompleteCriteriaPolicy: "preserve_non_terminal",
contractJson: {
revision: "telemetry-v1",
objective: "Emit telemetry",
criteria: [{ id: "objective", requirement: "Complete the task" }],
},
canonicalSha256: contractSha256,
createdByActorType: "system",
createdByActorId: "test",
});
await db.insert(heartbeatRuns).values({
id: runId,
companyId,
agentId,
status: "running",
runtimeMode: "native",
nativeIssueId: issueId,
nativeSessionId: sessionId,
runnerInstanceId,
completionContractId: contractId,
completionContractSha256: contractSha256,
contextSnapshot: { issueId },
});
return { issueId, contractId, contractSha256, runId, sessionId, runnerInstanceId };
}
function newPort(fixture: Awaited<ReturnType<typeof seedNativeRun>>) {
return new PaperclipControlPlanePort(db, {
companyId,
issueId: fixture.issueId,
runId: fixture.runId,
agentId,
sessionId: fixture.sessionId,
completionContractId: fixture.contractId,
completionContractSha256: fixture.contractSha256,
sourceInstanceId: fixture.runnerInstanceId,
controlPlaneSourceInstanceId: "telemetry-test",
});
}
async function driveToCompleteResult(
fixture: Awaited<ReturnType<typeof seedNativeRun>>,
terminal: typeof CONTROL_PLANE_CONFORMANCE_TERMINAL = CONTROL_PLANE_CONFORMANCE_TERMINAL,
result = CONTROL_PLANE_CONFORMANCE_RESULT,
) {
const port = newPort(fixture);
await port.openRun({
identity: {
runId: fixture.runId,
sessionId: fixture.sessionId,
companyId,
issueId: fixture.issueId,
agentId,
},
backendKind: "mock",
sourceInstanceId: fixture.runnerInstanceId,
});
await port.completeRun({
result,
terminal,
callerResultId: `${fixture.runId}:result`,
});
}
it("finishes an accepted result after shutdown failed and workspace repair succeeded", async () => {
const fixture = await seedNativeRun();
await db.update(completionContracts).set({ risk: "low", completionAuthority: "agent_claim_policy",
contractJson: { revision: CONTROL_PLANE_CONFORMANCE_RESULT.completionClaim.contractRevision,
objective: "Finish the work", criteria: [{ id: "objective", requirement: "Complete the task" }] } })
.where(eq(completionContracts.id, fixture.contractId));
await driveToCompleteResult(fixture);
await db.update(heartbeatRuns).set({ status: "failed", finishedAt: new Date(),
errorCode: "provider_transport_failed", error: "provider_transport_failed: runner did not durably suspend before checkpoint" })
.where(eq(heartbeatRuns.id, fixture.runId));
await db.update(nativeRunFinalizations).set({ phase: "retryable_failure", leaseOwner: null,
leaseExpiresAt: null, nextAttemptAt: null }).where(eq(nativeRunFinalizations.runId, fixture.runId));
const failed = await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "failed" });
// An unchanged failed workspace must replay its existing decision.
await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "failed" });
expect(await db.select().from(statusDecisions).where(eq(statusDecisions.runId, fixture.runId))).toHaveLength(1);
await db.insert(workspaceOperations).values({ companyId, issueId: fixture.issueId,
heartbeatRunId: fixture.runId, phase: "workspace_finalize", status: "succeeded" });
await db.update(nativeRunFinalizations).set({ nextAttemptAt: null }).where(eq(nativeRunFinalizations.runId, fixture.runId));
await reconcileNativeFinalizations(db, [fixture.runId]);
expect((await db.select().from(issues).where(eq(issues.id, fixture.issueId)))[0]).toMatchObject({
status: "done", executionRunId: null, checkoutRunId: null,
});
expect((await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId)))[0]).toMatchObject({
status: "succeeded", errorCode: null, error: null,
resultJson: { recoveredExecutionFailure: { errorCode: "provider_transport_failed" } },
});
const assessments = await db.select().from(workAssessments).where(eq(workAssessments.runId, fixture.runId));
expect(assessments).toHaveLength(2);
expect(assessments.find(row => row.id !== failed.assessmentId)?.supersedesAssessmentId).toBe(failed.assessmentId);
await reconcileNativeFinalizations(db, [fixture.runId]);
expect(await db.select().from(statusDecisions).where(eq(statusDecisions.runId, fixture.runId))).toHaveLength(2);
expect(await db.select().from(nativeRunResults).where(eq(nativeRunResults.runId, fixture.runId))).toHaveLength(1);
expect(await db.select().from(agentWakeupRequests).where(eq(agentWakeupRequests.companyId, companyId))).toHaveLength(0);
});
it("emits exactly one agent.task_run event when the native finalizer commits a terminal status", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture);
const callsBefore = mockTelemetryClient.track.mock.calls.length;
const captureCallsBefore = mockCaptureRunFailure.mock.calls.length;
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const newCalls = agentTaskRunCalls(callsBefore);
expect(newCalls).toHaveLength(1);
expect(newCalls[0]?.[1]).toMatchObject({ agent_id: agentId, state: "succeeded" });
const run = await db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]);
expect(run?.status).toBe("succeeded");
// "succeeded" is not a failure status, so it never reports to Sentry.
expect(captureRunFailureCallsFrom(captureCallsBefore)).toHaveLength(0);
});
it("emits zero events when a repeat finalize call preserves the succeeded terminal state", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture);
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const callsBefore = mockTelemetryClient.track.mock.calls.length;
// The coordinator is already "committed", so this second call takes the
// projectCommittedRun short-circuit. A succeeded row is eligible so stale
// cleanup errors can be projected separately; an unchanged terminal state
// must still never emit a second agent.task_run event.
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
expect(agentTaskRunCalls(callsBefore)).toHaveLength(0);
});
it("repairs a stale succeeded-run error once without duplicate telemetry or destroying retained owner evidence", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture);
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
await db
.update(heartbeatRuns)
.set({
errorCode: "adapter_failed",
error: "provider_transport_failed: retained cleanup evidence",
processPid: 987654,
runnerProfileJson: { sessionCheckpoint: { retainedEvidence: "keep" } },
})
.where(eq(heartbeatRuns.id, fixture.runId));
const callsBefore = mockTelemetryClient.track.mock.calls.length;
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const [recovered] = await db
.select()
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId));
expect(recovered).toMatchObject({
status: "succeeded",
error: null,
errorCode: null,
processPid: 987654,
runnerProfileJson: { sessionCheckpoint: { retainedEvidence: "keep" } },
resultJson: {
recoveredExecutionFailure: {
schema: "paperclip.recovered_execution_failure.v1",
errorCode: "adapter_failed",
error: "provider_transport_failed: retained cleanup evidence",
},
},
});
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const [replayed] = await db
.select()
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId));
expect(replayed.resultJson?.recoveredExecutionFailure).toEqual(
recovered.resultJson?.recoveredExecutionFailure,
);
expect(agentTaskRunCalls(callsBefore)).toHaveLength(0);
});
it.each([
"native_execution_ownership_unverified",
"native_adopted_runner_authentication_timeout",
])(
"does not project through retained ownership guard %s",
async (errorCode) => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture);
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const [held] = await db
.update(heartbeatRuns)
.set({
status: "running",
finishedAt: null,
nativePhase: "terminal_failure",
errorCode,
error: "Retained owner must remain fenced",
processPid: 987654,
})
.where(eq(heartbeatRuns.id, fixture.runId))
.returning();
const callsBefore = mockTelemetryClient.track.mock.calls.length;
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const [after] = await db
.select()
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId));
expect(after).toEqual(held);
expect(agentTaskRunCalls(callsBefore)).toHaveLength(0);
},
);
it.each([null, "Earlier diagnostic"])(
"preserves the current-row diagnostic when it changes after finalizer admission (prior=%s)",
async (priorError) => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture);
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
await db
.update(heartbeatRuns)
.set({
error: priorError,
errorCode: priorError ? "adapter_failed" : null,
})
.where(eq(heartbeatRuns.id, fixture.runId));
const select = db.select.bind(db);
let changed = false;
// Hold the persisted-result read inside projectCommittedRun, after its
// caller captured the run but before the terminal UPDATE. This models
// a late heartbeat cleanup diagnostic without changing production APIs.
const wrap = (query: any): any =>
new Proxy(query, {
get(target, key) {
const value = Reflect.get(target, key, target);
if (key === "then")
return async (fulfilled: any, rejected: any) => {
if (!changed) {
changed = true;
await db
.update(heartbeatRuns)
.set({
error: "Latest cleanup diagnostic",
errorCode: "provider_transport_failed",
resultJson: {
concurrentMarker: "keep",
nativeCommittedChatResponse: {
resultId: "retain-selector",
},
},
})
.where(eq(heartbeatRuns.id, fixture.runId));
}
return value.call(target, fulfilled, rejected);
};
return typeof value === "function"
? (...args: any[]) => wrap(value.apply(target, args))
: value;
},
});
const spy = vi.spyOn(db, "select").mockImplementation(((
selection: any,
) => {
const query = select(selection);
return selection?.resultJson === nativeRunResults.resultJson
? wrap(query)
: query;
}) as typeof db.select);
try {
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
} finally {
spy.mockRestore();
}
expect(changed).toBe(true);
const [after] = await db
.select()
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId));
expect(after).toMatchObject({
error: null,
errorCode: null,
resultJson: {
concurrentMarker: "keep",
nativeCommittedChatResponse: { resultId: "retain-selector" },
recoveredExecutionFailure: {
error: "Latest cleanup diagnostic",
errorCode: "provider_transport_failed",
},
},
});
},
);
it.each(["in_progress", "cancelled"])("does not redeliver a committed failure during reconciliation of a %s task", async (issueStatus) => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, {
...CONTROL_PLANE_CONFORMANCE_TERMINAL,
turnTerminalState: "failed",
runTerminalState: "failed",
});
// workspaceFinalizeStatus reports whether the workspace finalization
// step itself succeeded, independent of the run's own terminal state
// (runTerminalState below), which is what actually failed here.
const captureCallsBeforeFirstFinalize = mockCaptureRunFailure.mock.calls.length;
await finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
});
const run = await db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]);
expect(run?.status).toBe("failed");
// The first write is a genuine transition into "failed": it reports
// exactly one Sentry event.
await vi.waitFor(() => {
expect(captureRunFailureCallsFrom(captureCallsBeforeFirstFinalize)).toHaveLength(1);
}, { timeout: 5_000 });
const firstFinalizeCaptures = captureRunFailureCallsFrom(captureCallsBeforeFirstFinalize);
expect(firstFinalizeCaptures[0]?.[0]).toMatchObject({
runId: fixture.runId,
runStatus: "failed",
});
await db.update(issues).set({ status: issueStatus }).where(eq(issues.id, fixture.issueId));
const publish = vi.fn();
await deliverExecutionStatuses(db, { publish });
expect(publish.mock.calls.filter(([event]) => event.payload.runId === fixture.runId)).toHaveLength(1);
const [beforeReplay] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(beforeReplay.executionStatusDeliveryId).toBeNull();
publish.mockClear();
const callsBefore = mockTelemetryClient.track.mock.calls.length;
const captureCallsBeforeReplay = mockCaptureRunFailure.mock.calls.length;
// Simulate several periodic sweeps, including overlapping reconciliation.
for (let sweep = 0; sweep < 3; sweep += 1) {
await Promise.all([0, 1].map(() => finalizeNativeRun({
db,
runId: fixture.runId,
workspaceFinalizeStatus: "succeeded",
projectRunStatus: true,
})));
await deliverExecutionStatuses(db, { publish });
}
expect(publish.mock.calls.filter(([event]) => event.payload.runId === fixture.runId)).toHaveLength(0);
const [afterReplay] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(afterReplay).toMatchObject({
executionStatusDeliveryId: null,
updatedAt: beforeReplay.updatedAt,
nativePhaseUpdatedAt: beforeReplay.nativePhaseUpdatedAt,
finishedAt: beforeReplay.finishedAt,
});
expect(agentTaskRunCalls(callsBefore)).toHaveLength(0);
expect(captureRunFailureCallsFrom(captureCallsBeforeReplay)).toHaveLength(0);
});
it("repairs an incomplete committed failure once and preserves its pending delivery on replay", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, {
...CONTROL_PLANE_CONFORMANCE_TERMINAL,
turnTerminalState: "failed",
runTerminalState: "failed",
});
const finalize = () => finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
await finalize();
await db.update(heartbeatRuns).set({
finishedAt: null,
nativePhase: "arbitrating",
executionStatusDeliveryId: null,
}).where(eq(heartbeatRuns.id, fixture.runId));
await finalize();
const [repaired] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(repaired.status).toBe("failed");
expect(repaired.nativePhase).toBe("committed");
expect(repaired.finishedAt).toBeInstanceOf(Date);
expect(repaired.executionStatusDeliveryId).toBeTypeOf("string");
await finalize();
const [replayed] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(replayed).toEqual(repaired);
});
it("reports a committed failure once when the run row was an unreported pending retry", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, {
...CONTROL_PLANE_CONFORMANCE_TERMINAL,
turnTerminalState: "failed",
runTerminalState: "failed",
});
const finalize = () => finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
await finalize();
// The executor stores a scheduled same-run retry as failed + retryable_failure,
// and reportRunFailure skips that write.
await db.update(heartbeatRuns).set({
nativePhase: "retryable_failure",
}).where(eq(heartbeatRuns.id, fixture.runId));
await waitForPendingRunFailureReports();
const captureCallsBefore = mockCaptureRunFailure.mock.calls.length;
await finalize();
await waitForPendingRunFailureReports();
expect(captureRunFailureCallsFrom(captureCallsBefore)).toEqual([
[expect.objectContaining({ runId: fixture.runId, runStatus: "failed" })],
]);
await finalize();
await waitForPendingRunFailureReports();
expect(captureRunFailureCallsFrom(captureCallsBefore)).toHaveLength(1);
});
it("retires this run's scheduled finalization retry after successful commit", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL);
await recordNativeFinalizationFailure({ db, runId: fixture.runId,
error: new Error("native_workspace_sync_out_failed"), failureScope: "workspace", projectRunStatus: true });
const [pending] = await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId));
expect(pending).toMatchObject({ status: "active", evidence: { runId: fixture.runId } });
await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
const [settled] = await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.id, pending.id));
expect(settled.status).toBe("resolved");
});
it("repairs stale retry metadata on an already committed successful run", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL);
await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
const [before] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
await db.update(heartbeatRuns).set({ resultJson: {
...before.resultJson, finalizationPhase: "retryable_failure", failureCode: "native_finalization_invalid",
originalFailureCode: "native_finalization_invalid", nextAttemptAt: new Date().toISOString(),
} }).where(eq(heartbeatRuns.id, fixture.runId));
await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
const [after] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(after).toMatchObject({ status: "succeeded", nativePhase: "committed", resultJson: {
finalizationPhase: "committed", failureCode: null, originalFailureCode: null, nextAttemptAt: null,
} });
});
it("ignores a stale workspace failure after the same run committed successfully", async () => {
const fixture = await seedNativeRun();
await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL);
await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true });
const [before] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
const late = await recordNativeFinalizationFailure({
db, runId: fixture.runId, error: new Error("native_workspace_sync_out_failed"),
failureScope: "workspace", projectRunStatus: true,
});
expect(late.phase).toBe("committed");
const [after] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
expect(after).toEqual(before);
expect(await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId))).toEqual([]);
});
it("materializes recovery for an agent-owned invalid-result outcome", async () => {
const fixture = await seedNativeRun();
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId, companyId, issueId: fixture.issueId,
phase: "terminal_failure", failureCode: "native_finalization_invalid",
failureDetail: { recoveryOwner: { kind: "agent", agentId } },
});
const outcome = await recordNativeFinalizationFailure({
db, runId: fixture.runId, error: new Error("native_finalization_invalid"),
});
expect(outcome.phase).toBe("retryable_failure");
expect(await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId)))
.toEqual([expect.objectContaining({ status: "active", ownerType: "agent", cause: "native_finalization_invalid" })]);
});
it.each(["native_workspace_sync_out_unrecoverable", "native_workspace_sync_out_unsafe_archive"])(
"does not reopen board-owned %s repair for a late failure", async (failureCode) => {
const fixture = await seedNativeRun();
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId, companyId, issueId: fixture.issueId, phase: "workspace_finalizing",
});
await recordNativeFinalizationFailure({ db, runId: fixture.runId,
error: new Error(failureCode), failureScope: "workspace", permanent: true });
const [before] = await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, fixture.runId));
const recoveryBefore = await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId));
for (const failureScope of [undefined, "workspace"] as const) {
await recordNativeFinalizationFailure({ db, runId: fixture.runId,
error: new Error("native_workspace_sync_out_failed"), failureScope });
}
const [after] = await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, fixture.runId));
expect(after).toEqual(before);
expect(await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId))).toEqual(recoveryBefore);
});
it("emits zero events when a retryable-failure write's conditional status spread is omitted", async () => {
const fixture = await seedNativeRun();
// recordNativeFinalizationFailure only needs the run and coordinator rows
// to exist — no persisted native result is required.
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId,
companyId,
issueId: fixture.issueId,
phase: "observed",
attempt: 0,
});
const callsBefore = mockTelemetryClient.track.mock.calls.length;
// projectRunStatus is omitted (falsy): the conditional spread in
// recordRetryableFailure never includes `status`, so the write never sets
// a terminal status, regardless of the attempt count.
await recordNativeFinalizationFailure({
db,
runId: fixture.runId,
error: new Error("native_test_failure"),
});
expect(agentTaskRunCalls(callsBefore)).toHaveLength(0);
const run = await db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]);
expect(run?.status).toBe("running");
});
it("bounds workspace-only retries without consuming the provider attempt", async () => {
const fixture = await seedNativeRun();
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId,
companyId,
issueId: fixture.issueId,
phase: "observed",
attempt: 1,
});
for (
let expectedAttempt = 1;
expectedAttempt <= 3;
expectedAttempt += 1
) {
await recordNativeFinalizationFailure({
db,
runId: fixture.runId,
error: new Error("native_workspace_sync_out_failed"),
projectRunStatus: true,
failureScope: "workspace",
});
const coordinator = await db
.select()
.from(nativeRunFinalizations)
.where(eq(nativeRunFinalizations.runId, fixture.runId))
.then((rows) => rows[0]!);
expect(coordinator.attempt).toBe(1);
expect(coordinator.failureDetail).toMatchObject({
workspaceFinalizeAttempt: expectedAttempt,
});
expect(coordinator.phase).toBe(
expectedAttempt === 3 ? "terminal_failure" : "retryable_failure",
);
}
await expect(
db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]?.status),
).resolves.toBe("failed");
});
it("blocks immediately when the sandbox with unexported changes is gone", async () => {
const fixture = await seedNativeRun();
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId,
companyId,
issueId: fixture.issueId,
phase: "workspace_finalizing",
attempt: 1,
resultId: null,
});
const failure = await recordNativeFinalizationFailure({
db,
runId: fixture.runId,
error: new Error("native_workspace_sync_out_unrecoverable"),
projectRunStatus: true,
failureScope: "workspace",
permanent: true,
});
expect(failure).toMatchObject({
phase: "terminal_failure",
failureCode: "native_workspace_sync_out_unrecoverable",
nextAttemptAt: null,
attempt: 1,
});
await expect(
db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]?.status),
).resolves.toBe("failed");
await expect(
db
.select({ status: issues.status })
.from(issues)
.where(eq(issues.id, fixture.issueId))
.then((rows) => rows[0]?.status),
).resolves.toBe("blocked");
});
it("commits the saved result when unsafe workspace export is omitted, with only a run log", async () => {
const fixture = await seedNativeRun();
await db.update(completionContracts).set({ risk: "low", completionAuthority: "agent_claim_policy" })
.where(eq(completionContracts.id, fixture.contractId));
await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL, {
...CONTROL_PLANE_CONFORMANCE_RESULT,
completionClaim: { ...CONTROL_PLANE_CONFORMANCE_RESULT.completionClaim!, contractRevision: "telemetry-v1" },
});
const [original] = await db.select().from(nativeRunResults).where(eq(nativeRunResults.runId, fixture.runId));
const restore = vi.fn(async () => {
throw new Error("Daytona syncOut refusing tarball link whose target escapes the extraction dir: tools/pnpm -> /private/tool");
});
const assertOwnership = vi.fn(async () => {});
await restoreNativeWorkspaceBestEffort({ db, runId: fixture.runId, restore, assertOwnership });
const outcome = await finalizeNativeRun({ db, runId: fixture.runId, workspaceFinalizeStatus: "succeeded", projectRunStatus: true, preserveProviderAttempt: true });
expect(outcome.phase).toBe("committed");
expect(restore).toHaveBeenCalledOnce();
expect(assertOwnership).toHaveBeenCalledOnce();
const [run] = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId));
const [issue] = await db.select().from(issues).where(eq(issues.id, fixture.issueId));
expect(run).toMatchObject({ status: "succeeded", error: null, errorCode: null });
expect(issue.status).toBe("done");
const results = await db.select().from(nativeRunResults).where(eq(nativeRunResults.runId, fixture.runId));
expect(results).toEqual([original]);
const actions = await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId));
expect(actions).toEqual([]);
const events = await db.select().from(heartbeatRunEvents).where(eq(heartbeatRunEvents.runId, fixture.runId));
expect(events.filter(event => event.eventType === "workspace_export_omitted")).toMatchObject([
{ level: "info", payload: { reason: "restore_unsafe_archive" } },
]);
expect(JSON.stringify(events)).not.toContain("/private/tool");
});
it.each(["active", "resolved", "missing"])("automatically completes a legacy unsafe result with a %s repair action and no sandbox", async actionState => {
const fixture = await seedNativeRun();
await db.update(completionContracts).set({ risk: "low", completionAuthority: "agent_claim_policy" }).where(eq(completionContracts.id, fixture.contractId));
await driveToCompleteResult(fixture, CONTROL_PLANE_CONFORMANCE_TERMINAL, {
...CONTROL_PLANE_CONFORMANCE_RESULT,
completionClaim: { ...CONTROL_PLANE_CONFORMANCE_RESULT.completionClaim!, contractRevision: "telemetry-v1" },
});
const originalResults = await db.select().from(nativeRunResults).where(eq(nativeRunResults.runId, fixture.runId));
await db.update(nativeRunFinalizations).set({ phase: "terminal_failure", failureCode: "native_workspace_sync_out_unsafe_archive" }).where(eq(nativeRunFinalizations.runId, fixture.runId));
await db.update(heartbeatRuns).set({ status: "failed", nativePhase: "terminal_failure", errorCode: "native_workspace_sync_out_unsafe_archive",
runnerProfileJson: { nativeWorkspaceSync: { schema: "paperclip.native-workspace-sync/v1", state: "prepared",
descriptorSha256: "a".repeat(64), baselineSha256: "b".repeat(64), finalHostSha256: null,
workspaceId: randomUUID(), leaseId: randomUUID(), providerLeaseId: "missing-old-sandbox", remoteCwd: "/work", resourceDisposition: "destroy" } },
}).where(eq(heartbeatRuns.id, fixture.runId));
await db.update(issues).set({ status: "blocked" }).where(eq(issues.id, fixture.issueId));
if (actionState !== "missing") await db.insert(issueRecoveryActions).values({ companyId, sourceIssueId: fixture.issueId,
kind: "active_run_watchdog", ownerType: "board", cause: "native_workspace_sync_out_unsafe_archive", fingerprint: fixture.runId,
evidence: { runId: fixture.runId }, nextAction: "Repair the unsafe link manually", status: actionState,
...(actionState === "resolved" ? { outcome: "restored", resolutionNote: "new_source_execution_path", resolvedAt: new Date() } : {}),
});
const priorWakeups = await db.select().from(agentWakeupRequests).where(eq(agentWakeupRequests.companyId, companyId));
const priorActivity = await db.select().from(activityLog).where(eq(activityLog.entityId, fixture.issueId));
await recoverLegacyUnsafeWorkspaceExports(db, [fixture.runId]);
expect(await db.select().from(activityLog).where(eq(activityLog.entityId, fixture.issueId))).toEqual(priorActivity);
// No environment runtime is supplied: a stopped, deleted, or unavailable
// provider cannot prevent omission and accepted-result commitment.
await reconcileNativeFinalizations(db, [fixture.runId]);
await reconcileNativeFinalizations(db, [fixture.runId]);
expect((await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, fixture.runId)))[0]).toMatchObject({ status: "succeeded", nativePhase: "committed", error: null, errorCode: null });
expect((await db.select().from(issues).where(eq(issues.id, fixture.issueId)))[0].status).toBe("done");
expect(await db.select().from(nativeRunResults).where(eq(nativeRunResults.runId, fixture.runId))).toEqual(originalResults);
expect(await db.select().from(agentWakeupRequests).where(eq(agentWakeupRequests.companyId, companyId))).toEqual(priorWakeups);
expect(await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.nativeIssueId, fixture.issueId))).toHaveLength(1);
const actions = await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, fixture.issueId));
expect(actions.every(action => action.status === "resolved" && action.nextAction === "")).toBe(true);
expect((await db.select().from(workspaceOperations).where(eq(workspaceOperations.heartbeatRunId, fixture.runId)))[0]).toMatchObject({ status: "succeeded", metadata: { workspaceSync: { omitted: true, legacy: true } } });
const events = await db.select().from(heartbeatRunEvents).where(eq(heartbeatRunEvents.runId, fixture.runId));
expect(events.filter(event => event.eventType === "workspace_export_omitted")).toMatchObject([{ level: "info", payload: { reason: "restore_unsafe_archive", legacy: true } }]);
expect(events.filter(event => event.eventType === "workspace_export_omitted")).toHaveLength(1);
});
it("emits exactly one event for a cancel_continuations write (trap 2: :685/:518 overlap)", async () => {
const fixture = await seedNativeRun();
// Build the minimal real rows commitNativeStatusDecision's foreign keys
// require, without going through the evidence-classifier pipeline.
const resultId = randomUUID();
await db.insert(nativeRunResults).values({
id: resultId,
companyId,
issueId: fixture.issueId,
runId: fixture.runId,
completionContractId: fixture.contractId,
serverFingerprint: `fp-${resultId}`,
schemaStatus: "accepted",
resultJson: {},
canonicalSha256: `sha-${resultId}`,
});
const assessmentId = randomUUID();
await db.insert(workAssessments).values({
id: assessmentId,
companyId,
issueId: fixture.issueId,
runId: fixture.runId,
contractId: fixture.contractId,
resultId,
triggerKind: "native_result",
triggerActorCompanyId: companyId,
priorIssueStatus: "in_progress",
priorStatusVersion: 0,
policyVersion: "telemetry-v1",
assessmentJson: {},
inputDigest: `digest-${assessmentId}`,
});
await db.insert(nativeRunFinalizations).values({
runId: fixture.runId,
companyId,
issueId: fixture.issueId,
phase: "arbitrating",
attempt: 0,
resultId,
});
// Shaped exactly like resolveNativeCancellationStatus("issue", ...) in
// native-session-executor.ts — the only place cancel_continuations is
// produced today.
const decision: NativeStatusDecision = {
policyVersion: NATIVE_STATUS_ARBITER_POLICY_VERSION,
statusAction: "cancelled",
toStatus: "cancelled",
reasonCode: "cancellation_issue_authorized",
unblockDescriptor: null,
effects: [
{ kind: "release_checkout" },
{ kind: "cancel_continuations" },
],
};
const callsBefore = mockTelemetryClient.track.mock.calls.length;
await commitNativeStatusDecision({
db,
companyId,
issueId: fixture.issueId,
runId: fixture.runId,
assessmentId,
priorStatus: "in_progress",
priorStatusVersion: 0,
priorDecisionId: null,
decision,
});
const afterCommit = agentTaskRunCalls(callsBefore);
// status-decision-committer.ts:685 (the cancel_continuations effect)
// wrote this run's terminal status and emitted for it.
expect(afterCommit).toHaveLength(1);
expect(afterCommit[0]?.[1]).toMatchObject({ agent_id: agentId, state: "cancelled" });
const run = await db
.select({ status: heartbeatRuns.status })
.from(heartbeatRuns)
.where(eq(heartbeatRuns.id, fixture.runId))
.then((rows) => rows[0]);
expect(run?.status).toBe("cancelled");
// native-run-finalizer.ts:518's own guard: it skips its emit whenever the
// decision it just committed already included cancel_continuations,
// because :685 above already wrote and emitted for this run. Reproduce
// the exact guard predicate on the same decision object to prove it
// resolves to "skip", so the run's total event count for this commit
// stays at exactly one even after the finalizer's own write runs.
const alreadyEmittedByCommittedDecision = decision.effects.some(
(effect) => effect.kind === "cancel_continuations",
);
expect(alreadyEmittedByCommittedDecision).toBe(true);
expect(agentTaskRunCalls(callsBefore)).toHaveLength(1);
});
});
enableRunFailureReporting();