diff --git a/.changeset/fn-7721-worktree-heartbeat-retry-cap.md b/.changeset/fn-7721-worktree-heartbeat-retry-cap.md new file mode 100644 index 0000000000..6196a1b0c5 --- /dev/null +++ b/.changeset/fn-7721-worktree-heartbeat-retry-cap.md @@ -0,0 +1,7 @@ +--- +"@runfusion/fusion": patch +--- + +summary: Bound durable-agent heartbeat worktree-acquisition retries and count exhausted failures. +category: fix +dev: HeartbeatMonitor.executeHeartbeat's task worktree acquisition (agent-heartbeat.ts) previously requeued a task to "todo" on every acquisition failure with no cross-heartbeat retry cap, unlike Executor.createWorktree's bounded MAX_WORKTREE_RETRIES loop. Adds MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES (3), reusing Task.recoveryRetryCount as the counter (no schema migration). On cap exhaustion the task is terminally marked status:"failed" and a new onTaskAcquisitionExhausted callback is invoked; in-process-runtime.ts wires it to CentralCore.recordTaskCompletion(taskId, false) so the failure is counted (previously totalTasksFailed could stay 0 for this path). Investigation (FN-7721) found the other reported worktree-collision sub-gaps (branch-exists idempotent reuse, in-call retry cap, branch↔task-ID naming) already handled or not reproducing on HEAD — see task docs for evidence. diff --git a/docs/solutions/logic-errors/heartbeat-worktree-acquisition-unbounded-requeue.md b/docs/solutions/logic-errors/heartbeat-worktree-acquisition-unbounded-requeue.md new file mode 100644 index 0000000000..fbf8e68114 --- /dev/null +++ b/docs/solutions/logic-errors/heartbeat-worktree-acquisition-unbounded-requeue.md @@ -0,0 +1,84 @@ +--- +title: "Durable-agent heartbeat worktree acquisition retried unboundedly and failures went uncounted" +date: 2026-07-09 +category: docs/solutions/logic-errors +module: "engine agent heartbeat + worktree acquisition" +problem_type: logic_error +component: engine +symptoms: + - "A worktree-setup loop repeats an identical git worktree add -b failure across many hours" + - "The same branch collision is retried against several different generated worktree directories" + - "performanceSummary.totalTasksFailed / CentralCore failure stats stay 0 despite a real, eventually-terminal task failure" +root_cause: invariant_gap +resolution_type: code_fix +severity: medium +related_components: + - "packages/engine/src/agent-heartbeat.ts (HeartbeatMonitor.executeHeartbeat)" + - "packages/engine/src/runtimes/in-process-runtime.ts (recordTaskCompletion wiring)" +tags: + - worktrees + - heartbeat + - durable-agents + - retry-cap + - run-audit + - requeue-loop +--- + +# Durable-agent heartbeat worktree acquisition retried unboundedly and failures went uncounted + +## Problem + +`Executor.createWorktree` (the main task-execution path) has always bounded its +worktree-creation retries via `MAX_WORKTREE_RETRIES = 3` with exponential +backoff, and terminal failures flow through `Executor`'s `onError` callback into +`InProcessRuntime.recordTaskCompletion`, which increments `CentralCore`'s +`totalTasksFailed`. + +`HeartbeatMonitor.executeHeartbeat` has a **separate** task-worktree-acquisition +call path used when a durable custom agent's heartbeat picks up its assigned +task (`acquireTaskWorktree`, distinct from `Executor.createWorktree`). Before +this fix, that path had no retry cap at all: on any acquisition failure it +unconditionally moved the task back to `todo` (`preserveProgress: true`) and +completed the heartbeat run successfully. Each subsequent heartbeat interval +was an independent, uncounted retry of the same acquisition — a persistently +failing collision (e.g. a branch genuinely owned by a live foreign task with +sibling-branch-rename disabled) could requeue to `todo` indefinitely across +many hours, and because the task never reached a terminal `status: "failed"` +state, the failure was never recorded via `CentralCore.recordTaskCompletion`. + +## Root Cause + +Two independent retry/bounding mechanisms exist for worktree creation +(`Executor.createWorktree`'s in-call loop, and the heartbeat's per-cycle call), +but only the executor path was ever wired to a shared retry-cap counter and to +`CentralCore.recordTaskCompletion`. The heartbeat path bypassed both. + +## Fix + +- `agent-heartbeat.ts`: added `MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES = 3`. + Reuses `Task.recoveryRetryCount` (no schema migration) as a cross-heartbeat + counter. Below the cap, bump the counter and requeue as before. At/above the + cap, mark the task terminally `status: "failed"` (the same convention the + executor uses — the task stays visible in `todo` for `fn_task_retry`), log a + clear error citing the branch and attempt count, and invoke a new optional + `onTaskAcquisitionExhausted(taskId, detail)` callback. +- `runtimes/in-process-runtime.ts`: wires `onTaskAcquisitionExhausted` to + `this.recordTaskCompletion(taskId, false)`, so the failure is counted the + same way `Executor`'s `onError` counts one. + +## Prevention + +When adding a new retry loop around a resource-acquisition call that already +has an established bounded-retry convention elsewhere in the codebase (here: +`Executor.createWorktree`'s `MAX_WORKTREE_RETRIES` + `NonRetryableWorktreeError` ++ `onError` → `recordTaskCompletion`), verify the new call site reuses or +mirrors that convention instead of independently reimplementing a "just +requeue on failure" fallback with no cap and no failure-counting hook. + +## Related + +- `docs/solutions/logic-errors/repo-root-task-worktree-requeue-loop.md` — a + different (already-fixed) unbounded-requeue shape in the executor's own + resume path. +- Regression tests: `packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts`, + `packages/engine/src/__tests__/in-process-runtime.test.ts`. diff --git a/packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts b/packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts index b9acae3ce5..b4d9271155 100644 --- a/packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts +++ b/packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts @@ -37,6 +37,8 @@ describe("heartbeat worktree cwd", () => { getSettings: vi.fn().mockResolvedValue({}), getTask: vi.fn().mockResolvedValue({ id: "FN-1", title: "t", description: "d", column: "todo", dependencies: [], steps: [], log: [] }), moveTask: vi.fn(), + updateTask: vi.fn(), + logEntry: vi.fn(), appendAgentLog: vi.fn(), listTasks: vi.fn().mockResolvedValue([]), selectNextTaskForAgent: vi.fn().mockResolvedValue(null), @@ -68,5 +70,61 @@ describe("heartbeat worktree cwd", () => { await monitor.executeHeartbeat({ agentId: "a1", source: "on_demand" }); expect(piModule.createFnAgent).not.toHaveBeenCalled(); expect(taskStore.moveTask).toHaveBeenCalledWith("FN-1", "todo", { preserveProgress: true }); + // FN-7721: first failure bumps the bounded cross-heartbeat retry counter + // (reuses Task.recoveryRetryCount) rather than terminally failing the task. + expect(taskStore.updateTask).toHaveBeenCalledWith("FN-1", { recoveryRetryCount: 1 }); + }); + + // FN-7721 regression: reproduces the reported "worktree-setup loop" symptom + // (identical `git worktree add -b ` failure repeated indefinitely + // across heartbeat cycles, ~16.2h in the reported incident) and asserts the + // loop is now bounded: after MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES (3) + // consecutive cross-heartbeat acquisition failures for the same task, the + // task is terminally marked failed instead of being requeued to "todo" again. + it("terminally fails the task after the bounded cross-heartbeat worktree acquisition retry cap is hit (FN-7721)", async () => { + vi.spyOn(worktreeAcquisition, "acquireTaskWorktree").mockRejectedValue( + new Error("fatal: a branch named 'fusion/fn-1' already exists"), + ); + const onTaskAcquisitionExhausted = vi.fn(); + const monitor = new HeartbeatMonitor({ store, taskStore, rootDir: "/repo", onTaskAcquisitionExhausted }); + + // Simulate 3 independent heartbeat cycles, each reading back the + // recoveryRetryCount persisted by the previous cycle (as a real TaskStore + // would), reproducing the reported "identical failure against 4 different + // directories" loop shape without an unbounded real-time wait. + let recoveryRetryCount: number | null | undefined; + taskStore.updateTask.mockImplementation((_id: string, patch: Record) => { + if ("recoveryRetryCount" in patch) recoveryRetryCount = patch.recoveryRetryCount as number | null; + return Promise.resolve(); + }); + + for (let cycle = 0; cycle < 3; cycle++) { + taskStore.getTask.mockResolvedValue({ + id: "FN-1", title: "t", description: "d", column: "todo", dependencies: [], steps: [], log: [], + recoveryRetryCount, + }); + await monitor.executeHeartbeat({ agentId: "a1", source: "on_demand" }); + } + + // Bounded: exactly 3 acquisition attempts occurred (cap == 3), not an + // unbounded number of retries across heartbeat cycles. + expect(worktreeAcquisition.acquireTaskWorktree).toHaveBeenCalledTimes(3); + // Terminal failure surfaced via the same `status: "failed"` convention the + // executor uses, so it is a real, countable task failure rather than a + // silent infinite todo-requeue loop. + expect(taskStore.updateTask).toHaveBeenCalledWith("FN-1", expect.objectContaining({ + status: "failed", + recoveryRetryCount: null, + })); + expect(onTaskAcquisitionExhausted).toHaveBeenCalledTimes(1); + expect(onTaskAcquisitionExhausted.mock.calls[0][0]).toBe("FN-1"); + + // FN-7721 regression: `moveTask(..., "todo", ...)` reopen-to-todo semantics + // clear task.status/error back to undefined unless `preserveStatus: true` + // is passed (see store.ts's isReopenToTodoOrTriage clause). Without this, + // the `status: "failed"` written just above is silently wiped, and the + // task looks like an ordinary todo task that gets reassigned and retried + // from scratch — defeating the terminal-failure intent of this fix. + expect(taskStore.moveTask).toHaveBeenCalledWith("FN-1", "todo", expect.objectContaining({ preserveStatus: true })); }); }); diff --git a/packages/engine/src/__tests__/in-process-runtime.test.ts b/packages/engine/src/__tests__/in-process-runtime.test.ts index 8066f13ead..d092359128 100644 --- a/packages/engine/src/__tests__/in-process-runtime.test.ts +++ b/packages/engine/src/__tests__/in-process-runtime.test.ts @@ -23,6 +23,17 @@ describe("InProcessRuntime onStart duplicate guard", () => { expect(source).toContain("return this.chatStore;"); }); + it("wires heartbeat worktree-acquisition retry-cap exhaustion into CentralCore failure stats (FN-7721)", () => { + // FN-7721: a heartbeat-driven task worktree acquisition that exhausts its + // bounded cross-heartbeat retry cap must be counted the same way + // `Executor`'s `onError` counts a failure, so + // `performanceSummary.totalTasksFailed` / project health stats are not + // silently starved of a real failure. + const source = readFileSync(join(process.cwd(), "src/runtimes/in-process-runtime.ts"), "utf-8"); + expect(source).toContain("onTaskAcquisitionExhausted: (taskId, detail) => {"); + expect(source).toContain("this.recordTaskCompletion(taskId, false);"); + }); + it("rehydrates autopilot mission watches during startup recovery", () => { const source = readFileSync(join(process.cwd(), "src/runtimes/in-process-runtime.ts"), "utf-8"); expect(source).toContain("activeMissionAutopilot.recoverMissions(activeMissionStore)"); diff --git a/packages/engine/src/agent-heartbeat.ts b/packages/engine/src/agent-heartbeat.ts index 73d4bb85d7..e9f8d65a34 100644 --- a/packages/engine/src/agent-heartbeat.ts +++ b/packages/engine/src/agent-heartbeat.ts @@ -34,6 +34,23 @@ import { resolveHeartbeatPromptTemplate, resolveHeartbeatScopeDisciplineMode, se import { buildPromptLayers, collapsePromptLayers } from "./prompt-layers.js"; import { resolveAndEmitGoalContext } from "./goal-injection-diagnostics.js"; import { createLogger, heartbeatLog, formatError } from "./logger.js"; + +/** + * FNXC:WorktreeAcquisition 2026-07-09-00:00: + * Bounds how many consecutive heartbeat cycles may retry a task's worktree + * acquisition before the task is terminally failed instead of being requeued + * to "todo" forever. Mirrors `Executor.MAX_WORKTREE_RETRIES` (3): unlike the + * executor's in-call retry loop (which caps attempts within a single + * `tryCreateWorktree` invocation, bounded by exponential backoff of at most a + * few seconds), a durable agent's heartbeat re-runs `acquireTaskWorktree` from + * scratch on every heartbeat interval with no shared counter — a persistently + * failing acquisition (e.g. branch genuinely owned by a live foreign task with + * sibling-rename disabled) could requeue indefinitely across hours of + * heartbeat cycles (observed: ~16.2h across 4 distinct worktree directories, + * FN-7721). `Task.recoveryRetryCount` is reused here (no schema migration) + * as the cross-heartbeat counter. + */ +const MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES = 3; import { acquireTaskWorktree } from "./worktree-acquisition.js"; import { createRunAuditor, generateSyntheticRunId, type DatabaseMutationType, type EngineRunContext } from "./run-audit.js"; import { promptWithFallback } from "./pi.js"; @@ -125,6 +142,17 @@ export interface HeartbeatMonitorOptions { /** Optional self-improvement service for periodic self-improve injection */ selfImproveService?: SelfImproveServiceLike; secretsStore?: Pick; + /** + * FNXC:WorktreeAcquisition 2026-07-09-00:00: + * Callback invoked when a task's worktree acquisition has failed + * `MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES` consecutive times across heartbeat + * cycles and the task has been terminally marked `status: "failed"`. Lets the + * owning runtime (in-process-runtime.ts) route the failure into + * `CentralCore.recordTaskCompletion` the same way `Executor`'s `onError` does, + * so `performanceSummary.totalTasksFailed` is not silently starved of a real + * failure (FN-7721). + */ + onTaskAcquisitionExhausted?: (taskId: string, detail: string) => void; } /** Options for waking up an agent */ @@ -888,6 +916,7 @@ export class HeartbeatMonitor { private onTerminated?: (agentId: string, reason: string) => void; private onRunStarted?: (agentId: string, run: AgentHeartbeatRun) => void; private onRunCompleted?: (agentId: string, run: AgentHeartbeatRun) => void; + private onTaskAcquisitionExhausted?: (taskId: string, detail: string) => void; private taskStore?: TaskStore; private rootDir?: string; private messageStore?: MessageStore; @@ -921,6 +950,7 @@ export class HeartbeatMonitor { this.onTerminated = options.onTerminated; this.onRunStarted = options.onRunStarted; this.onRunCompleted = options.onRunCompleted; + this.onTaskAcquisitionExhausted = options.onTaskAcquisitionExhausted; this.taskStore = options.taskStore; this.rootDir = options.rootDir; this.messageStore = options.messageStore; @@ -2705,12 +2735,50 @@ export class HeartbeatMonitor { } catch (worktreeErr) { const detail = worktreeErr instanceof Error ? worktreeErr.message : String(worktreeErr); heartbeatLog.warn(`Heartbeat worktree acquisition failed for ${agentId}: ${detail}`); + + /* + * FNXC:WorktreeAcquisition 2026-07-09-00:00: + * Bound consecutive cross-heartbeat acquisition failures for this task + * (see MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES doc comment). On cap + * exhaustion, terminally fail the task (matching the executor's + * `status: "failed"` convention) instead of requeuing to "todo" again, + * and surface the exhaustion via onTaskAcquisitionExhausted so the + * owning runtime can record the failure in CentralCore stats (FN-7721). + */ + const priorAttempts = taskDetail.recoveryRetryCount ?? 0; + const attemptsSoFar = priorAttempts + 1; + const retryCapExhausted = attemptsSoFar >= MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES; + if (taskDetail.column !== "done" && taskDetail.column !== "archived") { - await taskStore.moveTask(taskDetail.id, "todo", { preserveProgress: true }); + if (retryCapExhausted) { + const exhaustionMessage = `Worktree acquisition failed after ${MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES} heartbeat attempts for branch "${taskDetail.branch ?? `fusion/${taskDetail.id.toLowerCase()}`}": ${detail}`; + await taskStore.updateTask(taskDetail.id, { + status: "failed", + error: exhaustionMessage, + recoveryRetryCount: null, + }); + await taskStore.logEntry(taskDetail.id, `Worktree acquisition retry cap reached (${MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES} attempts); task marked failed`, exhaustionMessage); + /* + * FNXC:WorktreeAcquisition 2026-07-09-00:00: + * `moveTask(..., "todo", ...)` reopen-to-todo semantics clear + * task.status/task.error back to undefined unless `preserveStatus` + * is passed (see store.ts isReopenToTodoOrTriage clause and + * move-task-preserve-status.test.ts) — without this flag the + * `status: "failed"` just written above would be silently wiped, + * leaving the task looking like a normal todo task that gets + * reassigned and retried from scratch, defeating the terminal- + * failure intent of this fix (FN-7721). + */ + await taskStore.moveTask(taskDetail.id, "todo", { preserveProgress: true, preserveStatus: true }); + this.onTaskAcquisitionExhausted?.(taskDetail.id, exhaustionMessage); + } else { + await taskStore.updateTask(taskDetail.id, { recoveryRetryCount: attemptsSoFar }); + await taskStore.moveTask(taskDetail.id, "todo", { preserveProgress: true }); + } } await this.completeRun(agentId, run.id, { status: "completed", - resultJson: { reason: "worktree_acquisition_failed", detail }, + resultJson: { reason: "worktree_acquisition_failed", detail, attempt: attemptsSoFar, retryCapExhausted }, stderrExcerpt: detail, skipStateTransition: true, }); diff --git a/packages/engine/src/runtimes/in-process-runtime.ts b/packages/engine/src/runtimes/in-process-runtime.ts index ecd66d01c9..9c14c98de4 100644 --- a/packages/engine/src/runtimes/in-process-runtime.ts +++ b/packages/engine/src/runtimes/in-process-runtime.ts @@ -710,6 +710,18 @@ export class InProcessRuntime runtimeLog.warn(`drainPendingAssignment failed for ${agentId}: ${err instanceof Error ? err.message : String(err)}`); }); }, + /* + * FNXC:WorktreeAcquisition 2026-07-09-00:00: + * A heartbeat-driven task worktree acquisition that exhausts its bounded + * retry cap (agent-heartbeat.ts MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES) + * is a real task failure that must be counted the same way `Executor`'s + * `onError` counts a failure, so `performanceSummary.totalTasksFailed` / + * project health stats are not silently starved (FN-7721). + */ + onTaskAcquisitionExhausted: (taskId, detail) => { + runtimeLog.error(`Heartbeat worktree acquisition exhausted retry cap for ${taskId}:`, detail); + this.recordTaskCompletion(taskId, false); + }, }); this.heartbeatMonitor.start(); }