FN-6296: fix stuck-kill force-requeue cleanup

Reap hung executor surfaces before requeueing stuck-kill timeout tasks.

- terminate spawned child agents and active session surfaces before clearing execution guards
- remove stale worktrees during force-requeue while preserving concurrent recovery ownership
- add regression coverage and architecture notes for the cleanup contract

Files changed:
 docs/architecture.md                               |   2 +
 .../engine/src/__tests__/executor-recovery.test.ts | 248 ++++++++++++++++++++-
 packages/engine/src/executor.ts                    |  61 ++++-
 3 files changed, 305 insertions(+), 6 deletions(-)

Fusion-Task-Id: FN-6296

Fusion-Task-Lineage: a393e2b1-a72c-4d7b-9de2-6bf7268986d4
This commit is contained in:
gsxdsm
2026-06-12 14:08:52 -07:00
parent dd51b5e321
commit ba610a1c0e
3 changed files with 305 additions and 6 deletions

View File

@@ -680,6 +680,8 @@ Runtime action-gate flow (v1):
#### Stuck-loop exhaustion terminal contract
When stuck-kill retries are exhausted, `checkStuckBudget()` marks the task `status: "failed"`, moves it to `in-review`, and writes an error that starts with `STUCK_LOOP_EXHAUSTED:`. The error and final task-log line both include the kill count/max and last stuck reason (`loop` or `inactivity`). `StuckTaskDetector` also untracks the task and refuses to re-track it while that failed terminal error remains, preventing further automatic kill/requeue churn. The final log line explicitly states that no further automatic retries will run and directs operators to manually retry, pause, or move the task back to triage to resume work.
If loop recovery times out during compact-and-resume and the executor does not unwind within the bounded force-requeue grace window, `TaskExecutor.markStuckAborted()` now hard-cancels the hung task before clearing execution guards: spawned child agents are terminated, `awaitAbortInFlightTaskWork()` reaps API/step/workflow/configured-command/subagent/CLI surfaces, the task worktree is removed with `RemovalReason.ExecutorStuckKilled`, stale in-memory worktree/loop/paused/stuck state is cleared, and then the task is moved back to `todo` with the configured `preserveProgressOnStuckRequeue` semantics. The path preserves the concurrent-recovery guard: if the latest task column is no longer `in-progress`, it only clears the execution guard and does not reap/remove resources that a self-healing recovery now owns. Task logs distinguish loop detection, compaction timeout, force-kill cleanup start, force-requeue, and cleanup completion/failure.
- `recoverMissingWorktreeReviewFailures()` is a narrow failed-review recovery: only `status: "failed"` `in-review` tasks with the explicit session-start signature `Refusing to start coding agent in missing worktree:` (from `assertValidWorktreeSession()`) are requeued. Recovery clears stale session metadata (`worktree`, `branch`, `sessionFile`, transient failure state), preserves valid step progress/retry counters, logs the auto-recovery reason, and moves the task back to `todo` for a clean retry.
- `recoverMergeableReviewTasks()` only re-enqueues truly eligible tasks; retry-exhausted review tasks are skipped to avoid re-enqueue/no-op loops that keep refreshing `updatedAt`.
- `recoverAlreadyMergedReviewTasks()` auto-finalizes retry-exhausted `in-review` tasks when self-healing can prove their work already landed on the merge target. On this landed-content path it clears soft blockers (`paused`, stale `status: "failed"`, and residual `error`) before moving to `done`; true hard blockers (for example incomplete steps, awaiting-user-review, or failed pre-merge workflow steps) still park the task in stable `in-review/failed` state with a blocker error instead of entering an auto-finalize loop.

View File

