FN-6598: suppress stuck detection during verification
Treat bounded verification subprocesses as healthy activity so progressing tasks avoid false stuck-loop recovery. - Bracket fn_run_verification commands with stuck-detector start/end signals. - Suppress loop and no-progress churn while verification is active, with timeout-bounded cleanup. - Add regression coverage for verification heartbeats, compact-and-resume recovery, and no-progress churn behavior. - Document verification suppression in reliability guidance. Files changed: docs/architecture.md | 5 +- docs/testing.md | 1 + .../src/__tests__/executor-step-session.test.ts | 10 +- .../non-progress-churn.test.ts | 55 +++++++++ .../src/__tests__/run-verification-command.test.ts | 45 ++++++- .../src/__tests__/stuck-task-detector.test.ts | 136 +++++++++++++++++++++ packages/engine/src/executor.ts | 2 + packages/engine/src/run-verification-tool.ts | 33 +++-- packages/engine/src/stuck-task-detector.ts | 69 +++++++++++ 9 files changed, 341 insertions(+), 15 deletions(-) Fusion-Task-Id: FN-6598 Fusion-Task-Lineage: 5449b413-c500-46aa-b46d-cf94c2d88710
This commit is contained in:
gsxdsm
@@ -683,6 +683,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.
|
||||
|
||||
Active `fn_run_verification` subprocesses are a bounded progress signal (FN-6598). `createRunVerificationTool()` brackets each command with `StuckTaskDetector.beginVerification()` / `endVerification()`; while the command is active and still inside its own timeout plus cleanup grace, the detector suppresses `loop` and `no-progress-churn` classification so healthy marathon verification output cannot consume stuck-kill budget. `inactivity` is not suppressed: the verification runner must continue emitting line output or synthetic heartbeats, and if the process overruns its recorded deadline or never sends an end signal, normal detection resumes.
|
||||
|
||||
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`.
|
||||
@@ -1807,6 +1809,7 @@ This section preserves the detailed lifecycle/self-healing contracts that were f
|
||||
- **Dual-observe parity seam (FN-5742 Phase 2)**: with the same flag ON, legacy remains authoritative while shadow reads compute/emit parity telemetry only. Scheduler emits `merge:dependency-parity-diff` when `in-review|done|archived` dependency satisfaction diverges from completion-handoff marker satisfaction, and `merge:lease-parity-diff` when legacy in-review overlap leasing diverges from shadow lease decomposition. Merger emits `merge:request-dequeued-shadow` (agree/disagree metadata) by comparing legacy dequeue selection to shadow merge-request selection while explicitly skipping `manual-required` rows. Phase 3 dequeue cutover is gated on sustained parity (low disagreement rate) from these additive events; no lifecycle authority changes in Phase 2.
|
||||
- **Authoritative cutover seam (FN-5743 Phase 3)**: with the flag ON, merge-request records and `completion_handoff_accepted` markers become authoritative enforcement signals for dequeue/retry ownership and dependency/lease gates. Accepted handoffs stop stamping `in-review` executor overlap leases, transient merge retries stay in merge-request state (`running → retrying → queued`, terminal `exhausted|succeeded|cancelled`) without `todo` rebounds, and user hard-cancel (`in-review → todo`) deterministically cancels pending merge-request records while keeping FN-5147/FN-5704 behavior unchanged.
|
||||
- **No-progress churn terminalization (FN-5168)**: `StuckTaskDetector` now tracks ignored `fn_task_update` rebuffs via `recordIgnoredStepUpdate(taskId)` and, after one loop/compact-and-resume recovery has already fired in the same `execute()` lifecycle, escalates `ignoredStepUpdateCount >= 25` to the terminal reason `no-progress-churn`. `SelfHealingManager.checkStuckBudget()` maps that reason directly to `STUCK_NO_PROGRESS_CHURN`, emits `task:stuck-no-progress-churn-terminalized` with `{ taskId, ignoredStepUpdateCount, stuckKillStreak, lastReason }`, and parks the task in `in-review` without consuming the normal stuck-kill budget. Under FN-5147 `autoMerge: false`, that failed in-review task remains terminal-until-merged just like `STUCK_LOOP_EXHAUSTED`; the new class adds an earlier bounded exit, not a re-execution path.
|
||||
- **Verification-active stuck-loop suppression (FN-6598)**: `fn_run_verification` registers a per-task active verification window with `StuckTaskDetector`. Within the command's own timeout budget, subprocess output/heartbeats are treated as forward progress and suppress only `loop` / `no-progress-churn`; the deadline restores normal classification if the command or end callback wedges, and `inactivity` remains governed by heartbeat flow.
|
||||
- **Todo↔in-progress flapping convergence (FN-5941)**: live backward-recovery paths now share a `getFalsePositiveRequeueSignal(...)` guard that suppresses `in-progress → todo` recovery when any hard liveness proof exists (`getExecutingTaskIds`, recent active-heartbeat run, checked-out lease, live worktree+branch binding, or recent `executionStartedAt` inside the relevant grace window). Suppressed candidates emit observation-only `task:*no-action` audits instead of silently mutating lifecycle state. Scheduler adds a short `recentEngineTodoRequeues` settle window so engine-sourced requeues cannot be re-dispatched immediately on the same `task:moved → todo` tick. The durable convergence backstop is the dispatch-oscillation breaker: scheduler reuses `task.dispatchStormCount` + `task.lastDispatchAt` as a sliding-window counter (`dispatchOscillationThreshold`, `dispatchOscillationWindowMs`) and, when the threshold is exceeded, leaves the task parked in `todo`, sets `paused: true` with `pausedReason: "dispatch-oscillation"`, records `task:dispatch-oscillation-terminalized`, and requires an operator unpause or forward move to reset the counter.
|
||||
- **Landed-files attribution (FN-5103)**: Rebase-strategy `mergeDetails.landedFiles` / `filesChanged` / `insertions` / `deletions` are captured from task-attributable commits only via `filterFilesToOwnTaskCommits` (subject-prefix + trailer + bracket-prefix evidence), tagged `landedFilesAttributionRestricted: true`. Zero own commits → `landedFiles: []` and `noOpVerifiedShortCircuit: true`. FN-5304 guard: when `<rebaseBaseSha>..HEAD` reports zero own commits, merger must also validate the source `fusion/<id>` tip; if that source tip still has attributable own commits relative to `rebaseBaseSha`, throw `SilentNoOpAttributionMismatchError`, refuse writing `mergeConfirmed: true`, park the task in `in-review` with `status: "failed"`, and emit `merge:no-op-attribution-mismatch`. If source ref is unavailable, skip with diagnostic + `merge:no-op-attribution-mismatch-skipped` (`reason: "source-ref-unavailable"`). Attribution-helper failures fall back to the unrestricted `rebaseBaseSha..sha` walk and set `landedFilesCaptureFallback: 'attribution-failed'`. Self-healing `recoverDoneTaskMergeMetadata` skips reconcile when `landedFilesAttributionRestricted` or `noOpVerifiedShortCircuit` is set so the narrower set is not overwritten with the full range. Squash-strategy capture is unchanged.
|
||||
- **Soft-delete scheduler invalidation (FN-5137)**: `task:deleted` events must invalidate `AutoClaimSnapshotManager` and clear scheduler bookkeeping (`pausedTaskIds`, `failedTaskIds`, `wasNodeDispatchValidationBlocked`, `wasNodeBlocked`); `executor.execute()` / `resumeOrphaned()` / `resumeTaskForAgent()` refuse any task with `deletedAt` set.
|
||||
@@ -1832,7 +1835,7 @@ Reliability-layer changes are in scope. Interaction regression backstops live in
|
||||
- FN-5093 backstop: `packages/engine/src/__tests__/reliability-interactions/in-review-stalled-detector.test.ts` covers composition between quiet-window in-review stalled surfacing and adjacent reason-driven/paused/ghost-recovery/auto-merge gating paths.
|
||||
- FN-5103 backstop: `packages/engine/src/__tests__/reliability-interactions/landed-files-attribution.test.ts` covers attribution-restricted rebase landed-files capture, verified-short-circuit zero-own-commit capture, and attribution-failure fallback composition.
|
||||
- FN-5147 backstop: `packages/engine/src/__tests__/reliability-interactions/in-review-automerge-off.test.ts` covers `autoMerge: false` + long-quiet in-review + maintenance/startup sweep cycles, asserting no column move / no paused / no status mutation / no requeue, plus explicit regression guards for `surfaceInReviewStalls` and `surfaceInReviewStalled`.
|
||||
- FN-5168 backstop: `packages/engine/src/__tests__/reliability-interactions/non-progress-churn.test.ts` covers loop→compact recovery followed by ignored-step-update churn escalation, terminal `beforeRequeue(false)` behavior, audit/log payloads, and FN-5147 autoMerge-off composition.
|
||||
- FN-5168/FN-6598 backstop: `packages/engine/src/__tests__/reliability-interactions/non-progress-churn.test.ts` covers loop→compact recovery followed by ignored-step-update churn escalation, terminal `beforeRequeue(false)` behavior, audit/log payloads, FN-5147 autoMerge-off composition, and verification-active suppression so healthy `fn_run_verification` runs do not reach `onLoopDetected` / stuck-budget handling while the no-verification control still trips.
|
||||
- FN-5219 backstop: `packages/engine/src/__tests__/reliability-interactions/in-progress-limbo-recovery.test.ts` covers `recoverInProgressLimbo` composition with `recoverOrphanedExecutions` (no double-recovery), `reconcile-task-worktree-metadata` (live rebindable worktree wins), `recoverMissingWorktreeReviewFailures` (in-review vs in-progress disjoint), and executor task-id claim skip, plus an explicit FN-5149 reproduction case.
|
||||
- FN-5704 backstop: `packages/engine/src/__tests__/reliability-interactions/reclaim-self-owned-resume-limbo-escalation.test.ts` covers bounded no-progress reclaim/resume detection, preserve-work escalation to `todo`, `task:resume-limbo-escalated` audit metadata, progress-signal reset behavior, and user-paused/autoMerge-off non-escalation guards.
|
||||
- FN-5715 backstop: `packages/engine/src/__tests__/reliability-interactions/mission-validation-trigger-gap.test.ts` locks the mission-validation trigger invariant so done mission-linked tasks still start validation when the mission loop was stopped, startup recovery replays done implementing features with unpassed assertions, and recovery remains idempotent for already-passed features.
|
||||
|
||||
@@ -371,6 +371,7 @@ Prefer `it.each` over copy-pasted `it()` blocks. When trimming, keep: first case
|
||||
Copy this checklist into a bug-fix or UI-affordance add/remove task's `## Surface Enumeration` section and make the implementation tests prove the invariant across every checked surface. This checklist applies to bug-fix tasks and UI-affordance add/remove tasks that add, remove, or restructure icons, buttons, chevrons/arrows, toggles, badges, menu entries, or click targets. See `AGENTS.md` → **Standing Rule: Fix the Invariant, Not the Repro (FN-5893)** for the enforced planning/review contract.
|
||||
|
||||
- [ ] Providers / bridges / execution paths touched by the invariant
|
||||
- [ ] Long-running subprocess or verification-active surfaces when the invariant involves engine liveness, stuck detection, or command execution (`fn_run_verification`, configured commands, timeout/deadline behavior)
|
||||
- [ ] Desktop + mobile breakpoints / platforms that exercise the behavior
|
||||
- [ ] Empty / undefined / duplicate / populated data states
|
||||
- [ ] Shared hooks / components / modules / helpers reusing the logic
|
||||
|
||||
@@ -2866,18 +2866,18 @@ describe("Workflow Steps Execution", () => {
|
||||
};
|
||||
return { session };
|
||||
} else {
|
||||
// Workflow step agent that passes with an explicit parseable verdict.
|
||||
let subscribeHandler: any;
|
||||
let stepSubscribeHandler: any;
|
||||
// Workflow step agent that passes with the structured verdict required by the workflow-step parser.
|
||||
return {
|
||||
session: {
|
||||
prompt: vi.fn().mockImplementation(async () => {
|
||||
subscribeHandler?.({
|
||||
stepSubscribeHandler?.({
|
||||
type: "message_update",
|
||||
assistantMessageEvent: { type: "text_delta", delta: "Verdict: APPROVE\n\nWorkflow step passed." },
|
||||
assistantMessageEvent: { type: "text_delta", delta: '{"verdict":"APPROVE","notes":""}' },
|
||||
});
|
||||
}),
|
||||
dispose: vi.fn(),
|
||||
subscribe: vi.fn((handler: any) => { subscribeHandler = handler; }),
|
||||
subscribe: vi.fn((handler: any) => { stepSubscribeHandler = handler; }),
|
||||
state: {},
|
||||
},
|
||||
};
|
||||
|
||||
@@ -190,6 +190,61 @@ describe("reliability interactions: non-progress churn", () => {
|
||||
manager.stop();
|
||||
});
|
||||
|
||||
it("does not route active verification churn into loop recovery or stuck-kill budget", async () => {
|
||||
const task = baseTask({ id: "FN-6598-RI" });
|
||||
const store = createStore(task);
|
||||
const manager = new SelfHealingManager(store, { rootDir: "/tmp/repo" });
|
||||
const beforeRequeue = vi.fn((taskId, reason, event) => manager.checkStuckBudget(taskId, reason, event));
|
||||
const onLoopDetected = vi.fn().mockResolvedValue(false);
|
||||
const detector = new StuckTaskDetector(store, { beforeRequeue, onLoopDetected });
|
||||
const session = { dispose: vi.fn() };
|
||||
|
||||
detector.trackTask(task.id, session as any);
|
||||
detector.beginVerification(task.id, 120_000);
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
detector.recordActivity(task.id);
|
||||
}
|
||||
|
||||
await detector.checkNow();
|
||||
|
||||
expect(onLoopDetected).not.toHaveBeenCalled();
|
||||
expect(beforeRequeue).not.toHaveBeenCalled();
|
||||
expect(session.dispose).not.toHaveBeenCalled();
|
||||
expect(task.column).toBe("in-progress");
|
||||
expect(task.stuckKillCount).toBe(0);
|
||||
|
||||
manager.stop();
|
||||
});
|
||||
|
||||
it("control: identical churn without active verification still reaches loop recovery and budget", async () => {
|
||||
const task = baseTask({ id: "FN-6598-RI-CONTROL" });
|
||||
const store = createStore(task);
|
||||
const manager = new SelfHealingManager(store, { rootDir: "/tmp/repo" });
|
||||
const beforeRequeue = vi.fn((taskId, reason, event) => manager.checkStuckBudget(taskId, reason, event));
|
||||
const onLoopDetected = vi.fn().mockResolvedValue(false);
|
||||
const detector = new StuckTaskDetector(store, { beforeRequeue, onLoopDetected });
|
||||
const session = { dispose: vi.fn() };
|
||||
|
||||
detector.trackTask(task.id, session as any);
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
detector.recordActivity(task.id);
|
||||
}
|
||||
|
||||
await detector.checkNow();
|
||||
|
||||
expect(onLoopDetected).toHaveBeenCalledWith(expect.objectContaining({ taskId: task.id, reason: "loop" }));
|
||||
expect(beforeRequeue).toHaveBeenCalledWith(
|
||||
task.id,
|
||||
"loop",
|
||||
expect.objectContaining({ taskId: task.id, reason: "loop" }),
|
||||
);
|
||||
expect(session.dispose).toHaveBeenCalledTimes(1);
|
||||
|
||||
manager.stop();
|
||||
});
|
||||
|
||||
it("parks incomplete STUCK_LOOP_EXHAUSTED tasks in todo when the churn signal does not fire", async () => {
|
||||
const task = baseTask({ id: "FN-5168-LOOP", stuckKillCount: 6 });
|
||||
const store = createStore(task);
|
||||
|
||||
@@ -1,7 +1,7 @@
|
||||
import { describe, it, expect, vi } from "vitest";
|
||||
import { tmpdir } from "node:os";
|
||||
import { fileURLToPath } from "node:url";
|
||||
import { runVerificationCommand, normalizeVerificationCommand, type RunVerificationOptions } from "../run-verification-tool.js";
|
||||
import { createRunVerificationTool, runVerificationCommand, normalizeVerificationCommand, type RunVerificationOptions } from "../run-verification-tool.js";
|
||||
|
||||
// Some tests use platform-appropriate shell syntax. On Windows, sh-style
|
||||
// quoting and pipes through `printf` are different — these tests are skipped
|
||||
@@ -83,6 +83,49 @@ describe("runVerificationCommand", { timeout: 30000 }, () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("tool verification lifecycle callbacks", () => {
|
||||
it("brackets a successful verification run with start and end callbacks", async () => {
|
||||
const onVerificationStart = vi.fn();
|
||||
const onVerificationEnd = vi.fn();
|
||||
const tool = createRunVerificationTool({
|
||||
worktreePath: tempDir,
|
||||
rootDir: workspaceRoot,
|
||||
taskId: "FN-6598",
|
||||
recordActivity: vi.fn(),
|
||||
onVerificationStart,
|
||||
onVerificationEnd,
|
||||
log: { info: vi.fn(), warn: vi.fn(), error: vi.fn() },
|
||||
});
|
||||
|
||||
await tool.execute("call-1", { command: "exit 0", scope: "package" });
|
||||
|
||||
expect(onVerificationStart).toHaveBeenCalledTimes(1);
|
||||
expect(onVerificationStart).toHaveBeenCalledWith(300_000);
|
||||
expect(onVerificationEnd).toHaveBeenCalledTimes(1);
|
||||
expect(onVerificationStart.mock.invocationCallOrder[0]).toBeLessThan(onVerificationEnd.mock.invocationCallOrder[0]);
|
||||
});
|
||||
|
||||
it("fires the end callback when the verification command fails", async () => {
|
||||
const onVerificationStart = vi.fn();
|
||||
const onVerificationEnd = vi.fn();
|
||||
const tool = createRunVerificationTool({
|
||||
worktreePath: tempDir,
|
||||
rootDir: workspaceRoot,
|
||||
taskId: "FN-6598",
|
||||
recordActivity: vi.fn(),
|
||||
onVerificationStart,
|
||||
onVerificationEnd,
|
||||
log: { info: vi.fn(), warn: vi.fn(), error: vi.fn() },
|
||||
});
|
||||
|
||||
const result = await tool.execute("call-2", { command: "exit 7", scope: "package" });
|
||||
|
||||
expect(result.details).toEqual(expect.objectContaining({ success: false, exitCode: 7 }));
|
||||
expect(onVerificationStart).toHaveBeenCalledTimes(1);
|
||||
expect(onVerificationEnd).toHaveBeenCalledTimes(1);
|
||||
});
|
||||
});
|
||||
|
||||
describe("basic command execution", () => {
|
||||
it("executes a simple echo command and captures output", async () => {
|
||||
const onHeartbeat = vi.fn();
|
||||
|
||||
@@ -411,6 +411,142 @@ describe("StuckTaskDetector", () => {
|
||||
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("suppresses loop classification while verification is active and within its deadline", async () => {
|
||||
const onStuck = vi.fn();
|
||||
const customDetector = new StuckTaskDetector(createMockStore({
|
||||
getSettings: vi.fn().mockResolvedValue({ taskStuckTimeoutMs: 60_000 }),
|
||||
}), { onStuck });
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
customDetector.trackTask("FN-6598", createMockSession());
|
||||
customDetector.beginVerification("FN-6598", 120_000);
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
customDetector.recordActivity("FN-6598");
|
||||
}
|
||||
|
||||
expect(customDetector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
await customDetector.checkNow();
|
||||
expect(onStuck).not.toHaveBeenCalled();
|
||||
expect(customDetector.trackedCount).toBe(1);
|
||||
|
||||
customDetector.stop();
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("resumes loop detection after verification ends and activity churn continues", () => {
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
detector.trackTask("FN-6598", createMockSession());
|
||||
detector.beginVerification("FN-6598", 120_000);
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
detector.recordActivity("FN-6598");
|
||||
}
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
|
||||
detector.endVerification("FN-6598");
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
|
||||
for (let i = 0; i < 60; i++) {
|
||||
detector.recordActivity("FN-6598");
|
||||
}
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBe("loop");
|
||||
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("resumes loop detection after the verification deadline elapses without an end signal", () => {
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
detector.trackTask("FN-6598", createMockSession());
|
||||
detector.beginVerification("FN-6598", 60_000);
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
detector.recordActivity("FN-6598");
|
||||
}
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
|
||||
vi.advanceTimersByTime(5_001);
|
||||
detector.recordActivity("FN-6598");
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBe("loop");
|
||||
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("suppresses no-progress-churn classification while verification is active", () => {
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
detector.trackTask("FN-6598", createMockSession());
|
||||
detector.beginVerification("FN-6598", 120_000);
|
||||
detector.markLoopObserved("FN-6598");
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 25; i++) {
|
||||
detector.recordIgnoredStepUpdate("FN-6598");
|
||||
}
|
||||
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
detector.endVerification("FN-6598");
|
||||
for (let i = 0; i < 25; i++) {
|
||||
detector.recordIgnoredStepUpdate("FN-6598");
|
||||
}
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBe("no-progress-churn");
|
||||
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("control: identical activity churn without active verification still trips loop detection", async () => {
|
||||
const onStuck = vi.fn();
|
||||
const store = createMockStore({
|
||||
getSettings: vi.fn().mockResolvedValue({ taskStuckTimeoutMs: 60_000 }),
|
||||
});
|
||||
const customDetector = new StuckTaskDetector(store, { onStuck });
|
||||
const session = createMockSession();
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
customDetector.trackTask("FN-6598", session);
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
customDetector.recordActivity("FN-6598");
|
||||
}
|
||||
|
||||
expect(customDetector.classifyStuckReason("FN-6598", 60_000)).toBe("loop");
|
||||
await customDetector.checkNow();
|
||||
expect(onStuck).toHaveBeenCalledWith(expect.objectContaining({ taskId: "FN-6598", reason: "loop" }));
|
||||
expect(session.dispose).toHaveBeenCalledTimes(1);
|
||||
|
||||
customDetector.stop();
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("verification accounting no-ops safely for untracked and unbalanced calls", () => {
|
||||
expect(() => detector.beginVerification("FN-MISSING", 60_000)).not.toThrow();
|
||||
expect(() => detector.endVerification("FN-MISSING")).not.toThrow();
|
||||
detector.trackTask("FN-6598", createMockSession());
|
||||
expect(() => detector.endVerification("FN-6598")).not.toThrow();
|
||||
expect(detector.classifyStuckReason("FN-6598", 60_000)).toBeNull();
|
||||
});
|
||||
|
||||
it("verification accounting resolves step-session entries by canonical task id", () => {
|
||||
vi.useFakeTimers({ shouldAdvanceTime: true });
|
||||
detector.trackTask("FN-6598-step-2", createMockSession(), "FN-6598");
|
||||
detector.beginVerification("FN-6598", 120_000);
|
||||
|
||||
vi.advanceTimersByTime(61_000);
|
||||
for (let i = 0; i < 80; i++) {
|
||||
detector.recordActivity("FN-6598-step-2");
|
||||
}
|
||||
|
||||
expect(detector.classifyStuckReason("FN-6598-step-2", 60_000)).toBeNull();
|
||||
detector.endVerification("FN-6598");
|
||||
for (let i = 0; i < 60; i++) {
|
||||
detector.recordActivity("FN-6598-step-2");
|
||||
}
|
||||
expect(detector.classifyStuckReason("FN-6598-step-2", 60_000)).toBe("loop");
|
||||
|
||||
vi.useRealTimers();
|
||||
});
|
||||
});
|
||||
|
||||
describe("killAndRetry", () => {
|
||||
|
||||
@@ -7730,6 +7730,8 @@ export class TaskExecutor {
|
||||
rootDir: this.rootDir,
|
||||
taskId: task.id,
|
||||
recordActivity: () => stuckDetector?.recordActivity(task.id),
|
||||
onVerificationStart: (timeoutMs) => stuckDetector?.beginVerification(task.id, timeoutMs),
|
||||
onVerificationEnd: () => stuckDetector?.endVerification(task.id),
|
||||
log: {
|
||||
info: (s) => executorLog.log(s),
|
||||
warn: (s) => executorLog.warn(s),
|
||||
|
||||
@@ -520,6 +520,16 @@ export interface CreateRunVerificationToolOpts {
|
||||
taskId: string;
|
||||
/** Called on every output line AND on synthetic quiet-interval heartbeats. */
|
||||
recordActivity: () => void;
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:12:
|
||||
* FN-6598 brackets fn_run_verification subprocesses so the stuck detector treats bounded, actively running verification as progress instead of no-progress loop churn.
|
||||
*/
|
||||
onVerificationStart?: (timeoutMs: number) => void;
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:12:
|
||||
* The end signal must fire from a finally block on success, failure, timeout, and spawn errors so detector suppression cannot leak after a verification command exits.
|
||||
*/
|
||||
onVerificationEnd?: () => void;
|
||||
log: {
|
||||
info: (s: string) => void;
|
||||
warn: (s: string) => void;
|
||||
@@ -536,7 +546,7 @@ export interface CreateRunVerificationToolOpts {
|
||||
export function createRunVerificationTool(
|
||||
opts: CreateRunVerificationToolOpts,
|
||||
): ToolDefinition {
|
||||
const { worktreePath, rootDir, taskId, recordActivity, log } = opts;
|
||||
const { worktreePath, rootDir, taskId, recordActivity, onVerificationStart, onVerificationEnd, log } = opts;
|
||||
|
||||
return {
|
||||
name: "fn_run_verification",
|
||||
@@ -615,13 +625,20 @@ export function createRunVerificationTool(
|
||||
);
|
||||
|
||||
// ── Run ───────────────────────────────────────────────────────────────
|
||||
const result = await runVerificationCommand({
|
||||
command: effectiveCommand,
|
||||
cwd: resolvedCwd,
|
||||
timeoutMs,
|
||||
expectFailure,
|
||||
onHeartbeat: recordActivity,
|
||||
});
|
||||
onVerificationStart?.(timeoutMs);
|
||||
const result = await (async () => {
|
||||
try {
|
||||
return await runVerificationCommand({
|
||||
command: effectiveCommand,
|
||||
cwd: resolvedCwd,
|
||||
timeoutMs,
|
||||
expectFailure,
|
||||
onHeartbeat: recordActivity,
|
||||
});
|
||||
} finally {
|
||||
onVerificationEnd?.();
|
||||
}
|
||||
})();
|
||||
|
||||
// ── Merge warnings from auto-bootstrap / scope check ─────────────────
|
||||
const allWarnings = [...warnings, ...result.warnings];
|
||||
|
||||
@@ -36,6 +36,16 @@ interface TrackedTask {
|
||||
activitySinceProgress: number;
|
||||
/** Number of ignored fn_task_update rebuffs since the last progress event. */
|
||||
ignoredStepUpdateCount: number;
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:05:
|
||||
* FN-6598 requires long fn_run_verification subprocesses to count as healthy in-flight work instead of loop churn. Track active runs with a count so nested or overlapping verification calls do not clear suppression until every run ends.
|
||||
*/
|
||||
verificationActiveCount: number;
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:05:
|
||||
* Verification suppression must be bounded by the command's own hard timeout plus a small cleanup grace, so a missing end signal cannot blind stuck detection forever.
|
||||
*/
|
||||
verificationDeadlineAt: number | null;
|
||||
/**
|
||||
* Set once the executor has already observed a loop in the current execute()
|
||||
* lifecycle. FN-5168 only escalates to no-progress churn after the existing
|
||||
@@ -85,6 +95,7 @@ const LOOP_ACTIVITY_THRESHOLD = 60;
|
||||
* is still churning on completed work instead of advancing.
|
||||
*/
|
||||
const NO_PROGRESS_CHURN_THRESHOLD = 25;
|
||||
const VERIFICATION_DEADLINE_GRACE_MS = 5_000;
|
||||
|
||||
export interface StuckTaskDetectorOptions {
|
||||
/** Polling interval in milliseconds. Default: 30000 (30 seconds). */
|
||||
@@ -219,6 +230,8 @@ export class StuckTaskDetector {
|
||||
lastProgressAt: now,
|
||||
activitySinceProgress: 0,
|
||||
ignoredStepUpdateCount: 0,
|
||||
verificationActiveCount: 0,
|
||||
verificationDeadlineAt: null,
|
||||
loopObservedInLifecycle: false,
|
||||
recoveryInProgress: false,
|
||||
canonicalTaskId: canonicalId,
|
||||
@@ -235,6 +248,8 @@ export class StuckTaskDetector {
|
||||
lastProgressAt: now,
|
||||
activitySinceProgress: 0,
|
||||
ignoredStepUpdateCount: 0,
|
||||
verificationActiveCount: 0,
|
||||
verificationDeadlineAt: null,
|
||||
loopObservedInLifecycle: false,
|
||||
recoveryInProgress: false,
|
||||
canonicalTaskId: canonicalId,
|
||||
@@ -251,6 +266,8 @@ export class StuckTaskDetector {
|
||||
lastProgressAt: now,
|
||||
activitySinceProgress: 0,
|
||||
ignoredStepUpdateCount: 0,
|
||||
verificationActiveCount: 0,
|
||||
verificationDeadlineAt: null,
|
||||
loopObservedInLifecycle: false,
|
||||
recoveryInProgress: false,
|
||||
canonicalTaskId: canonicalId,
|
||||
@@ -315,6 +332,45 @@ export class StuckTaskDetector {
|
||||
return undefined;
|
||||
}
|
||||
|
||||
private isVerificationActive(entry: TrackedTask, now: number): boolean {
|
||||
return entry.verificationActiveCount > 0
|
||||
&& entry.verificationDeadlineAt !== null
|
||||
&& now < entry.verificationDeadlineAt;
|
||||
}
|
||||
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:05:
|
||||
* fn_run_verification owns its subprocess timeout and emits line/synthetic heartbeats while alive. During that bounded active window, no-progress loop/churn classification is suspended because subprocess output is forward progress, not agent churn.
|
||||
*/
|
||||
beginVerification(taskId: string, timeoutMs: number): void {
|
||||
const entry = this.findTrackedEntry(taskId);
|
||||
if (!entry) return;
|
||||
const now = Date.now();
|
||||
entry.lastActivity = now;
|
||||
entry.verificationActiveCount++;
|
||||
const deadline = now + Math.max(0, timeoutMs) + VERIFICATION_DEADLINE_GRACE_MS;
|
||||
entry.verificationDeadlineAt = Math.max(entry.verificationDeadlineAt ?? 0, deadline);
|
||||
stuckLog.log(`Verification started for ${taskId} (active=${entry.verificationActiveCount})`);
|
||||
}
|
||||
|
||||
/**
|
||||
* FNXC:Reliability 2026-06-17-16:05:
|
||||
* Ending verification refreshes activity and clears accumulated subprocess heartbeat churn so a healthy long command does not get killed immediately after returning.
|
||||
*/
|
||||
endVerification(taskId: string): void {
|
||||
const entry = this.findTrackedEntry(taskId);
|
||||
if (!entry) return;
|
||||
if (entry.verificationActiveCount > 0) {
|
||||
entry.verificationActiveCount--;
|
||||
}
|
||||
entry.lastActivity = Date.now();
|
||||
entry.activitySinceProgress = 0;
|
||||
if (entry.verificationActiveCount === 0) {
|
||||
entry.verificationDeadlineAt = null;
|
||||
}
|
||||
stuckLog.log(`Verification ended for ${taskId} (active=${entry.verificationActiveCount})`);
|
||||
}
|
||||
|
||||
/**
|
||||
* Record a step progress event for a task's agent session.
|
||||
* Called on step transitions (in-progress, done, skipped).
|
||||
@@ -329,6 +385,8 @@ export class StuckTaskDetector {
|
||||
entry.lastProgressAt = Date.now();
|
||||
entry.activitySinceProgress = 0;
|
||||
entry.ignoredStepUpdateCount = 0;
|
||||
entry.verificationActiveCount = 0;
|
||||
entry.verificationDeadlineAt = null;
|
||||
entry.recoveryInProgress = false;
|
||||
}
|
||||
}
|
||||
@@ -403,12 +461,20 @@ export class StuckTaskDetector {
|
||||
const now = Date.now();
|
||||
const inactivityMs = now - entry.lastActivity;
|
||||
const noProgressMs = now - entry.lastProgressAt;
|
||||
const verificationActive = this.isVerificationActive(entry, now);
|
||||
|
||||
// Check inactivity first — if there's been zero activity, it's just inactive
|
||||
if (inactivityMs >= timeoutMs) {
|
||||
return "inactivity";
|
||||
}
|
||||
|
||||
// FN-6598: active verification output is healthy progress for loop/churn
|
||||
// accounting, but inactivity remains unsuppressed above and the verification
|
||||
// deadline restores normal detection if the subprocess never ends.
|
||||
if (verificationActive) {
|
||||
return null;
|
||||
}
|
||||
|
||||
// FN-5168: only escalate to churn after loop recovery already had one chance
|
||||
// in this execute() lifecycle and the agent kept hammering ignored step updates.
|
||||
if (
|
||||
@@ -605,6 +671,8 @@ export class StuckTaskDetector {
|
||||
entry.lastProgressAt = now;
|
||||
entry.activitySinceProgress = 0;
|
||||
entry.ignoredStepUpdateCount = 0;
|
||||
entry.verificationActiveCount = 0;
|
||||
entry.verificationDeadlineAt = null;
|
||||
entry.loopObservedInLifecycle = false;
|
||||
entry.recoveryInProgress = false;
|
||||
}
|
||||
@@ -631,6 +699,7 @@ export class StuckTaskDetector {
|
||||
* `lastProgressAt` still exceeds `taskStuckTimeoutMs` and ignored step-update rebuffs reach 25+
|
||||
* - **loop**: `lastProgressAt` older than `taskStuckTimeoutMs` AND `activitySinceProgress >= 60`
|
||||
* (agent is actively doing things but not advancing steps)
|
||||
* - Active `fn_run_verification`: suppresses loop/no-progress-churn until the command ends or its own deadline elapses; inactivity remains governed by `lastActivity`.
|
||||
*/
|
||||
private async checkStuckTasks(): Promise<void> {
|
||||
if (this.tracked.size === 0) return;
|
||||
|
||||
Reference in New Issue
Block a user