From 30b927635411d1c92b61fb1f21be181a7ac8a4f3 Mon Sep 17 00:00:00 2001 From: Dotta Date: Fri, 30 Oct 2026 19:32:47 -0500 Subject: [PATCH 1/3] Checkpoint scoped live recovery owners and durable cohorts Co-Authored-By: Paperclip --- .../adapters/deadline-work.ts | 62 ++++++ .../active-run-watchdog/adapters/postgres.ts | 9 +- .../active-run-watchdog/application/ports.ts | 1 + .../active-run-watchdog/application/types.ts | 2 +- .../application/use-cases.ts | 12 +- .../src/modules/active-run-watchdog/index.ts | 13 +- server/src/services/activity-log.ts | 3 + .../services/delivery-work-notifications.ts | 8 + .../execution-control-notifications.ts | 7 +- server/src/services/heartbeat.ts | 4 + server/src/services/heartbeat/agent-status.ts | 4 +- .../services/heartbeat/live-recovery-work.ts | 119 +++++++++++ server/src/services/heartbeat/recovery.ts | 186 +++++++++++------- server/src/services/heartbeat/run-output.ts | 9 +- server/src/services/instance-settings.ts | 2 + server/src/services/issues.ts | 7 +- .../legacy-shutdown-workspace-settlement.ts | 4 +- .../live-run-recovery-notifications.ts | 25 +++ .../native-finalization-notifications.ts | 2 + .../src/services/native-local-process-stop.ts | 7 +- server/src/services/recovery/service.ts | 7 +- 21 files changed, 402 insertions(+), 91 deletions(-) create mode 100644 server/src/modules/active-run-watchdog/adapters/deadline-work.ts create mode 100644 server/src/services/heartbeat/live-recovery-work.ts create mode 100644 server/src/services/live-run-recovery-notifications.ts diff --git a/server/src/modules/active-run-watchdog/adapters/deadline-work.ts b/server/src/modules/active-run-watchdog/adapters/deadline-work.ts new file mode 100644 index 00000000000..5c264d25396 --- /dev/null +++ b/server/src/modules/active-run-watchdog/adapters/deadline-work.ts @@ -0,0 +1,62 @@ +import { and, asc, eq, gt, sql } from "drizzle-orm"; +import { heartbeatRuns, type Db } from "@paperclipai/db"; +import type { createDeliveryWorkCoordinator } from "../../../services/delivery-work-coordinator.js"; +import { DELIVERY_QUEUES } from "../../../services/delivery-work-notifications.js"; +import type { LiveRunRecoveryScope } from "../../../services/live-run-recovery-notifications.js"; +import { registerScopedDeadlineWork } from "../../../services/scoped-deadline-work.js"; +import type { ScanSilentActiveRunsOptions } from "../application/use-cases.js"; +import type { WatchdogRunReader } from "../application/ports.js"; + +type Entry = { id: string; companyId: string; issueId: string | null; dueAt: number }; + +export function registerActiveRunSilenceWork(db: Db, + coordinator: ReturnType, + owner: { reader: WatchdogRunReader; scan(input: ScanSilentActiveRunsOptions): Promise; + suspicionThresholdMs: number; enabled(): Promise }, + canRun: () => boolean, +) { + const cursors = new Map(); + let enabled = false; + return registerScopedDeadlineWork(coordinator, { + queue: DELIVERY_QUEUES.activeRunSilence, + reconstructionIntervalMs: 30_000, + beforePass: async () => { enabled = await owner.enabled(); }, + decodeScope: hint => hint === "*" ? undefined : JSON.parse(hint), + matches: (entry, scope) => !scope || entry.companyId === scope.companyId && (!scope.runId || entry.id === scope.runId) && (!scope.issueId || entry.issueId === scope.issueId), + load: async scope => { + const key = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, issueId: scope.issueId }) : "*"; + if (!enabled) { cursors.delete(key); return []; } + const cursor = cursors.get(key); + const issueId = sql`coalesce(${heartbeatRuns.contextSnapshot}->>'issueId', ${heartbeatRuns.contextSnapshot}->>'taskId')`; + const rows = await db.select({ issueId, id: heartbeatRuns.id, companyId: heartbeatRuns.companyId, + lastActivity: sql`coalesce(${heartbeatRuns.lastOutputAt}, ${heartbeatRuns.processStartedAt}, + ${heartbeatRuns.startedAt}, ${heartbeatRuns.createdAt})`.mapWith(heartbeatRuns.createdAt), + }).from(heartbeatRuns).where(and(eq(heartbeatRuns.status, "running"), + scope ? eq(heartbeatRuns.companyId, scope.companyId) : undefined, + scope?.runId ? eq(heartbeatRuns.id, scope.runId) : undefined, + scope?.issueId ? eq(issueId, scope.issueId) : undefined, + cursor ? gt(heartbeatRuns.id, cursor) : undefined, + )).orderBy(asc(heartbeatRuns.id)).limit(100); + const complete = rows.length < 100; + if (complete) cursors.delete(key); else cursors.set(key, rows.at(-1)!.id); + return { complete, rows: rows.map(row => ({ id: row.id, companyId: row.companyId, issueId: row.issueId, + dueAt: row.lastActivity.getTime() + owner.suspicionThresholdMs })) }; + }, + check: async entry => { + if (!enabled) return null; + const run = await owner.reader.findRunForCompany(entry.companyId, entry.id); + if (!run || run.status !== "running") return null; + const started = run.lastOutputAt ?? run.processStartedAt ?? run.startedAt ?? run.createdAt; + if (!started) return null; + const due = started.getTime() + owner.suspicionThresholdMs; + if (due > Date.now()) return { ...entry, dueAt: due }; + const decision = await owner.reader.findLatestDecision(entry.companyId, entry.id, new Date()); + if (decision.quietUntilDecision) return { ...entry, dueAt: decision.quietUntilDecision.snoozedUntil.getTime() }; + let next: number | null = null; + await owner.scan({ companyId: entry.companyId, runId: entry.id, onDeferredDeadline: at => { + next = next === null ? at : Math.min(next, at); + } }); + return next === null ? null : { ...entry, dueAt: next }; + }, + }, canRun); +} diff --git a/server/src/modules/active-run-watchdog/adapters/postgres.ts b/server/src/modules/active-run-watchdog/adapters/postgres.ts index 9531c449260..2fdc6f68f3c 100644 --- a/server/src/modules/active-run-watchdog/adapters/postgres.ts +++ b/server/src/modules/active-run-watchdog/adapters/postgres.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "../../../services/live-run-recovery-notifications.js"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "../../../services/delivery-work-notifications.js"; import { notifyExternalAgentSettlement } from "../../external-agents/index.js"; import { notifyNativeStatusReassessment } from "../../../services/native-status-reassessment-notifications.js"; @@ -100,6 +101,7 @@ export function createPostgresWatchdogAdapter(db: Db): WatchdogRunReader & Watch async function findCandidateSilentRuns(input: { companyId?: string; + runId?: string; suspicionBefore: Date; issueCreatedAtGte?: Date | null; }): Promise { @@ -109,6 +111,7 @@ export function createPostgresWatchdogAdapter(db: Db): WatchdogRunReader & Watch .where( and( input.companyId ? eq(heartbeatRuns.companyId, input.companyId) : undefined, + input.runId ? eq(heartbeatRuns.id, input.runId) : undefined, eq(heartbeatRuns.status, "running"), sql`coalesce(${heartbeatRuns.lastOutputAt}, ${heartbeatRuns.processStartedAt}, ${heartbeatRuns.startedAt}, ${heartbeatRuns.createdAt}) <= ${input.suspicionBefore.toISOString()}::timestamptz`, ), @@ -282,8 +285,9 @@ export function createPostgresWatchdogAdapter(db: Db): WatchdogRunReader & Watch } async function recordDecision(companyId: string, input: RecordDecisionInput): Promise { - const [row] = await db - .insert(heartbeatRunWatchdogDecisions) + const [row] = await db.transaction(async tx => { + await notifyActiveRunSilence(tx, { companyId, runId: input.runId }); + return tx.insert(heartbeatRunWatchdogDecisions) .values({ companyId, runId: input.runId, @@ -296,6 +300,7 @@ export function createPostgresWatchdogAdapter(db: Db): WatchdogRunReader & Watch createdByRunId: input.createdByRunId, }) .returning(); + }); await logActivity(db, { companyId, diff --git a/server/src/modules/active-run-watchdog/application/ports.ts b/server/src/modules/active-run-watchdog/application/ports.ts index 594f0285a1c..d574d196c02 100644 --- a/server/src/modules/active-run-watchdog/application/ports.ts +++ b/server/src/modules/active-run-watchdog/application/ports.ts @@ -13,6 +13,7 @@ import type { export type FindCandidateSilentRunsInput = { companyId?: string; + runId?: string; suspicionBefore: Date; issueCreatedAtGte?: Date | null; }; diff --git a/server/src/modules/active-run-watchdog/application/types.ts b/server/src/modules/active-run-watchdog/application/types.ts index 63fc3a8995e..b74eacb9b31 100644 --- a/server/src/modules/active-run-watchdog/application/types.ts +++ b/server/src/modules/active-run-watchdog/application/types.ts @@ -114,7 +114,7 @@ export type FoldSourceResolvedRunInput = { export type FoldOutcome = | { kind: "folded"; evaluationIssueId: string | null } - | { kind: "stale" }; + | { kind: "stale"; retryAt?: number }; export type WatchdogDecisionActor = | { type: "board"; userId?: string | null; runId?: string | null } diff --git a/server/src/modules/active-run-watchdog/application/use-cases.ts b/server/src/modules/active-run-watchdog/application/use-cases.ts index c8aa801ada3..9ea0bf24d88 100644 --- a/server/src/modules/active-run-watchdog/application/use-cases.ts +++ b/server/src/modules/active-run-watchdog/application/use-cases.ts @@ -100,7 +100,7 @@ export function createFoldSourceResolvedRun(deps: FoldSourceResolvedRunDeps) { fallbackProcessGroupId: input.run.processGroupId, }); - return deps.writer.foldSourceResolvedRun(input.run.companyId, { + const outcome = await deps.writer.foldSourceResolvedRun(input.run.companyId, { run: input.run, sourceIssue: input.sourceIssue, evidence: input.evidence, @@ -110,6 +110,8 @@ export function createFoldSourceResolvedRun(deps: FoldSourceResolvedRunDeps) { cleanup, now: input.now, }); + return outcome.kind === "stale" && cleanup.attempted && cleanup.outcome === "termination_sent_still_running" + ? { ...outcome, retryAt: input.now.getTime() + 30_000 } : outcome; }; } @@ -227,12 +229,14 @@ export type ScanSilentActiveRunsDeps = { export type ScanSilentActiveRunsOptions = { now?: Date; + runId?: string; + onDeferredDeadline?: (at: number) => void; companyId?: string; issueCreatedAtGte?: Date | null; }; type InspectOutcome = - | { kind: "skipped" } + | { kind: "skipped"; retryAt?: number } | { kind: "existing"; evaluationIssueId: string } | { kind: "folded"; evaluationIssueId: string | null }; @@ -283,7 +287,7 @@ export function createScanSilentActiveRuns(deps: ScanSilentActiveRunsDeps) { }); return foldOutcome.kind === "folded" ? { kind: "folded", evaluationIssueId: foldOutcome.evaluationIssueId } - : { kind: "skipped" }; + : { kind: "skipped", ...(foldOutcome.retryAt === undefined ? {} : { retryAt: foldOutcome.retryAt }) }; } } @@ -305,6 +309,7 @@ export function createScanSilentActiveRuns(deps: ScanSilentActiveRunsDeps) { const suspicionBefore = new Date(now.getTime() - deps.suspicionThresholdMs); const candidates = await deps.reader.findCandidateSilentRuns({ companyId: opts?.companyId, + runId: opts?.runId, suspicionBefore, issueCreatedAtGte: opts?.issueCreatedAtGte, }); @@ -331,6 +336,7 @@ export function createScanSilentActiveRuns(deps: ScanSilentActiveRunsDeps) { now, dismissedFalsePositive: decisionState.dismissedFalsePositive, }); + if (outcome.kind === "skipped" && outcome.retryAt !== undefined) opts?.onDeferredDeadline?.(outcome.retryAt); if (outcome.kind === "existing") result.existing += 1; else if (outcome.kind === "folded") result.folded += 1; else result.skipped += 1; diff --git a/server/src/modules/active-run-watchdog/index.ts b/server/src/modules/active-run-watchdog/index.ts index 907420badf9..92a1c9fe779 100644 --- a/server/src/modules/active-run-watchdog/index.ts +++ b/server/src/modules/active-run-watchdog/index.ts @@ -1,3 +1,4 @@ +import { registerActiveRunSilenceWork } from "./adapters/deadline-work.js"; import type { Db } from "@paperclipai/db"; import { createPostgresWatchdogAdapter } from "./adapters/postgres.js"; import { createProcessAdapter } from "./adapters/process.js"; @@ -29,17 +30,19 @@ export function createActiveRunWatchdog(db: Db, config: ActiveRunWatchdogConfig) processController, }); + const scanSilentActiveRuns = createScanSilentActiveRuns({ reader: postgresAdapter, foldSourceResolvedRun, + suspicionThresholdMs: config.suspicionThresholdMs }); + return { + registerSilenceWork: (coordinator: Parameters[1], canRun: () => boolean, + scan = scanSilentActiveRuns, enabled = async () => true) => registerActiveRunSilenceWork(db, coordinator, { reader: postgresAdapter, + scan, enabled, suspicionThresholdMs: config.suspicionThresholdMs }, canRun), buildRunOutputSilence: createBuildRunOutputSilence({ reader: postgresAdapter, suspicionThresholdMs: config.suspicionThresholdMs, criticalThresholdMs: config.criticalThresholdMs, }), - scanSilentActiveRuns: createScanSilentActiveRuns({ - reader: postgresAdapter, - foldSourceResolvedRun, - suspicionThresholdMs: config.suspicionThresholdMs, - }), + scanSilentActiveRuns, recordWatchdogDecision: createRecordWatchdogDecision({ reader: postgresAdapter, writer: postgresAdapter, diff --git a/server/src/services/activity-log.ts b/server/src/services/activity-log.ts index 5b10dac43b5..4e3aab320b0 100644 --- a/server/src/services/activity-log.ts +++ b/server/src/services/activity-log.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js"; import { beginRunPhase } from "./execution-preparation-timing.js"; import type { ActivityPublication } from "../types/activity-publication.js"; @@ -181,6 +182,8 @@ export async function persistActivity(db: Db, input: LogActivityInput) { const [activity] = input.entityType === "issue" ? await db.transaction(async tx => { await notifyDeliveryWork(tx, DELIVERY_QUEUES.mcpEvents, `task:${input.entityId}`); + if (input.runId && input.action === "issue.updated" && ["done", "cancelled"].includes(String(input.details?.status))) + await notifyActiveRunSilence(tx, { companyId: input.companyId, runId: input.runId }); return insert(tx as unknown as Db); }) : await insert(db); diff --git a/server/src/services/delivery-work-notifications.ts b/server/src/services/delivery-work-notifications.ts index 79f0f5d1d3d..8ca650525ad 100644 --- a/server/src/services/delivery-work-notifications.ts +++ b/server/src/services/delivery-work-notifications.ts @@ -2,6 +2,14 @@ import { signalDatabaseWork, subscribeDatabaseWork } from "@paperclipai/db"; /** Topics for existing durable queues; register intent before their writes. */ export const DELIVERY_QUEUES = { + nativeProcessSessions: "native-process-sessions", + nativeQuestionCancellations: "native-question-cancellations", + activeExecutionRecovery: "active-execution-recovery", + settledNativeProcesses: "settled-native-processes", + orphanActiveLeases: "orphan-active-leases", + legacyShutdownSettlement: "legacy-shutdown-settlement", + strandedAgentStatus: "stranded-agent-status", + activeRunSilence: "active-run-silence", deferredExecutionReceipts: "deferred-execution-receipts", taskRetryReceiptSettlement: "task-retry-receipt-settlement", nativeStatusWakeIntents: "native-status-wake-intents", diff --git a/server/src/services/execution-control-notifications.ts b/server/src/services/execution-control-notifications.ts index 7d9530f5197..615c6452327 100644 --- a/server/src/services/execution-control-notifications.ts +++ b/server/src/services/execution-control-notifications.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import type { Db } from "@paperclipai/db"; @@ -9,6 +10,7 @@ export async function notifyExecutionRunWork(transaction: object, scope?: Execut if (scope) { await notifyRunDispatch(transaction, scope); await notifyDeferredExecutionEligibility(transaction, scope); + await notifyActiveRunSilence(transaction, scope); } for (const queue of [DELIVERY_QUEUES.executionStatus, DELIVERY_QUEUES.executionFinalization, DELIVERY_QUEUES.executionReplacement, DELIVERY_QUEUES.executionDisposition, DELIVERY_QUEUES.issueMonitors]) { @@ -24,7 +26,10 @@ export function writeExecutionControl( ): Promise { return db.transaction(async transaction => { await notifyRunDispatch(transaction, scope); - if (scope) await notifyDeferredExecutionEligibility(transaction, scope); + if (scope) { + await notifyDeferredExecutionEligibility(transaction, scope); + await notifyActiveRunSilence(transaction, scope); + } await notifyDeliveryWork(transaction, DELIVERY_QUEUES.issueMonitors); for (const topic of typeof queue === "string" ? [queue] : queue) await notifyDeliveryWork(transaction, topic); return write(transaction as unknown as Db); diff --git a/server/src/services/heartbeat.ts b/server/src/services/heartbeat.ts index 63b836a566f..57328de4f7a 100644 --- a/server/src/services/heartbeat.ts +++ b/server/src/services/heartbeat.ts @@ -4245,6 +4245,10 @@ export function heartbeatService( computeTaskDrain, applyTaskDrain, + registerActiveRunSilenceWork: (coordinator: Parameters[0], canRun: () => boolean) => + recovery.registerActiveRunSilenceWork(coordinator, () => canRun() && readTaskDrain(new Date()) === null, + async scope => recovery.scanSilentActiveRuns({ ...scope, issueCreatedAtGte: await getWorktreeExecutionCutoff() }), + async () => !(await getSchedulingSuppression(true)).suppressed), registerDeferredReceiptWork: (coordinator: Parameters[1], canRun: () => boolean) => registerDeferredReceiptWork(db, coordinator, { resume: scope => heartbeatQueue.resumeDeferredExecutionReceipts(scope), diff --git a/server/src/services/heartbeat/agent-status.ts b/server/src/services/heartbeat/agent-status.ts index f034cd06594..2957471926a 100644 --- a/server/src/services/heartbeat/agent-status.ts +++ b/server/src/services/heartbeat/agent-status.ts @@ -109,13 +109,15 @@ export function createHeartbeatAgentStatus(db: Db) { publishStatus(result.updated, outcome); } - async function reconcileStrandedAgentStatuses(liveRunIds: () => ReadonlySet) { + async function reconcileStrandedAgentStatuses(liveRunIds: () => ReadonlySet, scope: { companyId?: string; agentId?: string } = {}) { const now = new Date(); const cutoff = new Date(now.getTime() - RECONCILIATION_GRACE_MS); const candidates = await db.transaction(async tx => { await tx.execute(sql`SET LOCAL statement_timeout = '2s'`); return tx.select({ id: agents.id, companyId: agents.companyId }).from(agents) .where(and(eq(agents.status, "running"), eq(agents.lifecycleState, "ready"), + scope.companyId ? eq(agents.companyId, scope.companyId) : undefined, + scope.agentId ? eq(agents.id, scope.agentId) : undefined, lte(agents.updatedAt, cutoff), settledAgentWorkCondition(liveRunIds(), now))) .orderBy(asc(agents.updatedAt), asc(agents.id)).limit(RECONCILIATION_BATCH_SIZE); }); diff --git a/server/src/services/heartbeat/live-recovery-work.ts b/server/src/services/heartbeat/live-recovery-work.ts new file mode 100644 index 00000000000..eb3e41204b1 --- /dev/null +++ b/server/src/services/heartbeat/live-recovery-work.ts @@ -0,0 +1,119 @@ +import { and, asc, eq, gt, inArray, isNotNull, isNull, or, sql } from "drizzle-orm"; +import { agents, environmentLeases, heartbeatRuns, nativeRunFinalizations, type Db } from "@paperclipai/db"; +import type { createDeliveryWorkCoordinator } from "../delivery-work-coordinator.js"; +import { DELIVERY_QUEUES, type DeliveryQueue } from "../delivery-work-notifications.js"; +import type { LiveResourceRecoveryScope, LiveRunRecoveryScope } from "../live-run-recovery-notifications.js"; +import { registerScopedDeadlineWork } from "../scoped-deadline-work.js"; + +const TERMINAL = ["succeeded", "failed", "cancelled", "timed_out", "interrupted"]; +type Scope = LiveRunRecoveryScope & LiveResourceRecoveryScope; +type Entry = { id: string; companyId: string; runId?: string | null; dueAt: number }; +type CheckScope = { companyId: string; runId?: string; leaseId?: string; agentId?: string; + onDeferredDeadline(at: number): void; onError(error: unknown): void }; +type RunKind = "native" | "question" | "active" | "settled"; + +export function registerLiveRecoveryWork(db: Db, coordinator: ReturnType, owner: { + native(scope: CheckScope): Promise; + question(scope: CheckScope): Promise; + active(scope: CheckScope): Promise; + settled(scope: CheckScope): Promise; + orphanLease(scope: CheckScope): Promise; + shutdown(scope: CheckScope): Promise; + agent(scope: CheckScope): Promise; + enabled(): Promise; +}, canRun: () => boolean) { + function register(queue: DeliveryQueue, kind: RunKind | "orphanLease" | "shutdown" | "agent") { + const cursors = new Map(); + let enabled = false; + return registerScopedDeadlineWork(coordinator, { + queue, + reconstructionIntervalMs: 30_000, + beforePass: async () => { enabled = await owner.enabled(); }, + decodeScope: hint => hint === "*" ? undefined : JSON.parse(hint), + matches: (entry, scope) => !scope || entry.companyId === scope.companyId && ( + kind === "agent" ? !scope.agentId || entry.id === scope.agentId + : kind === "orphanLease" || kind === "shutdown" ? (!scope.leaseId || entry.id === scope.leaseId) && (!scope.runId || entry.runId === scope.runId) + : !scope.runId || entry.id === scope.runId), + load: async scope => { + const key = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, + leaseId: scope.leaseId, agentId: scope.agentId }) : "*"; + if (!enabled) { cursors.delete(key); return []; } + const cursor = cursors.get(key); + let rows: Entry[]; + if (kind === "agent") { + const candidates = await db.select({ id: agents.id, companyId: agents.companyId, updatedAt: agents.updatedAt }) + .from(agents).where(and(eq(agents.status, "running"), eq(agents.lifecycleState, "ready"), + scope ? eq(agents.companyId, scope.companyId) : undefined, + scope?.agentId ? eq(agents.id, scope.agentId) : undefined, + cursor ? gt(agents.id, cursor) : undefined, + )).orderBy(asc(agents.id)).limit(100); + rows = candidates.map(row => ({ id: row.id, companyId: row.companyId, dueAt: row.updatedAt.getTime() + 5 * 60_000 })); + } else if (kind === "orphanLease" || kind === "shutdown") { + const candidates = await db.select({ id: environmentLeases.id, companyId: environmentLeases.companyId, + runId: environmentLeases.heartbeatRunId, updatedAt: environmentLeases.updatedAt, metadata: environmentLeases.metadata }).from(environmentLeases) + .leftJoin(heartbeatRuns, and(eq(heartbeatRuns.id, environmentLeases.heartbeatRunId), + eq(heartbeatRuns.companyId, environmentLeases.companyId))) + .where(and(scope ? eq(environmentLeases.companyId, scope.companyId) : undefined, + scope?.leaseId ? eq(environmentLeases.id, scope.leaseId) : undefined, + scope?.runId ? eq(environmentLeases.heartbeatRunId, scope.runId) : undefined, + cursor ? gt(environmentLeases.id, cursor) : undefined, + kind === "orphanLease" ? and(eq(environmentLeases.status, "active"), + or(isNull(environmentLeases.heartbeatRunId), inArray(heartbeatRuns.status, TERMINAL))) + : sql`${environmentLeases.metadata}#>>'{legacyShutdownWorkspaceSettlement,schema}' = 'paperclip.legacy-shutdown-workspace-settlement.v1' + and ${environmentLeases.metadata}#>>'{legacyShutdownWorkspaceSettlement,state}' = 'pending'`, + )).orderBy(asc(environmentLeases.id)).limit(100); + rows = candidates.map(row => ({ id: row.id, companyId: row.companyId, runId: row.runId, + dueAt: kind === "orphanLease" ? row.updatedAt.getTime() + 5 * 60_000 + : Date.parse(String((row.metadata?.legacyShutdownWorkspaceSettlement as Record)?.deadlineAt)) || Date.now(), + })); + } else { + const candidates = await db.select({ id: heartbeatRuns.id, companyId: heartbeatRuns.companyId, + nextAttemptAt: nativeRunFinalizations.nextAttemptAt, leaseExpiresAt: nativeRunFinalizations.leaseExpiresAt }) + .from(heartbeatRuns).leftJoin(nativeRunFinalizations, and(eq(nativeRunFinalizations.runId, heartbeatRuns.id), + eq(nativeRunFinalizations.companyId, heartbeatRuns.companyId))) + .where(and(scope ? eq(heartbeatRuns.companyId, scope.companyId) : undefined, + scope?.runId ? eq(heartbeatRuns.id, scope.runId) : undefined, + cursor ? gt(heartbeatRuns.id, cursor) : undefined, + kind === "native" ? and(eq(heartbeatRuns.runtimeMode, "native"), inArray(heartbeatRuns.status, ["running", "failed"]), + eq(nativeRunFinalizations.phase, "retryable_failure"), isNull(nativeRunFinalizations.resultId)) + : kind === "question" ? and(inArray(heartbeatRuns.status, ["queued", "running", "scheduled_retry"]), + sql`${heartbeatRuns.contextSnapshot}->'nativeQuestionCancellation' is not null`) + : kind === "active" ? eq(heartbeatRuns.status, "running") + : and(eq(heartbeatRuns.runtimeMode, "native"), inArray(heartbeatRuns.status, ["failed", "cancelled", "timed_out", "interrupted"]), + isNotNull(heartbeatRuns.finishedAt), or(isNotNull(heartbeatRuns.processPid), + isNotNull(heartbeatRuns.processGroupId), isNotNull(heartbeatRuns.processStartedAt))), + )).orderBy(asc(heartbeatRuns.id)).limit(100); + rows = candidates.map(row => ({ id: row.id, companyId: row.companyId, dueAt: kind === "native" + ? Math.max(Date.now(), row.nextAttemptAt?.getTime() ?? 0, row.leaseExpiresAt?.getTime() ?? 0) : Date.now() })); + } + const complete = rows.length < 100; + if (complete) cursors.delete(key); else cursors.set(key, rows.at(-1)!.id); + return { complete, rows }; + }, + check: async entry => { + if (!enabled) return null; + let next: number | null = null; + const errors: unknown[] = []; + const scope: CheckScope = { companyId: entry.companyId, + ...(kind === "agent" ? { agentId: entry.id } : kind === "orphanLease" || kind === "shutdown" + ? { leaseId: entry.id } : { runId: entry.id }), + onDeferredDeadline: at => { next = next === null ? at : Math.min(next, at); }, + onError: error => { errors.push(error); }, + }; + await owner[kind](scope); + if (errors.length) throw new AggregateError(errors, `Recovery obligation ${entry.id} failed`); + return next === null ? null : { ...entry, dueAt: next }; + }, + }, canRun); + } + const workers = [register(DELIVERY_QUEUES.nativeProcessSessions, "native"), + register(DELIVERY_QUEUES.nativeQuestionCancellations, "question"), + register(DELIVERY_QUEUES.activeExecutionRecovery, "active"), + register(DELIVERY_QUEUES.settledNativeProcesses, "settled"), + register(DELIVERY_QUEUES.orphanActiveLeases, "orphanLease"), + register(DELIVERY_QUEUES.legacyShutdownSettlement, "shutdown"), + register(DELIVERY_QUEUES.strandedAgentStatus, "agent")]; + return { ready: Promise.all(workers.map(worker => worker.ready)), + wake() { for (const worker of workers) worker.invalidate(); }, + async stop() { await Promise.all(workers.map(worker => worker.stop())); } }; +} diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index e506f0f7e62..141d0f17755 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -22,7 +22,7 @@ import { discoverSettledNativeRunProcesses, recordNativeLocalProcessStop, retryP import { pendingCaseHandoffForRun } from "./case-handoff-lifecycle.js"; import { legacyControllerBootId, - hasLiveLegacyController, + liveLegacyControllerExpiresAt, revokeExpiredLegacyControllerWithState, } from "../legacy-controller-lease.js"; import { remoteTerminationReceipt } from "../remote-execution-termination.js"; @@ -1493,6 +1493,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD // data already on the lease row. async function sweepOrphanedActiveLeases(opts: { backoffMs: number; + companyId?: string; + leaseId?: string; }): Promise<{ recovered: number }> { const cutoff = new Date(Date.now() - opts.backoffMs); @@ -1506,6 +1508,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD .where( and( eq(environmentLeases.status, "active"), + opts.companyId ? eq(environmentLeases.companyId, opts.companyId) : undefined, + opts.leaseId ? eq(environmentLeases.id, opts.leaseId) : undefined, or( isNull(environmentLeases.heartbeatRunId), inArray(heartbeatRuns.status, [ @@ -1977,59 +1981,15 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD void cleanup.finally(() => activeRunExecutionPromises.delete(cleanup)); } - let settledProcessesDiscovered = false; + type RecoveryScope = { + companyId?: string; + runId?: string; + onDeferredDeadline?: (at: number) => void; + onError?: (error: unknown) => void; + }; - async function reapOrphanedRuns(opts?: { staleThresholdMs?: number; skipNativeStatusWakeIntents?: boolean; skipScheduledRetryCancellation?: boolean; skipCapturedInstructionCommit?: boolean; skipInstructionDirectoryCleanup?: boolean; skipStoppedInstructionCollection?: boolean; skipCancelledWorkspacePreservation?: boolean; skipObsoletePolicyReviews?: boolean; skipAutomaticCompletionReviews?: boolean; skipUnsafeWorkspaceExports?: boolean; skipNativePendingEffects?: boolean; skipNativeResponsePresentation?: boolean; skipNativeReviewResponse?: boolean; skipNativeStatusReassessment?: boolean; skipRetainedNativeSessionCleanup?: boolean; skipNativeWorkspaceFinalization?: boolean; skipNativeResultCommit?: boolean; skipNativeRunProjection?: boolean; skipNativeRecoveryNotices?: boolean; skipExternalConversationSettlement?: boolean; skipExternalAgentSettlement?: boolean; skipNativeEnvironmentSettlement?: boolean }) { - if (!opts?.skipCancelledWorkspacePreservation) await preserveCancelledNativeWorkspaces(db); - const staleThresholdMs = opts?.staleThresholdMs ?? 0; + async function resumeRetryableNativeProcessSessions(scope: RecoveryScope = {}, beforeDispatch?: () => Promise) { const now = new Date(); - if (!opts?.skipScheduledRetryCancellation) await scheduledRetryCancellation.sweep(); - // Recovery never launches a provider or infers stopped ownership from - // terminal status. Uncaptured local copies require durable stop evidence. - if (!opts?.skipStoppedInstructionCollection) await instructionCopies.recoverStopped().catch(error => { - logger.warn({ err: error }, "failed to recover stopped instruction copies"); - }); - await instructionCopies.recoverCaptured({ skipCommit: opts?.skipCapturedInstructionCommit, skipDirectoryCleanup: opts?.skipInstructionDirectoryCleanup }).catch(error => { - logger.warn({ err: error }, "failed to retry captured instruction revisions"); - }); - - // Complete persisted native results before generic orphan recovery. The - // reconciler reads the durable workspace barrier and persisted runtime - // mode, never the current feature flag. - await reconcileNativeFinalizations(db, undefined, { - skipObsoletePolicyReviews: opts?.skipObsoletePolicyReviews, - skipAutomaticCompletionReviews: opts?.skipAutomaticCompletionReviews, - skipUnsafeWorkspaceExports: opts?.skipUnsafeWorkspaceExports, - skipNativePendingEffects: opts?.skipNativePendingEffects, - skipNativeResponsePresentation: opts?.skipNativeResponsePresentation, - skipNativeReviewResponse: opts?.skipNativeReviewResponse, - skipNativeStatusReassessment: opts?.skipNativeStatusReassessment, - skipNativeWorkspaceFinalization: opts?.skipNativeWorkspaceFinalization, - skipNativeResultCommit: opts?.skipNativeResultCommit, - skipNativeRunProjection: opts?.skipNativeRunProjection, - skipExternalConversationSettlement: opts?.skipExternalConversationSettlement, - skipExternalAgentSettlement: opts?.skipExternalAgentSettlement, - skipNativeRecoveryNotices: opts?.skipNativeRecoveryNotices, - environmentRuntime, - pluginWorkerManager: dependencies.pluginWorkerManager, - onWorkspaceSettled: input => settleRecoveredNativeWorkspace(input, { - skipEnvironmentSettlement: opts?.skipNativeEnvironmentSettlement, - }), - }).catch((error) => { - logger.warn( - { err: error }, - "failed to reconcile persisted native finalizations before orphan reaping", - ); - }); - if (!opts?.skipRetainedNativeSessionCleanup) scheduleRetainedNativeSessionCleanup(); - await reconcileRetainedWorkspaces(db, environmentRuntime, resumeRemoteStopComments); - if (!opts?.skipNativeStatusWakeIntents) await dispatchPendingNativeStatusWakeups().catch((error) => { - logger.warn( - { err: error }, - "failed to dispatch persisted native status wake intents before orphan reaping", - ); - }); - // A retryable native run can retain process identifiers from the failed // attempt. Inspect them before the recovery claim: a live identifier is // unowned and blocks recovery, while identifiers that are all dead can be @@ -2044,6 +2004,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD ) .where( and( + scope.companyId ? eq(heartbeatRuns.companyId, scope.companyId) : undefined, + scope.runId ? eq(heartbeatRuns.id, scope.runId) : undefined, inArray(heartbeatRuns.status, ["running", "failed"]), eq(heartbeatRuns.runtimeMode, "native"), eq(nativeRunFinalizations.phase, "retryable_failure"), @@ -2067,6 +2029,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD processPidAlive, processGroupAlive, }); + scope.onDeferredDeadline?.(Date.now() + 30_000); continue; } const cleared = await db.transaction(async tx => { @@ -2101,17 +2064,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD if (cleared) claimableNativeRunIds.add(cleared.id); } - const executingRun = (runId: string) => activeRunExecutions.has(runId) || runningProcesses.has(runId); - if (!settledProcessesDiscovered) { - settledProcessesDiscovered = await discoverSettledNativeRunProcesses(db, { skip: executingRun }).then(() => true, (error) => { - logger.warn({ err: error }, "failed to discover settled native process identities"); - return false; - }); - } else { - await retryPendingSettledNativeRunProcesses(db, { skip: executingRun }).catch((error) => { - logger.warn({ err: error }, "failed to retry settled native process identity release"); - }); - } + await beforeDispatch?.(); // An explicit result-less retryable failure resumes on the original run. // The database lease is claimed before dispatch so concurrent service @@ -2141,6 +2094,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD ); }, }).catch((error) => { + scope.onError?.(error); logger.warn( { err: error }, "failed to claim persisted native session resumptions", @@ -2151,6 +2105,10 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD nativeResumeClaims.map((claim) => claim.runId), ); + return resumedRunIds; + } + + async function recoverQuestionCancellationRequests(scope: RecoveryScope = {}) { // A terminal issue transition writes this intent in the same transaction // that closes the question's task, even when its card is retained. Consume // it before generic orphan recovery so a restart preserves cancellation. @@ -2162,6 +2120,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD .from(heartbeatRuns) .where( and( + scope.companyId ? eq(heartbeatRuns.companyId, scope.companyId) : undefined, + scope.runId ? eq(heartbeatRuns.id, scope.runId) : undefined, inArray(heartbeatRuns.status, [ ...CANCELLABLE_HEARTBEAT_RUN_STATUSES, ]), @@ -2200,6 +2160,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD }, }); } catch (err) { + scope.onError?.(err); // Keep the marker intact for the next startup/periodic sweep. logger.warn( { err, runId: request.id }, @@ -2208,6 +2169,14 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD } } + } + + async function recoverActiveExecutions(scope: RecoveryScope = {}, options: { + staleThresholdMs?: number; resumedRunIds?: Set; + } = {}) { + const now = new Date(); + const staleThresholdMs = options.staleThresholdMs ?? 5 * 60_000; + const resumedRunIds = options.resumedRunIds ?? new Set(); // Find all runs stuck in "running" state (queued runs are legitimately waiting; resumeQueuedRuns handles them) const activeRuns = await db .select({ @@ -2229,7 +2198,9 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD nativeRunFinalizations, eq(nativeRunFinalizations.runId, heartbeatRuns.id), ) - .where(eq(heartbeatRuns.status, "running")); + .where(and(eq(heartbeatRuns.status, "running"), + scope.companyId ? eq(heartbeatRuns.companyId, scope.companyId) : undefined, + scope.runId ? eq(heartbeatRuns.id, scope.runId) : undefined)); // Reuse the orphan sweep's active-run inventory. Only an expired, untracked // controller creates recovery work; idle sweeps add no checkpoint query. @@ -2362,12 +2333,16 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD } if (resumedRunIds.has(run.id)) continue; if (locallyTracked) continue; - if (await hasLiveLegacyController(db, run)) continue; + const legacyLease = await liveLegacyControllerExpiresAt(db, run); + if (legacyLease) { scope.onDeferredDeadline?.(legacyLease.getTime()); continue; } // Apply staleness threshold to avoid false positives if (staleThresholdMs > 0) { const refTime = run.updatedAt ? new Date(run.updatedAt).getTime() : 0; - if (now.getTime() - refTime < staleThresholdMs) continue; + if (now.getTime() - refTime < staleThresholdMs) { + scope.onDeferredDeadline?.(refTime + staleThresholdMs); + continue; + } } const currentAdapterTracksLocalChild = @@ -2392,6 +2367,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD (processPidAlive || processGroupAlive) && readHotRestartAdoptionMetadata(parseObject(run.resultJson)) ) { + scope.onDeferredDeadline?.(Date.now() + 30_000); continue; } if (processPidAlive || processGroupAlive) { @@ -2417,6 +2393,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD }); } } + scope.onDeferredDeadline?.(Date.now() + 30_000); continue; } @@ -2566,6 +2543,80 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD ); } + return reaped; + } + + let settledProcessesDiscovered = false; + + async function reapOrphanedRuns(opts?: { staleThresholdMs?: number; skipNativeStatusWakeIntents?: boolean; skipScheduledRetryCancellation?: boolean; skipCapturedInstructionCommit?: boolean; skipInstructionDirectoryCleanup?: boolean; skipStoppedInstructionCollection?: boolean; skipCancelledWorkspacePreservation?: boolean; skipObsoletePolicyReviews?: boolean; skipAutomaticCompletionReviews?: boolean; skipUnsafeWorkspaceExports?: boolean; skipNativePendingEffects?: boolean; skipNativeResponsePresentation?: boolean; skipNativeReviewResponse?: boolean; skipNativeStatusReassessment?: boolean; skipRetainedNativeSessionCleanup?: boolean; skipNativeWorkspaceFinalization?: boolean; skipNativeResultCommit?: boolean; skipNativeRunProjection?: boolean; skipNativeRecoveryNotices?: boolean; skipExternalConversationSettlement?: boolean; skipExternalAgentSettlement?: boolean; skipNativeEnvironmentSettlement?: boolean }) { + if (!opts?.skipCancelledWorkspacePreservation) await preserveCancelledNativeWorkspaces(db); + const staleThresholdMs = opts?.staleThresholdMs ?? 0; + const now = new Date(); + if (!opts?.skipScheduledRetryCancellation) await scheduledRetryCancellation.sweep(); + // Recovery never launches a provider or infers stopped ownership from + // terminal status. Uncaptured local copies require durable stop evidence. + if (!opts?.skipStoppedInstructionCollection) await instructionCopies.recoverStopped().catch(error => { + logger.warn({ err: error }, "failed to recover stopped instruction copies"); + }); + await instructionCopies.recoverCaptured({ skipCommit: opts?.skipCapturedInstructionCommit, skipDirectoryCleanup: opts?.skipInstructionDirectoryCleanup }).catch(error => { + logger.warn({ err: error }, "failed to retry captured instruction revisions"); + }); + + // Complete persisted native results before generic orphan recovery. The + // reconciler reads the durable workspace barrier and persisted runtime + // mode, never the current feature flag. + await reconcileNativeFinalizations(db, undefined, { + skipObsoletePolicyReviews: opts?.skipObsoletePolicyReviews, + skipAutomaticCompletionReviews: opts?.skipAutomaticCompletionReviews, + skipUnsafeWorkspaceExports: opts?.skipUnsafeWorkspaceExports, + skipNativePendingEffects: opts?.skipNativePendingEffects, + skipNativeResponsePresentation: opts?.skipNativeResponsePresentation, + skipNativeReviewResponse: opts?.skipNativeReviewResponse, + skipNativeStatusReassessment: opts?.skipNativeStatusReassessment, + skipNativeWorkspaceFinalization: opts?.skipNativeWorkspaceFinalization, + skipNativeResultCommit: opts?.skipNativeResultCommit, + skipNativeRunProjection: opts?.skipNativeRunProjection, + skipExternalConversationSettlement: opts?.skipExternalConversationSettlement, + skipExternalAgentSettlement: opts?.skipExternalAgentSettlement, + skipNativeRecoveryNotices: opts?.skipNativeRecoveryNotices, + environmentRuntime, + pluginWorkerManager: dependencies.pluginWorkerManager, + onWorkspaceSettled: input => settleRecoveredNativeWorkspace(input, { + skipEnvironmentSettlement: opts?.skipNativeEnvironmentSettlement, + }), + }).catch((error) => { + logger.warn( + { err: error }, + "failed to reconcile persisted native finalizations before orphan reaping", + ); + }); + if (!opts?.skipRetainedNativeSessionCleanup) scheduleRetainedNativeSessionCleanup(); + await reconcileRetainedWorkspaces(db, environmentRuntime, resumeRemoteStopComments); + if (!opts?.skipNativeStatusWakeIntents) await dispatchPendingNativeStatusWakeups().catch((error) => { + logger.warn( + { err: error }, + "failed to dispatch persisted native status wake intents before orphan reaping", + ); + }); + + const resumedRunIds = await resumeRetryableNativeProcessSessions({}, async () => { + const executingRun = (runId: string) => activeRunExecutions.has(runId) || runningProcesses.has(runId); + if (!settledProcessesDiscovered) { + settledProcessesDiscovered = await discoverSettledNativeRunProcesses(db, { skip: executingRun }).then(() => true, (error) => { + logger.warn({ err: error }, "failed to discover settled native process identities"); + return false; + }); + } else { + await retryPendingSettledNativeRunProcesses(db, { skip: executingRun }).catch((error) => { + logger.warn({ err: error }, "failed to retry settled native process identity release"); + }); + } + + }); + + await recoverQuestionCancellationRequests(); + const reaped = await recoverActiveExecutions({}, { staleThresholdMs, resumedRunIds }); + // Recover an active lease whose run already ended before the same-tick // pending_cleanup sweep, so this tick can stop the recovered sandbox. // Isolate the sweep so its failure never hides the reaper result. @@ -2634,6 +2685,9 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD reconcileHotRestartAdoption, recoverNativeRunsAfterRestart, reapOrphanedRuns, + resumeRetryableNativeProcessSessions, + recoverQuestionCancellationRequests, + recoverActiveExecutions, sweepOrphanedActiveLeases, drainRunningRunsForShutdown, }; diff --git a/server/src/services/heartbeat/run-output.ts b/server/src/services/heartbeat/run-output.ts index 71a606a53a4..24a607297bf 100644 --- a/server/src/services/heartbeat/run-output.ts +++ b/server/src/services/heartbeat/run-output.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "../live-run-recovery-notifications.js"; import { eq } from "drizzle-orm"; import { heartbeatRuns, type Db } from "@paperclipai/db"; import type { AdapterInvocationMeta, AdapterRuntimeEvent } from "../../adapters/index.js"; @@ -94,8 +95,9 @@ export function createHeartbeatRunOutput(db: Db, input: HeartbeatRunOutputInput) pendingOutputProgress.at.getTime() - lastOutputFlushAt.getTime() >= ACTIVE_RUN_OUTPUT_PROGRESS_FLUSH_INTERVAL_MS; if (!shouldFlush) return; - progressWrite = db - .update(heartbeatRuns) + progressWrite = db.transaction(async tx => { + await notifyActiveRunSilence(tx, { companyId: run.companyId, runId: run.id }); + await tx.update(heartbeatRuns) .set({ lastOutputAt: pendingOutputProgress.at, lastOutputSeq: pendingOutputProgress.seq, @@ -103,7 +105,8 @@ export function createHeartbeatRunOutput(db: Db, input: HeartbeatRunOutputInput) lastOutputBytes: pendingOutputProgress.bytes, updatedAt: new Date(), }) - .where(eq(heartbeatRuns.id, run.id)) + .where(eq(heartbeatRuns.id, run.id)); + }) .then(() => { lastOutputFlushAt = pendingOutputProgress.at; if (outputProgressState.pending === pendingOutputProgress) diff --git a/server/src/services/instance-settings.ts b/server/src/services/instance-settings.ts index 6c5f948d303..a3e2b2f3b14 100644 --- a/server/src/services/instance-settings.ts +++ b/server/src/services/instance-settings.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import { notifySkillVersionRetentionReconstruction } from "./skill-version-retention-notifications.js"; @@ -634,6 +635,7 @@ export function instanceSettingsService(db: Db, options: InstanceSettingsService if (patch.enableWorktreeRunExecution !== undefined) { await notifyRunDispatch(tx); await notifyDeferredExecutionEligibility(tx); + await notifyActiveRunSilence(tx); await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); await notifyExternalAgentSettlement(tx); await notifyInstructionCommit(tx); diff --git a/server/src/services/issues.ts b/server/src/services/issues.ts index fa47af138b9..8955ace27c8 100644 --- a/server/src/services/issues.ts +++ b/server/src/services/issues.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyIssueRecovery } from "./issue-recovery-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; @@ -11507,6 +11508,7 @@ export function issueService(db: Db) { || blockedByIssueIds !== undefined) { await notifyRunDispatch(tx, { companyId: receiptExisting.companyId }); await notifyDeferredExecutionEligibility(tx, { companyId: receiptExisting.companyId }); + await notifyActiveRunSilence(tx, { companyId: receiptExisting.companyId, issueId: id }); await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); } if (patch.monitorNextCheckAt !== undefined || (receiptExisting.monitorNextCheckAt && @@ -11972,7 +11974,10 @@ export function issueService(db: Db) { await notifyDecisionTargetIssueRemoval(tx, id); await notifyDeliveryWork(tx, DELIVERY_QUEUES.issueMonitors); await notifyRunDispatch(tx, owner ? { companyId: owner.companyId } : undefined); - if (owner) await notifyDeferredExecutionEligibility(tx, owner); + if (owner) { + await notifyDeferredExecutionEligibility(tx, owner); + await notifyActiveRunSilence(tx, { companyId: owner.companyId, issueId: id }); + } await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); removedIssue = await tx .delete(issues) diff --git a/server/src/services/legacy-shutdown-workspace-settlement.ts b/server/src/services/legacy-shutdown-workspace-settlement.ts index 54f9b1a1c00..8c85cd3f14b 100644 --- a/server/src/services/legacy-shutdown-workspace-settlement.ts +++ b/server/src/services/legacy-shutdown-workspace-settlement.ts @@ -73,8 +73,10 @@ export async function legacyShutdownWorkspaceResourceProtected(db: Db, } /** Released stop receipts still need reconciliation if export never settled. */ -export async function sweepLegacyShutdownWorkspaceSettlements(db: Db, now = new Date()) { +export async function sweepLegacyShutdownWorkspaceSettlements(db: Db, now = new Date(), scope: { companyId?: string; leaseId?: string } = {}) { const rows = await db.select().from(environmentLeases).where(and( + scope.companyId ? eq(environmentLeases.companyId, scope.companyId) : undefined, + scope.leaseId ? eq(environmentLeases.id, scope.leaseId) : undefined, sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'schema' = ${SCHEMA}`, sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'state' = 'pending'`, sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'deadlineAt' <= ${now.toISOString()}`, diff --git a/server/src/services/live-run-recovery-notifications.ts b/server/src/services/live-run-recovery-notifications.ts new file mode 100644 index 00000000000..10334f6776c --- /dev/null +++ b/server/src/services/live-run-recovery-notifications.ts @@ -0,0 +1,25 @@ +import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js"; + +export type LiveRunRecoveryScope = { companyId: string; runId?: string; issueId?: string; agentId?: string }; + +export async function notifyActiveRunSilence(tx: object, scope?: LiveRunRecoveryScope) { + await notifyDeliveryWork(tx, DELIVERY_QUEUES.activeRunSilence, scope + ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, issueId: scope.issueId }) : "*"); +} + +export async function notifyLiveRunRecovery(tx: object, scope?: LiveRunRecoveryScope) { + const hint = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, agentId: scope.agentId }) : "*"; + for (const queue of [DELIVERY_QUEUES.nativeProcessSessions, DELIVERY_QUEUES.nativeQuestionCancellations, + DELIVERY_QUEUES.activeExecutionRecovery, DELIVERY_QUEUES.settledNativeProcesses, DELIVERY_QUEUES.strandedAgentStatus]) + await notifyDeliveryWork(tx, queue, hint); + await notifyActiveRunSilence(tx, scope); +} + +export type LiveResourceRecoveryScope = { companyId: string; runId?: string; leaseId?: string }; + +export async function notifyLiveResourceRecovery(tx: object, scope?: LiveResourceRecoveryScope) { + const hint = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, leaseId: scope.leaseId }) : "*"; + for (const queue of [DELIVERY_QUEUES.orphanActiveLeases, DELIVERY_QUEUES.legacyShutdownSettlement, + DELIVERY_QUEUES.strandedAgentStatus, DELIVERY_QUEUES.settledNativeProcesses]) + await notifyDeliveryWork(tx, queue, hint); +} diff --git a/server/src/services/native-finalization-notifications.ts b/server/src/services/native-finalization-notifications.ts index 72d4cbcac49..a38aae46c0b 100644 --- a/server/src/services/native-finalization-notifications.ts +++ b/server/src/services/native-finalization-notifications.ts @@ -1,3 +1,4 @@ +import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; import { notifyNativeEnvironmentSettlement } from "./native-environment-settlement-notifications.js"; import { notifyExternalAgentSettlement } from "../modules/external-agents/index.js"; import { notifyExternalConversationSettlement } from "./external-conversation-settlement-notifications.js"; @@ -15,6 +16,7 @@ export type NativeFinalizationWorkScope = { companyId: string; runId?: string; i export async function notifyNativeFinalizationWork(transaction: object, scope: NativeFinalizationWorkScope) { if (scope.issueId || scope.runId) { + await notifyActiveRunSilence(transaction, scope); await notifyNativeEnvironmentSettlement(transaction, scope); await notifyExternalAgentSettlement(transaction, scope); await notifyExternalConversationSettlement(transaction, scope); diff --git a/server/src/services/native-local-process-stop.ts b/server/src/services/native-local-process-stop.ts index 0d31853d552..b26a29e7add 100644 --- a/server/src/services/native-local-process-stop.ts +++ b/server/src/services/native-local-process-stop.ts @@ -145,7 +145,7 @@ export async function readNativeLocalProcessStop(db: Db, companyId: string, runI type SettledProcessRelease = "released" | "pending" | "skipped"; -export async function releaseSettledNativeRunProcess(db: Db, runId: string): Promise { +export async function releaseSettledNativeRunProcess(db: Db, runId: string, options: { onDeferredDeadline?: (at: number) => void } = {}): Promise { return db.transaction(async transaction => { const tx = transaction as unknown as Db; const [run] = await tx.select({ id: heartbeatRuns.id, companyId: heartbeatRuns.companyId, agentId: heartbeatRuns.agentId, @@ -173,7 +173,10 @@ export async function releaseSettledNativeRunProcess(db: Db, runId: string): Pro )).orderBy(desc(heartbeatRunEvents.seq)).limit(1); if (identity?.payload?.targetKind !== "local" || identity.payload.hostname !== os.hostname() || identity.payload.processPid !== run.processPid || identity.payload.processGroupId !== run.processGroupId) return "skipped"; - if (!(await recordNativeLocalProcessStop(tx, run))) return "pending"; + if (!(await recordNativeLocalProcessStop(tx, run))) { + options.onDeferredDeadline?.(Date.now() + 30_000); + return "pending"; + } } await notifyRetainedNativeSessionCleanup(tx, { companyId: run.companyId, runId: run.id }); await tx.update(heartbeatRuns).set({ diff --git a/server/src/services/recovery/service.ts b/server/src/services/recovery/service.ts index 4b2ec5c0672..df9b7f84333 100644 --- a/server/src/services/recovery/service.ts +++ b/server/src/services/recovery/service.ts @@ -2384,11 +2384,7 @@ export function recoveryService( }); } - async function scanSilentActiveRuns(opts?: { - now?: Date; - companyId?: string; - issueCreatedAtGte?: Date | null; - }) { + async function scanSilentActiveRuns(opts?: Parameters[0]) { return watchdog.scanSilentActiveRuns(opts); } @@ -6568,6 +6564,7 @@ export function recoveryService( escalateStrandedAssignedIssue, recordWatchdogDecision, scanSilentActiveRuns, + registerActiveRunSilenceWork: watchdog.registerSilenceWork, reconcileStrandedAssignedIssues, reconcileUnassignedBlockingIssues, reconcileActiveRecoveryActions, From 63d33c07f8717aac42a677699f4af55c8895794c Mon Sep 17 00:00:00 2001 From: Dotta Date: Fri, 30 Oct 2026 20:04:46 -0500 Subject: [PATCH 2/3] Checkpoint residual recovery deadline rechecks and owning producers Co-Authored-By: Paperclip --- server/src/services/agent-configuration.ts | 2 ++ .../agent-instruction-working-copies.ts | 5 ++- server/src/services/agent-lifecycle.ts | 2 ++ .../environment-cleanup-notifications.ts | 13 +++++++ .../execution-control-notifications.ts | 6 ++-- server/src/services/heartbeat-run-events.ts | 6 +++- server/src/services/heartbeat.ts | 4 +++ server/src/services/heartbeat/agent-status.ts | 19 +++++++++- .../services/heartbeat/live-recovery-work.ts | 35 +++++++++++++------ server/src/services/heartbeat/recovery.ts | 34 ++++++++++++++++-- .../src/services/legacy-controller-lease.ts | 14 ++++++-- .../legacy-shutdown-workspace-settlement.ts | 13 +++++-- .../live-run-recovery-notifications.ts | 5 +++ .../native-finalization-notifications.ts | 4 +-- .../src/services/native-local-process-stop.ts | 2 ++ .../native-runtime/native-execution-lease.ts | 2 ++ .../native-finalization-reconciler.ts | 4 +++ .../native-runtime/native-question-bridge.ts | 2 ++ .../native-runtime/native-restart-recovery.ts | 3 ++ .../native-runner-checkpoint.ts | 2 ++ 20 files changed, 151 insertions(+), 26 deletions(-) diff --git a/server/src/services/agent-configuration.ts b/server/src/services/agent-configuration.ts index 2d30da27cb7..3b23d901eef 100644 --- a/server/src/services/agent-configuration.ts +++ b/server/src/services/agent-configuration.ts @@ -1,3 +1,4 @@ +import { notifyStrandedAgentStatus } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import { notifySkillVersionPinChange } from "./skill-version-retention-notifications.js"; @@ -85,6 +86,7 @@ export async function prepareAgentConfiguration(db: Db, existing: AgentConfigura existing.adapterConfig, ); } + await notifyStrandedAgentStatus(db, { companyId: existing.companyId, agentId: existing.id }); await notifyRunDispatch(db, { companyId: existing.companyId }); await notifyDeferredExecutionEligibility(db, { companyId: existing.companyId }); if (normalizedPatch.runtimeConfig !== undefined || normalizedPatch.reportsTo !== undefined) { diff --git a/server/src/services/agent-instruction-working-copies.ts b/server/src/services/agent-instruction-working-copies.ts index e0309bc8792..6cb0aebb3d4 100644 --- a/server/src/services/agent-instruction-working-copies.ts +++ b/server/src/services/agent-instruction-working-copies.ts @@ -1,3 +1,4 @@ +import { notifyStrandedAgentStatus } from "./live-run-recovery-notifications.js"; import { notifyInstructionCollection, type InstructionCollectionScope } from "./instruction-collection-notifications.js"; import { notifyDirectoryCleanup, type DirectoryCleanupScope } from "./directory-cleanup-notifications.js"; import { notifyInstructionCommit, type InstructionCommitScope } from "./instruction-commit-notifications.js"; @@ -101,6 +102,7 @@ export function agentInstructionWorkingCopyService(db: Db, options: { environmen const signalsCleanup = directoryCleanupEntry(row) !== null || directoryCleanupEntry({ ...row, ...values }) !== null; const signalsCommit = row.state === "pending_commit" || values.state === "pending_commit"; const write = async (tx: Db) => { + await notifyStrandedAgentStatus(tx, { companyId: row.companyId, agentId: row.agentId }); if (signalsCommit) await notifyInstructionCommit(tx, { companyId: row.companyId, runId: row.runId }); if (signalsCleanup) await notifyDirectoryCleanup(tx, { companyId: row.companyId, runId: row.runId }); @@ -112,7 +114,7 @@ export function agentInstructionWorkingCopyService(db: Db, options: { environmen )).returning(); return updated; }; - return signalsCommit || signalsCleanup || signalsCollection ? db.transaction(tx => write(tx as unknown as Db)) : write(db); + return db.transaction(tx => write(tx as unknown as Db)); } async function patch(row: Copy, values: Partial) { const updated = await tryPatch(row, values); @@ -204,6 +206,7 @@ export function agentInstructionWorkingCopyService(db: Db, options: { environmen if (!existing) { await db.transaction(async tx => { await notifyInstructionCollection(tx, { companyId: input.companyId, runId: input.runId }); + await notifyStrandedAgentStatus(tx, { companyId: input.companyId, agentId: input.agentId }); await tx.insert(copies).values({ runId: input.runId, companyId: input.companyId, agentId: input.agentId, responsibleUserId: bound.onBehalfOfUserId!, entryFile, diff --git a/server/src/services/agent-lifecycle.ts b/server/src/services/agent-lifecycle.ts index 8bb46882256..9302e2796c7 100644 --- a/server/src/services/agent-lifecycle.ts +++ b/server/src/services/agent-lifecycle.ts @@ -1,3 +1,4 @@ +import { notifyStrandedAgentStatus } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import { notifyNativeReviewResponse } from "./native-review-response-notifications.js"; @@ -41,6 +42,7 @@ export function createAgentLifecycleEffects(_hooks: BudgetServiceHooks = {}): li notifyWork: tx => notifyDeliveryWork(tx, DELIVERY_QUEUES.agentLifecycle), async beforeStatusChange(tx, companyId, agentId, before, after) { if (before !== after) { + await notifyStrandedAgentStatus(tx, { companyId, agentId }); await notifyRunDispatch(tx, { companyId }); await notifyDeferredExecutionEligibility(tx, { companyId }); await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); diff --git a/server/src/services/environment-cleanup-notifications.ts b/server/src/services/environment-cleanup-notifications.ts index 728f05b9303..bd26350e3ab 100644 --- a/server/src/services/environment-cleanup-notifications.ts +++ b/server/src/services/environment-cleanup-notifications.ts @@ -1,8 +1,21 @@ +import { and, eq, sql } from "drizzle-orm"; +import { environmentLeases } from "@paperclipai/db"; +import { notifyLiveResourceRecovery } from "./live-run-recovery-notifications.js"; import { notifyNativeEnvironmentSettlement, type NativeEnvironmentSettlementScope } from "./native-environment-settlement-notifications.js"; import type { Db } from "@paperclipai/db"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js"; export async function notifyEnvironmentCleanup(transaction: object, scope?: NativeEnvironmentSettlementScope): Promise { + await notifyLiveResourceRecovery(transaction, scope); + if (scope?.runId && typeof (transaction as Db).select === "function") { + const peers = await (transaction as Db).select({ id: environmentLeases.id, companyId: environmentLeases.companyId, + runId: environmentLeases.heartbeatRunId }).from(environmentLeases).where(and(eq(environmentLeases.status, "active"), + sql`exists (select 1 from environment_leases changed where changed.company_id = ${scope.companyId} + and changed.heartbeat_run_id = ${scope.runId} and changed.provider_lease_id is not null + and changed.provider = ${environmentLeases.provider} and changed.provider_lease_id = ${environmentLeases.providerLeaseId})`)); + for (const peer of peers) await notifyDeliveryWork(transaction, DELIVERY_QUEUES.orphanActiveLeases, + JSON.stringify({ companyId: peer.companyId, leaseId: peer.id })); + } await notifyNativeEnvironmentSettlement(transaction, scope); await notifyDeliveryWork(transaction, DELIVERY_QUEUES.environmentCleanup); await notifyDeliveryWork(transaction, DELIVERY_QUEUES.historicalCleanup); diff --git a/server/src/services/execution-control-notifications.ts b/server/src/services/execution-control-notifications.ts index 615c6452327..b79e0a7b24e 100644 --- a/server/src/services/execution-control-notifications.ts +++ b/server/src/services/execution-control-notifications.ts @@ -1,4 +1,4 @@ -import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; +import { notifyLiveRunRecovery } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import type { Db } from "@paperclipai/db"; @@ -10,7 +10,7 @@ export async function notifyExecutionRunWork(transaction: object, scope?: Execut if (scope) { await notifyRunDispatch(transaction, scope); await notifyDeferredExecutionEligibility(transaction, scope); - await notifyActiveRunSilence(transaction, scope); + await notifyLiveRunRecovery(transaction, scope); } for (const queue of [DELIVERY_QUEUES.executionStatus, DELIVERY_QUEUES.executionFinalization, DELIVERY_QUEUES.executionReplacement, DELIVERY_QUEUES.executionDisposition, DELIVERY_QUEUES.issueMonitors]) { @@ -28,7 +28,7 @@ export function writeExecutionControl( await notifyRunDispatch(transaction, scope); if (scope) { await notifyDeferredExecutionEligibility(transaction, scope); - await notifyActiveRunSilence(transaction, scope); + await notifyLiveRunRecovery(transaction, scope); } await notifyDeliveryWork(transaction, DELIVERY_QUEUES.issueMonitors); for (const topic of typeof queue === "string" ? [queue] : queue) await notifyDeliveryWork(transaction, topic); diff --git a/server/src/services/heartbeat-run-events.ts b/server/src/services/heartbeat-run-events.ts index ebce78a8266..a755062048e 100644 --- a/server/src/services/heartbeat-run-events.ts +++ b/server/src/services/heartbeat-run-events.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "./live-run-recovery-notifications.js"; import { readNativeEventEvidenceOutcome } from "./native-runtime/evidence-classifier.js"; import { notifyNativeStatusReassessment } from "./native-status-reassessment-notifications.js"; import { isNativeResponseEvidence, notifyNativeResponsePresentation } from "./native-response-presentation-notifications.js"; @@ -74,10 +75,11 @@ export async function appendHeartbeatRunEvent( db: Db, input: AppendHeartbeatRunEventInput, ): Promise { + const projectsRecovery = ["native.process_start_requested", "native.process_identity_recorded", "native.local_process_stopped"].includes(input.eventType); const projectsReassessment = readNativeEventEvidenceOutcome(input.payload?.prpEvent) !== null; const projectsProgress = isSafeNativeChatProgressEventType(input.eventType); const projectsResponse = isNativeResponseEvidence(input.eventType, input.payload?.prpEvent); - if (!input.nativeSource && !input.retryExhaustion && !projectsProgress && !projectsResponse && !projectsReassessment) { + if (!input.nativeSource && !input.retryExhaustion && !projectsProgress && !projectsResponse && !projectsReassessment && !projectsRecovery) { const allocated = db.$with("allocated_run_event", {}).as(sql` update ${heartbeatRuns} set next_event_seq = ${heartbeatRuns.nextEventSeq} + 1, @@ -117,6 +119,8 @@ export async function appendHeartbeatRunEvent( throw new Error("heartbeat_run_event_binding_mismatch"); } + if (projectsRecovery) await notifyLiveRunRecovery(tx, input); + if (input.retryExhaustion && !input.nativeSource) { // The run lock also serializes concurrent recovery checks across server // instances. Reusing the receipt must not allocate a sequence or publish diff --git a/server/src/services/heartbeat.ts b/server/src/services/heartbeat.ts index 57328de4f7a..f04c192efb3 100644 --- a/server/src/services/heartbeat.ts +++ b/server/src/services/heartbeat.ts @@ -1026,6 +1026,7 @@ export function heartbeatService( }); const { + registerResidualRecoveryWork: registerResidualRecoveryOwner, sweepPendingCleanupLeases, markNativeOwnershipUnverified, prepareHotRestartShutdown, @@ -4245,6 +4246,9 @@ export function heartbeatService( computeTaskDrain, applyTaskDrain, + registerResidualRecoveryWork: (coordinator: Parameters[0], canRun: () => boolean) => + registerResidualRecoveryOwner(coordinator, () => canRun() && readTaskDrain(new Date()) === null, + async () => !(await getSchedulingSuppression(true)).suppressed), registerActiveRunSilenceWork: (coordinator: Parameters[0], canRun: () => boolean) => recovery.registerActiveRunSilenceWork(coordinator, () => canRun() && readTaskDrain(new Date()) === null, async scope => recovery.scanSilentActiveRuns({ ...scope, issueCreatedAtGte: await getWorktreeExecutionCutoff() }), diff --git a/server/src/services/heartbeat/agent-status.ts b/server/src/services/heartbeat/agent-status.ts index 2957471926a..a53cdb5cd52 100644 --- a/server/src/services/heartbeat/agent-status.ts +++ b/server/src/services/heartbeat/agent-status.ts @@ -1,3 +1,4 @@ +import { notifyStrandedAgentStatus } from "../live-run-recovery-notifications.js"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "../delivery-work-notifications.js"; import { agents, heartbeatRuns, type Db } from "@paperclipai/db"; import { and, asc, desc, eq, lte, sql } from "drizzle-orm"; @@ -91,6 +92,7 @@ export function createHeartbeatAgentStatus(db: Db) { )).limit(1); const nextStatus = running ? "running" : settledStatus(outcome, options?.keepIdleOnFailure); const now = new Date(); + await notifyStrandedAgentStatus(tx, { companyId: existing.companyId, agentId }); await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); const [updated] = await tx.update(agents).set({ status: nextStatus, @@ -109,7 +111,7 @@ export function createHeartbeatAgentStatus(db: Db) { publishStatus(result.updated, outcome); } - async function reconcileStrandedAgentStatuses(liveRunIds: () => ReadonlySet, scope: { companyId?: string; agentId?: string } = {}) { + async function reconcileStrandedAgentStatuses(liveRunIds: () => ReadonlySet, scope: { companyId?: string; agentId?: string; onDeferredDeadline?: (at: number) => void } = {}) { const now = new Date(); const cutoff = new Date(now.getTime() - RECONCILIATION_GRACE_MS); const candidates = await db.transaction(async tx => { @@ -158,6 +160,21 @@ export function createHeartbeatAgentStatus(db: Db) { for (const publication of publications) publishActivity(publication); publishStatus(updated, "reconciled"); } + if (scope.companyId && scope.agentId && reconciled.length === 0 && scope.onDeferredDeadline) { + const rows = await db.execute(sql`select min(deadline) as deadline from ( + select r.controller_lease_expires_at as deadline from heartbeat_runs r + where r.company_id = ${scope.companyId} and r.agent_id = ${scope.agentId} + union all + select f.lease_expires_at as deadline from native_run_finalizations f + inner join heartbeat_runs r on r.id = f.run_id and r.company_id = f.company_id + where r.company_id = ${scope.companyId} and r.agent_id = ${scope.agentId} + ) authority where deadline > ${now.toISOString()}::timestamptz`); + const deadline = rows[0]?.deadline; + if (deadline) { + const at = deadline instanceof Date ? deadline.getTime() : Date.parse(String(deadline)); + if (Number.isFinite(at) && at > Date.now()) scope.onDeferredDeadline(at); + } + } return reconciled; } diff --git a/server/src/services/heartbeat/live-recovery-work.ts b/server/src/services/heartbeat/live-recovery-work.ts index eb3e41204b1..d2d9ab78a5b 100644 --- a/server/src/services/heartbeat/live-recovery-work.ts +++ b/server/src/services/heartbeat/live-recovery-work.ts @@ -25,16 +25,7 @@ export function registerLiveRecoveryWork(db: Db, coordinator: ReturnType(); let enabled = false; - return registerScopedDeadlineWork(coordinator, { - queue, - reconstructionIntervalMs: 30_000, - beforePass: async () => { enabled = await owner.enabled(); }, - decodeScope: hint => hint === "*" ? undefined : JSON.parse(hint), - matches: (entry, scope) => !scope || entry.companyId === scope.companyId && ( - kind === "agent" ? !scope.agentId || entry.id === scope.agentId - : kind === "orphanLease" || kind === "shutdown" ? (!scope.leaseId || entry.id === scope.leaseId) && (!scope.runId || entry.runId === scope.runId) - : !scope.runId || entry.id === scope.runId), - load: async scope => { + async function load(scope?: Scope) { const key = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, leaseId: scope.leaseId, agentId: scope.agentId }) : "*"; if (!enabled) { cursors.delete(key); return []; } @@ -89,9 +80,26 @@ export function registerLiveRecoveryWork(db: Db, coordinator: ReturnType(coordinator, { + queue, + reconstructionIntervalMs: 30_000, + beforePass: async () => { enabled = await owner.enabled(); }, + decodeScope: hint => hint === "*" ? undefined : JSON.parse(hint), + matches: (entry, scope) => !scope || entry.companyId === scope.companyId && ( + kind === "agent" ? !scope.agentId || entry.id === scope.agentId + : kind === "orphanLease" || kind === "shutdown" ? (!scope.leaseId || entry.id === scope.leaseId) && (!scope.runId || entry.runId === scope.runId) + : !scope.runId || entry.id === scope.runId), + load, check: async entry => { if (!enabled) return null; + const currentScope = { companyId: entry.companyId, + ...(kind === "agent" ? { agentId: entry.id } : kind === "orphanLease" || kind === "shutdown" + ? { leaseId: entry.id } : { runId: entry.id }) }; + const loaded = await load(currentScope); + const current = (Array.isArray(loaded) ? loaded : loaded.rows).find(row => row.id === entry.id); + if (!current) return null; + if (current.dueAt > Date.now()) return current; let next: number | null = null; const errors: unknown[] = []; const scope: CheckScope = { companyId: entry.companyId, @@ -102,6 +110,11 @@ export function registerLiveRecoveryWork(db: Db, coordinator: ReturnType row.id === entry.id); + if (remaining && remaining.dueAt > Date.now()) next = next === null ? remaining.dueAt : Math.min(next, remaining.dueAt); + } return next === null ? null : { ...entry, dueAt: next }; }, }, canRun); diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index 141d0f17755..75afd5d881c 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -1,3 +1,4 @@ +import { registerLiveRecoveryWork } from "./live-recovery-work.js"; import { nativeEnvironmentSettlementDisposition, nativeEnvironmentSettlementWork } from "../native-runtime/native-environment-settlement-work.js"; import { nativeWorkspaceFinalizationWork } from "../native-runtime/native-workspace-finalization-work.js"; import { attemptNativeWorkspaceFinalization } from "../native-runtime/native-workspace-finalizer.js"; @@ -18,7 +19,7 @@ import { hasStopOnlyCleanup, settleStopOnlyCleanup, } from "../sandbox-stop-and-retain.js"; -import { discoverSettledNativeRunProcesses, recordNativeLocalProcessStop, retryPendingSettledNativeRunProcesses } from "../native-local-process-stop.js"; +import { discoverSettledNativeRunProcesses, recordNativeLocalProcessStop, releaseSettledNativeRunProcess, retryPendingSettledNativeRunProcesses } from "../native-local-process-stop.js"; import { pendingCaseHandoffForRun } from "./case-handoff-lifecycle.js"; import { legacyControllerBootId, @@ -2010,6 +2011,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD eq(heartbeatRuns.runtimeMode, "native"), eq(nativeRunFinalizations.phase, "retryable_failure"), isNull(nativeRunFinalizations.resultId), + sql`${heartbeatRuns.contextSnapshot}->'nativeQuestionCancellation' is null`, ), ); const claimableNativeRunIds = new Set(); @@ -2260,6 +2262,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD nativeControllerLeaseExpiresAt, nativeWorkspaceFinalizationPending, } of activeRuns) { + if (parseObject(run.contextSnapshot).nativeQuestionCancellation) continue; // Native recovery owns these dispositions. Its writes happened after this // inventory was read; do not reap or overwrite them using the old row. if (remoteRecoveryRunIds.has(run.id)) continue; @@ -2329,10 +2332,16 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD processPidAlive: nativeProcessPidAlive, processGroupAlive: nativeProcessGroupAlive, }); + if (nativeControllerLeaseExpiresAt && nativeControllerLeaseExpiresAt > now) + scope.onDeferredDeadline?.(nativeControllerLeaseExpiresAt.getTime()); continue; } if (resumedRunIds.has(run.id)) continue; - if (locallyTracked) continue; + if (locallyTracked) { + if (!activeRunExecutions.has(run.id) && !runningProcesses.has(run.id) && nativeControllerLeaseExpiresAt) + scope.onDeferredDeadline?.(nativeControllerLeaseExpiresAt.getTime()); + continue; + } const legacyLease = await liveLegacyControllerExpiresAt(db, run); if (legacyLease) { scope.onDeferredDeadline?.(legacyLease.getTime()); continue; } @@ -2674,7 +2683,28 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD return { reaped: reaped.length, runIds: reaped }; } + function registerResidualRecoveryWork(coordinator: Parameters[1], + canRun: () => boolean, enabled: () => Promise) { + return registerLiveRecoveryWork(db, coordinator, { + native: scope => resumeRetryableNativeProcessSessions(scope), + question: recoverQuestionCancellationRequests, + active: scope => recoverActiveExecutions(scope), + settled: async scope => { + if (!scope.runId || activeRunExecutions.has(scope.runId) || runningProcesses.has(scope.runId) + || adapterExecutionControls.has(scope.runId)) return; + await releaseSettledNativeRunProcess(db, scope.runId, scope); + }, + orphanLease: scope => sweepOrphanedActiveLeases({ ...scope, backoffMs: 5 * 60_000 }), + shutdown: scope => sweepLegacyShutdownWorkspaceSettlements(db, new Date(), scope), + agent: scope => createHeartbeatAgentStatus(db).reconcileStrandedAgentStatuses(() => new Set([ + ...activeRunExecutions, ...runningProcesses.keys(), ...adapterExecutionControls.keys(), + ]), scope), + enabled, + }, canRun); + } + return { + registerResidualRecoveryWork, registerRetainedNativeSessionCleanupWork: retainedNativeCleanup.register, registerNativeWorkspaceFinalizationWork: nativeWorkspaceFinalization.register, registerNativeEnvironmentSettlementWork: nativeEnvironmentSettlement.register, diff --git a/server/src/services/legacy-controller-lease.ts b/server/src/services/legacy-controller-lease.ts index 22fa078f459..95ebc8db584 100644 --- a/server/src/services/legacy-controller-lease.ts +++ b/server/src/services/legacy-controller-lease.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "./live-run-recovery-notifications.js"; import { randomUUID } from "node:crypto"; import { and, eq, gt, lte, sql } from "drizzle-orm"; import { heartbeatRuns, livenessDb, type Db } from "@paperclipai/db"; @@ -40,7 +41,9 @@ export async function renewLegacyControllerLease( run: Pick, stage?: "dispatching", ): Promise { - const [renewed] = await db.update(heartbeatRuns).set({ + const [renewed] = await db.transaction(async tx => { + await notifyLiveRunRecovery(tx, { companyId: run.companyId, runId: run.id }); + return tx.update(heartbeatRuns).set({ controllerLeaseExpiresAt: sql`clock_timestamp() + interval '60 seconds'`, ...(stage ? { executionStage: stage } : {}), }).where(and( @@ -49,6 +52,7 @@ export async function renewLegacyControllerLease( eq(heartbeatRuns.controllerBootId, legacyControllerBootId), gt(heartbeatRuns.controllerLeaseExpiresAt, sql`clock_timestamp()`), )).returning({ id: heartbeatRuns.id }); + }); return Boolean(renewed); } @@ -105,19 +109,23 @@ export async function revokeExpiredLegacyControllerWithState( if (run.runtimeMode === "native" || !run.controllerBootId) { return { executionStage: run.executionStage, processPid: run.processPid, processGroupId: run.processGroupId }; } - const [revoked] = await db.update(heartbeatRuns).set({ + const controllerBootId = run.controllerBootId; + const [revoked] = await db.transaction(async tx => { + await notifyLiveRunRecovery(tx, { companyId: run.companyId, runId: run.id }); + return tx.update(heartbeatRuns).set({ controllerBootId: randomUUID(), controllerLeaseExpiresAt: sql`clock_timestamp() + interval '60 seconds'`, }).where(and( eq(heartbeatRuns.id, run.id), eq(heartbeatRuns.companyId, run.companyId), eq(heartbeatRuns.status, "running"), - eq(heartbeatRuns.controllerBootId, run.controllerBootId), + eq(heartbeatRuns.controllerBootId, controllerBootId), lte(heartbeatRuns.controllerLeaseExpiresAt, sql`clock_timestamp()`), )).returning({ executionStage: heartbeatRuns.executionStage, processPid: heartbeatRuns.processPid, processGroupId: heartbeatRuns.processGroupId, }); + }); return revoked ?? null; } diff --git a/server/src/services/legacy-shutdown-workspace-settlement.ts b/server/src/services/legacy-shutdown-workspace-settlement.ts index 8c85cd3f14b..4a3576f997d 100644 --- a/server/src/services/legacy-shutdown-workspace-settlement.ts +++ b/server/src/services/legacy-shutdown-workspace-settlement.ts @@ -1,3 +1,4 @@ +import { notifyEnvironmentCleanup } from "./environment-cleanup-notifications.js"; import { and, eq, gt, inArray, ne, or, sql } from "drizzle-orm"; import { environmentLeases, heartbeatRuns, issues, type Db } from "@paperclipai/db"; import { adapterExecutionControls } from "./adapter-execution-control.js"; @@ -33,6 +34,7 @@ export function maintainLegacyShutdownWorkspaceSettlement(db: Db, run: Run) { pending = db.transaction(async tx => { await tx.execute(sql`SET LOCAL lock_timeout = '1s'`); await tx.execute(sql`SET LOCAL statement_timeout = '5s'`); + await notifyEnvironmentCleanup(tx, { companyId: run.companyId, runId: run.id }); await tx.update(environmentLeases).set({ metadata: sql`jsonb_set(${environmentLeases.metadata}, '{legacyShutdownWorkspaceSettlement,deadlineAt}', ${JSON.stringify(new Date(Date.now() + SETTLEMENT_LEASE_MS).toISOString())}::jsonb)` }) .where(and(eq(environmentLeases.companyId, run.companyId), eq(environmentLeases.heartbeatRunId, run.id), @@ -86,23 +88,29 @@ export async function sweepLegacyShutdownWorkspaceSettlements(db: Db, now = new /** Commit the fence while the run is still live, before exposing interruption. */ export async function beginLegacyShutdownWorkspaceSettlement(db: Db, run: Run, deadlineAt: Date) { - await db.update(environmentLeases).set({ metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || + await db.transaction(async tx => { + await notifyEnvironmentCleanup(tx, { companyId: run.companyId, runId: run.id }); + await tx.update(environmentLeases).set({ metadata: sql`coalesce(${environmentLeases.metadata}, '{}'::jsonb) || ${JSON.stringify({ legacyShutdownWorkspaceSettlement: { schema: SCHEMA, state: "pending", runId: run.id, controllerBootId: legacyControllerBootId, deadlineAt: deadlineAt.toISOString() } })}::jsonb`, }).where(and(eq(environmentLeases.companyId, run.companyId), eq(environmentLeases.heartbeatRunId, run.id), eq(environmentLeases.status, "active"), ne(environmentLeases.provider, "local"), or(sql`${environmentLeases.metadata}->>'driver' = 'sandbox'`, sql`${environmentLeases.metadata}->>'sandboxProviderPlugin' = 'true'`))); + }); } /** The owner joins settlement, or records exact retention before timeout cleanup. */ export async function finishLegacyShutdownWorkspaceSettlement(db: Db, run: Run, state: "settled" | "expired" = "settled") { - await db.update(environmentLeases).set({ metadata: sql`jsonb_set(${environmentLeases.metadata}, + await db.transaction(async tx => { + await notifyEnvironmentCleanup(tx, { companyId: run.companyId, runId: run.id }); + await tx.update(environmentLeases).set({ metadata: sql`jsonb_set(${environmentLeases.metadata}, '{legacyShutdownWorkspaceSettlement,state}', ${JSON.stringify(state)}::jsonb)` }).where(and( eq(environmentLeases.companyId, run.companyId), eq(environmentLeases.heartbeatRunId, run.id), sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'schema' = ${SCHEMA}`, sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'controllerBootId' = ${legacyControllerBootId}`, sql`${environmentLeases.metadata}->'legacyShutdownWorkspaceSettlement'->>'state' = 'pending'`, )); + }); } /** A restart or another cleanup worker must never infer saved files from timeout. */ @@ -140,6 +148,7 @@ export async function allowLegacyShutdownWorkspaceCleanup(db: Db, lease: Lease, if (!Number.isFinite(deadline) || deadline > now.getTime()) return false; // A killed container cannot certify export. Preserve source and hold in // this same transaction before any worker may perform provider cleanup. + await notifyEnvironmentCleanup(tx, { companyId: run.companyId, runId: run.id }); if (current.status !== "active") { const { hasConfirmedSandboxStopAndRetain, readStopOnlyCleanup } = await import("./sandbox-stop-and-retain.js"); if (!(current.status === "released" && hasConfirmedSandboxStopAndRetain(current)) diff --git a/server/src/services/live-run-recovery-notifications.ts b/server/src/services/live-run-recovery-notifications.ts index 10334f6776c..b270e3b9564 100644 --- a/server/src/services/live-run-recovery-notifications.ts +++ b/server/src/services/live-run-recovery-notifications.ts @@ -23,3 +23,8 @@ export async function notifyLiveResourceRecovery(tx: object, scope?: LiveResourc DELIVERY_QUEUES.strandedAgentStatus, DELIVERY_QUEUES.settledNativeProcesses]) await notifyDeliveryWork(tx, queue, hint); } + +export async function notifyStrandedAgentStatus(tx: object, scope: { companyId: string; agentId: string }) { + await notifyDeliveryWork(tx, DELIVERY_QUEUES.strandedAgentStatus, + JSON.stringify({ companyId: scope.companyId, agentId: scope.agentId })); +} diff --git a/server/src/services/native-finalization-notifications.ts b/server/src/services/native-finalization-notifications.ts index a38aae46c0b..2427ca0fd17 100644 --- a/server/src/services/native-finalization-notifications.ts +++ b/server/src/services/native-finalization-notifications.ts @@ -1,4 +1,4 @@ -import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; +import { notifyLiveRunRecovery } from "./live-run-recovery-notifications.js"; import { notifyNativeEnvironmentSettlement } from "./native-environment-settlement-notifications.js"; import { notifyExternalAgentSettlement } from "../modules/external-agents/index.js"; import { notifyExternalConversationSettlement } from "./external-conversation-settlement-notifications.js"; @@ -16,7 +16,7 @@ export type NativeFinalizationWorkScope = { companyId: string; runId?: string; i export async function notifyNativeFinalizationWork(transaction: object, scope: NativeFinalizationWorkScope) { if (scope.issueId || scope.runId) { - await notifyActiveRunSilence(transaction, scope); + await notifyLiveRunRecovery(transaction, scope); await notifyNativeEnvironmentSettlement(transaction, scope); await notifyExternalAgentSettlement(transaction, scope); await notifyExternalConversationSettlement(transaction, scope); diff --git a/server/src/services/native-local-process-stop.ts b/server/src/services/native-local-process-stop.ts index b26a29e7add..e30c18e9cdc 100644 --- a/server/src/services/native-local-process-stop.ts +++ b/server/src/services/native-local-process-stop.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "./live-run-recovery-notifications.js"; import { and, asc, desc, eq, gt, inArray, isNotNull, isNull, or, sql } from "drizzle-orm"; import { environmentLeases, heartbeatRunEvents, heartbeatRuns, nativeRunFinalizations, type Db } from "@paperclipai/db"; import { notifyRetainedNativeSessionCleanup } from "./retained-native-session-cleanup-notifications.js"; @@ -178,6 +179,7 @@ export async function releaseSettledNativeRunProcess(db: Db, runId: string, opti return "pending"; } } + await notifyLiveRunRecovery(tx, { companyId: run.companyId, runId: run.id, agentId: run.agentId }); await notifyRetainedNativeSessionCleanup(tx, { companyId: run.companyId, runId: run.id }); await tx.update(heartbeatRuns).set({ processPid: null, processGroupId: null, processStartedAt: null, updatedAt: new Date(), diff --git a/server/src/services/native-runtime/native-execution-lease.ts b/server/src/services/native-runtime/native-execution-lease.ts index 645cdb24fdf..c91803da33c 100644 --- a/server/src/services/native-runtime/native-execution-lease.ts +++ b/server/src/services/native-runtime/native-execution-lease.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import type { Db } from "@paperclipai/db"; import { livenessDb, nativeRunFinalizations } from "@paperclipai/db"; import { and, eq, gt, sql } from "drizzle-orm"; @@ -53,6 +54,7 @@ async function renewNativeSessionExecutionLeaseDeadline( // but conservatively include UPDATE/commit response time without assuming // that this server's wall clock agrees with the database's clock. confirmedDeadline = performance.now() + leaseTtlMs; + await notifyLiveRunRecovery(tx, { companyId: input.companyId, runId: input.runId }); return tx.update(nativeRunFinalizations) .set({ leaseExpiresAt: sql`clock_timestamp() + (${leaseTtlMs} * interval '1 millisecond')`, diff --git a/server/src/services/native-runtime/native-finalization-reconciler.ts b/server/src/services/native-runtime/native-finalization-reconciler.ts index af828edfb98..d24988d291c 100644 --- a/server/src/services/native-runtime/native-finalization-reconciler.ts +++ b/server/src/services/native-runtime/native-finalization-reconciler.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import { notifyExternalAgentSettlement } from "../../modules/external-agents/index.js"; import { pendingNativeRunProjectionCondition } from "./native-run-projection.js"; import { nativeStatusReassessmentSourceIsSuperseded, reassessNativeStatusFromSource } from "./native-status-reassessment.js"; @@ -244,6 +245,7 @@ export async function claimNativeSessionResumptions(input: { ) { const failureCode = originalFailureCode; await notifyDeliveryWork(tx, DELIVERY_QUEUES.accounting, row.run.companyId); + await notifyLiveRunRecovery(tx, { companyId: row.run.companyId, runId: row.run.id, agentId: row.run.agentId }); await tx.update(nativeRunFinalizations).set({ phase: "terminal_failure", leaseOwner: null, @@ -312,6 +314,7 @@ export async function claimNativeSessionResumptions(input: { } const leaseExpiresAt = new Date(now.getTime() + 20 * 60_000); + await notifyLiveRunRecovery(tx, { companyId: row.run.companyId, runId: row.run.id, agentId: row.run.agentId }); const updated = await tx.update(nativeRunFinalizations).set({ phase: "observed", leaseOwner, @@ -362,6 +365,7 @@ export async function claimNativeSessionResumptions(input: { if (claimed) claims.push({ runId: candidate.runId, leaseOwner }); else await input.db.transaction(async tx => { await tx.execute(sql`select set_config('statement_timeout', '10000', true), set_config('lock_timeout', '2000', true)`); + await notifyLiveRunRecovery(tx, { companyId: candidate.companyId, runId: candidate.runId }); await tx.update(nativeRunFinalizations).set({ nextAttemptAt: new Date(now.getTime() + 30_000), updatedAt: now, diff --git a/server/src/services/native-runtime/native-question-bridge.ts b/server/src/services/native-runtime/native-question-bridge.ts index f6ae8d7ae82..1ebc09d0e0f 100644 --- a/server/src/services/native-runtime/native-question-bridge.ts +++ b/server/src/services/native-runtime/native-question-bridge.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import { and, eq, inArray, sql } from "drizzle-orm"; import type { Db } from "@paperclipai/db"; @@ -348,6 +349,7 @@ export async function requestNativeQuestionRunCancellation( ...cause, requestedAt: new Date().toISOString(), }); + await notifyLiveRunRecovery(db, { companyId: interaction.companyId, runId: run.id }); return db.update(heartbeatRuns).set({ contextSnapshot: sql`jsonb_set( case diff --git a/server/src/services/native-runtime/native-restart-recovery.ts b/server/src/services/native-runtime/native-restart-recovery.ts index b54f6019f3b..03649cf852b 100644 --- a/server/src/services/native-runtime/native-restart-recovery.ts +++ b/server/src/services/native-runtime/native-restart-recovery.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import { notifyNativeEnvironmentSettlement } from "../native-environment-settlement-notifications.js"; import { notifyExternalAgentSettlement } from "../../modules/external-agents/index.js"; import { notifyNativeStatusReassessment } from "../native-status-reassessment-notifications.js"; @@ -649,6 +650,7 @@ export async function claimNativeRestartRecoveries(input: { hasProviderEvidence: false, stderrTail: row.run.stderrExcerpt, }); + await notifyLiveRunRecovery(tx, { companyId: row.run.companyId, runId: row.run.id, agentId: row.run.agentId }); await tx .update(nativeRunFinalizations) .set({ @@ -1020,6 +1022,7 @@ export async function claimNativeRestartRecoveries(input: { recycledProviderPids: providerProcesses.recycledPids, stderrTail: row.run.stderrExcerpt, }); + await notifyLiveRunRecovery(tx, { companyId: row.run.companyId, runId: row.run.id, agentId: row.run.agentId }); const claimed = await tx .update(nativeRunFinalizations) .set({ diff --git a/server/src/services/native-runtime/native-runner-checkpoint.ts b/server/src/services/native-runtime/native-runner-checkpoint.ts index 3cdef6040e2..455abdda25a 100644 --- a/server/src/services/native-runtime/native-runner-checkpoint.ts +++ b/server/src/services/native-runtime/native-runner-checkpoint.ts @@ -1,3 +1,4 @@ +import { notifyLiveRunRecovery } from "../live-run-recovery-notifications.js"; import { and, eq, exists, gt, isNull, lte, inArray, notExists, or, sql } from "drizzle-orm"; import { checkpointDb, heartbeatRuns, issues, nativeRunFinalizations, nativeRunnerCheckpoints, type Db } from "@paperclipai/db"; import { inspectDurablePrpCheckpointHeader, decodeDurablePrpCheckpoint, type DurablePrpCheckpoint, type DurablePrpControlPlane } from "../../vendor/paperclip-runner/index.js"; @@ -75,6 +76,7 @@ export function nativeRunnerCheckpointWriter(db: Db, owner: Owner) { eq(heartbeatRuns.nativeSessionId, checkpoint.predecessor.normalizedSessionId))); if (!prior) throw new Error("native_runner_checkpoint_binding_mismatch"); } + await notifyLiveRunRecovery(tx, { companyId: owner.companyId, runId: owner.runId }); if (checkpoint.reset) await tx.delete(nativeRunnerCheckpoints).where(and( eq(nativeRunnerCheckpoints.companyId, owner.companyId), eq(nativeRunnerCheckpoints.runId, owner.runId))); else if (checkpoint.removedRecords.length) await tx.delete(nativeRunnerCheckpoints).where(and( From 31955507a38e8ca536f2d540b819dee57f8819fa Mon Sep 17 00:00:00 2001 From: Dotta Date: Fri, 30 Oct 2026 20:34:30 -0500 Subject: [PATCH 3/3] Drive live run and resource recovery from scoped durable deadlines Co-Authored-By: Paperclip --- doc/plans/2026-10-30-live-recovery-sleep.md | 26 ++ ...artbeat-active-run-output-watchdog.test.ts | 12 +- .../src/__tests__/live-recovery-work.test.ts | 413 ++++++++++++++++++ .../native-settled-process-release.test.ts | 13 +- .../server-startup-feedback-export.test.ts | 27 +- server/src/index.ts | 69 +-- .../active-run-watchdog/adapters/postgres.ts | 3 +- .../environment-cleanup-notifications.ts | 10 +- .../services/heartbeat/live-recovery-work.ts | 6 +- server/src/services/heartbeat/recovery.ts | 23 +- server/src/services/instance-settings.ts | 5 +- .../live-run-recovery-notifications.ts | 13 +- .../src/services/native-local-process-stop.ts | 9 +- 13 files changed, 536 insertions(+), 93 deletions(-) create mode 100644 doc/plans/2026-10-30-live-recovery-sleep.md create mode 100644 server/src/__tests__/live-recovery-work.test.ts diff --git a/doc/plans/2026-10-30-live-recovery-sleep.md b/doc/plans/2026-10-30-live-recovery-sleep.md new file mode 100644 index 00000000000..10dfec0ff76 --- /dev/null +++ b/doc/plans/2026-10-30-live-recovery-sleep.md @@ -0,0 +1,26 @@ +# Live run and resource recovery deadlines + +This is the final recovery slice after run dispatch, issue state recovery, and deferred execution receipts. It removes the automatic aggregate orphan and silence scans from `index.ts`. The aggregate API remains for explicit compatibility callers. Startup native classification and hot adoption still run first. Native classification failure still closes startup. Unrelated session-goal startup errors no longer skip independent recovery registrations. + +| Duty | Durable truth and pending predicate | Producers | Deadline and exit | +| --- | --- | --- | --- | +| Resultless native session | Native running/failed run; finalization `retryable_failure`; no result | Execution/finalization writes, checkpoint writes, restart claim writes, process identity events | Maximum saved retry/claim lease deadline. Fresh claim owner validates provider/session state. Accepted result, terminal failure, or explicit ownership gate removes the entry. | +| Native question cancellation | Cancellable run with committed `nativeQuestionCancellation` marker | Authorized task-completion interaction transaction | Immediate. Existing cancellation owner consumes exact company/run marker. Terminal status removes debt. | +| Active execution | Running run | Run lifecycle, controller renewal/revocation, native authority and process evidence writes | Fresh native/legacy controller expiry, saved five-minute preparation grace, or bounded physical-process probe. Local execution promises retain execution ownership. Explicit evidence/manual gates park until their owning producer changes truth. | +| Settled native process identity | Terminal native failure/cancellation with persisted process identity | Terminal execution writes, server process identity/stop receipts, environment settlement | Immediate inspection. Only matched local host/PID/group/birth or confirmed remote stop evidence clears identity. A live matched process or local execution owner keeps a bounded probe. Missing authority waits for committed evidence. Startup reconstructs rows independently of the old capped process Map. Successful release removes any obsolete compatibility Map entry. | +| Orphan active environment lease | Active lease with NULL run reference or terminal same-company run | Environment owning transactions and indexed physical-resource peer notifications | Saved lease updatedAt plus five minutes, re-read before due work. Existing export, shutdown, and shared-resource fences remain. Exact-lease dispatch does not mutate timestamps for broad-page fairness. Successful CAS hands work to the existing pending-cleanup owner. | +| Legacy shutdown settlement | Exact lease with pending shutdown marker | Begin, renew, finish, expiry settlement owning transactions | Exact saved marker deadline. Existing owner revalidates boot/controller, source, competing allocations and stop/copyback authority. Expiry records preserved workspace recovery; it never infers file export from process loss. | +| Stranded agent status | Ready agent with status running | Agent configuration/lifecycle/instruction settlement and run/resource transitions | Saved updatedAt plus five minutes, then actual surviving controller expiry when present. Fresh settlement rechecks live execution, native controller, working copy, and lease truth. Settled status removes debt. | +| Active output silence | Running run and coalesced last output/process start/run start/created timestamp | Actual output progress transaction, terminal source mutation, same-run terminal activity commit, watchdog decisions, execution state | Five-minute threshold, exact saved snooze/continue expiry, or physical termination probe. Fresh check re-reads output and decision. Existing watchdog alone owns completion evidence, process cleanup and fold. Suppressed/manual/blocked history does not poll. | + +All reconstruction queries use company/run/lease/agent scopes and keyset pages. Run and resource topics discard irrelevant fields before coalescing. The generic scheduler's pending/deadline reads use memory. Ordinary writes register intent before mutation in the same owning transaction. Nested commit, outer rollback and uncertain transaction reconciliation retain the shared database-work semantics. + +The existing retained-workspace, native finalization, native result, native environment, instruction, review, conversation, status and pending-cleanup owners remain registered. Startup native recovery explicitly skips their aggregate prefix. The residual owners do not call that prefix or `reapOrphanedRuns`. + +## Proof + +The real PostgreSQL matrix uses the actual heartbeat service and all recovery, dispatch, retry-cancellation and deferred-receipt registrations together. It verifies durable status/output, competing owners, current lease authority, exact saved deadlines, more than 100 guarded/suppressed rows, late host/birth evidence, deleted run references, nested transactions, task drain, warm standby, feature suppression and a one-shot PostgreSQL write failure. Each fully settled fixture requires no running/queued run, no scheduler deadline, and no idle hold before twenty virtual minutes with zero actual SQL. The live-run pagination fixture keeps real controller obligations and proves their exact remaining deadline separately. + +The legacy/controller process retry executes on real JavaScript and PostgreSQL clocks. Other deadline cases install their virtual clock before scheduler registration. Installing fake timers after a real scheduler timer has armed is not a valid deadline test. + +The initial matrix passed12/12 in97.89s. Startup registration, scheduler-disabled and unrelated-owner failure contracts passed111/111. Final expanded receipts and current-head CI/review results are recorded in the PR. diff --git a/server/src/__tests__/heartbeat-active-run-output-watchdog.test.ts b/server/src/__tests__/heartbeat-active-run-output-watchdog.test.ts index 42d8ad30150..3300ccd12a4 100644 --- a/server/src/__tests__/heartbeat-active-run-output-watchdog.test.ts +++ b/server/src/__tests__/heartbeat-active-run-output-watchdog.test.ts @@ -1,5 +1,6 @@ +import { resolveExternalTestDatabaseUrl } from "./helpers/external-test-database.js"; import { randomUUID } from "node:crypto"; -import { and, eq } from "drizzle-orm"; +import { and, eq, sql } from "drizzle-orm"; import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest"; import { activityLog, @@ -39,7 +40,8 @@ vi.mock("../services/heartbeat-run-events.js", async (importOriginal) => { const mockedAppendHeartbeatRunEvent = vi.mocked(appendHeartbeatRunEvent); const embeddedPostgresSupport = await getEmbeddedPostgresTestSupport(); -const describeEmbeddedPostgres = embeddedPostgresSupport.supported ? describe : describe.skip; +const external = resolveExternalTestDatabaseUrl("PAPERCLIP_OUTPUT_WATCHDOG_TEST_DATABASE_URL"); +const describeEmbeddedPostgres = external || embeddedPostgresSupport.supported ? describe : describe.skip; if (!embeddedPostgresSupport.supported) { console.warn( @@ -52,8 +54,9 @@ describeEmbeddedPostgres("active-run output watchdog", () => { let db: ReturnType; beforeAll(async () => { - tempDb = await startEmbeddedPostgresTestDatabase("paperclip-active-run-output-watchdog-"); - db = createDb(tempDb.connectionString); + if (!external) tempDb = await startEmbeddedPostgresTestDatabase("paperclip-active-run-output-watchdog-"); + db = createDb(external ?? tempDb!.connectionString); + if (external) await db.execute(sql`truncate companies cascade`); }, 30_000); afterEach(async () => { @@ -65,6 +68,7 @@ describeEmbeddedPostgres("active-run output watchdog", () => { }); afterAll(async () => { + await db?.$client.end({ timeout: 1 }); await tempDb?.cleanup(); }); diff --git a/server/src/__tests__/live-recovery-work.test.ts b/server/src/__tests__/live-recovery-work.test.ts new file mode 100644 index 00000000000..82cc2f87251 --- /dev/null +++ b/server/src/__tests__/live-recovery-work.test.ts @@ -0,0 +1,413 @@ +import { randomUUID } from "node:crypto"; +import os from "node:os"; +import { spawn } from "node:child_process"; +import { once } from "node:events"; +import { setImmediate as immediate } from "node:timers/promises"; +import { and, eq, sql } from "drizzle-orm"; +import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; +import { agents, authUsers, companies, companyMemberships, createDb, closeLivenessDb, closeCheckpointDb, + heartbeatRuns, heartbeatRunEvents, nativeRunFinalizations, environmentLeases, issueThreadInteractions, + issueRecoveryActions, issues, activityLog } from "@paperclipai/db"; +import { resolveExternalTestDatabaseUrl } from "./helpers/external-test-database.js"; +import { startEmbeddedPostgresTestDatabase } from "./helpers/embedded-postgres.js"; +import { createDeliveryWorkCoordinator } from "../services/delivery-work-coordinator.js"; +import { heartbeatService } from "../services/heartbeat.js"; +import { notifyLiveRunRecovery, notifyLiveResourceRecovery, notifyStrandedAgentStatus } from "../services/live-run-recovery-notifications.js"; +import { notifyExecutionRunWork } from "../services/execution-control-notifications.js"; +import { appendHeartbeatRunEvent } from "../services/heartbeat-run-events.js"; +import { writeEnvironmentCleanup } from "../services/environment-cleanup-notifications.js"; +import { beginLegacyShutdownWorkspaceSettlement } from "../services/legacy-shutdown-workspace-settlement.js"; +import { legacyControllerBootId } from "../services/legacy-controller-lease.js"; +import { idleWorkSnapshot } from "../services/task-admission.js"; +import { createHeartbeatRunOutput } from "../services/heartbeat/run-output.js"; +import { recoveryService } from "../services/recovery/service.js"; +import { instanceSettingsService } from "../services/instance-settings.js"; +import { persistActivity } from "../services/activity-log.js"; +import { issueService } from "../services/issues.js"; + +vi.setConfig({ testTimeout: 90_000 }); +describe("residual recovery production matrix", () => { + let temporary: Awaited> | undefined; + let db: ReturnType; + let heartbeat: ReturnType; + let coordinator: ReturnType; + let draining = false, standby = false; + const errors: unknown[] = [], passes = new Set>(); + const deadlines = new Map number | null>(); + const timeline: unknown[] = []; + const extraStops: Array<() => Promise> = []; + beforeAll(async () => { + const external = resolveExternalTestDatabaseUrl("PAPERCLIP_LIVE_RECOVERY_TEST_DATABASE_URL"); + if (!external) temporary = await startEmbeddedPostgresTestDatabase("live-recovery-"); + db = createDb(external ?? temporary!.connectionString, { maxConnections: 6, idleTimeoutSeconds: 0, maxLifetimeSeconds: 0 }); + await Promise.all(Array.from({ length: 6 }, () => db.execute(sql`select pg_sleep(0.01)`))); + }); + beforeEach(async () => { + await db.execute(sql`truncate companies cascade`); errors.length = 0; deadlines.clear(); timeline.length = 0; draining = false; standby = false; + heartbeat = heartbeatService(db); + coordinator = createDeliveryWorkCoordinator({ owner: db, canRun: () => !standby, canReconcile: () => !standby, + onError: error => errors.push(error) }); + const register = coordinator.register.bind(coordinator); + coordinator.register = (queue, task) => { deadlines.set(queue, () => task.nextRunAt?.() ?? null); return register(queue, { ...task, onSettled: hints => { timeline.push(["settled", queue, Date.now(), [...hints ?? []]]); task.onSettled?.(hints); }, run: signal => { + timeline.push(["pass", queue, Date.now()]); + const pass = Promise.resolve(task.run(signal)); passes.add(pass); + void pass.then(() => passes.delete(pass), () => passes.delete(pass)); return pass; + } }); }; + }); + afterEach(async () => { + for (const stop of extraStops.splice(0)) await stop(); + await coordinator.stop(); await heartbeat.drainActiveRunExecutions(); + vi.useRealTimers(); vi.restoreAllMocks(); expect(errors).toEqual([]); + }); + afterAll(async () => { + await closeLivenessDb(db, 1); await closeCheckpointDb(db, 1); + await db?.$client.end({ timeout: 1 }); await temporary?.cleanup(); + }); + async function fixture() { + const companyId = randomUUID(), actorId = "live-recovery-user"; + await db.insert(authUsers).values({ id: actorId, name: "Recovery owner", email: `${actorId}@example.test`, + createdAt: new Date(), updatedAt: new Date() }).onConflictDoNothing(); + await db.insert(companies).values({ id: companyId, name: "Live recovery", issuePrefix: `LR${companyId.slice(0, 6)}`, + requireBoardApprovalForNewAgents: false, defaultResponsibleUserId: actorId }); + await db.insert(companyMemberships).values({ companyId, principalType: "user", principalId: actorId, + status: "active", membershipRole: "owner" }); + const [agent] = await db.insert(agents).values({ companyId, name: "Recovery process", status: "idle", adapterType: "process", + adapterConfig: { command: process.execPath, args: ["-e", "console.log('live-recovery-proof')"], cwd: process.cwd() }, + runtimeConfig: { heartbeat: { enabled: true, intervalSec: 0, wakeOnDemand: true } } }).returning(); + const [issue] = await db.insert(issues).values({ companyId, title: "Recovered work", status: "done", assigneeAgentId: agent.id }).returning(); + return { companyId, agent, issue, actorId }; + } + async function start(realClock = false) { + if (!realClock && !vi.isFakeTimers()) vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"] }); + const admitted = () => !draining && !standby; + await heartbeat.registerResidualRecoveryWork(coordinator, admitted).ready; + await heartbeat.registerActiveRunSilenceWork(coordinator, admitted).ready; + await heartbeat.registerIssueStateRecoveryWork(coordinator, admitted).ready; + await heartbeat.registerDeferredReceiptWork(coordinator, admitted).ready; + await heartbeat.registerRunDispatchWork(coordinator, admitted).ready; + await heartbeat.registerScheduledRetryCancellationWork(coordinator, admitted).ready; + } + async function advance(ms: number) { + if (!vi.isFakeTimers()) vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"] }); + const until = Date.now() + ms; + while (Date.now() < until) { + await vi.advanceTimersByTimeAsync(Math.min(500, until - Date.now())); + await Promise.allSettled([...passes]); await immediate(); + } + } + async function quiet() { + await heartbeat.drainActiveRunExecutions(); + expect(await db.select().from(heartbeatRuns).where(sql`${heartbeatRuns.status} in ('queued', 'running')`)).toHaveLength(0); + const quietAt = Date.now(); + if (vi.isFakeTimers()) await advance(31_000); + else await vi.waitFor(() => expect(coordinator.nextWakeAt()).toBeNull(), { timeout: 35_000 }); + console.info("quiet-drain", JSON.stringify({ quietAt, now: Date.now(), active: idleWorkSnapshot().active, next: [...deadlines].map(([q, at]) => [q, at()]), timeline })); + await vi.waitFor(() => { expect(coordinator.nextWakeAt(), JSON.stringify([...deadlines].map(([name, at]) => [name, at()]))).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }); + const queries: string[] = [], prior = db.$client.options.debug; + db.$client.options.debug = (_connection, query) => { queries.push(query); }; + try { if (!vi.isFakeTimers()) vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"] }); await vi.advanceTimersByTimeAsync(20 * 60_000); await immediate(); expect(queries).toEqual([]); } + finally { db.$client.options.debug = prior; } + } + async function getRun(id: string) { return (await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)))[0]; } + async function getLease(id: string) { return (await db.select().from(environmentLeases).where(eq(environmentLeases.id, id)))[0]; } + it("leaves configured idle and completed native history without a timer or SQL", async () => { + const f = await fixture(); + const runs = await db.insert(heartbeatRuns).values(Array.from({ length: 150 }, () => ({ companyId: f.companyId, + agentId: f.agent.id, status: "failed", runtimeMode: "native", nativeIssueId: f.issue.id, finishedAt: new Date() }))).returning(); + await db.insert(nativeRunFinalizations).values(runs.map(run => ({ companyId: f.companyId, issueId: f.issue.id, runId: run.id, phase: "committed" }))); + await start(); await quiet(); + }); + it("catches up native resultless retry debt through its real claim owner without replaying missing state", async () => { + const f = await fixture(); await db.update(issues).set({ status: "todo" }).where(eq(issues.id, f.issue.id)); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, + status: "failed", runtimeMode: "native", nativeIssueId: f.issue.id, contextSnapshot: { issueId: f.issue.id }, + finishedAt: new Date(), errorCode: "original_native_failure" }).returning(); + await db.insert(nativeRunFinalizations).values({ companyId: f.companyId, issueId: f.issue.id, runId: run.id, + phase: "retryable_failure", nextAttemptAt: new Date(Date.now() - 1_000) }); + await start(); + await vi.waitFor(async () => { + expect((await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, run.id)))[0]) + .toMatchObject({ phase: "terminal_failure", nextAttemptAt: null, leaseOwner: null }); + }); + expect((await getRun(run.id)).errorCode).toBe("original_native_failure"); + expect(await db.select().from(issueRecoveryActions).where(eq(issueRecoveryActions.sourceIssueId, f.issue.id))) + .toEqual([expect.objectContaining({ ownerType: "board", status: "active" })]); + expect(await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.companyId, f.companyId))).toHaveLength(1); + await quiet(); + }); + it("consumes the durable native question cancellation from ordinary task completion", async () => { + const f = await fixture(); await db.update(issues).set({ status: "in_progress" }).where(eq(issues.id, f.issue.id)); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, status: "running", + runtimeMode: "native", nativeIssueId: f.issue.id, contextSnapshot: { issueId: f.issue.id }, nativePhase: "awaiting_input" }).returning(); + await db.insert(nativeRunFinalizations).values({ companyId: f.companyId, issueId: f.issue.id, runId: run.id, + phase: "observed", recoveryState: "awaiting_evidence", leaseExpiresAt: new Date(Date.now() + 60_000) }); + await db.insert(issueThreadInteractions).values({ companyId: f.companyId, issueId: f.issue.id, kind: "ask_user_questions", + sourceRunId: run.id, status: "pending", continuationPolicy: "none", + idempotencyKey: `paperclip-runner-question:${run.id}:question-1`, payload: { + version: 1, questions: [{ id: "continue", prompt: "Continue?", selectionMode: "single", required: true, allowOther: false, options: [{ id: "yes", label: "Yes" }] }], + questionSet: { schema: "paperclip.question_set.v1", questions: [{ id: "continue", prompt: "Continue?", required: true, answerMode: "single_select", options: [{ id: "yes", label: "Yes" }] }] }, runtimeRequestId: "question-1", + } }); + await start(); await issueService(db).update(f.issue.id, { status: "done" }); + await vi.waitFor(async () => expect((await getRun(run.id)).status).toBe("cancelled"), { timeout: 15_000 }); + expect((await getRun(run.id)).resultJson).toMatchObject({ cancelledByIssueStatus: "done", cancelledIssueId: f.issue.id }); + await quiet(); + }); + it("preserves a fresh foreign controller until exact expiry and admits one process retry across two owners", async () => { + const f = await fixture(), expiry = new Date(Date.now() + 3_000); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, status: "running", + runtimeMode: "legacy", responsibleUserId: f.actorId, controllerBootId: randomUUID(), controllerLeaseExpiresAt: expiry, + executionStage: "preparing", updatedAt: new Date(Date.now() - 6 * 60_000), startedAt: new Date(Date.now() - 6 * 60_000) }).returning(); + await start(true); + const other = heartbeatService(db), competing = createDeliveryWorkCoordinator({ owner: db, canRun: () => true, onError: error => errors.push(error) }); + await other.registerResidualRecoveryWork(competing, () => true).ready; extraStops.push(() => competing.stop()); + expect((await getRun(run.id)).status).toBe("running"); expect(coordinator.nextWakeAt()).toBeLessThanOrEqual(expiry.getTime()); + await vi.waitFor(async () => expect((await getRun(run.id)).status).toBe("failed"), { timeout: 10_000 }); + let retryId: string; + await vi.waitFor(async () => { + const retries = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.retryOfRunId, run.id)); + expect(retries).toHaveLength(1); retryId = retries[0].id; + await heartbeat.drainActiveRunExecutions(); await other.drainActiveRunExecutions(); + expect((await getRun(retryId)).status).toBe("succeeded"); + expect((await getRun(retryId)).stdoutExcerpt).toContain("live-recovery-proof"); + }, { timeout: 45_000 }); + await competing.stop(); extraStops.pop(); await quiet(); + }); + it("releases a settled native process only after matching host and birth evidence arrives", async () => { + const f = await fixture(), startedAt = new Date(); + const child = spawn(process.execPath, ["-e", "console.log('identity-proof')"], { stdio: "ignore" }); + const pid = child.pid!; await once(child, "exit"); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, runtimeMode: "native", + nativeIssueId: f.issue.id, status: "failed", finishedAt: new Date(), processPid: pid, processStartedAt: startedAt, + runnerProfileJson: { sessionCheckpoint: { sessionId: "preserved-native-session" } } }).returning(); + await db.insert(nativeRunFinalizations).values({ companyId: f.companyId, issueId: f.issue.id, runId: run.id, phase: "committed" }); + await appendHeartbeatRunEvent(db, { companyId: f.companyId, agentId: f.agent.id, runId: run.id, + eventType: "native.process_identity_recorded", payload: { targetKind: "local", hostname: os.hostname(), + processPid: pid, processGroupId: null, processStartedAt: new Date(startedAt.getTime() - 1).toISOString() } }); + await start(); expect((await getRun(run.id)).processPid).toBe(pid); + await appendHeartbeatRunEvent(db, { companyId: f.companyId, agentId: f.agent.id, runId: run.id, + eventType: "native.process_identity_recorded", payload: { targetKind: "local", hostname: os.hostname(), + processPid: pid, processGroupId: null, processStartedAt: startedAt.toISOString() } }); + await vi.waitFor(async () => expect((await getRun(run.id)).processPid).toBeNull(), { timeout: 40_000 }); + expect(await db.select().from(heartbeatRunEvents).where(and(eq(heartbeatRunEvents.runId, run.id), + eq(heartbeatRunEvents.eventType, "native.local_process_stopped")))).toHaveLength(1); + await quiet(); + }); + it("recovers orphan active leases after restart, including a deleted heartbeat reference, without starving behind 100 guarded rows", async () => { + const f = await fixture(), foreign = await fixture(), resource = randomUUID(), old = new Date(Date.now() - 6 * 60_000); + await db.insert(environmentLeases).values({ companyId: foreign.companyId, status: "retained", provider: "fixture", providerLeaseId: resource, updatedAt: old }); + const guarded = await db.insert(environmentLeases).values(Array.from({ length: 105 }, () => ({ companyId: f.companyId, + status: "active", provider: "fixture", providerLeaseId: resource, updatedAt: old }))).returning(); + const [deleted] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, status: "succeeded", finishedAt: old }).returning(); + const [orphan] = await db.insert(environmentLeases).values({ companyId: f.companyId, heartbeatRunId: deleted.id, + status: "active", provider: "local", updatedAt: old }).returning(); + await db.delete(heartbeatRuns).where(eq(heartbeatRuns.id, deleted.id)); + expect((await getLease(orphan.id)).heartbeatRunId).toBeNull(); await start(); + await vi.waitFor(async () => expect((await getLease(orphan.id)).status).toBe("pending_cleanup"), { timeout: 15_000 }); + expect(await db.select().from(environmentLeases).where(and(eq(environmentLeases.companyId, f.companyId), + eq(environmentLeases.status, "pending_cleanup")))).toHaveLength(1); + for (const row of guarded) expect((await getLease(row.id)).status).toBe("active"); + await quiet(); + }); + it("reactivates an orphan when a different company's physical resource owner releases it", async () => { + const f = await fixture(), other = await fixture(), old = new Date(Date.now() - 6 * 60_000), resource = randomUUID(); + const [run] = await db.insert(heartbeatRuns).values({ companyId: other.companyId, agentId: other.agent.id, status: "succeeded", finishedAt: old }).returning(); + const [owner] = await db.insert(environmentLeases).values({ companyId: other.companyId, heartbeatRunId: run.id, + status: "retained", provider: "fixture", providerLeaseId: resource, updatedAt: old }).returning(); + const [orphan] = await db.insert(environmentLeases).values({ companyId: f.companyId, status: "active", + provider: "fixture", providerLeaseId: resource, updatedAt: old }).returning(); + await start(); expect((await getLease(orphan.id)).status).toBe("active"); + await writeEnvironmentCleanup(db, tx => tx.update(environmentLeases).set({ status: "released", releasedAt: new Date() }) + .where(eq(environmentLeases.id, owner.id)), { companyId: other.companyId, runId: run.id, leaseId: owner.id }); + await vi.waitFor(async () => expect((await getLease(orphan.id)).status).toBe("pending_cleanup"), { timeout: 40_000 }); + await quiet(); + }); + it("expires the exact shutdown settlement marker into preserved recovery instead of inferring file export", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, issueId: f.issue.id, + status: "failed", runtimeMode: "legacy", contextSnapshot: { issueId: f.issue.id }, finishedAt: old }).returning(); + const [lease] = await db.insert(environmentLeases).values({ companyId: f.companyId, heartbeatRunId: run.id, + issueId: f.issue.id, status: "active", provider: "fixture", providerLeaseId: randomUUID(), updatedAt: old, + metadata: { driver: "sandbox" } }).returning(); + await beginLegacyShutdownWorkspaceSettlement(db, run, new Date(Date.now() + 1_500)); await start(); + expect((await getLease(lease.id)).metadata?.legacyShutdownWorkspaceSettlement).toMatchObject({ state: "pending" }); + await vi.waitFor(async () => expect((await getLease(lease.id)).metadata?.legacyShutdownWorkspaceSettlement) + .toMatchObject({ state: "expired" }), { timeout: 10_000 }); + expect((await getLease(lease.id)).leasePolicy).toBe("retain_on_failure"); + expect((await getLease(lease.id)).metadata?.workspaceRestoreRecovery).toBeTruthy(); + expect((await getLease(lease.id)).providerLeaseId).toBe(lease.providerLeaseId); + expect((await getLease(lease.id)).metadata).toMatchObject({ workspaceRestoreRecovery: { schema: "paperclip.workspace-restore-recovery.v1", runId: run.id } }); + await quiet(); + }); + it("settles stranded agent status at its saved grace", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000); + await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, status: "succeeded", finishedAt: old }); + await db.transaction(async tx => { + await notifyStrandedAgentStatus(tx, { companyId: f.companyId, agentId: f.agent.id }); + await tx.update(agents).set({ status: "running", updatedAt: old }).where(eq(agents.id, f.agent.id)); + }); + await start(); await vi.waitFor(async () => expect((await db.select().from(agents).where(eq(agents.id, f.agent.id)))[0].status).toBe("idle")); + await quiet(); + }); + it("moves the silence threshold on actual output and folds same-run completion only at strict snooze expiry", async () => { + const f = await fixture(), now = new Date(), old = new Date(now.getTime() - 10 * 60_000); + await db.update(issues).set({ status: "in_progress" }).where(eq(issues.id, f.issue.id)); + await db.update(agents).set({ status: "running" }).where(eq(agents.id, f.agent.id)); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, + status: "running", runtimeMode: "legacy", contextSnapshot: { issueId: f.issue.id }, + responsibleUserId: f.actorId, startedAt: old, processStartedAt: old, updatedAt: old, + controllerBootId: randomUUID(), controllerLeaseExpiresAt: new Date(now.getTime() + 60 * 60_000) }).returning(); + const output = createHeartbeatRunOutput(db, { run, runId: run.id, issueId: f.issue.id, + runLogStore: { begin: async () => ({ store: "local_file", logRef: "fixture-output.ndjson" }), append: async (_handle, event) => Buffer.byteLength(event.chunk) }, + identityRedactor: { chunk: (_stream, chunk) => chunk, redact: value => value }, secretKeys: new Set(), + appendRunEvent: async (_run, event) => { await appendHeartbeatRunEvent(db, { companyId: f.companyId, agentId: f.agent.id, runId: run.id, ...event }); }, + getCurrentUserRedactionOptions: async () => ({ enabled: false }) }); + await (await output.begin(run)).onLog("stdout", "fresh actual output"); + const progressed = await getRun(run.id), snoozedUntil = new Date(progressed.lastOutputAt!.getTime() + 5 * 60_000 + 2_000); + expect(progressed.lastOutputSeq).toBe(1); expect(progressed.lastOutputAt!.getTime()).toBeGreaterThan(old.getTime()); + await issueService(db).update(f.issue.id, { status: "done" }); + await persistActivity(db, { companyId: f.companyId, actorType: "agent", actorId: f.agent.id, agentId: f.agent.id, + runId: run.id, entityType: "issue", entityId: f.issue.id, action: "issue.updated", details: { status: "done" } }); + await recoveryService(db, { enqueueWakeup: heartbeat.wakeup }).recordWatchdogDecision({ runId: run.id, + actor: { type: "board" }, decision: "snooze", snoozedUntil, reason: "Wait for the exact saved deadline" }); + await start(); + await advance(snoozedUntil.getTime() - Date.now() - 1); + expect((await getRun(run.id)).status).toBe("running"); + await advance(1); + await vi.waitFor(async () => expect((await getRun(run.id)).status).toBe("succeeded")); + expect((await getRun(run.id)).resultJson).toMatchObject({ sourceResolvedWatchdogFold: { sourceIssueStatus: "done", sameRunEvidenceKind: "activity" } }); + await quiet(); + }); + it("re-reads a concurrently moved stranded-agent grace before settlement", async () => { + const f = await fixture(), initialAt = new Date(); + await db.update(agents).set({ status: "running", updatedAt: initialAt }).where(eq(agents.id, f.agent.id)); + await start(); await advance(60_000); + const moved = new Date(); + await db.update(agents).set({ updatedAt: moved }).where(eq(agents.id, f.agent.id)); + await advance(initialAt.getTime() + 5 * 60_000 - Date.now()); + expect((await db.select().from(agents).where(eq(agents.id, f.agent.id)))[0].status).toBe("running"); + await advance(moved.getTime() + 5 * 60_000 - Date.now()); + await vi.waitFor(async () => expect((await db.select().from(agents).where(eq(agents.id, f.agent.id)))[0].status).toBe("idle")); + await quiet(); + }); + it("reaches a silent run behind more than 100 suppressed live runs and leaves only real controller deadlines", async () => { + const f = await fixture(), now = new Date(), old = new Date(now.getTime() - 20 * 60_000); + await db.update(issues).set({ status: "blocked" }).where(eq(issues.id, f.issue.id)); + const expiry = new Date(now.getTime() + 60 * 60_000); + const suppressed = await db.insert(heartbeatRuns).values(Array.from({ length: 105 }, () => ({ companyId: f.companyId, + agentId: f.agent.id, status: "running", runtimeMode: "legacy", contextSnapshot: { issueId: f.issue.id }, + startedAt: old, updatedAt: old, controllerBootId: randomUUID(), controllerLeaseExpiresAt: expiry }))).returning(); + const [source] = await db.insert(issues).values({ companyId: f.companyId, status: "done", title: "Actual completed source", assigneeAgentId: f.agent.id }).returning(); + const [target] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, + status: "running", runtimeMode: "legacy", contextSnapshot: { issueId: source.id }, + startedAt: new Date(old.getTime() + 60_000), updatedAt: old, + controllerBootId: randomUUID(), controllerLeaseExpiresAt: expiry }).returning(); + await db.insert(activityLog).values({ companyId: f.companyId, actorType: "agent", actorId: f.agent.id, + agentId: f.agent.id, runId: target.id, entityType: "issue", entityId: source.id, action: "issue.updated", details: { status: "done" } }); + await start(); await advance(31_000); + await vi.waitFor(async () => expect((await getRun(target.id)).status).toBe("succeeded")); + expect(await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.status, "running"))).toHaveLength(suppressed.length); + expect(deadlines.get("active-run-silence")!()).toBeNull(); + const [agentState] = await db.select().from(agents).where(eq(agents.id, f.agent.id)); + const grace = agentState.updatedAt.getTime() + 5 * 60_000; + expect(agentState.status).toBe("running"); + expect(deadlines.get("stranded-agent-status")!()).toBe(grace); + await advance(grace - Date.now() + 1); + expect(deadlines.get("stranded-agent-status")!()).toBe(expiry.getTime()); + expect(coordinator.nextWakeAt(), JSON.stringify([...deadlines].map(([name, at]) => [name, at()]))).toBe(expiry.getTime()); + const queries: string[] = [], prior = db.$client.options.debug; + db.$client.options.debug = (_connection, query) => { queries.push(query); }; + try { await advance(20 * 60_000); expect(queries).toEqual([]); } + finally { db.$client.options.debug = prior; } + }); + it("reconciles nested rollback and dispatches only the outer committed orphan producer", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000), rolledBack = randomUUID(); + await start(); await quiet(); + await expect(db.transaction(async outer => { + await outer.transaction(async inner => { + await notifyLiveResourceRecovery(inner, { companyId: f.companyId, leaseId: rolledBack }); + await inner.insert(environmentLeases).values({ id: rolledBack, companyId: f.companyId, status: "active", provider: "local", updatedAt: old }); + }); + throw new Error("abort outer producer"); + })).rejects.toThrow("abort outer producer"); + await advance(31_000); expect(await getLease(rolledBack)).toBeUndefined(); await quiet(); + const committed = randomUUID(); + await db.transaction(async outer => { + await outer.transaction(async inner => { + await notifyLiveResourceRecovery(inner, { companyId: f.companyId, leaseId: committed }); + await inner.insert(environmentLeases).values({ id: committed, companyId: f.companyId, status: "active", provider: "local", updatedAt: old }); + }); + expect(await getLease(committed)).toBeUndefined(); + }); + await advance(1_000); + await vi.waitFor(async () => expect((await getLease(committed)).status).toBe("pending_cleanup")); + await quiet(); + }); + it("retains and re-reads a moved native controller deadline while awaiting recovery evidence", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000), expiry = new Date(Date.now() + 3_000); + const [run] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agent.id, + status: "running", runtimeMode: "native", nativeIssueId: f.issue.id, contextSnapshot: { issueId: f.issue.id }, + startedAt: old, updatedAt: old }).returning(); + await db.insert(nativeRunFinalizations).values({ companyId: f.companyId, issueId: f.issue.id, runId: run.id, + phase: "observed", recoveryState: "awaiting_evidence", controllerBootId: randomUUID(), controllerPid: process.pid + 100_000, + controllerProcessStartedAt: old, leaseExpiresAt: expiry }); + await start(); expect(deadlines.get("active-execution-recovery")!()).toBe(expiry.getTime()); + const moved = new Date(expiry.getTime() + 10_000); + await db.update(nativeRunFinalizations).set({ leaseExpiresAt: moved }).where(eq(nativeRunFinalizations.runId, run.id)); + await advance(expiry.getTime() - Date.now()); + expect((await getRun(run.id)).status).toBe("running"); expect((await getRun(run.id)).errorCode).toBeNull(); + expect(deadlines.get("active-execution-recovery")!()).toBe(moved.getTime()); + await db.transaction(async tx => { + await notifyExecutionRunWork(tx, { companyId: f.companyId, runId: run.id, agentId: f.agent.id }); + await tx.update(heartbeatRuns).set({ status: "cancelled", finishedAt: new Date() }).where(eq(heartbeatRuns.id, run.id)); + await tx.update(nativeRunFinalizations).set({ phase: "terminal_failure", recoveryState: "blocked", leaseExpiresAt: null }) + .where(eq(nativeRunFinalizations.runId, run.id)); + }); + await quiet(); + }); + it("retains failed orphan work with bounded backoff after a real PostgreSQL write failure", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000); + const [lease] = await db.insert(environmentLeases).values({ companyId: f.companyId, status: "active", provider: "local", updatedAt: old }).returning(); + await db.execute(sql`create sequence live_recovery_failure_once`); + await db.execute(sql.raw(`create function live_recovery_failure_once() returns trigger language plpgsql as $$ + begin if new.id = '${lease.id}'::uuid and new.status = 'pending_cleanup' and nextval('live_recovery_failure_once') = 1 + then raise exception 'fixture cleanup persistence unavailable'; end if; return new; end $$`)); + await db.execute(sql`create trigger live_recovery_failure_once before update on environment_leases for each row execute function live_recovery_failure_once()`); + extraStops.push(async () => { + await db.execute(sql`drop trigger if exists live_recovery_failure_once on environment_leases`); + await db.execute(sql`drop function if exists live_recovery_failure_once()`); + await db.execute(sql`drop sequence if exists live_recovery_failure_once`); + }); + await start(); + expect(errors).toHaveLength(1); expect(errors.shift()).toBeInstanceOf(AggregateError); + expect((await getLease(lease.id)).status).toBe("active"); + await advance(29_000); expect((await getLease(lease.id)).status).toBe("active"); + await advance(1_000); + await vi.waitFor(async () => expect((await getLease(lease.id)).status).toBe("pending_cleanup")); + await quiet(); + }); + it("parks suppressed worktree recovery without probes and reconstructs it on the committed feature change", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000); + const settings = instanceSettingsService(db); + await settings.updateExperimental({ enableWorktreeRunExecution: false }); + heartbeat = heartbeatService(db, { runtimeEnv: { PAPERCLIP_IN_WORKTREE: "true" } }); + const [lease] = await db.insert(environmentLeases).values({ companyId: f.companyId, status: "active", provider: "local", updatedAt: old }).returning(); + await start(); expect((await getLease(lease.id)).status).toBe("active"); await quiet(); + try { + await settings.updateExperimental({ enableWorktreeRunExecution: true }); + await advance(1_000); + await vi.waitFor(async () => expect((await getLease(lease.id)).status).toBe("pending_cleanup")); + } finally { await settings.updateExperimental({ enableWorktreeRunExecution: false }); } + await quiet(); + }); + it("retains first producer debt during drain and warm standby, then resumes without duplicate cleanup", async () => { + const f = await fixture(), old = new Date(Date.now() - 6 * 60_000); + draining = true; await start(); + const [lease] = await writeEnvironmentCleanup(db, tx => tx.insert(environmentLeases).values({ companyId: f.companyId, + status: "active", provider: "local", updatedAt: old }).returning(), { companyId: f.companyId }); + await advance(1_000); await vi.waitFor(() => expect(idleWorkSnapshot().active).toBe(0)); + expect((await getLease(lease.id)).status).toBe("active"); + standby = true; draining = false; await advance(60_000); expect((await getLease(lease.id)).status).toBe("active"); + standby = false; await advance(30_000); + await vi.waitFor(async () => expect((await getLease(lease.id)).status).toBe("pending_cleanup")); await quiet(); + }); +}); diff --git a/server/src/__tests__/native-settled-process-release.test.ts b/server/src/__tests__/native-settled-process-release.test.ts index d2a60b89ccb..50a52e40e90 100644 --- a/server/src/__tests__/native-settled-process-release.test.ts +++ b/server/src/__tests__/native-settled-process-release.test.ts @@ -1,9 +1,10 @@ +import { resolveExternalTestDatabaseUrl } from "./helpers/external-test-database.js"; import { EMBEDDED_POSTGRES_TEST_TIMEOUT_MS } from "@paperclipai/db"; import { randomBytes, randomUUID } from "node:crypto"; import { createDatabaseResponseCapture, installDatabaseResponseCapture } from "@paperclipai/db/response-capture"; import { spawn } from "node:child_process"; import os from "node:os"; -import { and, eq } from "drizzle-orm"; +import { and, eq, sql } from "drizzle-orm"; import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest"; import { agents, @@ -39,8 +40,9 @@ vi.mock("../adapters/index.js", async () => { return { ...actual, getServerAdapter: vi.fn(() => ({ supportsLocalAgentJwt: false, execute })) }; }); +const external = resolveExternalTestDatabaseUrl("PAPERCLIP_SETTLED_PROCESS_TEST_DATABASE_URL"); const support = await getEmbeddedPostgresTestSupport(); -const suite = support.supported ? describe : describe.skip; +const suite = external || support.supported ? describe : describe.skip; function startDetached() { const child = spawn(process.execPath, ["-e", "setInterval(() => {}, 1000)"], { detached: true, stdio: "ignore" }); @@ -57,14 +59,15 @@ async function exitedPid() { suite("settled native run process identity", () => { let db: ReturnType; - let temporary: Awaited>; + let temporary: Awaited> | undefined; let companyId: string; let agentId: string; const children: ReturnType[] = []; beforeAll(async () => { - temporary = await startEmbeddedPostgresTestDatabase("native-settled-process-"); - db = createDb(temporary.connectionString); + if (!external) temporary = await startEmbeddedPostgresTestDatabase("native-settled-process-"); + db = createDb(external ?? temporary!.connectionString); + if (external) await db.execute(sql`truncate companies cascade`); companyId = randomUUID(); agentId = randomUUID(); await db.insert(companies).values({ id: companyId, name: "Settled processes", issuePrefix: "SPR", defaultResponsibleUserId: "owner" }); diff --git a/server/src/__tests__/server-startup-feedback-export.test.ts b/server/src/__tests__/server-startup-feedback-export.test.ts index 55d261f91c0..371801f79dd 100644 --- a/server/src/__tests__/server-startup-feedback-export.test.ts +++ b/server/src/__tests__/server-startup-feedback-export.test.ts @@ -134,6 +134,8 @@ const { })), reconcileHotRestartAdoption: vi.fn(async () => ({ mode: "none" })), reapOrphanedRuns: vi.fn(async () => ({ reaped: 0, runIds: [] })), + registerResidualRecoveryWork: vi.fn((_coordinator: unknown, _canRun: () => boolean) => ({ ready: Promise.resolve() })), + registerActiveRunSilenceWork: vi.fn((_coordinator: unknown, _canRun: () => boolean) => ({ ready: Promise.resolve() })), registerIssueStateRecoveryWork: vi.fn((_coordinator: unknown, _canRun: () => boolean) => ({ ready: Promise.resolve() })), registerDeferredReceiptWork: vi.fn((_coordinator: unknown, _canRun: () => boolean) => ({ ready: Promise.resolve() })), registerRunDispatchWork: vi.fn((_coordinator: unknown, _canRun: () => boolean) => ({ ready: Promise.resolve() })), @@ -930,6 +932,8 @@ describe("startServer feedback export wiring", () => { loadConfigMock.mockReturnValue(buildTestConfig({ heartbeatSchedulerEnabled: enabled })); await startServer(); await settleStartupHousekeeping(); expect(heartbeatServiceMock.registerIssueStateRecoveryWork).toHaveBeenCalledTimes(enabled ? 1 : 0); + expect(heartbeatServiceMock.registerResidualRecoveryWork).toHaveBeenCalledTimes(enabled ? 1 : 0); + expect(heartbeatServiceMock.registerActiveRunSilenceWork).toHaveBeenCalledTimes(enabled ? 1 : 0); expect(heartbeatServiceMock.registerRunDispatchWork).toHaveBeenCalledTimes(enabled ? 1 : 0); expect(heartbeatServiceMock.registerDeferredReceiptWork).toHaveBeenCalledTimes(enabled ? 1 : 0); expect(heartbeatServiceMock.resumeQueuedRuns).not.toHaveBeenCalled(); @@ -1344,7 +1348,8 @@ describe("startServer feedback export wiring", () => { intervalCallback?.(); await new Promise((resolve) => setImmediate(resolve)); expect(heartbeatServiceMock.sweepStaleIssueLocks).not.toHaveBeenCalled(); - expect(heartbeatServiceMock.reapOrphanedRuns).toHaveBeenLastCalledWith({ staleThresholdMs: 300_000, skipNativeStatusWakeIntents: true, skipScheduledRetryCancellation: true, skipCapturedInstructionCommit: true, skipInstructionDirectoryCleanup: true, skipStoppedInstructionCollection: true, skipCancelledWorkspacePreservation: true, skipObsoletePolicyReviews: true, skipAutomaticCompletionReviews: true, skipUnsafeWorkspaceExports: true, skipNativePendingEffects: true, skipNativeResponsePresentation: true, skipNativeReviewResponse: true, skipNativeStatusReassessment: true, skipRetainedNativeSessionCleanup: true, skipNativeWorkspaceFinalization: true, skipNativeResultCommit: true, skipNativeRunProjection: true, skipNativeRecoveryNotices: true, skipExternalConversationSettlement: true, skipExternalAgentSettlement: true, skipNativeEnvironmentSettlement: true }); + expect(heartbeatServiceMock.reapOrphanedRuns).not.toHaveBeenCalled(); + expect(heartbeatServiceMock.scanSilentActiveRuns).not.toHaveBeenCalled(); expect(heartbeatServiceMock.reconcileCostAccounting).toHaveBeenCalledTimes(1); expect(heartbeatServiceMock.promoteDueScheduledRetries).not.toHaveBeenCalled(); expect(retiredDetector).not.toHaveBeenCalled(); @@ -1611,20 +1616,30 @@ describe("startServer feedback export wiring", () => { } }); - it("does not replay hot-restart adoption when the orphan reaper retries", async () => { + it("keeps residual recovery independent after a partial hot-restart adoption", async () => { loadConfigMock.mockReturnValue(buildTestConfig({ heartbeatSchedulerEnabled: true, heartbeatSchedulerIntervalMs: 30000, })); heartbeatServiceMock.reconcileHotRestartAdoption.mockRejectedValueOnce(new Error("partial adoption")); - heartbeatServiceMock.reapOrphanedRuns - .mockRejectedValueOnce(new Error("transient reap failure")) - .mockResolvedValueOnce({ reaped: 0, runIds: [] }); + await startServer(); expect(heartbeatServiceMock.reconcileHotRestartAdoption).toHaveBeenCalledTimes(1); - expect(heartbeatServiceMock.reapOrphanedRuns).toHaveBeenCalledTimes(2); + expect(heartbeatServiceMock.reapOrphanedRuns).not.toHaveBeenCalled(); + expect(heartbeatServiceMock.registerResidualRecoveryWork).toHaveBeenCalledTimes(1); + expect(heartbeatServiceMock.registerActiveRunSilenceWork).toHaveBeenCalledTimes(1); + }); + + it.each(["recoverPendingSessionGoalActions", "recoverActiveSessionGoals"] as const)("continues independent recovery after %s startup failure", async method => { + loadConfigMock.mockReturnValue(buildTestConfig({ heartbeatSchedulerEnabled: true })); + heartbeatServiceMock[method].mockRejectedValueOnce(new Error("goal owner unavailable")); + await startServer(); await settleStartupHousekeeping(); + expect(heartbeatServiceMock.registerResidualRecoveryWork).toHaveBeenCalledTimes(1); + expect(heartbeatServiceMock.registerActiveRunSilenceWork).toHaveBeenCalledTimes(1); + expect(heartbeatServiceMock.registerRunDispatchWork).toHaveBeenCalledTimes(1); + expect(fakeServer.close).not.toHaveBeenCalled(); }); it("closes the bound listener when native startup recovery fails", async () => { diff --git a/server/src/index.ts b/server/src/index.ts index fffac2a7972..5a3ff5ff900 100644 --- a/server/src/index.ts +++ b/server/src/index.ts @@ -62,7 +62,6 @@ import { chatCompletionDeliveryService } from "./services/chat-completion-delive // instrumentationReady before opening DB connections or constructing the // HTTP server, so trace coverage does not depend on incidental timing. import { instrumentationReady, shutdownInstrumentation } from "./instrumentation.js"; -import { createTrackedSingleFlight } from "./lib/single-flight.js"; import { sentryReady, shutdownSentry, captureException } from "./sentry.js"; import { setSentryRunLinkResolver } from "./sentry-links.js"; import { createSentryRunLinkResolver } from "./services/sentry-run-links.js"; @@ -1262,16 +1261,6 @@ async function startServerWithDatabaseTeardown( }); heartbeatSchedulerInFlight.add(tracked); }; - const runPeriodicRecovery = createTrackedSingleFlight({ - trackWork: trackHeartbeatSchedulerWork, - onSkipped: (inFlightForMs) => { - if (inFlightForMs >= 3 * config.heartbeatSchedulerIntervalMs) { - logger.error({ inFlightForMs }, "periodic heartbeat recovery remains in flight; duplicate pass suppressed"); - } else { - logger.warn({ inFlightForMs }, "skipped periodic heartbeat recovery tick; previous chain still in flight"); - } - }, - }); const waitForHeartbeatSchedulerIdle = async () => { while (heartbeatSchedulerInFlight.size > 0) { await Promise.allSettled([...heartbeatSchedulerInFlight]); @@ -1715,7 +1704,7 @@ async function startServerWithDatabaseTeardown( // workers before cleanup or retry admission, including unmanaged installs. await timeStartupRecovery("plugin_workers", () => app.locals.bundledPluginsStartup); try { - const nativeRecovery = await timeStartupRecovery("native_recovery", () => heartbeat.recoverNativeRunsAfterRestart()); + const nativeRecovery = await timeStartupRecovery("native_recovery", () => heartbeat.recoverNativeRunsAfterRestart(new Date(), undefined, { skipDelegatedWork: true })); if (nativeRecovery.dispositions.length > 0) { logger.info( { @@ -1750,31 +1739,14 @@ async function startServerWithDatabaseTeardown( } catch (err) { logger.error( { err }, - "startup hot-restart adoption reconciliation failed - orphan reaper will serve as degraded backstop", + "startup hot-restart adoption reconciliation failed - recovery deadlines remain registered", ); } - for (let attempt = 1; attempt <= 2; attempt++) { - try { - const result = await timeStartupRecovery("orphan_reaping", () => heartbeat.reapOrphanedRuns()); - logger.info( - { reaped: result.reaped, runIds: result.runIds }, - "startup reap of orphaned heartbeat runs complete", - ); - break; - } catch (err) { - if (attempt < 2) { - logger.warn({ err, attempt }, "startup reap failed, retrying"); - } else { - logger.error( - { err }, - "startup reap of orphaned heartbeat runs failed after retry - periodic reaper will serve as degraded backstop", - ); - } - } - } - - const recoveredGoalActions = await timeStartupRecovery("goal_actions", () => heartbeat.recoverPendingSessionGoalActions()); + const recoveredGoalActions = await timeStartupRecovery("goal_actions", () => heartbeat.recoverPendingSessionGoalActions()).catch(err => { + logger.error({ err }, "startup session-goal action recovery failed"); + return { enqueued: 0, invalid: 0 }; + }); if ( recoveredGoalActions.enqueued > 0 || recoveredGoalActions.invalid > 0 @@ -1784,17 +1756,16 @@ async function startServerWithDatabaseTeardown( "startup session-goal action outbox recovery reconciled pending controls", ); } - const recoveredGoals = await timeStartupRecovery("active_goals", () => heartbeat.recoverActiveSessionGoals()); + const recoveredGoals = await timeStartupRecovery("active_goals", () => heartbeat.recoverActiveSessionGoals()).catch(err => { + logger.error({ err }, "startup active session-goal recovery failed"); + return { enqueued: 0 }; + }); if (recoveredGoals.enqueued > 0) { logger.warn( recoveredGoals, "startup session-goal recovery resumed durable agent goals", ); } - const scanned = await heartbeat.scanSilentActiveRuns(); - if (scanned.created > 0 || scanned.escalated > 0) { - logger.warn({ ...scanned }, "startup active-run output watchdog created review work"); - } })().catch((err) => { logger.error({ err }, "startup heartbeat recovery failed"); throw err; @@ -1803,6 +1774,10 @@ async function startServerWithDatabaseTeardown( await startupHeartbeatRecovery; } + if (config.heartbeatSchedulerEnabled) await heartbeat.registerResidualRecoveryWork(deliveryWork, + () => !isIdleTaskDrainActive() && !isWarmStandby() && !heartbeatSchedulerStopped).ready; + if (config.heartbeatSchedulerEnabled) await heartbeat.registerActiveRunSilenceWork(deliveryWork, + () => !isIdleTaskDrainActive() && !isWarmStandby() && !heartbeatSchedulerStopped).ready; if (config.heartbeatSchedulerEnabled) await heartbeat.registerIssueStateRecoveryWork(deliveryWork, () => !isIdleTaskDrainActive() && !isWarmStandby() && !heartbeatSchedulerStopped).ready; if (config.heartbeatSchedulerEnabled) await heartbeat.registerDeferredReceiptWork(deliveryWork, @@ -2005,22 +1980,6 @@ async function startServerWithDatabaseTeardown( logger.error({ err }, "status-card scheduler tick failed"); })); - if (isIdleTaskDrainActive() || heartbeatSchedulerStopped) return; - if (!(await heartbeat.resolveSchedulingSuppression()).suppressed) { - // Periodically reap orphaned runs (5-min staleness threshold) and make sure - // persisted queued work is still being driven forward. - runPeriodicRecovery(() => heartbeat - .reapOrphanedRuns({ staleThresholdMs: 5 * 60 * 1000, skipNativeStatusWakeIntents: true, skipScheduledRetryCancellation: true, skipCapturedInstructionCommit: true, skipInstructionDirectoryCleanup: true, skipStoppedInstructionCollection: true, skipCancelledWorkspacePreservation: true, skipObsoletePolicyReviews: true, skipAutomaticCompletionReviews: true, skipUnsafeWorkspaceExports: true, skipNativePendingEffects: true, skipNativeResponsePresentation: true, skipNativeReviewResponse: true, skipNativeStatusReassessment: true, skipRetainedNativeSessionCleanup: true, skipNativeWorkspaceFinalization: true, skipNativeResultCommit: true, skipNativeRunProjection: true, skipNativeRecoveryNotices: true, skipExternalConversationSettlement: true, skipExternalAgentSettlement: true, skipNativeEnvironmentSettlement: true }) - .then(async () => { - const scanned = await heartbeat.scanSilentActiveRuns(); - if (scanned.created > 0 || scanned.escalated > 0) { - logger.warn({ ...scanned }, "periodic active-run output watchdog created review work"); - } - }) - .catch((err) => { - logger.error({ err }, "periodic heartbeat recovery failed"); - })); - } })().catch((err) => { logger.error({ err }, "heartbeat scheduler tick failed"); })); diff --git a/server/src/modules/active-run-watchdog/adapters/postgres.ts b/server/src/modules/active-run-watchdog/adapters/postgres.ts index 2fdc6f68f3c..151c57e7a16 100644 --- a/server/src/modules/active-run-watchdog/adapters/postgres.ts +++ b/server/src/modules/active-run-watchdog/adapters/postgres.ts @@ -1,4 +1,4 @@ -import { notifyActiveRunSilence } from "../../../services/live-run-recovery-notifications.js"; +import { notifyActiveRunSilence, notifyLiveRunRecovery } from "../../../services/live-run-recovery-notifications.js"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "../../../services/delivery-work-notifications.js"; import { notifyExternalAgentSettlement } from "../../external-agents/index.js"; import { notifyNativeStatusReassessment } from "../../../services/native-status-reassessment-notifications.js"; @@ -348,6 +348,7 @@ export function createPostgresWatchdogAdapter(db: Db): WatchdogRunReader & Watch }; const transactionResult = await db.transaction(async (tx) => { + await notifyLiveRunRecovery(tx, input.run); await notifyInstructionCollection(tx, { companyId, runId: input.run.id }); await notifyExternalAgentSettlement(tx, { companyId, runId: input.run.id }); await notifyCancelledWorkspacePreservation(tx, { companyId, runId: input.run.id }); diff --git a/server/src/services/environment-cleanup-notifications.ts b/server/src/services/environment-cleanup-notifications.ts index bd26350e3ab..ce0ded6fcc0 100644 --- a/server/src/services/environment-cleanup-notifications.ts +++ b/server/src/services/environment-cleanup-notifications.ts @@ -5,13 +5,15 @@ import { notifyNativeEnvironmentSettlement, type NativeEnvironmentSettlementScop import type { Db } from "@paperclipai/db"; import { DELIVERY_QUEUES, notifyDeliveryWork } from "./delivery-work-notifications.js"; -export async function notifyEnvironmentCleanup(transaction: object, scope?: NativeEnvironmentSettlementScope): Promise { +export type EnvironmentCleanupWorkScope = NativeEnvironmentSettlementScope & { leaseId?: string }; + +export async function notifyEnvironmentCleanup(transaction: object, scope?: EnvironmentCleanupWorkScope): Promise { await notifyLiveResourceRecovery(transaction, scope); - if (scope?.runId && typeof (transaction as Db).select === "function") { + if (scope && (scope.runId || scope.leaseId) && typeof (transaction as Db).select === "function") { const peers = await (transaction as Db).select({ id: environmentLeases.id, companyId: environmentLeases.companyId, runId: environmentLeases.heartbeatRunId }).from(environmentLeases).where(and(eq(environmentLeases.status, "active"), sql`exists (select 1 from environment_leases changed where changed.company_id = ${scope.companyId} - and changed.heartbeat_run_id = ${scope.runId} and changed.provider_lease_id is not null + and ${scope.leaseId ? sql`changed.id = ${scope.leaseId}` : sql`changed.heartbeat_run_id = ${scope.runId}`} and changed.provider_lease_id is not null and changed.provider = ${environmentLeases.provider} and changed.provider_lease_id = ${environmentLeases.providerLeaseId})`)); for (const peer of peers) await notifyDeliveryWork(transaction, DELIVERY_QUEUES.orphanActiveLeases, JSON.stringify({ companyId: peer.companyId, leaseId: peer.id })); @@ -21,7 +23,7 @@ export async function notifyEnvironmentCleanup(transaction: object, scope?: Nati await notifyDeliveryWork(transaction, DELIVERY_QUEUES.historicalCleanup); } -export function writeEnvironmentCleanup(db: Db, write: (tx: Db) => PromiseLike, scope: NativeEnvironmentSettlementScope): Promise { +export function writeEnvironmentCleanup(db: Db, write: (tx: Db) => PromiseLike, scope: EnvironmentCleanupWorkScope): Promise { return db.transaction(async tx => { await notifyEnvironmentCleanup(tx, scope); return write(tx as unknown as Db); diff --git a/server/src/services/heartbeat/live-recovery-work.ts b/server/src/services/heartbeat/live-recovery-work.ts index d2d9ab78a5b..a15cbeed18c 100644 --- a/server/src/services/heartbeat/live-recovery-work.ts +++ b/server/src/services/heartbeat/live-recovery-work.ts @@ -66,10 +66,12 @@ export function registerLiveRecoveryWork(db: Db, coordinator: ReturnType'nativeQuestionCancellation' is null`) : kind === "question" ? and(inArray(heartbeatRuns.status, ["queued", "running", "scheduled_retry"]), sql`${heartbeatRuns.contextSnapshot}->'nativeQuestionCancellation' is not null`) - : kind === "active" ? eq(heartbeatRuns.status, "running") + : kind === "active" ? and(eq(heartbeatRuns.status, "running"), + sql`${heartbeatRuns.contextSnapshot}->'nativeQuestionCancellation' is null`) : and(eq(heartbeatRuns.runtimeMode, "native"), inArray(heartbeatRuns.status, ["failed", "cancelled", "timed_out", "interrupted"]), isNotNull(heartbeatRuns.finishedAt), or(isNotNull(heartbeatRuns.processPid), isNotNull(heartbeatRuns.processGroupId), isNotNull(heartbeatRuns.processStartedAt))), diff --git a/server/src/services/heartbeat/recovery.ts b/server/src/services/heartbeat/recovery.ts index 75afd5d881c..089a4ab8f66 100644 --- a/server/src/services/heartbeat/recovery.ts +++ b/server/src/services/heartbeat/recovery.ts @@ -916,8 +916,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD }; } - async function recoverNativeRunsAfterRestart(now = new Date(), runIds?: string[]) { - if (!runIds) { + async function recoverNativeRunsAfterRestart(now = new Date(), runIds?: string[], options?: { skipDelegatedWork?: boolean }) { + if (!runIds && !options?.skipDelegatedWork) { await reconcileRetainedWorkspaces(db, environmentRuntime, resumeRemoteStopComments); await reconcileNativeFinalizations(db, undefined, { environmentRuntime, @@ -1529,11 +1529,11 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD if (lease.heartbeatRunId && !activeRunExecutions.has(lease.heartbeatRunId) && !adapterExecutionControls.has(lease.heartbeatRunId) && await preserveOrphanedNativeWorkspace(db, lease)) recovered += 1; - await deferOrphanedActiveLease(lease.id); + if (!opts.leaseId) await deferOrphanedActiveLease(lease.id); continue; } if (!(await allowLegacyShutdownWorkspaceCleanup(db, lease))) { - await deferOrphanedActiveLease(lease.id); + if (!opts.leaseId) await deferOrphanedActiveLease(lease.id); continue; } // A provider resource id names one physical sandbox. A different lease @@ -1560,7 +1560,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD // Defer this row so the fixed-size page reaches the rows behind // it next tick, instead of re-selecting the same guarded rows // forever. - await deferOrphanedActiveLease(lease.id); + if (!opts.leaseId) await deferOrphanedActiveLease(lease.id); continue; } } @@ -1582,7 +1582,7 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD eq(environmentLeases.status, "active"), ), ) - .returning({ id: environmentLeases.id }), { companyId: lease.companyId, runId: lease.heartbeatRunId ?? undefined }); + .returning({ id: environmentLeases.id }), { companyId: lease.companyId, runId: lease.heartbeatRunId ?? undefined, leaseId: lease.id }); if (flipped.length > 0) recovered += 1; } @@ -2292,6 +2292,10 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD runningProcesses.has(run.id) || activeRunExecutions.has(run.id) || coordinatorOwnedByCurrentController; + if (nativeRun && !locallyTracked && nativeControllerLeaseExpiresAt && nativeControllerLeaseExpiresAt > now) { + scope.onDeferredDeadline?.(nativeControllerLeaseExpiresAt.getTime()); + continue; + } if ( nativeRun && ([ @@ -2302,6 +2306,8 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD ].includes(nativeRecoveryState ?? "") || nativeCoordinatorPhase === "retryable_failure") ) { + if (nativeControllerLeaseExpiresAt && nativeControllerLeaseExpiresAt > now) + scope.onDeferredDeadline?.(nativeControllerLeaseExpiresAt.getTime()); continue; } const observedOwnerUnverified = @@ -2691,7 +2697,10 @@ export function createHeartbeatRecovery(db: Db, dependencies: HeartbeatRecoveryD active: scope => recoverActiveExecutions(scope), settled: async scope => { if (!scope.runId || activeRunExecutions.has(scope.runId) || runningProcesses.has(scope.runId) - || adapterExecutionControls.has(scope.runId)) return; + || adapterExecutionControls.has(scope.runId)) { + scope.onDeferredDeadline(Date.now() + 30_000); + return; + } await releaseSettledNativeRunProcess(db, scope.runId, scope); }, orphanLease: scope => sweepOrphanedActiveLeases({ ...scope, backoffMs: 5 * 60_000 }), diff --git a/server/src/services/instance-settings.ts b/server/src/services/instance-settings.ts index a3e2b2f3b14..ad47e240014 100644 --- a/server/src/services/instance-settings.ts +++ b/server/src/services/instance-settings.ts @@ -1,4 +1,4 @@ -import { notifyActiveRunSilence } from "./live-run-recovery-notifications.js"; +import { notifyLiveRunRecovery, notifyLiveResourceRecovery } from "./live-run-recovery-notifications.js"; import { notifyDeferredExecutionEligibility } from "./deferred-execution-notifications.js"; import { notifyRunDispatch } from "./run-dispatch-notifications.js"; import { notifySkillVersionRetentionReconstruction } from "./skill-version-retention-notifications.js"; @@ -635,7 +635,8 @@ export function instanceSettingsService(db: Db, options: InstanceSettingsService if (patch.enableWorktreeRunExecution !== undefined) { await notifyRunDispatch(tx); await notifyDeferredExecutionEligibility(tx); - await notifyActiveRunSilence(tx); + await notifyLiveRunRecovery(tx); + await notifyLiveResourceRecovery(tx); await notifyDeliveryWork(tx, DELIVERY_QUEUES.agentTimers); await notifyExternalAgentSettlement(tx); await notifyInstructionCommit(tx); diff --git a/server/src/services/live-run-recovery-notifications.ts b/server/src/services/live-run-recovery-notifications.ts index b270e3b9564..05ec8842d15 100644 --- a/server/src/services/live-run-recovery-notifications.ts +++ b/server/src/services/live-run-recovery-notifications.ts @@ -8,10 +8,12 @@ export async function notifyActiveRunSilence(tx: object, scope?: LiveRunRecovery } export async function notifyLiveRunRecovery(tx: object, scope?: LiveRunRecoveryScope) { - const hint = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, agentId: scope.agentId }) : "*"; + const hint = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId }) : "*"; for (const queue of [DELIVERY_QUEUES.nativeProcessSessions, DELIVERY_QUEUES.nativeQuestionCancellations, - DELIVERY_QUEUES.activeExecutionRecovery, DELIVERY_QUEUES.settledNativeProcesses, DELIVERY_QUEUES.strandedAgentStatus]) + DELIVERY_QUEUES.activeExecutionRecovery, DELIVERY_QUEUES.settledNativeProcesses]) await notifyDeliveryWork(tx, queue, hint); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.strandedAgentStatus, scope + ? JSON.stringify({ companyId: scope.companyId, agentId: scope.agentId }) : "*"); await notifyActiveRunSilence(tx, scope); } @@ -19,9 +21,12 @@ export type LiveResourceRecoveryScope = { companyId: string; runId?: string; lea export async function notifyLiveResourceRecovery(tx: object, scope?: LiveResourceRecoveryScope) { const hint = scope ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId, leaseId: scope.leaseId }) : "*"; - for (const queue of [DELIVERY_QUEUES.orphanActiveLeases, DELIVERY_QUEUES.legacyShutdownSettlement, - DELIVERY_QUEUES.strandedAgentStatus, DELIVERY_QUEUES.settledNativeProcesses]) + for (const queue of [DELIVERY_QUEUES.orphanActiveLeases, DELIVERY_QUEUES.legacyShutdownSettlement]) await notifyDeliveryWork(tx, queue, hint); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.settledNativeProcesses, scope + ? JSON.stringify({ companyId: scope.companyId, runId: scope.runId }) : "*"); + await notifyDeliveryWork(tx, DELIVERY_QUEUES.strandedAgentStatus, scope + ? JSON.stringify({ companyId: scope.companyId }) : "*"); } export async function notifyStrandedAgentStatus(tx: object, scope: { companyId: string; agentId: string }) { diff --git a/server/src/services/native-local-process-stop.ts b/server/src/services/native-local-process-stop.ts index e30c18e9cdc..69630667313 100644 --- a/server/src/services/native-local-process-stop.ts +++ b/server/src/services/native-local-process-stop.ts @@ -147,7 +147,7 @@ export async function readNativeLocalProcessStop(db: Db, companyId: string, runI type SettledProcessRelease = "released" | "pending" | "skipped"; export async function releaseSettledNativeRunProcess(db: Db, runId: string, options: { onDeferredDeadline?: (at: number) => void } = {}): Promise { - return db.transaction(async transaction => { + const outcome = await db.transaction(async transaction => { const tx = transaction as unknown as Db; const [run] = await tx.select({ id: heartbeatRuns.id, companyId: heartbeatRuns.companyId, agentId: heartbeatRuns.agentId, runtimeMode: heartbeatRuns.runtimeMode, status: heartbeatRuns.status, finishedAt: heartbeatRuns.finishedAt, @@ -173,7 +173,8 @@ export async function releaseSettledNativeRunProcess(db: Db, runId: string, opti eq(heartbeatRunEvents.eventType, PROCESS_IDENTITY_RECORDED), isNull(heartbeatRunEvents.sourceEventId), )).orderBy(desc(heartbeatRunEvents.seq)).limit(1); if (identity?.payload?.targetKind !== "local" || identity.payload.hostname !== os.hostname() || - identity.payload.processPid !== run.processPid || identity.payload.processGroupId !== run.processGroupId) return "skipped"; + identity.payload.processPid !== run.processPid || identity.payload.processGroupId !== run.processGroupId || + !run.processStartedAt || identity.payload.processStartedAt !== run.processStartedAt.toISOString()) return "skipped"; if (!(await recordNativeLocalProcessStop(tx, run))) { options.onDeferredDeadline?.(Date.now() + 30_000); return "pending"; @@ -184,8 +185,10 @@ export async function releaseSettledNativeRunProcess(db: Db, runId: string, opti await tx.update(heartbeatRuns).set({ processPid: null, processGroupId: null, processStartedAt: null, updatedAt: new Date(), }).where(eq(heartbeatRuns.id, run.id)); - return "released"; + return "released" as const; }); + if (outcome !== "pending") pendingSettledProcessReleases.delete(runId); + return outcome; } const MAX_SETTLED_PROCESS_RELEASE_ATTEMPTS = 20;