@@ -9,11 +9,12 @@ import { createFnAgent } from "../pi.js";
import { reviewStep as mockedReviewStepFn } from "../reviewer.js";
import { execSync } from "node:child_process";
import { findWorktreeUser, aiMergeTask } from "../merger.js";
import { WorktreePool } from "../worktree-pool.js";
import { WorktreePool, removeWorktree } from "../worktree-pool.js";
import { generateWorktreeName, slugify } from "../worktree-names.js";
import type { Task, TaskDetail } from "@fusion/core";
import { SessionManager } from "@earendil-works/pi-coding-agent";
import { StepSessionExecutor } from "../step-session-executor.js";
import { executingTaskLock } from "../active-session-registry.js";
import { executorLog } from "../logger.js";
import { withRateLimitRetry } from "../rate-limit-retry.js";
import { runVerificationCommand as mockedRunVerificationCommand } from "../verification-utils.js";
@@ -565,6 +566,251 @@ describe("TaskExecutor bounded recovery retries", () => {
);
});
it("force-requeue timeout reaps hung in-flight surfaces and removes the worktree before clearing guards", async () => {
vi.useFakeTimers();
try {
const store = createMockStore();
const agentStore = {
updateAgentState: vi.fn().mockResolvedValue(undefined),
deleteAgent: vi.fn().mockResolvedValue(undefined),
};
const executor = new TaskExecutor(store, "/tmp/test", { agentStore: agentStore as any });
const taskId = "FN-001";
const worktreePath = "/tmp/test/.worktrees/FN-001";
const session = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
const workflowSession = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
const stepExecutor = {
abortAllSessionBash: vi.fn(),
terminateAllSessions: vi.fn().mockResolvedValue(undefined),
};
const controller = new AbortController();
const controllerAbort = vi.spyOn(controller, "abort");
const subagent = { dispose: vi.fn(), state: {} };
const cliSession = { kill: vi.fn().mockResolvedValue(undefined) };
const childSession = { dispose: vi.fn(), state: {} };
vi.mocked(removeWorktree).mockResolvedValue(undefined as any);
store.getTask.mockResolvedValue({
id: taskId,
title: "Test",
description: "Test task",
column: "in-progress",
worktree: worktreePath,
dependencies: [],
steps: [],
currentStep: 0,
log: [],
createdAt: new Date().toISOString(),
updatedAt: new Date().toISOString(),
});
(executor as any).executing.add(taskId);
executingTaskLock.tryClaim(taskId);
(executor as any).activeWorktrees.set(taskId, worktreePath);
(executor as any).activeSessions.set(taskId, { session });
(executor as any).activeStepExecutors.set(taskId, stepExecutor);
(executor as any).activeWorkflowStepSessions.set(taskId, workflowSession);
(executor as any).activeConfiguredCommandControllers.set(taskId, new Set([controller]));
(executor as any).activeSubagentSessions.set(taskId, new Set([subagent]));
(executor as any).activeCliTaskSessions.set(taskId, cliSession);
(executor as any).spawnedAgents.set(taskId, new Set(["child-agent"]));
(executor as any).childSessions.set("child-agent", childSession);
(executor as any).loopRecoveryState.set(taskId, { attempts: 1, pending: true });
executor.markStuckAborted(taskId, true);
await vi.advanceTimersByTimeAsync(60_000);
expect(agentStore.updateAgentState).toHaveBeenCalledWith("child-agent", "paused");
expect(agentStore.deleteAgent).toHaveBeenCalledWith("child-agent");
expect(childSession.dispose).toHaveBeenCalledTimes(1);
expect(session.abort).toHaveBeenCalledTimes(1);
expect(session.dispose).toHaveBeenCalledTimes(1);
expect(stepExecutor.abortAllSessionBash).toHaveBeenCalledTimes(1);
expect(stepExecutor.terminateAllSessions).toHaveBeenCalled();
expect(workflowSession.abort).toHaveBeenCalledTimes(1);
expect(workflowSession.dispose).toHaveBeenCalledTimes(1);
expect(controllerAbort).toHaveBeenCalledTimes(1);
expect(subagent.dispose).toHaveBeenCalledTimes(1);
expect(cliSession.kill).toHaveBeenCalledWith("killed");
expect(removeWorktree).toHaveBeenCalledWith(expect.objectContaining({
worktreePath,
rootDir: "/tmp/test",
taskId,
expectedOwnerTaskId: taskId,
}));
expect(store.updateTask).toHaveBeenCalledWith(taskId, {
status: "queued",
error: null,
worktree: null,
branch: null,
});
expect(store.moveTask).toHaveBeenCalledWith(taskId, "todo", { preserveProgress: true });
expect(session.abort.mock.invocationCallOrder[0]).toBeLessThan(vi.mocked(removeWorktree).mock.invocationCallOrder[0]);
expect(vi.mocked(removeWorktree).mock.invocationCallOrder[0]).toBeLessThan(store.moveTask.mock.invocationCallOrder[0]);
const cleanupCompleteLogIndex = store.logEntry.mock.calls.findIndex(([, message]: any[]) => String(message).includes("Force-kill cleanup completed"));
expect(cleanupCompleteLogIndex).toBeGreaterThanOrEqual(0);
expect(store.moveTask.mock.invocationCallOrder[0]).toBeLessThan(store.logEntry.mock.invocationCallOrder[cleanupCompleteLogIndex]);
expect((executor as any).activeWorktrees.has(taskId)).toBe(false);
expect((executor as any).executing.has(taskId)).toBe(false);
expect(executingTaskLock.has(taskId)).toBe(false);
expect((executor as any).stuckAborted.has(taskId)).toBe(false);
expect((executor as any).loopRecoveryState.has(taskId)).toBe(false);
expect((executor as any).pausedAborted.has(taskId)).toBe(false);
expect(store.logEntry).toHaveBeenCalledWith(taskId, expect.stringContaining("Force-kill cleanup starting"));
expect(store.logEntry).toHaveBeenCalledWith(taskId, expect.stringContaining("Force-requeued after stuck-kill"));
expect(store.logEntry).toHaveBeenCalledWith(taskId, expect.stringContaining("progress preserved"));
expect(store.logEntry).toHaveBeenCalledWith(taskId, expect.stringContaining("Force-kill cleanup completed"));
} finally {
vi.useRealTimers();
executingTaskLock._clearForTest();
}
});
it("force-requeue timeout preserves concurrent non-in-progress recovery without reaping surfaces", async () => {
vi.useFakeTimers();
try {
const store = createMockStore();
const executor = new TaskExecutor(store, "/tmp/test", {});
const session = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
store.getTask.mockResolvedValue({
id: "FN-001",
title: "Test",
description: "Test task",
column: "in-review",
worktree: "/tmp/test/.worktrees/FN-001",
dependencies: [],
steps: [],
currentStep: 0,
log: [],
createdAt: new Date().toISOString(),
updatedAt: new Date().toISOString(),
});
(executor as any).executing.add("FN-001");
executingTaskLock.tryClaim("FN-001");
(executor as any).activeWorktrees.set("FN-001", "/tmp/test/.worktrees/FN-001");
(executor as any).activeSessions.set("FN-001", { session });
executor.markStuckAborted("FN-001", true);
await vi.advanceTimersByTimeAsync(60_000);
expect(session.abort).not.toHaveBeenCalled();
expect(session.dispose).not.toHaveBeenCalled();
expect(removeWorktree).not.toHaveBeenCalled();
expect(store.moveTask).not.toHaveBeenCalledWith("FN-001", "todo", expect.anything());
expect((executor as any).executing.has("FN-001")).toBe(false);
expect(executingTaskLock.has("FN-001")).toBe(false);
} finally {
vi.useRealTimers();
executingTaskLock._clearForTest();
}
});
it("force-requeue timeout no-ops when the executor unwound before the grace timer", async () => {
vi.useFakeTimers();
try {
const store = createMockStore();
const executor = new TaskExecutor(store, "/tmp/test", {});
const session = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
(executor as any).executing.add("FN-001");
executingTaskLock.tryClaim("FN-001");
(executor as any).activeSessions.set("FN-001", { session });
executor.markStuckAborted("FN-001", true);
(executor as any).executing.delete("FN-001");
executingTaskLock.release("FN-001");
await vi.advanceTimersByTimeAsync(60_000);
expect(session.abort).not.toHaveBeenCalled();
expect(removeWorktree).not.toHaveBeenCalled();
expect(store.moveTask).not.toHaveBeenCalledWith("FN-001", "todo", expect.anything());
} finally {
vi.useRealTimers();
executingTaskLock._clearForTest();
}
});
it("force-requeue timeout logs non-fatal worktree cleanup failures distinctly", async () => {
vi.useFakeTimers();
try {
const store = createMockStore();
const executor = new TaskExecutor(store, "/tmp/test", {});
const session = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
store.getTask.mockResolvedValue({
id: "FN-001",
title: "Test",
description: "Test task",
column: "in-progress",
worktree: "/tmp/test/.worktrees/FN-001",
dependencies: [],
steps: [],
currentStep: 0,
log: [],
createdAt: new Date().toISOString(),
updatedAt: new Date().toISOString(),
});
vi.mocked(removeWorktree).mockRejectedValue(new Error("worktree busy"));
(executor as any).executing.add("FN-001");
executingTaskLock.tryClaim("FN-001");
(executor as any).activeWorktrees.set("FN-001", "/tmp/test/.worktrees/FN-001");
(executor as any).activeSessions.set("FN-001", { session });
executor.markStuckAborted("FN-001", true);
await vi.advanceTimersByTimeAsync(60_000);
expect(store.logEntry).toHaveBeenCalledWith("FN-001", expect.stringContaining("Force-kill cleanup failed to remove worktree"));
expect(store.logEntry).toHaveBeenCalledWith("FN-001", expect.stringContaining("Force-kill cleanup completed with non-fatal worktree removal failure"));
expect(store.moveTask).toHaveBeenCalledWith("FN-001", "todo", { preserveProgress: true });
} finally {
vi.useRealTimers();
executingTaskLock._clearForTest();
}
});
it("force-requeue timeout honors disabled preserveProgressOnStuckRequeue", async () => {
vi.useFakeTimers();
try {
const store = createMockStore();
store.getSettings.mockResolvedValue({
maxConcurrent: 2,
maxWorktrees: 4,
pollIntervalMs: 15000,
groupOverlappingFiles: false,
autoMerge: false,
worktreeInitCommand: undefined,
preserveProgressOnStuckRequeue: false,
});
const executor = new TaskExecutor(store, "/tmp/test", {});
const resetSpy = vi.spyOn(executor as any, "resetStepsIfWorkLost").mockResolvedValue(undefined);
const session = { abort: vi.fn().mockResolvedValue(undefined), dispose: vi.fn(), state: {} };
store.getTask.mockResolvedValue({
id: "FN-001",
title: "Test",
description: "Test task",
column: "in-progress",
worktree: "/tmp/test/.worktrees/FN-001",
dependencies: [],
steps: [{ name: "step", status: "in-progress" }],
currentStep: 0,
log: [],
createdAt: new Date().toISOString(),
updatedAt: new Date().toISOString(),
});
vi.mocked(removeWorktree).mockResolvedValue(undefined as any);
(executor as any).executing.add("FN-001");
executingTaskLock.tryClaim("FN-001");
(executor as any).activeWorktrees.set("FN-001", "/tmp/test/.worktrees/FN-001");
(executor as any).activeSessions.set("FN-001", { session });
executor.markStuckAborted("FN-001", true);
await vi.advanceTimersByTimeAsync(60_000);
expect(resetSpy).toHaveBeenCalledWith(expect.objectContaining({ id: "FN-001" }));
expect(store.moveTask).toHaveBeenCalledWith("FN-001", "todo", undefined);
} finally {
vi.useRealTimers();
executingTaskLock._clearForTest();
}
});
it("does not let a late graph failure clobber a retryable requeue", async () => {
const store = createMockStore();
const task = {

View File

@@ -1953,7 +1953,6 @@ export class TaskExecutor {
}
this.loopRecoveryState.delete(taskId);
this.spawnedAgents.delete(taskId);
this.stuckAborted.delete(taskId);
if (hadActiveSurface) {
@@ -13867,6 +13866,51 @@ Backward compat fallback: if JSON is unavailable, you may still begin output wit
try {
const settings = await this.store.getSettings();
const preserveProgress = settings.preserveProgressOnStuckRequeue !== false;
const latestTask = await this.store.getTask(taskId);
const worktreePath = this.getWorktreePath(taskId) ?? latestTask.worktree;
await this.store.logEntry(
taskId,
`Force-kill cleanup starting after stuck-kill unwind timeout — reaping in-flight surfaces and worktree`,
);
// Spawned children must be terminated before the canonical reaper clears
// spawnedAgents bookkeeping; otherwise child agent sessions would be orphaned.
await this.terminateAllChildren(taskId).catch((err: unknown) => {
executorLog.warn(`${taskId}: spawned child cleanup failed during force-requeue: ${err instanceof Error ? err.message : String(err)}`);
});
await this.awaitAbortInFlightTaskWork(taskId, "force-requeue after stuck-kill unwind timeout");
// awaitAbortInFlightTaskWork marks pausedAborted as a generic hard-cancel
// signal. The force-requeue path has already handled the task move, so
// clear it to prevent a later subprocess unwind from logging/moving as a pause.
this.pausedAborted.delete(taskId);
if (!preserveProgress) {
await this.resetStepsIfWorkLost(latestTask);
}
let cleanupFailed = false;
if (worktreePath && existsSync(worktreePath)) {
try {
await removeWorktree({
worktreePath,
rootDir: this.rootDir,
settings,
taskId,
reason: RemovalReason.ExecutorStuckKilled,
expectedOwnerTaskId: taskId,
liveOwnerProbe: (path, ownerTaskId) => this.hasActiveWorktreeBinding(ownerTaskId, path),
});
executorLog.log(`${taskId}: removed worktree during force-requeue cleanup: ${worktreePath}`);
} catch (cleanupErr: unknown) {
cleanupFailed = true;
const cleanupErrMessage = cleanupErr instanceof Error ? cleanupErr.message : String(cleanupErr);
executorLog.warn(`${taskId}: worktree removal failed during force-requeue cleanup (${worktreePath}): ${cleanupErrMessage}`);
await this.store.logEntry(taskId, `Force-kill cleanup failed to remove worktree ${worktreePath}: ${cleanupErrMessage}`);
}
}
this.activeWorktrees.delete(taskId);
await this.store.logEntry(
taskId,
`Force-requeued after stuck-kill: executor did not unwind within ${FORCE_REQUEUE_GRACE_MS / 1000}s (hung subprocess)${preserveProgress ? " — progress preserved" : ""}`,
@@ -13878,16 +13922,23 @@ Backward compat fallback: if JSON is unavailable, you may still begin output wit
branch: null,
});
await this.store.moveTask(taskId, "todo", preserveProgress ? { preserveProgress: true } : undefined);
// Remove from executing so the scheduler can re-dispatch normally.
// The old Promise is still running but the executing guard is cleared so
// a fresh execute() call won't be blocked.
// Remove from executing only after the hung surfaces and worktree have
// been reaped, preventing a scheduler re-dispatch onto stale resources.
this.executing.delete(taskId);
executingTaskLock.release(taskId);
this.stuckAborted.delete(taskId);
executorLog.log(`${taskId} force-requeued to todo`);
this.loopRecoveryState.delete(taskId);
await this.store.logEntry(
taskId,
cleanupFailed
? "Force-kill cleanup completed with non-fatal worktree removal failure — task requeued"
: "Force-kill cleanup completed — in-flight surfaces reaped and task requeued",
);
executorLog.log(`${taskId} force-requeued to todo after stuck-kill cleanup`);
} catch (err: unknown) {
const errorMessage = err instanceof Error ? err.message : String(err);
executorLog.error(`Failed to force-requeue stuck task ${taskId}: ${errorMessage}`);
await this.store.logEntry(taskId, `Force-kill cleanup failed during stuck-kill force-requeue: ${errorMessage}`).catch(() => undefined);
}
}, FORCE_REQUEUE_GRACE_MS);
}