mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-08 12:33:05 +01:00
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - The execution-control watchdog fails a run when its control deadline passes and no owner finished it. > - The watchdog replaces the run's error code with `execution_finalization_deadline_exceeded`. > - The run-failure report reads the root cause from `resultJson.originalFailureCode`. The watchdog did not write that field. > - So every watchdog failure goes to Sentry with the same fingerprint, whatever its first failure was. > - This pull request keeps the earlier failure code as `originalFailureCode`, as the native finalizer already does. > - The benefit is that Sentry groups watchdog failures by their real first failure, so each cause can be found and fixed. ## Linked Issues or Issue Description **What happened?** One hosted Sentry group collects all `execution_finalization_deadline_exceeded` run failures. It has 17 events from many drivers (Codex app server, OpenCode server, ACPX runtime). In one recent event, the run first failed with `native_execution_ownership_unverified`. The watchdog then failed it at the deadline. The recovery action evidence kept `originalFailureCode: native_execution_ownership_unverified`, but the run row and the Sentry event did not. The event had no `root_error_code` tag, and its fingerprint was only `[execution_finalization_deadline_exceeded, paperclip_runner]`. **Expected behavior** When the watchdog replaces an earlier, more specific error code, the run keeps that code as `resultJson.originalFailureCode`. The run-failure report then sends `root_error_code` and adds it to the fingerprint (`server/src/sentry.ts`). **Steps to reproduce** 1. Create a running run with `errorCode: native_execution_ownership_unverified` and an expired `executionControlDeadlineAt`. 2. Run `reconcileAbandonedExecutionControl`. 3. The run fails with `execution_finalization_deadline_exceeded`, and the earlier code is lost. The captured event has no `diagnostics.execution.originalFailureCode`. **Paperclip version or commit** `master` at `89703c3ff7de`. Refs #14110, a similar fix for the finalization sweep. A search found no other open PR for this path. Draft #18672 changes legacy deferred wakes, which is a different path. ## What Changed - `execution-control-reconciliation.ts`: when the watchdog fails a run, it writes the earlier code (`coordinator.failureCode ?? run.errorCode`) to `resultJson.originalFailureCode`. This is the same value that it already writes to the recovery action evidence. - The watchdog keeps the other `resultJson` fields. - The watchdog does not replace a root cause that is already recorded. - The watchdog does not record the deadline code as its own root cause. - Two regression tests in `execution-control-reconciliation.test.ts`. ## Verification - The new test "keeps the run's prior failure code as the reported root cause" fails on unchanged `master`. The run's `resultJson` has no `originalFailureCode`. With the fix, the test passes. - `pnpm exec vitest run src/services/execution-control-reconciliation.test.ts src/__tests__/execution-control-work.test.ts src/__tests__/run-failure-sentry.test.ts src/__tests__/sentry.test.ts`: 111 passed, 5 skipped. - `pnpm exec vitest run src/services/task-retry.test.ts src/services/heartbeat/recovery.test.ts src/services/native-runtime/native-safe-replacement.test.ts src/services/workspace-recovery.test.ts`: 437 passed. These suites use this watchdog cause. - `node scripts/typecheck-layers.mjs` in `server/`: passed. - Not run locally: the full `pnpm -r typecheck` (the sandbox has no Rust toolchain for the runner crate), `pnpm test:run` and `pnpm build`. CI runs these. ## Risks - Low risk. The change adds one `resultJson` key only when the watchdog moves a run to `failed`, and only when a different earlier code exists. - Other readers of `resultJson.originalFailureCode` (`native-run-projection.ts`, `idle-sleep-safety.ts`) only check committed or succeeded runs. A watchdog failure is neither, so their results do not change. - `isPendingNativeRetry` reads only `nativePhase`, so reporting is not suppressed. - Sentry groups will split by root cause after deployment. New events will go to new groups, and the existing group will get fewer events. This is the intended change. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), with tool use and code execution in a Paperclip agent sandbox. ## 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>
351 lines
16 KiB
TypeScript
351 lines
16 KiB
TypeScript
import { notifyNativeEnvironmentSettlement } from "./native-environment-settlement-notifications.js";
|
|
import { notifyExternalAgentSettlement } from "../modules/external-agents/index.js";
|
|
import { notifyNativeStatusReassessment } from "./native-status-reassessment-notifications.js";
|
|
import { notifyNativeFinalizationWork } from "./native-finalization-notifications.js";
|
|
import { notifyUnsafeWorkspaceExportRunChange } from "./unsafe-workspace-export-notifications.js";
|
|
import { notifyCancelledWorkspacePreservation } from "./cancelled-workspace-preservation-notifications.js";
|
|
import { notifyInstructionCollection } from "./instruction-collection-notifications.js";
|
|
import { notifyExecutionRunWork } from "./execution-control-notifications.js";
|
|
import { randomUUID } from "node:crypto";
|
|
import { logger } from "../middleware/logger.js";
|
|
import { and, asc, eq, isNotNull, lte, sql } from "drizzle-orm";
|
|
import {
|
|
agents,
|
|
heartbeatRuns,
|
|
issues,
|
|
nativeRunFinalizations,
|
|
type Db,
|
|
} from "@paperclipai/db";
|
|
import { parseIssueExecutionState } from "./issue-execution-policy.js";
|
|
import { issueRecoveryActionService } from "./issue-recovery-actions.js";
|
|
import { hasLiveLegacyController } from "./legacy-controller-lease.js";
|
|
import { reportRunFailure } from "./run-failure-report.js";
|
|
import { getNativeReviewAssignment, readNativeReviewAssignmentContext } from "./native-runtime/native-review-participant.js";
|
|
import { preserveNativeFailedWorkspace } from "./native-runtime/native-failed-workspace-recovery.js";
|
|
import { EXECUTION_RECONCILIATION_INTERVAL_MS } from "./execution-control-deadline.js";
|
|
import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js";
|
|
import { NATIVE_STARTUP_CLEANUP_PENDING, readNativeStartupContext, promoteNativeStartupCleanup } from "./native-runtime/native-startup-cleanup.js";
|
|
|
|
/** Only newly recorded control deadlines are eligible. Upgrades never replay ambiguous historical runs. */
|
|
export async function reconcileAbandonedExecutionControl(
|
|
db: Db,
|
|
now = new Date(),
|
|
options: { startupCleanup?: (scope: { companyId: string; runId: string }) => Promise<unknown> } = {},
|
|
) {
|
|
const nativeDue = await db
|
|
.select({
|
|
runId: nativeRunFinalizations.runId,
|
|
issueId: nativeRunFinalizations.issueId,
|
|
companyId: nativeRunFinalizations.companyId,
|
|
failureCode: nativeRunFinalizations.failureCode,
|
|
leaseOwner: nativeRunFinalizations.leaseOwner,
|
|
controllerGeneration: nativeRunFinalizations.controllerGeneration,
|
|
attempt: nativeRunFinalizations.attempt,
|
|
})
|
|
.from(nativeRunFinalizations)
|
|
.where(
|
|
and(
|
|
isNotNull(nativeRunFinalizations.controlDeadlineAt),
|
|
lte(nativeRunFinalizations.controlDeadlineAt, now),
|
|
),
|
|
)
|
|
.orderBy(asc(nativeRunFinalizations.controlDeadlineAt), asc(nativeRunFinalizations.runId))
|
|
.limit(50);
|
|
const controlDue = await db
|
|
.select({
|
|
runId: heartbeatRuns.id,
|
|
companyId: heartbeatRuns.companyId,
|
|
context: heartbeatRuns.contextSnapshot,
|
|
nativeIssueId: nativeRunFinalizations.issueId,
|
|
failureCode: nativeRunFinalizations.failureCode,
|
|
leaseOwner: nativeRunFinalizations.leaseOwner,
|
|
controllerGeneration: nativeRunFinalizations.controllerGeneration,
|
|
attempt: nativeRunFinalizations.attempt,
|
|
})
|
|
.from(heartbeatRuns)
|
|
.leftJoin(nativeRunFinalizations, eq(nativeRunFinalizations.runId, heartbeatRuns.id))
|
|
.where(
|
|
and(
|
|
isNotNull(heartbeatRuns.executionControlDeadlineAt),
|
|
lte(heartbeatRuns.executionControlDeadlineAt, now),
|
|
),
|
|
)
|
|
.orderBy(asc(heartbeatRuns.executionControlDeadlineAt), asc(heartbeatRuns.id))
|
|
.limit(50);
|
|
const due = [
|
|
...new Map(
|
|
[
|
|
...nativeDue,
|
|
...controlDue.map((row) => ({
|
|
...row,
|
|
issueId: row.nativeIssueId ?? (
|
|
typeof row.context?.issueId === "string"
|
|
? row.context.issueId
|
|
: null),
|
|
})),
|
|
].map((row) => [row.runId, row]),
|
|
).values(),
|
|
];
|
|
let surfaced = 0;
|
|
// Bound contention latency across independent tasks: a locked task must not
|
|
// consume the entire reconciliation window for every task behind it.
|
|
let nextCandidate = 0;
|
|
await Promise.all(Array.from({ length: Math.min(5, due.length) }, async () => {
|
|
while (nextCandidate < due.length) {
|
|
const candidate = due[nextCandidate++]!;
|
|
try {
|
|
if (candidate.failureCode === NATIVE_STARTUP_CLEANUP_PENDING) {
|
|
if (!options.startupCleanup) continue;
|
|
try {
|
|
await options.startupCleanup({ companyId: candidate.companyId, runId: candidate.runId });
|
|
} finally {
|
|
await db.transaction(async tx => {
|
|
if (candidate.issueId) await tx.select({ id: issues.id }).from(issues).where(eq(issues.id, candidate.issueId)).for("update");
|
|
const [owner] = await tx.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, candidate.runId)).for("update");
|
|
if (owner?.failureCode !== NATIVE_STARTUP_CLEANUP_PENDING || !owner.controlDeadlineAt || owner.controlDeadlineAt > now ||
|
|
owner.leaseOwner !== candidate.leaseOwner || owner.controllerGeneration !== candidate.controllerGeneration || owner.attempt !== candidate.attempt) return;
|
|
const cleanupRetryAt = new Date(Math.max(now.getTime(), Date.now()) + EXECUTION_RECONCILIATION_INTERVAL_MS);
|
|
await notifyDeliveryWork(tx, DELIVERY_QUEUES.executionFinalization);
|
|
await tx.update(nativeRunFinalizations).set({ controlDeadlineAt: cleanupRetryAt }).where(eq(nativeRunFinalizations.runId, candidate.runId));
|
|
await tx.update(heartbeatRuns).set({ executionControlDeadlineAt: cleanupRetryAt }).where(and(eq(heartbeatRuns.id, candidate.runId),
|
|
isNotNull(heartbeatRuns.executionControlDeadlineAt), lte(heartbeatRuns.executionControlDeadlineAt, now)));
|
|
});
|
|
}
|
|
continue;
|
|
}
|
|
// Set inside the transaction only when the write below genuinely
|
|
// transitions the run into "failed". Read after the transaction
|
|
// commits, so a rolled-back write never reports a false failure.
|
|
let terminalRunToReport: typeof heartbeatRuns.$inferSelect | null = null;
|
|
const repaired = await db.transaction(async (tx) => {
|
|
await tx.execute(
|
|
sql`select set_config('statement_timeout', '15000', true), set_config('lock_timeout', '1000', true)`,
|
|
);
|
|
const task = candidate.issueId
|
|
? (
|
|
await tx
|
|
.select()
|
|
.from(issues)
|
|
.where(
|
|
and(
|
|
eq(issues.id, candidate.issueId),
|
|
eq(issues.companyId, candidate.companyId),
|
|
),
|
|
)
|
|
.for("update")
|
|
)[0]
|
|
: null;
|
|
const [coordinator] = await tx
|
|
.select()
|
|
.from(nativeRunFinalizations)
|
|
.where(
|
|
and(
|
|
eq(nativeRunFinalizations.runId, candidate.runId),
|
|
eq(nativeRunFinalizations.companyId, candidate.companyId),
|
|
),
|
|
)
|
|
.for("update");
|
|
const [run] = await tx
|
|
.select()
|
|
.from(heartbeatRuns)
|
|
.where(
|
|
and(
|
|
eq(heartbeatRuns.id, candidate.runId),
|
|
eq(heartbeatRuns.companyId, candidate.companyId),
|
|
),
|
|
)
|
|
.for("update");
|
|
if (
|
|
!run ||
|
|
![
|
|
coordinator?.controlDeadlineAt,
|
|
run.executionControlDeadlineAt,
|
|
].some((deadline) => deadline && deadline <= now)
|
|
)
|
|
return false;
|
|
if (coordinator?.failureCode === NATIVE_STARTUP_CLEANUP_PENDING) return false;
|
|
const startupContext = coordinator && readNativeStartupContext(run, coordinator);
|
|
if (startupContext) {
|
|
if (!await promoteNativeStartupCleanup(tx as unknown as Db, run, coordinator!, now)) {
|
|
const retryAt = new Date(Math.max(now.getTime() + EXECUTION_RECONCILIATION_INTERVAL_MS,
|
|
startupContext.deadlineAtMs, coordinator!.leaseExpiresAt?.getTime() ?? 0));
|
|
await notifyDeliveryWork(tx, DELIVERY_QUEUES.executionFinalization);
|
|
await tx.update(nativeRunFinalizations).set({ controlDeadlineAt: retryAt }).where(eq(nativeRunFinalizations.runId, run.id));
|
|
await tx.update(heartbeatRuns).set({ executionControlDeadlineAt: retryAt }).where(eq(heartbeatRuns.id, run.id));
|
|
}
|
|
return false;
|
|
}
|
|
await tx
|
|
.update(heartbeatRuns)
|
|
.set({ executionControlDeadlineAt: null })
|
|
.where(eq(heartbeatRuns.id, run.id));
|
|
if (
|
|
[
|
|
"succeeded",
|
|
"failed",
|
|
"cancelled",
|
|
"timed_out",
|
|
"interrupted",
|
|
].includes(run.status)
|
|
) {
|
|
if (coordinator?.controlDeadlineAt)
|
|
await tx
|
|
.update(nativeRunFinalizations)
|
|
.set({ controlDeadlineAt: null })
|
|
.where(eq(nativeRunFinalizations.runId, run.id));
|
|
return true;
|
|
}
|
|
// A persisted result belongs to the existing finalizer, not a replacement provider.
|
|
if (coordinator?.resultId) {
|
|
await notifyNativeFinalizationWork(tx, { companyId: run.companyId, runId: run.id });
|
|
await tx
|
|
.update(nativeRunFinalizations)
|
|
.set({
|
|
controlDeadlineAt: null,
|
|
leaseOwner: null,
|
|
leaseExpiresAt: null,
|
|
updatedAt: now,
|
|
})
|
|
.where(eq(nativeRunFinalizations.runId, run.id));
|
|
return true;
|
|
}
|
|
if (await hasLiveLegacyController(tx as unknown as Db, run)) {
|
|
await tx
|
|
.update(heartbeatRuns)
|
|
.set({ executionControlDeadlineAt: run.controllerLeaseExpiresAt })
|
|
.where(eq(heartbeatRuns.id, run.id));
|
|
return false;
|
|
}
|
|
const cause = "execution_finalization_deadline_exceeded";
|
|
const nextAction =
|
|
"Inspect the failed run and verify its provider has stopped. Reconcile any uncertain external action before explicitly continuing this task.";
|
|
// The deadline replaces the run's error code. Keep the earlier
|
|
// diagnosis as its root cause, as the native finalizer does.
|
|
const priorFailureCode = coordinator?.failureCode ?? run.errorCode;
|
|
const recordsOriginalFailure = Boolean(priorFailureCode) && priorFailureCode !== cause &&
|
|
typeof run.resultJson?.originalFailureCode !== "string";
|
|
if (coordinator)
|
|
await tx
|
|
.update(nativeRunFinalizations)
|
|
.set({
|
|
phase: "terminal_failure",
|
|
controlDeadlineAt: null,
|
|
leaseOwner: null,
|
|
leaseExpiresAt: null,
|
|
recoveryState: "blocked",
|
|
nextAttemptAt: null,
|
|
failureCode: cause,
|
|
failureDetail: {
|
|
...coordinator.failureDetail,
|
|
nextAction,
|
|
recoveryOwner: { kind: "board" },
|
|
},
|
|
updatedAt: now,
|
|
})
|
|
.where(eq(nativeRunFinalizations.runId, run.id));
|
|
await notifyInstructionCollection(tx, { companyId: run.companyId, runId: run.id });
|
|
await notifyExternalAgentSettlement(tx, { companyId: run.companyId, runId: run.id });
|
|
await notifyNativeEnvironmentSettlement(tx, { companyId: run.companyId, runId: run.id });
|
|
await notifyCancelledWorkspacePreservation(tx, { companyId: run.companyId, runId: run.id });
|
|
await notifyUnsafeWorkspaceExportRunChange(tx, run);
|
|
await notifyExecutionRunWork(tx, { companyId: run.companyId });
|
|
const [updatedRun] = await tx
|
|
.update(heartbeatRuns)
|
|
.set({
|
|
status: "failed",
|
|
executionStatusDeliveryId: randomUUID(),
|
|
finishedAt: now,
|
|
...(coordinator
|
|
? { nativePhase: "terminal_failure", nativePhaseUpdatedAt: now }
|
|
: {}),
|
|
errorCode: cause,
|
|
error: nextAction,
|
|
nextAction,
|
|
...(recordsOriginalFailure
|
|
? { resultJson: { ...run.resultJson, originalFailureCode: priorFailureCode } }
|
|
: {}),
|
|
updatedAt: now,
|
|
})
|
|
.where(eq(heartbeatRuns.id, run.id))
|
|
.returning();
|
|
if (updatedRun && updatedRun.status !== run.status) {
|
|
terminalRunToReport = updatedRun;
|
|
}
|
|
await tx
|
|
.update(agents)
|
|
.set({ status: "idle", updatedAt: now })
|
|
.where(
|
|
and(
|
|
eq(agents.id, run.agentId),
|
|
eq(agents.companyId, run.companyId),
|
|
eq(agents.status, "running"),
|
|
eq(agents.lifecycleState, "ready"),
|
|
sql`not exists (select 1 from ${heartbeatRuns} where ${heartbeatRuns.agentId} = ${run.agentId} and ${heartbeatRuns.status} = 'running')`,
|
|
),
|
|
);
|
|
const nativeReviewContext = readNativeReviewAssignmentContext(run.contextSnapshot);
|
|
const nativeReviewAssignment = nativeReviewContext && task
|
|
? await getNativeReviewAssignment(tx as unknown as Db, {
|
|
companyId: run.companyId,
|
|
issueId: task.id,
|
|
agentId: run.agentId,
|
|
contextSnapshot: nativeReviewContext,
|
|
})
|
|
: null;
|
|
const review = task?.status === "in_review" ? parseIssueExecutionState(task.executionState) : null;
|
|
const isCurrentReviewer = (review?.status === "pending" &&
|
|
review.currentParticipant?.type === "agent" && review.currentParticipant.agentId === run.agentId)
|
|
|| nativeReviewAssignment?.interaction.status === "pending";
|
|
if (
|
|
!task ||
|
|
(task.assigneeAgentId !== run.agentId && !isCurrentReviewer) ||
|
|
["done", "cancelled"].includes(task.status) ||
|
|
(task.executionRunId && task.executionRunId !== run.id) ||
|
|
(task.checkoutRunId && task.checkoutRunId !== run.id)
|
|
) {
|
|
if (updatedRun) await preserveNativeFailedWorkspace(tx as unknown as Db, updatedRun);
|
|
return true;
|
|
}
|
|
await notifyNativeStatusReassessment(tx, { companyId: task.companyId, issueId: task.id });
|
|
await tx
|
|
.update(issues)
|
|
.set({ executionRunId: null, checkoutRunId: null, updatedAt: now })
|
|
.where(eq(issues.id, task.id));
|
|
await issueRecoveryActionService(
|
|
tx as unknown as Db,
|
|
).upsertSourceScoped({
|
|
companyId: run.companyId,
|
|
sourceIssueId: task.id,
|
|
kind: "active_run_watchdog",
|
|
ownerType: "board",
|
|
ownerAgentId: null,
|
|
returnOwnerAgentId: task.assigneeAgentId,
|
|
cause,
|
|
fingerprint: `execution-control:${run.id}`,
|
|
evidence: {
|
|
runId: run.id,
|
|
...(isCurrentReviewer ? { reviewParticipantAgentId: run.agentId } : {}),
|
|
originalFailureCode: coordinator?.failureCode ?? run.errorCode,
|
|
providerOwnership: "unverified",
|
|
},
|
|
nextAction,
|
|
wakePolicy: null,
|
|
maxAttempts: 3,
|
|
supersedeOnIdentityChange: true,
|
|
});
|
|
if (updatedRun) await preserveNativeFailedWorkspace(tx as unknown as Db, updatedRun);
|
|
return true;
|
|
});
|
|
if (repaired) surfaced += 1;
|
|
if (terminalRunToReport) void reportRunFailure(db, terminalRunToReport);
|
|
} catch {
|
|
logger.warn(
|
|
{ runId: candidate.runId },
|
|
"Execution finalization reconciliation remains pending; continuing with other runs",
|
|
);
|
|
}
|
|
}
|
|
}));
|
|
return { scanned: due.length, surfaced };
|
|
}
|