FN-7721: cap heartbeat worktree-acquisition retries and record exhaustion failures
Bounds durable-agent heartbeat worktree acquisition to a fixed retry count instead of requeuing to todo indefinitely across heartbeat cycles. - Add MAX_HEARTBEAT_WORKTREE_ACQUISITION_RETRIES (3) in agent-heartbeat.ts, reusing Task.recoveryRetryCount as a cross-heartbeat counter (no schema migration) - On cap exhaustion, terminally mark the task status:"failed" with an explanatory error, log the entry, and reopen to todo with preserveStatus so the failed status isn't wiped by reopen-to-todo semantics - Add onTaskAcquisitionExhausted callback wired in in-process-runtime.ts to CentralCore.recordTaskCompletion(taskId, false) so exhausted acquisitions count toward totalTasksFailed - Add regression tests in agent-heartbeat-worktree.test.ts and in-process-runtime.test.ts covering the retry cap and completion recording - Add changeset (patch) and a docs/solutions/logic-errors writeup documenting the investigation and other worktree-collision sub-gaps found not to reproduce on HEAD Files changed: .changeset/fn-7721-worktree-heartbeat-retry-cap.md | 7 ++ docs/solutions/logic-errors/heartbeat-worktree-acquisition-unbounded-requeue.md | 84 ++++++++++++++++++++++ packages/engine/src/__tests__/agent-heartbeat-worktree.test.ts | 58 +++++++++++++++ packages/engine/src/__tests__/in-process-runtime.test.ts | 11 +++ packages/engine/src/agent-heartbeat.ts | 72 ++++++++++++++++++- packages/engine/src/runtimes/in-process-runtime.ts | 12 ++++ 6 files changed, 242 insertions(+), 2 deletions(-) Fusion-Task-Id: FN-7721 Fusion-Task-Lineage: caad671c-f360-4c1c-8aaa-5b48fca5a55b Co-authored-by: Fusion (runfusion.ai) <noreply@runfusion.ai>
This commit is contained in:
gsxdsm
7
.changeset/fn-7721-worktree-heartbeat-retry-cap.md
Normal file
7
.changeset/fn-7721-worktree-heartbeat-retry-cap.md
Normal file
@@ -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.
|
||||
@@ -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 <branch> 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`.
|
||||
@@ -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 <branch>` 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<string, unknown>) => {
|
||||
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 }));
|
||||
});
|
||||
});
|
||||
|
||||
@@ -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)");
|
||||
|
||||
@@ -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<import("@fusion/core").SecretsStore, "listEnvExportable">;
|
||||
/**
|
||||
* 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,
|
||||
});
|
||||
|
||||
@@ -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();
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user