diff --git a/doc/run-log-events.md b/doc/run-log-events.md index d71bbe9283e..e8b60c76481 100644 --- a/doc/run-log-events.md +++ b/doc/run-log-events.md @@ -330,6 +330,12 @@ the initiator, reason, and recording time. Recorded stop intent survives adapter completion. `controller_lease` means the host stopped its own legacy adapter after it lost the durable controller lease; the reason names a closed cause (`renewal_rejected`, `renewal_deadline`, or `renewal_error`). +A lease lost during run setup (for example a rejected renewal while preparing +the workspace) settles the run `failed` with error code `controller_lease_lost`, +the same `controller_lease` cancellation evidence, and +`executionRecovery.providerWorkStarted: false`. Recovery retries it as transient +infrastructure instead of blocking on `setup_failed`. A setup-phase error after +provider dispatch began keeps `setup_failed`, so started work is never retried. The local lifecycle event includes this evidence. Started cancellations without an expected stop are also reported to Sentry; its cancellation diagnostics contain only source, expectedness, initiator type, and the closed lease-loss cause, never diff --git a/server/src/__tests__/heartbeat-process-recovery.test.ts b/server/src/__tests__/heartbeat-process-recovery.test.ts index 5fc23dd2a86..66f16134ef1 100644 --- a/server/src/__tests__/heartbeat-process-recovery.test.ts +++ b/server/src/__tests__/heartbeat-process-recovery.test.ts @@ -2112,6 +2112,141 @@ describeEmbeddedPostgres("heartbeat orphaned process recovery", () => { ).resolves.toEqual({ status: "idle", errorReason: null }); }); + it("retries a continuation whose controller lease is lost before dispatch instead of blocking the issue", async () => { + const { agentId, runId, issueId } = await seedQueuedIssueRunFixture(); + const originalWatch = controllerLeases.watchLegacyControllerLease; + // Expire the claimed lease before workspace preparation renews it, so the + // real renewal is rejected and the watchdog stops setup before dispatch. + const watcher = vi.spyOn(controllerLeases, "watchLegacyControllerLease").mockImplementation((...args) => { + const lease = originalWatch(...args); + if (args[1].id !== runId) return lease; + return { ...lease, async assertOwned(stage?: "dispatching") { + if (stage === undefined) { + await db.update(heartbeatRuns).set({ controllerLeaseExpiresAt: new Date(Date.now() - 60_000) }) + .where(eq(heartbeatRuns.id, runId)); + } + return lease.assertOwned(stage); + } }; + }); + const heartbeat = heartbeatService(db); + try { + await heartbeat.resumeQueuedRuns(); + await waitForRunToSettle(heartbeat, runId); + await heartbeat.waitForRunExecutionDrain(runId); + + expect(await heartbeat.getRun(runId)).toMatchObject({ + status: "failed", + errorCode: "controller_lease_lost", + resultJson: { + cancellation: { source: "controller_lease", reason: "Legacy controller lease lost (renewal_rejected)" }, + executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + }, + }); + expect( + mockAdapterExecute.mock.calls.some( + ([input]) => (input as { runId?: string } | undefined)?.runId === runId, + ), + ).toBe(false); + const retries = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.retryOfRunId, runId)); + expect(retries).toHaveLength(1); + // One bounded transient retry, instead of escalating `setup_failed`. + expect(retries[0]).toMatchObject({ scheduledRetryReason: "transient_failure", scheduledRetryAttempt: 1 }); + expect( + await db.select({ status: issues.status }).from(issues).where(eq(issues.id, issueId)) + .then((rows) => rows[0]?.status), + ).toBe("in_progress"); + expect( + await db.select({ status: agents.status }).from(agents).where(eq(agents.id, agentId)) + .then((rows) => rows[0]?.status), + ).not.toBe("error"); + } finally { + await heartbeat.drainActiveRunExecutions().catch(() => undefined); + watcher.mockRestore(); + } + }); + + it("retries an accepted interaction continuation whose controller lease is lost before dispatch", async () => { + const { companyId, agentId, runId, wakeupRequestId, issueId } = await seedQueuedIssueRunFixture(); + const interactionId = randomUUID(); + await db.insert(issueThreadInteractions).values({ + id: interactionId, + companyId, + issueId, + kind: "request_confirmation", + status: "accepted", + continuationPolicy: "wake_assignee_on_accept", + createdByAgentId: agentId, + resolvedByUserId: "responsible-user", + resolvedAt: new Date("2026-03-19T00:00:00.000Z"), + payload: { + version: 1, + prompt: "Approve the plan?", + target: { type: "issue_document", issueId, key: "plan", revisionId: randomUUID() }, + }, + result: { version: 1, outcome: "accepted" }, + }); + const interactionContext = { + issueId, + interactionId, + interactionKind: "request_confirmation", + interactionStatus: "accepted", + mutation: "interaction", + }; + await db.update(agentWakeupRequests) + .set({ source: "automation", reason: "issue_commented", payload: interactionContext }) + .where(eq(agentWakeupRequests.id, wakeupRequestId)); + await db.update(heartbeatRuns) + .set({ + invocationSource: "automation", + contextSnapshot: { ...interactionContext, taskId: issueId, wakeReason: "issue_commented" }, + }) + .where(eq(heartbeatRuns.id, runId)); + await db.update(issues).set({ status: "in_progress" }).where(eq(issues.id, issueId)); + + const originalWatch = controllerLeases.watchLegacyControllerLease; + const watcher = vi.spyOn(controllerLeases, "watchLegacyControllerLease").mockImplementation((...args) => { + const lease = originalWatch(...args); + if (args[1].id !== runId) return lease; + return { ...lease, async assertOwned(stage?: "dispatching") { + if (stage === undefined) { + await db.update(heartbeatRuns).set({ controllerLeaseExpiresAt: new Date(Date.now() - 60_000) }) + .where(eq(heartbeatRuns.id, runId)); + } + return lease.assertOwned(stage); + } }; + }); + const heartbeat = heartbeatService(db); + try { + await heartbeat.resumeQueuedRuns(); + await waitForRunToSettle(heartbeat, runId); + await heartbeat.waitForRunExecutionDrain(runId); + + expect(await heartbeat.getRun(runId)).toMatchObject({ + status: "failed", + errorCode: "controller_lease_lost", + resultJson: { executionRecovery: { kind: "bootstrap", providerWorkStarted: false } }, + }); + expect( + mockAdapterExecute.mock.calls.some( + ([input]) => (input as { runId?: string } | undefined)?.runId === runId, + ), + ).toBe(false); + const retries = await db.select().from(heartbeatRuns).where(eq(heartbeatRuns.retryOfRunId, runId)); + expect(retries).toHaveLength(1); + expect(retries[0]).toMatchObject({ + scheduledRetryReason: INTERACTION_CONTINUATION_INFRA_RETRY_REASON, + scheduledRetryAttempt: 1, + }); + expect( + await db.select({ status: issues.status }).from(issues).where(eq(issues.id, issueId)) + .then((rows) => rows[0]?.status), + ).toBe("in_progress"); + } finally { + await heartbeat.drainActiveRunExecutions().catch(() => undefined); + watcher.mockRestore(); + } + }); + it("does not queue immediate recovery when the failed run's issue is hidden", async () => { mockAdapterExecute.mockResolvedValueOnce({ exitCode: 1, diff --git a/server/src/services/heartbeat.ts b/server/src/services/heartbeat.ts index f8bbb4b6330..b71a0cebc5c 100644 --- a/server/src/services/heartbeat.ts +++ b/server/src/services/heartbeat.ts @@ -3645,7 +3645,9 @@ export function heartbeatService( ); } else { await runCompletion.failRunSetup({ - run, runId, outerErr, identityRedactor, readFailureReportSecrets, + run, runId, outerErr, signal: executionControl.controller.signal, + providerDispatchStarted: legacyAdapterEntered || nativeDispatchStarted, + identityRedactor, readFailureReportSecrets, }); } } finally { diff --git a/server/src/services/heartbeat/retries.ts b/server/src/services/heartbeat/retries.ts index eaf07ae7b7f..c6c5d296ac9 100644 --- a/server/src/services/heartbeat/retries.ts +++ b/server/src/services/heartbeat/retries.ts @@ -16,6 +16,7 @@ import { accountingForScheduledRetry, } from "../execution-recovery-attempt.js"; import { WORKSPACE_GIT_SCAN_ERROR_CODES } from "../workspace-git-operation-scheduler.js"; +import { CONTROLLER_LEASE_LOST_FAILURE_CODE } from "../legacy-controller-lease.js"; import { randomUUID } from "node:crypto"; import { and, @@ -320,9 +321,12 @@ function isRetryableInteractionContinuationInfrastructureFailure( "error" | "errorCode" | "resultJson" >, ) { + // `controller_lease_lost` is only recorded before provider dispatch, so the + // retry cannot repeat started work. if ( run.errorCode === WORKSPACE_VALIDATION_FAILURE_CODE || - run.errorCode === "process_lost" + run.errorCode === "process_lost" || + run.errorCode === CONTROLLER_LEASE_LOST_FAILURE_CODE ) { return true; } diff --git a/server/src/services/heartbeat/run-completion.test.ts b/server/src/services/heartbeat/run-completion.test.ts index bb1e74005c3..38b8946d75b 100644 --- a/server/src/services/heartbeat/run-completion.test.ts +++ b/server/src/services/heartbeat/run-completion.test.ts @@ -108,7 +108,7 @@ describe.skipIf(!support.supported)("heartbeat run completion boundary", () => { }; const completion = createHeartbeatRunCompletion(db, deps); const failure = (err: unknown): FailHeartbeatRunInput => ({ ...input, runId: run.id, err, identityRedactor: createAgentIdentityRedactor("private-identity-material"), requiredWorkspaceRestoreEvidence: { workspaceRestoreFailure: { reason: "missing_base" } }, legacyAdapterEntered: true, goalCheckpointSession: { current: null }, previousSessionDisplayId: "previous-session", taskSession: null }); - const setup = (outerErr: unknown) => ({ run, runId: run.id, outerErr, identityRedactor: createAgentIdentityRedactor(), readFailureReportSecrets: () => [] }); + const setup = (outerErr: unknown, providerDispatchStarted = false) => ({ run, runId: run.id, outerErr, signal: controller.signal, providerDispatchStarted, identityRedactor: createAgentIdentityRedactor(), readFailureReportSecrets: () => [] }); return { run, agent, wake, deps, controller, input, completion, failure, setup }; } const read = (id: string) => db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)).then(rows => rows[0]!); @@ -187,9 +187,10 @@ describe.skipIf(!support.supported)("heartbeat run completion boundary", () => { it("records the lease-loss cause and timings when setup fails on the abort reason", async () => { const f = await fixture(); - await f.completion.failRunSetup(f.setup(new LegacyControllerLeaseLostError("renewal_deadline", - { sinceRenewalMs: 60_004, renewalPendingMs: null, deadlineLateMs: 55_000, renewalCount: 3 }))); - expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "setup_failed", resultJson: { + f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline", + { sinceRenewalMs: 60_004, renewalPendingMs: null, deadlineLateMs: 55_000, renewalCount: 3 })); + await f.completion.failRunSetup(f.setup(f.controller.signal.reason)); + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost", resultJson: { executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, controllerLeaseLoss: { cause: "renewal_deadline", sinceRenewalMs: 60_004, renewalPendingMs: null, deadlineLateMs: 55_000, renewalCount: 3 } } }); @@ -327,6 +328,34 @@ describe.skipIf(!support.supported)("heartbeat run completion boundary", () => { } }); }); + it("records a lease lost before dispatch as a retryable host stop, not an opaque setup failure", async () => { + const f = await fixture(); + f.controller.abort(new LegacyControllerLeaseLostError("renewal_rejected")); + await f.completion.failRunSetup(f.setup(f.controller.signal.reason)); + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost", resultJson: { + cancellation: { source: "controller_lease", expected: false, reason: "Legacy controller lease lost (renewal_rejected)" }, + executionRecovery: { kind: "bootstrap", providerWorkStarted: false } } }); + expect(f.deps.releaseIssueExecutionAndPromote).toHaveBeenCalledOnce(); + expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "failed", expect.any(String), expect.objectContaining({ keepIdleOnFailure: true })); + }); + + it("attributes a lease loss even when a setup step throws its own abort error", async () => { + const f = await fixture(); + f.controller.abort(new LegacyControllerLeaseLostError("renewal_deadline")); + await f.completion.failRunSetup(f.setup(new Error("environment acquisition aborted"))); + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "controller_lease_lost", + resultJson: { cancellation: { source: "controller_lease", reason: "Legacy controller lease lost (renewal_deadline)" } } }); + }); + + it("does not make a lease loss retryable once provider work has started", async () => { + const f = await fixture(); + f.controller.abort(new LegacyControllerLeaseLostError("renewal_error")); + await f.completion.failRunSetup(f.setup(new Error("usage capture write failed"), true)); + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "setup_failed", + resultJson: { cancellation: { source: "controller_lease", reason: "Legacy controller lease lost (renewal_error)" } } }); + expect(f.deps.finalizeAgentStatus).toHaveBeenCalledWith(f.agent.id, "failed", expect.any(String), expect.objectContaining({ keepIdleOnFailure: false })); + }); + it("leaves a winning terminal outcome and agent state untouched after a late setup error", async () => { const f = await fixture({ status: "succeeded", resultJson: { winner: "completion" } }); await f.completion.failRunSetup(f.setup(new Error("late setup error"))); diff --git a/server/src/services/heartbeat/run-completion.ts b/server/src/services/heartbeat/run-completion.ts index 83767f3e780..e1a3d0a3738 100644 --- a/server/src/services/heartbeat/run-completion.ts +++ b/server/src/services/heartbeat/run-completion.ts @@ -7,7 +7,7 @@ import { CONFIGURATION_INCOMPLETE_FAILURE_CODE, ConfigurationIncompleteFailure } import { isWorkspaceValidationFailedRun, isWorkspaceValidationFailure, attachPaperclipSessionMetadataToSessionParams } from "./workspaces.js"; import { preserveWorkspaceRestoreRecoveryMetadataSql } from "../legacy-workspace-restore-recovery.js"; import { cancellationResultJson, controllerLeaseLossCancellation, readRunCancellation } from "../run-cancellation.js"; -import { LegacyControllerLeaseLostError } from "../legacy-controller-lease.js"; +import { CONTROLLER_LEASE_LOST_FAILURE_CODE, LegacyControllerLeaseLostError } from "../legacy-controller-lease.js"; import { accountRunCost } from "../run-cost-accounting.js"; import { isConversation, settleConversationTurn } from "../agent-conversations.js"; import { legacyExecutionNeedsReconciliationWithEvidence } from "../legacy-execution-recovery.js"; @@ -133,6 +133,9 @@ export interface FailHeartbeatRunSetupInput { run: Run; runId: string; outerErr: unknown; + signal: AbortSignal; + /** True once a legacy adapter or native dispatch began provider work. */ + providerDispatchStarted: boolean; identityRedactor: Pick, "redact">; readFailureReportSecrets: () => string[]; } @@ -1258,7 +1261,13 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC } async function failRunSetup(input: FailHeartbeatRunSetupInput) { - const { run, runId, outerErr, identityRedactor, readFailureReportSecrets } = input; + const { run, runId, outerErr, signal, providerDispatchStarted, identityRedactor, readFailureReportSecrets } = input; + // The lease watchdog stopped preparation because this host no longer owns + // the run. That is host infrastructure, not a defect in the agent or setup. + // A post-dispatch error can also land here (for example a failed usage + // capture write), so only a stop before dispatch is a retryable lease loss. + const controllerLeaseLost = !providerDispatchStarted && + signal.reason instanceof LegacyControllerLeaseLostError; // Setup code before adapter.execute threw (e.g. ensureRuntimeState, resolveWorkspaceForRun). // The inner catch did not fire, so we must record the failure here. const message = redactCurrentUserText( @@ -1297,6 +1306,7 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC nonRetryablePreflightFailureCode(outerErr); const workspaceGitScanFailure = isWorkspaceGitScanError(outerErr) ? outerErr : null; const setupFailureErrorCode = + (controllerLeaseLost ? CONTROLLER_LEASE_LOST_FAILURE_CODE : null) ?? workspaceGitScanFailure?.code ?? workspaceValidationSetupFailure?.code ?? configurationIncompleteSetupFailure?.code ?? @@ -1341,8 +1351,10 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC const setupFailureResultJson = { ...setupFailureDetails, ...(connectionFailure ? { connectionFailure } : {}), - // A lease lost during setup surfaces as the thrown abort reason. + // A lease lost during setup surfaces as the thrown abort reason, or as + // the signal's reason when a setup step threw a different error after it. ...controllerLeaseLossEvidence(outerErr), + ...controllerLeaseLossResultJson(signal), executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, }; const setupFailureWrite = await setRunStatusIfRunning(runId, "failed", { @@ -1475,7 +1487,7 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC // Keep the failed run and its safe provider refusal authoritative, // but return the agent to idle so clients do not also announce a // misleading agent-wide error for the same rejected chat turn. - keepIdleOnFailure: Boolean(nonRetryablePreflightCode), + keepIdleOnFailure: Boolean(nonRetryablePreflightCode) || controllerLeaseLost, }).catch(() => undefined); } } diff --git a/server/src/services/heartbeat/run-lifecycle.ts b/server/src/services/heartbeat/run-lifecycle.ts index 135a085292c..b92b8054fbd 100644 --- a/server/src/services/heartbeat/run-lifecycle.ts +++ b/server/src/services/heartbeat/run-lifecycle.ts @@ -24,6 +24,7 @@ import { rethrowNativeCancellationLockConflict, } from "../native-runtime/native-cancellation-request.js"; import { cancellationResultJson } from "../run-cancellation.js"; +import { CONTROLLER_LEASE_LOST_FAILURE_CODE } from "../legacy-controller-lease.js"; import { accountRunCost } from "../run-cost-accounting.js"; import { isWaitingConversation } from "../agent-conversations.js"; import { PROCESS_IDENTITY_RECORDED } from "../native-local-process-stop.js"; @@ -247,6 +248,7 @@ export const NON_RETRYABLE_PREFLIGHT_FAILURE_CODES = new Set([ // of these codes when a failure happens before `adapter.execute`. const PRE_ADAPTER_SETUP_FAILURE_CODES = new Set([ "setup_failed", + CONTROLLER_LEASE_LOST_FAILURE_CODE, CONFIGURATION_INCOMPLETE_FAILURE_CODE, WORKSPACE_VALIDATION_FAILURE_CODE, ...NON_RETRYABLE_PREFLIGHT_FAILURE_CODES, diff --git a/server/src/services/legacy-controller-lease.ts b/server/src/services/legacy-controller-lease.ts index 10ee785e4ea..fe6b7e68f28 100644 --- a/server/src/services/legacy-controller-lease.ts +++ b/server/src/services/legacy-controller-lease.ts @@ -10,6 +10,10 @@ export const LEGACY_CONTROLLER_RENEW_MS = 10_000; type Run = typeof heartbeatRuns.$inferSelect; +/** A lease lost before adapter dispatch: no provider work began, so the + * continuation is retryable rather than an opaque `setup_failed`. */ +export const CONTROLLER_LEASE_LOST_FAILURE_CODE = "controller_lease_lost"; + /** Abort reason for a lost lease, so completion can attribute the stop. */ export class LegacyControllerLeaseLostError extends Error { constructor( diff --git a/server/src/services/recovery/provider-failure-classification.test.ts b/server/src/services/recovery/provider-failure-classification.test.ts index 9343e878138..31407ac82c3 100644 --- a/server/src/services/recovery/provider-failure-classification.test.ts +++ b/server/src/services/recovery/provider-failure-classification.test.ts @@ -21,6 +21,12 @@ describe("classifyAdapterFailureForRecovery", () => { expect(classifyContinuationFailure(unknown as never).kind).toBe("transient_infra"); expect(isConfigurationIncompleteFailedRun(unknown)).toBe(false); }); + it("retries a continuation whose host lost the controller lease before dispatch", () => { + expect(classifyContinuationFailure({ errorCode: "controller_lease_lost", error: "Legacy controller lease lost", resultJson: null } as never)) + .toMatchObject({ kind: "transient_infra", maxAttempts: 3 }); + expect(classifyContinuationFailure({ errorCode: "setup_failed", error: "Legacy controller lease lost", resultJson: null } as never).kind) + .toBe("non_retryable"); + }); it.each(["acpx_auth_required", "claude_auth_required", "codex_auth_required", "adapter_auth_missing", "refresh_token_reused", "authentication_required"])("does not automatically retry provider authentication failure %s", (errorCode) => { const classification = classifyRunLiveness({ runStatus: "failed", issue: null, errorCode, authenticationRepairRequested: true }); const run = { errorCode, ...classification }; diff --git a/server/src/services/recovery/service.ts b/server/src/services/recovery/service.ts index 23a092420c1..1248f6cfb9a 100644 --- a/server/src/services/recovery/service.ts +++ b/server/src/services/recovery/service.ts @@ -13,7 +13,7 @@ import { decideLegacyContinuation, legacyDispositionEpisode, legacyDispositionFingerprint, LEGACY_DISPOSITION_REPAIR_INSTRUCTION, type LegacyDispositionEpisode, } from "./legacy-continuation.js"; -import { hasLiveLegacyController } from "../legacy-controller-lease.js"; +import { CONTROLLER_LEASE_LOST_FAILURE_CODE, hasLiveLegacyController } from "../legacy-controller-lease.js"; import { isCompletedOnboardingHandoffWake } from "../chat-completion-delivery.js"; import { instanceSettingsService } from "../instance-settings.js"; import { isWaitingConversation, settleConversationTurn, deliverConversationComments } from "../agent-conversations.js"; @@ -495,6 +495,8 @@ const TRANSIENT_INFRA_CONTINUATION_ERROR_CODES = new Set([ "claude_transient_upstream", "provider_quota", "timeout", + // The host lost run ownership before dispatch; no provider work began. + CONTROLLER_LEASE_LOST_FAILURE_CODE, ]); const NON_RETRYABLE_CONTINUATION_ERROR_CODES = new Set([