import { fireAndForget } from "./async-guard"; import type { RelayClient, RelayCommand } from "./relay"; interface CommandPollerControl { handleCommand(command: RelayCommand): Promise; } // #1760 — a health snapshot of the command loop, surfaced on /api/health so a CRAWLING loop (a // healthy heartbeat while commands sit unhandled for minutes) is detectable without log archaeology. export interface CommandLoopHealth { /** True while a poll+handle cycle is running. */ inFlight: boolean; /** Where the in-flight cycle is: waiting on the network poll, or running a command handler. */ phase: "idle" | "poll" | "handler"; /** How long the in-flight cycle has been running (0 when idle). */ activeForMs: number; /** The command currently being handled inline, when phase === "handler". */ handlingType?: string; handlingId?: string; /** True once the in-flight cycle has exceeded the watchdog threshold — the crawl signal. */ stalled: boolean; stalledForMs?: number; } interface CommandPollerOptions { relay: Pick; control: CommandPollerControl; log?: (message: string) => void; intervalMs?: number; errorBackoffMs?: number; watchdogMs?: number; watchdogCheckMs?: number; now?: () => number; } const DEFAULT_WATCHDOG_MS = 5 * 60 * 1000; export function createCommandPoller({ relay, control, log = console.error, intervalMs = 3_000, errorBackoffMs = 3_000, watchdogMs = DEFAULT_WATCHDOG_MS, watchdogCheckMs = Math.min(60_000, watchdogMs), now = Date.now, }: CommandPollerOptions) { let inFlight = false; let stopped = true; let timer: ReturnType | undefined; let watchdogTimer: ReturnType | undefined; let activePollController: AbortController | undefined; let activePollStartedAt = 0; let activePhase: "idle" | "poll" | "handler" = "idle"; // #1760 — the command currently being handled inline, and the timestamp at which the loop was first // observed stalled in the current cycle (0 when not stalled). Only used for detection/surfacing. let activeCommandType: string | undefined; let activeCommandId: string | undefined; let stalledSince = 0; let lastTickErrored = false; let lastCycleCompletedAt = now(); let generation = 0; function clearActiveCommand(): void { activeCommandType = undefined; activeCommandId = undefined; stalledSince = 0; } async function tick(): Promise { if (!relay.connected || inFlight) return false; const tickGeneration = generation; const controller = new AbortController(); inFlight = true; activePollController = controller; activePollStartedAt = now(); activePhase = "poll"; lastTickErrored = false; try { const commands = await relay.pollCommands(controller.signal); if (tickGeneration !== generation) return false; if (activePollController === controller) activePollController = undefined; activePhase = "handler"; if (commands.length > 0) { log(`[orchestrator] Received ${commands.length} command(s)`); } for (const command of commands) { if (tickGeneration !== generation) return false; log(`[orchestrator] Handling command: ${command.type} ${command.id}`); activeCommandType = command.type; activeCommandId = command.id; stalledSince = 0; try { await control.handleCommand(command); } finally { if (tickGeneration === generation) clearActiveCommand(); } } return true; } catch (err) { lastTickErrored = true; log(`[orchestrator] Poll error: ${err}`); return false; } finally { if (activePollController === controller) activePollController = undefined; if (tickGeneration === generation) { inFlight = false; activePhase = "idle"; activePollStartedAt = 0; clearActiveCommand(); } } } function schedule(delayMs: number): void { if (stopped) return; timer = setTimeout(() => { timer = undefined; void fireAndForget("Command poll cycle", () => runCycle(generation), log); }, delayMs); timer.unref?.(); } async function runCycle(runGeneration: number): Promise { let errored = false; try { await tick(); errored = lastTickErrored; } catch (err) { errored = true; log(`[orchestrator] Poll loop error: ${err}`); } finally { if (runGeneration === generation) lastCycleCompletedAt = now(); if (!stopped && runGeneration === generation) schedule(errored ? errorBackoffMs : intervalMs); } } function startWatchdog(): void { if (watchdogTimer || watchdogMs <= 0 || watchdogCheckMs <= 0) return; watchdogTimer = setInterval(() => { if (stopped) return; if (!inFlight || activePhase === "idle" || activePollStartedAt === 0) return; const staleForMs = now() - activePollStartedAt; if (staleForMs < watchdogMs) return; if (activePhase === "poll" && activePollController) { // A stuck network poll is safely abortable (its AbortController cancels the in-flight // request); bump the generation, abort, and restart the cycle. Unchanged from pre-#1760. generation += 1; activePollController.abort(); activePollController = undefined; activePollStartedAt = 0; activePhase = "idle"; inFlight = false; clearActiveCommand(); log(`[orchestrator] Poll loop watchdog: command poll stuck for ${staleForMs}ms; aborting stuck poll and restarting`); if (!timer) schedule(0); lastCycleCompletedAt = now(); return; } if (activePhase === "handler") { // #1760 — a command handler (agent.restart / agent.shutdown / workspace.merge / …) is running // INLINE in the poll tick and has exceeded the threshold, head-of-line-blocking every command // queued behind it. We DETECT and SURFACE it (log once + a health flag) but deliberately do // NOT abort: unlike a network poll, a handler is mid-mutation (a git land, a session teardown) // and cancelling it by bumping the generation would free the single-flight guard while the // work runs on, risking a concurrent re-dispatch of the same command. Spawn handling is // already backgrounded off the tick (dispatchSpawnCommand), so it cannot land here; the // inline handlers that can are bounded by their own timeouts. Surfacing turns a silent crawl // into an observable one. if (stalledSince === 0) { stalledSince = activePollStartedAt; log( `[orchestrator] Command loop STALLED: handling ${activeCommandType ?? "command"} ${activeCommandId ?? ""} for ${staleForMs}ms ` + `(heartbeat stays healthy; commands queued behind it are blocked). Not aborting an in-flight mutating handler.`, ); } return; } }, watchdogCheckMs); watchdogTimer.unref?.(); } function start(): void { if (!stopped) return; stopped = false; lastCycleCompletedAt = now(); startWatchdog(); schedule(0); } function stop(): void { stopped = true; generation += 1; activePollController?.abort(); activePollController = undefined; activePollStartedAt = 0; activePhase = "idle"; clearActiveCommand(); if (timer) clearTimeout(timer); timer = undefined; if (watchdogTimer) clearInterval(watchdogTimer); watchdogTimer = undefined; } function getHealth(): CommandLoopHealth { const active = inFlight && activePollStartedAt > 0; const activeForMs = active ? Math.max(0, now() - activePollStartedAt) : 0; const stalled = active && stalledSince > 0; return { inFlight, phase: activePhase, activeForMs, stalled, ...(stalled ? { stalledForMs: Math.max(0, now() - stalledSince) } : {}), ...(activePhase === "handler" && activeCommandType ? { handlingType: activeCommandType } : {}), ...(activePhase === "handler" && activeCommandId ? { handlingId: activeCommandId } : {}), }; } return { tick, start, stop, getHealth, get inFlight() { return inFlight; }, }; }