/** * Watching the orchestrator, and the two ways of getting its attention. * * The dispatcher's tier-2 escalation target is another agent session, so the * dispatcher owns a liveness problem: a session that stopped consuming ticks * looks exactly like a quiet fleet until something needs a decision. This module * is the whole of that concern — the stall gate and its once-per-hour renotify, * the bounded exact-identity restart, and the escalation lines that describe * what was attempted. * * The two `wakeOrchestrator*` helpers live here rather than in `tick.ts` because * a blocked run wakes the orchestrator from inside `handleIssue` and * `handleReviewRevision` too. Parked in the tick they would drag the whole tick * pass into the dispatch path's import graph, for two functions whose subject — * "make the orchestrator look at this now" — is already this module's. */ import { existsSync, readFileSync, statSync } from "node:fs"; import { join } from "node:path"; import { stateDir } from "../config.ts"; import { stallSilenceMs } from "../failure-class.ts"; import { resolvePaneHaltPath, stopConductorPane } from "../fleet.ts"; import { errText, log, safeEscalate } from "../log.ts"; import { STALL_MARKER_FILE, readTickRequestReason, requestImmediateTick, resolveTickConfigCwd } from "../orchestrator-tick.ts"; import { LIVE_STATES } from "../store.ts"; import { wakeDispatch } from "../wake.ts"; import { NO_ISSUE, type Deps, type StallGate } from "./deps.ts"; import { markPaged } from "./integrity.ts"; /** No more than one reminder per hour while the same marker remains. */ export const STALL_RENOTIFY_MS = 60 * 60_000; export interface StallVerdict { /** The marker's own line, when one is there. */ since?: string; /** Count written by the stalled tick producer, when its marker is readable. */ unconsumedTicks?: number; /** Whole hours elapsed since the marker timestamp, when it is parseable. */ stalledHours?: number; page: boolean; } /** * Reads the orchestrator's stall marker and decides whether this tick pages. * * The marker is written by the tick extension inside the orchestrator session * ({@link STALL_MARKER_FILE}) when two of its own prompts go unconsumed — the * one signal that separates "the process is alive" from "the loop is reading * its queue". Every other guard in this system reads healthy through a wedge: * the herdr recovery plugin tests for a live process and an agent label, both * of which survive it, and `/healthz` describes this daemon, which is a * different process entirely. * * The daemon is the natural watcher precisely because it is that different * process: it already wakes every five minutes, it owns a working escalation * path, and nothing about its health depends on the session that is stuck. A * wedged loop cannot page for itself, and the herdr plugin only runs on session * lifecycle events — a session that stays alive and stops working emits none. * * Resets when the marker disappears, so a second stall days later pages again. */ export function checkStall(gate: StallGate, marker: string, now = Date.now()): StallVerdict { if (!existsSync(marker)) { gate.paged = false; delete gate.lastPagedAt; return { page: false }; } const page = !gate.paged || gate.lastPagedAt === undefined || now - gate.lastPagedAt >= STALL_RENOTIFY_MS; let since: string | undefined; let unconsumedTicks: number | undefined; let stalledHours: number | undefined; try { const body = readFileSync(marker, "utf8").split("\n")[0]?.trim(); if (body !== undefined && body !== "") { since = body; const ticks = /\b(\d+) ticks queued unconsumed\b/.exec(body)?.[1]; if (ticks !== undefined) unconsumedTicks = Number(ticks); const startedAt = Date.parse(body.split(/\s+/, 1)[0] ?? ""); if (Number.isFinite(startedAt)) { stalledHours = Math.max(0, Math.floor((now - startedAt) / STALL_RENOTIFY_MS)); } } } catch { // An unreadable marker still means stalled; its evidence is a nicety. } return { ...(since === undefined ? {} : { since }), ...(unconsumedTicks === undefined ? {} : { unconsumedTicks }), ...(stalledHours === undefined ? {} : { stalledHours }), page, }; } /** * At most three automatic restarts in six hours, per project (Phase 4). * * Three, because the failure this bound exists for is a wedge whose cause the * restart does not remove: a session that gets stuck, gets resumed, and gets * stuck again on the same turn. Two restarts can be bad luck; the third * consecutive one is a diagnosis nobody has made, and continuing to resume it * automatically would replace an operator's page with an invisible loop. Beyond * the bound the hourly page is the whole behaviour, exactly as before. * * Six hours, because the page it falls back to renotifies hourly * ({@link STALL_RENOTIFY_MS}) and a restart is only ever attempted on a tick * that pages — so the window holds three attempts and then at least three * hours of pages before the counter can drain. */ export const ORCHESTRATOR_RESTART_LIMIT = 3; export const ORCHESTRATOR_RESTART_WINDOW_MS = 6 * 60 * 60_000; /** * What one automatic-restart attempt did, for the escalation to state verbatim. * * Every variant is a fact about this daemon's own action, not a guess about the * session: the page has to be readable by an operator who will decide whether * to intervene, and "the daemon tried X and X said Y" is the only thing that * lets them skip re-deriving it. */ export type OrchestratorRestartOutcome = /** The wedged omp process was signalled; herdr's hook owns the resume now. * `attempt` is this restart's ordinal inside the 6h window, so the page says * "2 of 3" rather than leaving the operator to count pages. */ | { kind: "signalled"; detail: string; attempt: number } /** Nothing was running under the configured identity — nothing to restart. */ | { kind: "already-gone"; detail: string; attempt: number } /** The bound is spent; these are the attempts inside the window. */ | { kind: "bounded"; attempts: readonly { at: number; reason: string }[] } /** A precondition says an automatic restart cannot work here. */ | { kind: "declined"; why: string } /** The attempt was made and refused to report success. */ | { kind: "failed"; error: string; attempt: number }; /** * Restart a wedged orchestrator by exact identity, bounded (Phase 4). * * ## Why this mechanism and not `agent start --resume=` * * `recover.sh:start_fleet` resumes the fleet with * `agent start --kind omp --pane -- --resume=`. The daemon * cannot issue that: it knows neither the pane nor the session ref. Both live in * herdr's own saved identity, written by `remember_identity` at the last * successful recovery, and `agent start` submits omp *into* a pane's shell — run * against the wrong pane it would collide with a live session. * * So the daemon does the one half it can do exactly, and lets herdr do the half * it owns: SIGTERM the wedged omp process, leaving its shell alive, so herdr's * `pane.exited` hook fires `recover.sh`, which resumes the SAVED ref * (`recover-test.sh` case 9b is precisely "dead omp, surviving shell"). That is * also, word for word, what today's escalation already tells the operator to do * by hand — this makes the daemon do it three times before asking. * * It is never a fresh session: nothing here supplies a ref, so if herdr has no * saved identity it pages instead of inventing one. * * ## Preconditions, both of which must be read rather than assumed * * - **External orchestrator only.** An embedded session is a child of this * daemon with no herdr pane and no saved ref; killing it would produce a * fresh session or none. A dead embedded session is * {@link reconcileOrchestratorDown}'s machine, with its own incident rows — * this must not page or act against it. * - **Recovery not pinned.** `omp-conductor stop --pane` leaves a pin file that * `recover.sh` obeys by refusing to resume. Signalling through a pin would * convert a wedged-but-running session into a stopped one with nothing * coming back, which is strictly worse than the page. * * The counter row is written BEFORE the signal, deliberately: a crash between * the two must not leave the restart uncounted, because an uncounted restart is * how a bound of three becomes unbounded. */ export async function restartWedgedOrchestrator( d: Pick, now: number, ): Promise { if (d.project.escalation.orchestrator !== "external") { return { kind: "declined", why: `this project runs an embedded orchestrator, which has no herdr pane and no saved ` + `session ref — there is nothing to resume by exact identity, and a crashed embedded ` + `session is the orchestrator-down incident's business, not this watch's`, }; } // Read the pin, never assume it: an unresolvable pin path means this host has // no tick config where herdr expects one, and then the identity a restart // would act on is a guess — the same refusal `stopConductorPane` makes. const pin = resolvePaneHaltPath(d.project.name); if (pin.kind === "unresolved") { return { kind: "declined", why: `the pane recovery pin could not be located (${pin.reason}), so whether herdr would resume is unknown`, }; } if (existsSync(pin.path)) { return { kind: "declined", why: `pane recovery is pinned at ${pin.path} (\`omp-conductor stop --pane\`), so herdr would ` + `not resume the session this would stop — clear it with \`omp-conductor resume\` first`, }; } const prior = d.store.orchestratorRestartsSince( d.project.name, now - ORCHESTRATOR_RESTART_WINDOW_MS, ); if (prior.length >= ORCHESTRATOR_RESTART_LIMIT) return { kind: "bounded", attempts: prior }; const attempt = prior.length + 1; const reason = "wedged: stall marker present on a paging tick"; d.store.recordOrchestratorRestart(d.project.name, now, reason); try { // `stopConductorPane` is the verified exact-identity path: it resolves the // agent name from the tick config, refuses on an invalid config, on a // non-unique name, on a pane whose agent is not omp, and on any liveness // probe or signal it cannot prove — then SIGTERMs (SIGKILL after a 10s // grace). It does NOT pin recovery; only `haltWithPane` does, which is what // makes it usable here. Its herdr reads are `spawnSync`, so this blocks the // loop for seconds — acceptable at most three times per six hours, and the // alternative is a second, unverified implementation of pane identity. const stopped = await (d.restartOrchestrator ?? ((project: string) => stopConductorPane(project)))( d.project.name, ); return stopped.stopped === "already-gone" ? { kind: "already-gone", detail: stopped.detail, attempt } : { kind: "signalled", detail: stopped.detail, attempt }; } catch (err) { return { kind: "failed", error: errText(err), attempt }; } } /** The escalation's account of the restart: what was tried, and what happened. */ export function restartLines(outcome: OrchestratorRestartOutcome): string[] { switch (outcome.kind) { case "signalled": return [ `Automatic restart ${outcome.attempt} of ${ORCHESTRATOR_RESTART_LIMIT} per 6h: the daemon`, `SIGTERMed the wedged omp process (${outcome.detail}). Its shell survives, so herdr's`, "pane-exited hook runs recover.sh, which resumes the SAVED session ref — never a fresh", "session. If the session is back and consuming ticks, this page is the record of that,", "not a request.", ]; case "already-gone": return [ `Automatic restart ${outcome.attempt} of ${ORCHESTRATOR_RESTART_LIMIT} per 6h: nothing was`, `running under the configured identity (${outcome.detail}), so there was nothing to`, "signal. herdr's recovery owns bringing it back.", ]; case "bounded": return [ `Automatic restart NOT attempted: the bound of ${ORCHESTRATOR_RESTART_LIMIT} per 6h is spent.`, "It tried, and each of these was followed by another wedge:", // The store answers newest-first; read oldest-first here, because the // point of the list is the sequence that failed to fix anything. ...[...outcome.attempts] .sort((a, b) => a.at - b.at) .map((attempt) => `- ${new Date(attempt.at).toISOString()} ${attempt.reason}`), `${ORCHESTRATOR_RESTART_LIMIT} resumes did not fix it, so the cause is not the session —`, "attach and diagnose.", ]; case "declined": return [`Automatic restart NOT attempted: ${outcome.why}.`]; case "failed": return [ `Automatic restart ${outcome.attempt} of ${ORCHESTRATOR_RESTART_LIMIT} FAILED: ${outcome.error}`, "It is counted against the 6h bound anyway — a failed attempt is an attempt, and a", "restart that cannot prove it worked must not be retried freely.", ]; } } /** * Restarts a wedged orchestrator, bounded, then pages tier 2 either way. * * It used to only page, on the reasoning that a wedge lands mid-turn and this * process cannot tell a half-applied edit from an idle loop. That reasoning was * right about the danger and wrong about the remedy: the page's own instruction * was "SIGTERM the omp process; herdr-conductor resumes it by exact identity", * so the operator's correct action was mechanical, and an unattended fleet spent * hours wedged waiting for somebody to perform it. Phase 4 has the daemon * perform it — at most three times per six hours, by exact ref only, never a * fresh session — and keeps the page, now carrying what it did. * * The page still goes out on a successful restart. That is deliberate: the * marker is written by the wedged session and cleared by the resumed one's first * consumed tick, so "restarted" is a claim about the signal, not about recovery. * The operator gets the record, and the next tick's silence is the confirmation. * * The restart is attempted only on a tick that pages, which is what bounds its * frequency to the hourly renotify — so the 6h counter can hold three attempts * with hours of pages between them, rather than three inside fifteen minutes. */ export async function watchOrchestrator(d: Deps, now = Date.now()): Promise { const marker = join(stateDir(), STALL_MARKER_FILE); const repeat = d.stall.paged; const verdict = checkStall(d.stall, marker, now); if (!verdict.page) return; // Before the page, so the page can state what was done rather than describing // a remedy that has in fact already been applied. Never throws: every failure // mode is an outcome variant the escalation renders, because a restart that // blew up must not also swallow the page that says the session is wedged. const restart = await restartWedgedOrchestrator(d, now); const greenRuns = d.store.activeRuns(d.project.name).filter((run) => run.state === "pushed-green"); const repeatSuffix = repeat ? ` — still stalled (${ verdict.stalledHours === undefined ? `${new Date(now).toISOString().slice(0, 13)}Z` : `${verdict.stalledHours}h` })` : ""; log(`ERROR: the orchestrator session is not draining its queue — ${verdict.since ?? "no timestamp"}`); for (const line of restartLines(restart)) log(line); const delivered = await safeEscalate(d, { tier: 2, category: "confirmed-failure", urgent: true, project: d.project.name, issue: NO_ISSUE, // Keyed on the marker's own timestamp, not the date. The dedup ledger keys // on this summary, and two wedges in one day is not a hypothetical — the // failure mode is a session that gets stuck, gets restarted, and gets stuck // again on the same cause an hour later. The hourly suffix makes bounded // reminders distinct without allowing every five-minute tick through. summary: `Orchestrator session wedged (${verdict.since ?? `marker at ${marker}`}) — ` + `it has stopped reading its queue (${d.project.name})${repeatSuffix}`, detail: [ verdict.since ?? "Marker present with no readable timestamp.", `Unconsumed ticks: ${verdict.unconsumedTicks ?? "unknown"}`, `Open green worker PRs: ${greenRuns.length}`, ...greenRuns.map((run) => `- ${run.prUrl ?? `#${run.issue} (PR URL unavailable)`}`), `Marker: ${marker}`, "", "Its process and its herdr agent label are both healthy, which is why nothing else noticed:", "the loop is alive and consuming nothing, so ticks and your messages queue behind it unread.", "", ...restartLines(restart), "", // Only worth saying while the daemon has not already done it. Telling an // operator to SIGTERM a process the daemon just SIGTERMed is how a page // stops being read. ...(restart.kind === "signalled" || restart.kind === "already-gone" ? ["Attach and look before you act further — a wedge lands mid-turn.", ""] : [ "Attach and look before you act — a wedge lands mid-turn. Then SIGTERM the omp process:", "herdr-conductor resumes it by exact identity, and the first consumed tick clears this marker.", "", ]), "Dispatch is unaffected: workers keep running. What stops is drain, groom, report and merge.", ].join("\n"), }); markPaged(d.stall, delivered, now); } /** * After a false→true condition transition, poke the orchestrator heartbeat so * it does not wait a full interval (#329). Best-effort: missing tick config or * a failed write leaves the row flagged in the ledger for the next heartbeat. */ export function wakeOrchestratorForMetConditions( projectName: string, met: readonly { id: string; condition?: string }[], writeLog: (line: string) => void = log, ): void { if (met.length === 0) return; for (const decision of met) { writeLog( `decision ${decision.id} condition met (${decision.condition ?? "?"}) — requesting orchestrator tick`, ); } const tickCwd = resolveTickConfigCwd(projectName); if (tickCwd === undefined) { writeLog( `decision condition met for ${met.map((m) => m.id).join(", ")} but no tick config cwd — heartbeat will surface them on its next interval`, ); return; } const ids = met.map((m) => m.id).join(","); const reason = `condition-met ${ids}`; if (requestImmediateTick(tickCwd, reason)) { writeLog(`requested immediate tick at ${tickCwd}: ${reason}`); } else { writeLog( `could not write tick request under ${tickCwd}; conditions ${ids} wait for the next heartbeat`, ); } } /** * Wake the orchestrator because a worker stopped to ask a question (#990). * * `question` is the third-largest class in this ledger — 58 of 839 runs — and * every one of them is a parked worker holding a slot until someone reads the * question. Nothing woke the orchestrator for it: the only wake was a decision * condition being met, so on a fleet with a 1800s heartbeat a tier-1 question * whose answer is one comment could sit unread for half an hour. * * Deliberately narrow. Only the blocked path wakes: a failed run, a cap kill * and a clean settle are the next scheduled tick's business, and waking on * every terminal state turns the heartbeat into a busy loop — which would be a * worse fleet than the one that waits. * * Debounced by the marker itself rather than by a counter: an unconsumed * request already asks for exactly the wake this call wants, so three workers * blocking in one pass write one request and the *first* question's number * survives as the reason. Best effort throughout — a marker that cannot be * written is logged, and the settlement it belongs to is never affected. */ export function wakeOrchestratorForBlockedRun( projectName: string, issue: number, writeLog: (line: string) => void = log, ): void { const tickCwd = resolveTickConfigCwd(projectName); if (tickCwd === undefined) { writeLog( `#${issue} is blocked but no tick config cwd — the question waits for the next heartbeat`, ); return; } const pending = readTickRequestReason(tickCwd); if (pending !== undefined) { writeLog(`#${issue} is blocked; a tick request is already pending (${pending})`); return; } const reason = `tier1-question #${issue}`; if (requestImmediateTick(tickCwd, reason)) { writeLog(`requested immediate tick at ${tickCwd}: ${reason}`); } else { writeLog( `could not write tick request under ${tickCwd}; #${issue}'s question waits for the next heartbeat`, ); } } // ----------------------------------------------------------------- worker progress /** * Watching live workers for silence, and settling a run that stopped making * progress (#1086). * * The only bounds a worker's own session enforces are the turn ceiling and the * wall clock — neither fires until the whole budget is gone, so a session that * hangs at minute 44 keeps its slot for another 46 minutes and then dies as a * `wall-clock-cap-*` verdict that reads like an oversized slice about work that * may already be merged. The signal that separates "thinking" from "gone" is * already on disk: a live session writes its transcript continuously, so the * file's own mtime is when the worker was last demonstrably alive. * * Deliberately transcript-only: the row's turn counter rides in the evidence, * but it is never the trigger — one turn can legitimately run for minutes on a * slow provider, and this fleet has measured 1.5 min/turn. * * A stall whose PR is already pushed and green settles `pushed-green` — the * exact state any delivered run holds — so the settle sweep owns the merge and * no continuation is charged for work that landed (#1086). Every other stall * settles `killed` over the observed facts; the classifier turns those into * `progress-stall`, whose recovery splits on artifacts exactly as the caps do. */ export async function watchWorkerProgress( d: Pick, now = Date.now(), ): Promise { const thresholdMs = stallSilenceMs(d.caps); // A paused worker banks its wall clock and goes quiet on purpose (#938): // silence under pause is the pause working, never a hang. const pausedIssues = new Set( d.workerControls .snapshot(d.project.name) .filter((w) => w.phase === "pausing" || w.phase === "paused") .map((w) => w.issue), ); for (const run of d.store.liveRuns(d.project.name)) { if (pausedIssues.has(run.issue)) continue; if (run.sessionFile === undefined) continue; let wroteAt: number; try { wroteAt = Math.trunc(statSync(run.sessionFile).mtimeMs); } catch { // No transcript yet (claimed, session opening) or none readable: nothing // to observe, which is never evidence of a stall. continue; } // Record before judging: `status` renders this instant as the run's // silence interval whether or not the threshold fires (#1086). if (run.lastProgressAt !== wroteAt) { d.store.updateRun(run.id, { lastProgressAt: wroteAt }); } const silentMs = now - wroteAt; if (silentMs < thresholdMs) continue; // Re-read before settling: the session can finish between the stat above // and here, and a terminal row must never be re-settled over. const current = d.store.getRun(run.id); if (current === undefined || !LIVE_STATES.includes(current.state)) continue; const minutes = Math.round(silentMs / 60_000); const silent = minutes < 60 ? `${minutes}m` : `${Math.floor(minutes / 60)}h${minutes % 60 === 0 ? "" : `${minutes % 60}m`}`; const why = `transcript silent ${silent} at turn ${current.turns}/${current.maxTurns}`; log(`#${current.issue} ${why} — settling (silence window ${Math.round(thresholdMs / 60_000)}m)`); // Best-effort abort through the run-control surface, so a session that can // still answer exits through its own settlement path. One that cannot is // exactly the case this pass exists for: the row settles below regardless, // and the re-read guard keeps whichever writer lands second out. try { void d.workerControls.stop(d.project.name, current.issue, `progress stall: ${why}`).catch(() => {}); } catch { // No live control for this run — the settle below is the only writer. } // Work that already landed is delivered work — but only verified green // counts: landing `pushed-green` puts the row exactly where any delivered // run sits, under the settle sweep's merge watch, with nothing charged. let deliveredGreen = false; if (current.prUrl !== undefined && current.headSha !== undefined) { try { deliveredGreen = (await d.tracker.verifyPr(current.prUrl, current.headSha))?.status === "green"; } catch { deliveredGreen = false; } } if (deliveredGreen) { d.store.updateRun(current.id, { state: "pushed-green", endedAt: now }); log(`#${current.issue} stalled but ${current.prUrl} was already green — settled as delivered`); await safeEscalate(d, { tier: 1, project: d.project.name, issue: current.issue, runId: current.id, summary: `#${current.issue} went silent (${why}) with its PR already green — settled as delivered`, detail: [ current.prUrl ?? "(no PR URL)", `Branch ${current.branch} at ${current.headSha}.`, `Session: ${current.sessionFile ?? "(no transcript)"}`, "", "The worker never reported, so there is no settlement narrative — the PR's diff is the record.", "The slot is released; the settle sweep watches the merge from here.", ].join("\n"), }); await wakeDispatchLogged(d.project.name); continue; } d.store.updateRun(current.id, { state: "killed", endedAt: now, lastError: `progress-stall: ${why}`, }); await safeEscalate(d, { tier: 1, project: d.project.name, issue: current.issue, runId: current.id, summary: `[progress-stall] #${current.issue} attempt ${current.attempt}: ${why}`, detail: [ `${current.prUrl === undefined ? "No PR" : `PR ${current.prUrl} not verified green`} — the classifier decides continue vs escalate from what attempt ${current.attempt} left.`, `Branch ${current.branch}; worktree ${current.worktree === "" ? "(none)" : current.worktree}.`, `Session: ${current.sessionFile ?? "(no transcript)"}`, ].join("\n"), }); await wakeDispatchLogged(d.project.name); } } /** Best-effort dispatch wake once a stall settle freed its slot (#1086). */ async function wakeDispatchLogged(projectName: string): Promise { try { log(`dispatch wake after stall settle: ${await wakeDispatch(projectName)}`); } catch (err) { log(`dispatch wake after stall settle failed: ${errText(err)}`); } }