Files
PaperClipAI/server/src/services/heartbeat/run-completion.test.ts
T
DottaandPaperclip 9f524ec1a7 fix: persist native Runner usage before transport acknowledgement (#18354)
## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work.
> - Agent execution must preserve usage so Paperclip can price work and
enforce budgets.
> - Remote Runner execution can outlive its web receiver.
> - The receiver previously acknowledged Runner events before its later
usage recorder saved the accounting receipt.
> - This pull request saves required native usage receipts before that
transport acknowledgement.
> - A replacement receiver can accept the same retained report and
create one ledger charge.

## Linked Issues or Issue Description

**What happened?**

Native remote Runner usage could leave its durable outbox before the web
receiver saved its accounting receipt. The later recorder required a
local receipt directory. A replacement web receiver could lose the only
remaining report when the database write failed.

**Expected behavior**

The Runner retains unaccepted structured usage. Postgres owns accepted
receipts. Repeated delivery preserves one receipt for each source report
and one charge for the run. Missing usage keeps accounting pending.

**Steps to reproduce**

1. Start a supported built-in native remote Runner.
2. Make the receipt database insert fail after the provider reports
usage.
3. Replace the web receiver and its local directory.
4. Reconnect the same Runner and inspect the saved receipt and ledger.

**Paperclip version or commit**

The initial investigation used
`ebd05e9f4c88c66af7473db86bbaacfd1544aa0a`.

**Deployment mode**

A web server with a remote native Runner and shared Postgres.

Related work: #18327 owns output logs and provider traces. This change
has no dependency on its S3 export path. #18031 covers interrupted Codex
receipt recovery. #18005 covers legacy spool reads. #17516 covers Codex
stop-boundary retention.

## What Changed

- Add native producer receipt delivery through the existing Runner
callback before transport acknowledgement.
- Reuse `run_usage_receipts`, stable source sequences, and deterministic
report identities. Reject conflicting replay and retry a lost commit
response with the same receipt.
- Restore per-turn usage from structured receipt facts. Preserve
provider turns that share one PRP envelope turn.
- Bind retained warm transport callbacks to the current run authority
epoch, allowing old attachment control acknowledgements while preserving
accounting ownership.
- Persist Codex session baselines and cumulative totals in the existing
provider checkpoint. Mark qualified whole-run deltas, preserve them
across resume/restart/attachment, and leave old unmarked reports
incomplete and unpriced.
- Normalize the bounded final usage tail before the terminal event.
Retain later increases for explicit reconciliation, block further
attachment, and fail an affected successor without changing its
baseline.
- Complete runs from the accepted immutable receipt and its exact saved
rate-card amount; preserve existing live-budget enforcement.
- Skip the local receipt recorder for supported built-in native remote
Runner execution. Keep local, legacy, and external Dot/Muse behavior
unchanged.
- Keep pricing, reservations, ledger settlement, source fencing, and
budget holds with their existing owners.
- Put the actual Runner integration test in the existing Rust-cached
native test lane. Build before opening Postgres and give cold
compilation its own bounded budget.

## Verification

- Fresh Greptile review is 5/5 on
`e7376a50c8162770da1d581ecf25c8cffac64520`, with no unresolved findings.
Parent and independent peer review approved the final changes.
- Real PostgreSQL 18.6 and a real Rust Runner exercise failed receipt
insertion, receiver-directory loss, replay from the same producer, and
exactly one 25-cent ledger charge. The actual accounting spool path
stays absent. Optional logs/traces are disabled. The provider is
controlled; no paid request is made and the fixture never pre-saves the
expected receipt.
- Producer checks passed 32 usage/provider tests,37 terminal controls,
corrected completion, all 3 previously failing exit cases, and both full
transport goal-continuation cases. Rejected active-goal completion
retains its 120-token tail before failure. Baseline 100→successor150→33
duplicate old snapshots→old120 retains explicit incomplete
reconciliation evidence and positive budget exposure.
- Heartbeat executor checks passed 982/982. PostgreSQL tests preserve
exact 1.002 USD pricing, the 100.2-cent ledger amount, budget holds,
source takeover, partial/final receipts, cost-only corrections, equal
rate-card replay, and stale-completion interleaving. Newer incomplete
usage remains pending rather than settling an older snapshot.
- Runtime replay and strict usage-schema checks passed 2/2; generated
contracts and Rust formatting pass. Test-partition contracts passed
32/32.
- [Final combined-head
evidence](https://github.com/paperclipai/paperclip/pull/18354#issuecomment-6531526158)
records full workspace typecheck/build and 41/41 accounting tests
against all five cloud PR heads, including this final accounting commit.
It includes commands and evidence limits.
- Exact-head CI is green: 53successful checks, 6intentional skips, and
the legacy Snyk status passed. Typecheck, build, Runner, server,
browser, and aggregate gates pass. Runner Vitest1/2 initially failed an
unchanged mocked Antigravity login fixture; its focused case passed
locally, then one unchanged job retry passed 131 files/1995 tests,
including all 11 Antigravity tests. The initial failed attempt remains
recorded in CI.

Initial local attempts exposed the host SysV semaphore limit and
corrected harness path, IPC readiness, and queue-counter defects. A
temporary test loader selected an existing POSIX-semaphore PostgreSQL
18.6 build without changing repository dependencies. An optional
expanded debug provider run was interrupted at its unrelated 8192-turn
rollover stress case; no full-file local pass is claimed. Required
failure cases were run directly, and the full Runner CI remains
required.

## Risks

- The guarantee covers built-in native remote Runner execution. Local
native execution, legacy adapters, external Dot/Muse execution, and
server-originated model calls retain their existing contracts.
- This does not provide traffic switching or general web-server
failover. The existing controller identity, checkpoint, and generation
gates still apply.
- The receipt JSON gains optional structured producer facts. No schema
migration or accounting S3 spool is added. Text output and raw trace
payloads are excluded.
- Codex accounting authority requires a Runner artifact built from this
provider baseline implementation and qualified by digest. Update
receivers and strict usage-schema readers before releasing that Runner;
PRP does not negotiate this payload field. Existing unmarked Codex
reports remain pending/unpriced. No deployed Runner artifact is claimed
fixed.
- Usage arriving beyond the bounded terminal tail may require manual
reconciliation or a fresh session. Its evidence remains in the existing
producer checkpoint/outbox; no adjustment ledger or recurring scan is
added.

## Model Used

OpenAI `gpt-6.1-sol` assisted with the implementation, tests, and
documentation through code execution and repository tools. The context
window size is unavailable.

## 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
- [x] All Paperclip CI gates are green
- [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups
- [x] I will address all Greptile and reviewer comments before
requesting merge

---------

Co-authored-by: Paperclip <noreply@paperclip.ing>
2026-10-30 15:20:42 -05:00

465 lines
35 KiB
TypeScript

import { createNativeUsageDelivery } from "../native-runtime/native-usage-delivery.js";
import type { PrpEvent } from "../../vendor/paperclip-runner/index.js";
import { randomUUID } from "node:crypto";
import type { Db } from "@paperclipai/db";
import { agents, agentWakeupRequests, caseHandoffs, cases, companies, costEvents, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, issues, nativeRunFinalizations } from "@paperclipai/db";
import { eq, sql } from "drizzle-orm";
import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js";
import * as usageReceipts from "../usage-receipts.js";
import { createAgentIdentityRedactor } from "../agent-identity-redaction.js";
import { UnresolvedWorkspaceBaseRefError } from "../workspace-runtime.js";
import { LegacyControllerLeaseLostError } from "../legacy-controller-lease.js";
import { requestedRunCancellation } from "../run-cancellation.js";
import { ProjectAccessDeniedError } from "../project-access-denial.js";
import { createHeartbeatLifecycle, type HeartbeatLifecycleDependencies } from "./run-lifecycle.js";
import { createHeartbeatRunPreparation, ConfigurationIncompleteFailure } from "./run-preparation.js";
import { createHeartbeatRunState, getAdapterSessionCodec } from "./run-state.js";
import { buildEffectiveRunSessionConfigMetadata } from "./workspaces.js";
import { createHeartbeatRunCompletion, type CompleteHeartbeatRunInput, type FailHeartbeatRunInput, type HeartbeatRunCompletionDependencies } from "./run-completion.js";
import { createHeartbeatAgentStatus } from "./agent-status.js";
vi.mock("../live-events.js", () => ({ publishLiveEvent: vi.fn() }));
type Dependencies = HeartbeatRunCompletionDependencies;
function callbacks(db: Db) {
const state = createHeartbeatRunState(db);
const lifecycleDeps = {
...state, ...createHeartbeatRunPreparation(db),
issuesSvc: { addComment: vi.fn(), listReviewAttention: vi.fn() },
recovery: { escalateStrandedAssignedIssue: vi.fn() },
companySkills: { completeTestRunForIssue: vi.fn() },
budgets: { getInvocationBlock: vi.fn(async () => null) },
treeControlSvc: { getActivePauseHoldGate: vi.fn(async () => null) },
enqueueWakeup: vi.fn(),
getCurrentUserRedactionOptions: vi.fn(async () => ({ enabled: false })),
getAgentInvokability: vi.fn<HeartbeatLifecycleDependencies["getAgentInvokability"]>(async () => ({ invokable: true })),
emitTerminalAgentTaskRun: vi.fn(), budgetHooks: {},
} satisfies HeartbeatLifecycleDependencies;
const lifecycle = createHeartbeatLifecycle(db, lifecycleDeps);
return {
...state, ...lifecycle,
setRunStatusIfRunning: vi.fn(lifecycle.setRunStatusIfRunning),
setWakeupStatus: vi.fn(lifecycle.setWakeupStatus),
upsertTaskSession: vi.fn(state.upsertTaskSession),
clearTaskSessions: vi.fn(state.clearTaskSessions),
classifyAndPersistRunLiveness: vi.fn<Dependencies["classifyAndPersistRunLiveness"]>(async run => run),
completeSkillTestRunForHeartbeatOutcome: vi.fn<Dependencies["completeSkillTestRunForHeartbeatOutcome"]>(async () => null),
refreshContinuationSummaryForRun: vi.fn<Dependencies["refreshContinuationSummaryForRun"]>(async () => null),
findRunIssueComment: vi.fn<Dependencies["findRunIssueComment"]>(async () => null),
findLatestCompletedFinalAgentMessage: vi.fn<Dependencies["findLatestCompletedFinalAgentMessage"]>(async () => null),
finalizeIssueCommentPolicy: vi.fn<Dependencies["finalizeIssueCommentPolicy"]>(async () => ({ outcome: "not_applicable", queuedRun: null })),
handleIssueReviewPathDisposition: vi.fn<Dependencies["handleIssueReviewPathDisposition"]>(async () => undefined),
handleRunLivenessContinuation: vi.fn<Dependencies["handleRunLivenessContinuation"]>(),
handleSuccessfulRunHandoff: vi.fn<Dependencies["handleSuccessfulRunHandoff"]>(),
updateRuntimeState: vi.fn<Dependencies["updateRuntimeState"]>(),
scheduleBoundedRetryForRun: vi.fn<Dependencies["scheduleBoundedRetryForRun"]>(),
scheduleInteractionContinuationInfrastructureRetryIfEligible: vi.fn<Dependencies["scheduleInteractionContinuationInfrastructureRetryIfEligible"]>(async () => null),
timerClaimWasFirstHeartbeat: vi.fn<Dependencies["timerClaimWasFirstHeartbeat"]>(() => undefined),
releaseIssueExecutionAndPromote: vi.fn<Dependencies["releaseIssueExecutionAndPromote"]>(async () => undefined),
finalizeAgentStatus: vi.fn<Dependencies["finalizeAgentStatus"]>(async () => undefined),
enqueueWakeup: vi.fn<Dependencies["enqueueWakeup"]>(),
issuesSvc: { addComment: vi.fn<Dependencies["issuesSvc"]["addComment"]>() },
recovery: { reconcileLegacyContinuation: vi.fn<Dependencies["recovery"]["reconcileLegacyContinuation"]>(), reconcileResolvedDependencyWakeBackstop: vi.fn<Dependencies["recovery"]["reconcileResolvedDependencyWakeBackstop"]>() },
getCurrentUserRedactionOptions: lifecycleDeps.getCurrentUserRedactionOptions,
budgetHooks: {},
runLogStore: { finalize: vi.fn<Dependencies["runLogStore"]["finalize"]>(async () => ({ bytes: 123, sha256: "log-hash", compressed: true })) },
traceStore: { finalize: vi.fn<Dependencies["traceStore"]["finalize"]>() },
processRunCancellationSettlements: new Map<string, { settled: Promise<void>; failed: boolean }>(),
failedProcessRunCancellations: new Map<string, { settled: Promise<void>; failed: boolean }>(),
} satisfies Dependencies;
}
it("constructs completion handlers without querying or starting work", () => {
const access = vi.fn(() => { throw new Error("Unexpected database access"); });
const db = new Proxy({}, { get: access }) as Db;
const deps = callbacks(db);
createHeartbeatRunCompletion(db, deps);
expect(access).not.toHaveBeenCalled();
for (const callback of Object.values(deps)) if (vi.isMockFunction(callback)) expect(callback).not.toHaveBeenCalled();
});
const support = await getEmbeddedPostgresTestSupport();
describe.skipIf(!support.supported && !process.env.PAPERCLIP_TEST_DATABASE_URL)("heartbeat run completion boundary", () => {
let database: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | undefined;
let db: Db;
beforeAll(async () => {
// Keep the accounting transaction real without reading provider receipt files.
vi.spyOn(usageReceipts, "indexPendingUsageReceipts").mockResolvedValue(new Map());
vi.spyOn(usageReceipts, "recoverPendingRunUsageReceipts").mockResolvedValue([]);
const external = process.env.PAPERCLIP_TEST_DATABASE_URL;
if (external) db = createDb(external);
else {
database = await startEmbeddedPostgresTestDatabase("paperclip-heartbeat-completion");
db = createDb(database.connectionString);
}
await db.execute(sql`set client_min_messages = warning`);
}, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS);
afterAll(async () => { await db?.$client.end(); await database?.cleanup(); vi.restoreAllMocks(); });
beforeEach(async () => { await db.execute(sql`truncate table companies restart identity cascade`); });
async function fixture(patch: Partial<typeof heartbeatRuns.$inferInsert> = {}) {
const [company] = await db.insert(companies).values({ name: "Completion", issuePrefix: "CMP" }).returning();
const [agent] = await db.insert(agents).values({ companyId: company.id, name: "Completing agent", adapterType: "process" }).returning();
const [wake] = await db.insert(agentWakeupRequests).values({ companyId: company.id, agentId: agent.id, source: "on_demand", status: "claimed" }).returning();
const [run] = await db.insert(heartbeatRuns).values({ companyId: company.id, agentId: agent.id, wakeupRequestId: wake.id, status: "running", runtimeMode: "legacy", ...patch }).returning();
const deps = callbacks(db);
const controller = new AbortController();
const input: CompleteHeartbeatRunInput = {
run, agent, issueId: null, issueRef: null, signal: controller.signal,
output: { handle: { store: "local_file", logRef: "test-log" }, outputProgressState: { pending: { bytes: 7 } }, flushOutputProgress: vi.fn(async () => {}), stdoutExcerpt: "answer", stderrExcerpt: "diagnostic" },
session: { runtimeForAdapter: { sessionId: null, sessionDisplayId: null }, previousSessionParams: null, taskKey: "completion-task", configuredModel: "test-model",
sessionConfigMetadata: await buildEffectiveRunSessionConfigMetadata({ adapterType: agent.adapterType, effectiveAdapterConfig: {}, agentRuntimeConfig: {}, issueOverrides: null, workspaceConfig: null, environment: null, environmentEnv: null, projectEnv: null, routineEnv: null, runtimeSkills: [] }),
},
readFailureReportSecrets: () => [],
adapterResult: { exitCode: 0, signal: null, timedOut: false, sessionId: "provider-session", sessionParams: { sessionId: "provider-session" }, usage: { inputTokens: 20, cachedInputTokens: 5, outputTokens: 8 }, usageBasis: "per_run", costUsd: 0.01, provider: "test", model: "test-model", resultJson: { finalResponse: "Completed the work." } },
sessionCodec: getAdapterSessionCodec(agent.adapterType), taskSessionForRun: null, sessionCompaction: { rotate: false, reason: null }, configFreshnessResultMetadata: { version: 1 }, runLedgerScope: {}, currentUserRedactionOptions: { enabled: false }, providerTraceCapture: true, onProviderTraceFinalized: vi.fn(), issueContext: null, onLog: vi.fn(async () => {}),
};
const completion = createHeartbeatRunCompletion(db, deps);
const failure = (err: unknown): FailHeartbeatRunInput => ({ ...input, runId: run.id, err, identityRedactor: createAgentIdentityRedactor("private-identity-material"), requiredWorkspaceRestoreEvidence: { workspaceRestoreFailure: { reason: "missing_base" } }, legacyAdapterEntered: true, goalCheckpointSession: { current: null }, previousSessionDisplayId: "previous-session", taskSession: null });
const setup = (outerErr: unknown, providerDispatchStarted = false) => ({ run, runId: run.id, outerErr, signal: controller.signal, providerDispatchStarted, identityRedactor: createAgentIdentityRedactor(), readFailureReportSecrets: () => [] });
return { run, agent, wake, deps, controller, input, completion, failure, setup };
}
const read = (id: string) => db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)).then(rows => rows[0]!);
it.each(["completeRun", "failRun"] as const)("settles the outgoing agent after a case handoff in %s", async operation => {
const f = await fixture();
await db.update(agents).set({ status: "running", lifecycleState: "ready" }).where(eq(agents.id, f.agent.id));
const [recipient] = await db.insert(agents).values({ companyId: f.agent.companyId, name: "Next phase", adapterType: "process" }).returning();
const [issue] = await db.insert(issues).values({ companyId: f.agent.companyId, title: "Case task", status: "in_progress", assigneeAgentId: f.agent.id }).returning();
const [record] = await db.insert(cases).values({ companyId: f.agent.companyId, caseNumber: 1, identifier: "CASE-1", caseType: "work", title: issue.title, workIssueId: issue.id, handoffVersion: 1 }).returning();
await db.insert(caseHandoffs).values({ companyId: f.agent.companyId, caseId: record.id, issueId: issue.id, version: 1,
fromAgentId: f.agent.id, toAgentId: recipient.id, phase: "verification", instructions: "Verify the saved work",
actorType: "agent", actorId: f.agent.id, sourceRunId: f.run.id, wakeupRequestId: randomUUID(), idempotencyKey: "next-phase", inputFingerprint: "next-phase", state: "awaiting_release" });
f.input.issueId = issue.id;
f.input.issueRef = issue;
f.deps.finalizeAgentStatus.mockImplementation(createHeartbeatAgentStatus(db).finalizeAgentStatus);
if (operation === "completeRun") await f.completion.completeRun(f.input);
else await f.completion.failRun(f.failure(new Error("Provider exited after the accepted handoff")));
const [settledAgent] = await db.select().from(agents).where(eq(agents.id, f.agent.id));
expect(settledAgent).toMatchObject({ status: operation === "completeRun" ? "idle" : "error", lastHeartbeatAt: expect.any(Date) });
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledOnce();
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledWith(expect.objectContaining({ id: f.run.id }), { suppressImmediateRecovery: true });
expect(f.deps.handleSuccessfulRunHandoff).not.toHaveBeenCalled();
expect(f.deps.scheduleBoundedRetryForRun).not.toHaveBeenCalled();
expect((await db.select().from(issues).where(eq(issues.id, issue.id)))[0]?.status).toBe("in_progress");
});
it("persists usage, accounting, final logs, presentation and the next task session", async () => {
const f = await fixture();
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: "succeeded", sessionIdAfter: "provider-session", logBytes: 123, logSha256: "log-hash", logCompressed: true, stdoutExcerpt: "answer", costAccountingPending: false, costAccountedAt: expect.any(Date), usageJson: { inputTokens: 20, cachedInputTokens: 5, outputTokens: 8, usageSource: "per_run", configFreshness: { version: 1 } }, resultJson: { presentationDecision: { commentAction: "none" } } });
expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id))).toHaveLength(1);
expect((await f.deps.getTaskSession(f.agent.companyId, f.agent.id, f.agent.adapterType, "completion-task"))?.sessionDisplayId).toBe("provider-session");
expect(f.input.output.outputProgressState.pending?.bytes).toBe(123);
expect(f.input.onProviderTraceFinalized).toHaveBeenCalledOnce();
expect(f.deps.setWakeupStatus).toHaveBeenCalledWith(f.wake.id, "completed", expect.any(Object));
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce();
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "succeeded", null, expect.any(Object));
});
it("settles the accepted native exact rate-card price without replacing it with zero", async () => {
const f = await fixture({ runtimeMode: "native" });
const runnerInstanceId = randomUUID();
const delivery = await createNativeUsageDelivery(db, { companyId: f.run.companyId, runId: f.run.id, runnerInstanceId,
provider: { kind: "codex", model: "gpt-6.1-sol" }, billing: { provider: "openai", biller: "openai", billingType: "metered_api" } });
const event = (sourceSeq: number, eventType: string, payload: Record<string, unknown>): PrpEvent => ({
sourceKind: "runner", sourceInstanceId: runnerInstanceId, runId: f.run.id, sourceSeq, sourceEventId: `rate-card-${sourceSeq}`,
turnId: "price-turn", eventType, emittedAt: new Date().toISOString(), payload,
} as PrpEvent);
await delivery.capture(event(1, "usage.reported", { runDeltaBasis: "run", runDeltaAvailable: true,
runDelta: { inputTokens: 1000, outputTokens: 100000, providerCostUsd: 0 } }));
await delivery.capture(event(2, "turn.completed", {}));
const accepted = await usageReceipts.readAcceptedRunUsageCheckpoint(db, { companyId: f.run.companyId, runId: f.run.id });
expect(accepted?.costStatus).toBe("estimated");
const exact = accepted!.costUsdExact;
f.input.adapterResult = { exitCode: 0, signal: null, timedOut: false, ...accepted, usageComplete: accepted!.complete };
await f.completion.completeRun(f.input);
const saved = await read(f.run.id);
expect(saved).toMatchObject({ status: "succeeded", costAccountingPending: false, costAccountedAt: expect.any(Date),
usageJson: { costUsdExact: exact, costStatus: "estimated" } });
const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id));
expect(ledger).toHaveLength(1);
expect(ledger[0].costCents).toBe(100.2);
});
it("retains newer accepted native usage when completion consumed an older receipt", async () => {
const f = await fixture({ runtimeMode: "native", usageJson: { sessionRotated: true, configFreshness: { version: 0 } } });
const runnerInstanceId = randomUUID();
const delivery = await createNativeUsageDelivery(db, { companyId: f.run.companyId, runId: f.run.id, runnerInstanceId,
provider: { kind: "codex", model: "test-model" }, billing: { provider: "openai", biller: "openai", billingType: "metered_api" } });
const event = (sourceSeq: number, eventType: string, inputTokens = 100): PrpEvent => ({
sourceInstanceId: runnerInstanceId, runId: f.run.id, sourceSeq, sourceEventId: `racing-${sourceSeq}`, turnId: "turn-1",
emittedAt: new Date().toISOString(), eventType, payload: eventType === "usage.reported"
? { runDeltaBasis: "run", runDeltaAvailable: true, runDelta: { inputTokens, outputTokens: 10, providerCostUsd: inputTokens / 1000 } } : {},
} as PrpEvent);
await delivery.capture(event(1, "usage.reported"));
await delivery.capture(event(2, "turn.completed"));
const acceptedA = await usageReceipts.readAcceptedRunUsageCheckpoint(db, { companyId: f.run.companyId, runId: f.run.id });
await delivery.capture(event(3, "usage.reported", 120));
f.input.adapterResult = { exitCode: 0, signal: null, timedOut: false, ...acceptedA, usageComplete: acceptedA!.complete };
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: "succeeded", costAccountingPending: true, costAccountedAt: null,
usageJson: { inputTokens: 120, costUsd: 0.12, accountingReceiptSequence: 3, accountingReceiptReady: false, sessionRotated: false, configFreshness: { version: 1 } } });
expect(await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id))).toHaveLength(0);
await delivery.capture(event(4, "turn.completed", 120));
expect(await (await import("../run-cost-accounting.js")).accountRunCost(db, f.run.id)).toBe(true);
const ledger = await db.select().from(costEvents).where(eq(costEvents.heartbeatRunId, f.run.id));
expect(ledger).toHaveLength(1);
expect(ledger[0].costCents).toBe(12);
});
it.each([
{ timedOut: true, expected: "timed_out", errorCode: "timeout" },
{ signal: "SIGTERM", expected: "failed", errorCode: "adapter_failed" },
{ errorMessage: "provider quota", errorCode: "provider_quota", expected: "failed" },
])("keeps adapter outcome classification ($expected, $errorCode)", async ({ expected, ...result }) => {
const f = await fixture();
Object.assign(f.input.adapterResult, result);
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: expected, errorCode: result.errorCode });
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, expected, expect.any(String), expect.objectContaining({ keepIdleOnFailure: result.errorCode === "provider_quota" }));
});
it.each(["completeRun", "failRun"] as const)("waits for an owned Stop before %s can write a competing outcome", async operation => {
const f = await fixture();
let settle!: () => void;
const settled = new Promise<void>(resolve => { settle = resolve; });
f.deps.processRunCancellationSettlements.set(f.run.id, { settled, failed: false });
const completion = operation === "completeRun" ? f.completion.completeRun(f.input) : f.completion.failRun(f.failure(new Error("late adapter error")));
await Promise.resolve();
expect(f.deps.setRunStatusIfRunning).not.toHaveBeenCalled();
await db.update(heartbeatRuns).set({ status: "cancelled", errorCode: "cancelled", finishedAt: new Date() }).where(eq(heartbeatRuns.id, f.run.id));
f.controller.abort();
settle();
await completion;
expect((await read(f.run.id)).status).toBe("cancelled");
if (operation === "completeRun") {
expect((await read(f.run.id)).sessionIdAfter).toBe("provider-session");
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "cancelled", expect.any(String), expect.any(Object));
} else expect(f.deps.finalizeAgentStatus).not.toHaveBeenCalled();
});
it("attributes an adapter stop caused by a lost controller lease", async () => {
const f = await fixture();
Object.assign(f.input.adapterResult, { exitCode: null, errorCode: "cancelled", errorMessage: "Grok execution was cancelled" });
f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline"));
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: "cancelled", resultJson: { cancellation: {
source: "controller_lease", expected: false, initiator: { type: "system" }, reason: "Legacy controller lease lost (renewal_deadline)" } } });
});
it("attributes a lost controller lease when the adapter throws the abort reason", async () => {
const f = await fixture();
f.controller.abort(new LegacyControllerLeaseLostError("renewal_rejected"));
await f.completion.failRun(f.failure(f.controller.signal.reason));
expect(await read(f.run.id)).toMatchObject({ status: "cancelled", resultJson: {
workspaceRestoreFailure: { reason: "missing_base" },
cancellation: { source: "controller_lease", expected: false, reason: "Legacy controller lease lost (renewal_rejected)" } } });
});
it("records the watchdog timings with a lease loss that stops the adapter", async () => {
const f = await fixture();
Object.assign(f.input.adapterResult, { exitCode: null, errorCode: "cancelled", errorMessage: "Grok execution was cancelled" });
f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline",
{ sinceRenewalMs: 61_000, renewalPendingMs: 58_000, deadlineLateMs: 2, renewalCount: 41 }));
await f.completion.completeRun(f.input);
expect((await read(f.run.id)).resultJson).toMatchObject({ controllerLeaseLoss: {
cause: "renewal_deadline", sinceRenewalMs: 61_000, renewalPendingMs: 58_000, deadlineLateMs: 2, renewalCount: 41 } });
});
it("records the lease-loss cause and timings when setup fails on the abort reason", async () => {
const f = await fixture();
f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline",
{ sinceRenewalMs: 60_004, renewalPendingMs: null, deadlineLateMs: 55_000, renewalCount: 3 }));
await f.completion.failRunSetup(f.setup(f.controller.signal.reason));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost", resultJson: {
executionRecovery: { kind: "bootstrap", providerWorkStarted: false },
controllerLeaseLoss: { cause: "renewal_deadline", sinceRenewalMs: 60_004, renewalPendingMs: null,
deadlineLateMs: 55_000, renewalCount: 3 } } });
});
it("keeps a stop requested before the lease loss when the adapter throws", async () => {
const f = await fixture();
const requested = requestedRunCancellation({ cancelledByActorType: "user", cancelledByUserId: "operator-1" }, "Stopped from the board");
await db.update(heartbeatRuns).set({ resultJson: { cancellation: requested } }).where(eq(heartbeatRuns.id, f.run.id));
f.controller.abort(new LegacyControllerLeaseLostError("renewal_error"));
await f.completion.failRun(f.failure(f.controller.signal.reason));
expect(await read(f.run.id)).toMatchObject({ status: "cancelled", resultJson: { cancellation: {
source: "operator", expected: true, initiator: { type: "user", id: "operator-1" }, reason: "Stopped from the board" } } });
});
it("does not publish or overwrite a conflicting terminal transition that wins the compare-and-set", async () => {
const f = await fixture();
const write = f.deps.setRunStatusIfRunning.getMockImplementation()!;
f.deps.setRunStatusIfRunning.mockImplementationOnce(async (...args) => {
await db.update(heartbeatRuns).set({ status: "cancelled", errorCode: "cancelled", resultJson: { winner: "Stop" } }).where(eq(heartbeatRuns.id, f.run.id));
return write(...args);
});
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: "cancelled", resultJson: { winner: "Stop" }, sessionIdAfter: null });
expect(f.deps.setWakeupStatus).not.toHaveBeenCalled();
expect(f.deps.updateRuntimeState).not.toHaveBeenCalled();
expect(f.deps.releaseIssueExecutionAndPromote).not.toHaveBeenCalled();
expect(f.deps.finalizeAgentStatus).not.toHaveBeenCalled();
});
it("retains native completion metadata when reconciliation already committed the same terminal status", async () => {
const finishedAt = new Date("2026-10-09T12:00:00Z");
const f = await fixture({ runtimeMode: "native", status: "succeeded", finishedAt, resultJson: { durable: "accepted" }, usageJson: { durableReceipt: "native" } });
f.input.adapterResult.nativeFinalization = { schema: "paperclip.native-finalization.v1", runtimeMode: "native", runId: f.run.id, companyId: f.run.companyId, issueId: "unused", result: {}, terminal: { schema: "paperclip.prp.terminal.v1", turnTerminalState: "completed", runTerminalState: "succeeded", reportedWorkDisposition: "done" }, turnId: null, sourceInstanceId: "test", normalizedSessionId: "native-session", providerSessionId: null, driverKind: "test", driverVersion: "1", nativeEventCount: 1, highestContiguousSourceSeq: 1, workspaceFinalizeStatus: "succeeded" };
await f.completion.completeRun(f.input);
expect(await read(f.run.id)).toMatchObject({ status: "succeeded", finishedAt, sessionIdAfter: "provider-session", resultJson: { durable: "accepted" }, usageJson: { durableReceipt: "native", inputTokens: 20 } });
expect(f.deps.updateRuntimeState).toHaveBeenCalledOnce();
});
it("reports trace completion before a later write throws and reads output after log finalization", async () => {
const f = await fixture();
let excerpt = "before finalize";
Object.defineProperty(f.input.output, "stdoutExcerpt", { get: () => excerpt });
f.deps.runLogStore.finalize.mockImplementationOnce(async () => { excerpt = "last provider output"; return { bytes: 99, compressed: false }; });
const writeError = new Error("write failed");
f.deps.setRunStatusIfRunning.mockRejectedValueOnce(writeError);
await expect(f.completion.completeRun(f.input)).rejects.toBe(writeError);
expect(f.input.onProviderTraceFinalized).toHaveBeenCalledOnce();
expect(f.deps.setRunStatusIfRunning).toHaveBeenCalledWith(f.run.id, "succeeded", expect.objectContaining({ stdoutExcerpt: "last provider output", logBytes: 99 }), expect.any(Object));
});
it("keeps a failed trace finalization eligible for the executor's cleanup retry", async () => {
const f = await fixture();
f.deps.traceStore.finalize.mockRejectedValueOnce(new Error("trace store unavailable"));
await f.completion.completeRun(f.input);
expect((await read(f.run.id)).status).toBe("succeeded");
expect(f.input.onProviderTraceFinalized).not.toHaveBeenCalled();
});
it("keeps completion and session persistence moving after a response comment fails", async () => {
const f = await fixture();
f.input.adapterResult.resultJson = { finalResponseDisposition: "final", finalResponse: "Completed the work." };
const [issue] = await db.insert(issues).values({ companyId: f.run.companyId, title: "Report the result" }).returning();
f.input.issueId = issue.id;
f.input.issueRef = issue;
f.input.issueContext = await createHeartbeatRunPreparation(db).getIssueExecutionContext(f.run.companyId, issue.id);
f.deps.issuesSvc.addComment.mockRejectedValueOnce(new Error("comment unavailable"));
await f.completion.completeRun(f.input);
expect(f.deps.issuesSvc.addComment).toHaveBeenCalledOnce();
expect(f.input.onLog).toHaveBeenCalledWith("stderr", expect.stringContaining("comment unavailable"));
expect((await read(f.run.id)).status).toBe("succeeded");
expect(f.deps.upsertTaskSession).toHaveBeenCalledOnce();
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce();
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledOnce();
});
it("clears only the completed task session when the adapter requests a reset", async () => {
const f = await fixture();
f.input.adapterResult.clearSession = true;
await f.completion.completeRun(f.input);
expect(f.deps.clearTaskSessions).toHaveBeenCalledWith(f.run.companyId, f.agent.id, { taskKey: "completion-task", adapterType: "process", expectedRunId: f.run.id });
expect(f.deps.upsertTaskSession).not.toHaveBeenCalled();
});
it("redacts execution failures, retains restore evidence and resumes the latest checkpoint", async () => {
const f = await fixture();
const failure = f.failure(new Error("private-identity-material crashed"));
failure.goalCheckpointSession.current = { params: { sessionId: "checkpoint" }, displayId: "checkpoint" };
await f.completion.failRun(failure);
const run = await read(f.run.id);
expect(run).toMatchObject({ status: "failed", errorCode: "adapter_failed", logBytes: 123, resultJson: { workspaceRestoreFailure: { reason: "missing_base" } } });
expect(run.error).not.toContain("private-identity-material");
expect((await f.deps.getTaskSession(f.agent.companyId, f.agent.id, f.agent.adapterType, "completion-task"))?.sessionDisplayId).toBe("checkpoint");
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledOnce();
});
it("still records failure and releases issue ownership when log finalization and progress flushing fail", async () => {
const f = await fixture();
f.deps.runLogStore.finalize.mockRejectedValueOnce(new Error("log unavailable"));
f.input.output.flushOutputProgress = vi.fn(async () => { throw new Error("progress unavailable"); });
await f.completion.failRun(f.failure(new Error("adapter failed")));
expect((await read(f.run.id)).status).toBe("failed");
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce();
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledOnce();
});
it("keeps durable result-less native failure authoritative and suppresses generic replacement recovery", async () => {
const f = await fixture({ runtimeMode: "native", status: "failed", errorCode: "native_result_missing" });
const [issue] = await db.insert(issues).values({ companyId: f.run.companyId, title: "Native recovery" }).returning();
await db.update(heartbeatRuns).set({ nativeIssueId: issue.id }).where(eq(heartbeatRuns.id, f.run.id));
await db.insert(nativeRunFinalizations).values({ runId: f.run.id, companyId: f.run.companyId, issueId: issue.id, phase: "terminal_failure", failureCode: "native_result_missing" });
await f.completion.failRun(f.failure(new Error("transport ended")));
expect((await read(f.run.id)).errorCode).toBe("native_result_missing");
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledWith(expect.objectContaining({ id: f.run.id }), { suppressImmediateRecovery: true });
});
it("persists a project denial without provider work or an automatic retry", async () => {
const f = await fixture();
const projectId = randomUUID();
await f.completion.failRunSetup(f.setup(new ProjectAccessDeniedError(projectId)));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "project_access_denied",
resultJson: { projectAccessDenied: { projectId }, executionRecovery: { kind: "bootstrap", providerWorkStarted: false } } });
expect(f.deps.scheduleBoundedRetryForRun).not.toHaveBeenCalled();
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
expect(f.deps.scheduleInteractionContinuationInfrastructureRetryIfEligible).not.toHaveBeenCalled();
expect(f.deps.finalizeIssueCommentPolicy).not.toHaveBeenCalled();
});
it("records a setup configuration gap without inventing provider work or applying comment policy", async () => {
const f = await fixture();
await f.completion.failRunSetup(f.setup(new ConfigurationIncompleteFailure("missing credential", { configurationIncomplete: { reason: "missing_binding" } })));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "configuration_incomplete", resultJson: { configurationIncomplete: { reason: "missing_binding" }, executionRecovery: { kind: "bootstrap", providerWorkStarted: false } } });
expect(f.deps.finalizeIssueCommentPolicy).not.toHaveBeenCalled();
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce();
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledOnce();
});
it("retains the default branch needed to repair an unresolved workspace base ref", async () => {
const f = await fixture();
const error = new UnresolvedWorkspaceBaseRefError({
requestedRef: "main", recoveryIdentityRef: "origin/main", attemptedRefs: ["origin/main"], defaultBranch: "master",
});
await f.completion.failRunSetup(f.setup(error));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "configuration_incomplete", resultJson: {
configurationIncomplete: { reason: "workspace_base_ref_unresolved", requestedRef: "main", defaultBranch: "master", attemptedRefs: ["origin/main"], fingerprint: "workspace_base_ref:origin/main" },
executionRecovery: { kind: "bootstrap", providerWorkStarted: false },
} });
});
it("records a lease lost before dispatch as a retryable host stop, not an opaque setup failure", async () => {
const f = await fixture();
f.controller.abort(new LegacyControllerLeaseLostError("renewal_rejected"));
await f.completion.failRunSetup(f.setup(f.controller.signal.reason));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost", resultJson: {
cancellation: { source: "controller_lease", expected: false, reason: "Legacy controller lease lost (renewal_rejected)" },
executionRecovery: { kind: "bootstrap", providerWorkStarted: false } } });
expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce();
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "failed", expect.any(String), expect.objectContaining({ keepIdleOnFailure: true }));
});
it("attributes a lease loss even when a setup step throws its own abort error", async () => {
const f = await fixture();
f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline"));
await f.completion.failRunSetup(f.setup(new Error("environment acquisition aborted")));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost",
resultJson: { cancellation: { source: "controller_lease", reason: "Legacy controller lease lost (renewal_deadline)" } } });
});
it("does not make a lease loss retryable once provider work has started", async () => {
const f = await fixture();
f.controller.abort(new LegacyControllerLeaseLostError("renewal_error"));
await f.completion.failRunSetup(f.setup(new Error("usage capture write failed"), true));
expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "setup_failed",
resultJson: { cancellation: { source: "controller_lease", reason: "Legacy controller lease lost (renewal_error)" } } });
expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "failed", expect.any(String), expect.objectContaining({ keepIdleOnFailure: false }));
});
it("leaves a winning terminal outcome and agent state untouched after a late setup error", async () => {
const f = await fixture({ status: "succeeded", resultJson: { winner: "completion" } });
await f.completion.failRunSetup(f.setup(new Error("late setup error")));
expect(await read(f.run.id)).toMatchObject({ status: "succeeded", resultJson: { winner: "completion" } });
expect(f.deps.setWakeupStatus).not.toHaveBeenCalled();
expect(f.deps.releaseIssueExecutionAndPromote).not.toHaveBeenCalled();
expect(f.deps.finalizeAgentStatus).not.toHaveBeenCalled();
});
});