Files
gbrain/test/autopilot-failure-cooldown.test.ts
T
bb2e88c42a v0.42.52.0 fix(reliability): autopilot dead-job storm + supervisor wedge + sync/status/minion reliability (#2194 #2227 #1994 #1737 #1738 #1950 #1984) (#2287)
* test(supervisor): pin LOCK_HELD fence-exit is never counted as a crash (#2227)

A duplicate supervisor loses the queue-scoped DB singleton lock (#1849) and
exits LOCK_HELD before spawning a worker or emitting 'started'. summarizeCrashes
counts only worker_exited, so the fence path is structurally uncountable. Pin it
so a future refactor that logs worker_exited on the fence path fails here instead
of silently re-introducing the crash-budget breaker-trip loop.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(autopilot): per-source cycle binds FS phases to source.local_path, not global repo (#2194 #2227)

A per-source autopilot-cycle inherited the global sync.repo_path as brainDir while
stamping DB freshness for source_id — mixed scope. FS phases (sync/lint/extract)
ran against the wrong tree, so the failure-cooldown and freshness gates would
attribute work to the wrong source. Resolve the source's local_path in the handler
(reuse the archive-recheck SELECT) and bind brainDir to it; a pure-DB source gets
null (FS phases skip) instead of falling through to the global checkout. Legacy
no-source dispatch keeps the global repoPath. Prerequisite for the cooldown/split
commits (codex outside-voice #8). Resolves TODOS:634.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(supervisor): detect a live supervisor via the DB lock under split $HOME (#2227)

jobs supervisor status + doctor read the HOME-derived pidfile, so a supervisor
started under a different $HOME (keeper=/root vs ops=/data) read as 'not running'
while healthy — the false signal that drives an operator to spawn a duplicate.
Both surfaces now fall back to the queue-scoped DB singleton lock (#1849), the
HOME-independent authority, when the pidfile shows nothing. New isLockHolderLive
keys on lock freshness (ttl + heartbeat steal-grace), never process.kill, so PID
reuse can't false-positive (pid-liveness-alone-pid-reuse). Status surfaces the
holder host/pid + recorded concurrency/max-rss from the latest started event.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(supervisor): degraded retry instead of permanent give-up on crash storm (#1994 #2227)

max_crashes_exceeded gave up forever, so a transient DB-pooler blip that tripped
the soft budget wedged the queue until a human restart (#2227's breaker-trips tail).
Crossing the soft budget now enters degraded mode: keep respawning with capped
exponential backoff (60s cap — a paced retry, not a hot loop) and emit a loud
crash_budget_degraded health_warn. The existing stable-run reset clears the count
once a respawn survives >5min, so a recovered DB self-heals. Permanent give-up
fires only at a much-higher hard ceiling (maxCrashes × 10), tunable/disablable via
GBRAIN_SUPERVISOR_HARD_STOP_CRASHES (0 = never). Resolves TODOS:92.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* feat(autopilot): clamp fan-out to worker concurrency + doctor warning (#2194)

Fan-out resolved to 4 (Postgres) regardless of worker --concurrency, so surplus
cycles queued behind the worker and raced the stalled-sweeper. Two fixes for the
same mismatch:
- resolveEffectiveFanoutMax clamps to max(1, concurrency-1) (reserve a slot),
  gated on a LIVE DB-lock holder so a stale started-audit row can't shrink
  throughput (codex #9/D5); no live holder → unknown → unclamped base. Escape
  hatch autopilot.fanout_clamp_to_concurrency.
- doctor's autopilot_fanout_concurrency check warns when fan-out exceeds
  effective slots — the misconfig was silent before. Advisory (started-event
  concurrency), wired into both doctor surfaces.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* feat(autopilot): per-source failure cooldown — break the dead-job storm (#2194)

Only SUCCESS gated dispatch, so a source whose cycle kept failing/timing-out
re-fanned-out every 5-min tick forever (200+ dead jobs/24h). Now a failed source
backs off with bounded exponential cooldown (10→120min). Read at DISPATCH from
minion_jobs dead/failed rows (timeouts/RSS-kills dead-letter via SQL and never
run handler code, so a write-only hook would miss them) AND re-checked at CLAIM
time in the handler (codex #5: already-queued/retrying jobs). A success clears it
(codex #7); null-source rows excluded (codex #6); engine-parity via executeRaw.
Disable with autopilot.failure_cooldown_min=0. Fail-open if config/history reads
error. Surfaced via fanout_cooldown_skipped + the fanout summary.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* feat(autopilot): split the cycle — per-source phases + one global-maintenance job (#2194 #2227)

N per-source cycles each ran the brain-wide global phases (embed-all/orphans/
purge/…) concurrently, thrashing the same rows and taking the worker 4→10GB in
<60s → RSS-kill → orphaned stalls. Split them: per-source jobs now run only
source-scoped (+ mixed) phases and stamp last_source_cycle_at; a new
autopilot-global-maintenance job runs the global phases ONCE per window
(idempotency_key + maxWaiting:1 = structural single-flight) and stamps
autopilot.last_global_at. This is the codex-endorsed design that replaced the
rejected skip-and-stamp-fresh approach (codex #1/#2): no freshness poisoning, no
starvation — global work always runs as its own job, never marked done when it
wasn't. PHASE_SCOPE is now a runtime partition (GLOBAL ∪ NON_GLOBAL == ALL).
last_full_cycle_at still written for doctor/legacy (no longer a global gate).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(doctor): guard nullable engine in supervisor DB-lock fallback (#2227)

Follow-up to the supervisor-visibility commit: doctor's engine binding is
BrainEngine | null, so the inspectLock fallback must guard on a non-null engine
(tsc TS2345). No behavior change — a null engine simply skips the DB-lock probe
and falls back to the pidfile reading, as before.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(doctor): categorize autopilot_fanout_concurrency check as ops (#2194)

Follow-up to the fan-out/concurrency commit: the doctor-categories drift guard
requires every check name in doctor.ts to belong to exactly one category set.
Add the new autopilot_fanout_concurrency check to OPS_CHECK_NAMES (infrastructure
liveness, alongside wedged_queue/supervisor).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* docs: update KEY_FILES for the autopilot cycle split + supervisor degraded-retry (#2194 #2227)

Post-ship document-release: refresh the KEY_FILES current-state entries that
drifted — cycle.ts (GLOBAL/NON_GLOBAL phase split + last_source_cycle_at /
autopilot.last_global_at), jobs.ts (per-source local_path brainDir, claim-time
cooldown, autopilot-global-maintenance handler), supervisor.ts + child-worker
(degraded retry instead of permanent give-up; hard ceiling), db-lock.ts
(isLockHolderLive), handler-timeouts (new handler). Regenerated llms bundle.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(minions): handleTimeouts counts the timed-out run as a spent attempt (#1737)

The per-job timeout_at dead-letter (handleTimeouts) set status='dead' without
incrementing attempts_made, unlike the wall-clock and stall dead-letter siblings.
It is the FIRST killer to fire for the long-lane handlers (subagent / embed-backfill
/ autopilot-cycle) because timeout_ms is stamped at submit, so a timed-out long job
reported `attempts: 0/N (started: N)`. Mirror the siblings with attempts_made + 1
(terminal, no retry). Safe against double-count: the worker sweep runs handleStalled
-> handleTimeouts -> handleWallClockTimeouts sequentially and awaited, each guarded on
status='active', so the first to dead-letter excludes the row from the rest.

Regression assertions added (test/minions.test.ts + e2e/minions-resilience.test.ts)
so the increment can't be silently dropped.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(agent): recognize trailing switches in `agent run`, keep prompts freeform (#1738)

parseRunFlags() broke flag parsing at the first positional token, so any flag
after the prompt (`gbrain agent run "do X" --detach`) was swallowed into the
prompt string and silently ignored. Now the no-value switches --detach/--follow/
--no-follow are hoisted when they trail the prompt, while everything else stays
verbatim: an unknown --word is treated as prompt text (no "unknown flag" throw),
a --switch mid-prompt is preserved, and `--` suppresses hoisting entirely for a
literal escape. Value-flags now reject a missing or flag-shaped value (and
--max-turns/--timeout-ms a non-number) instead of capturing undefined/NaN.

Contract change: a prompt that starts with or trails an unguarded --word no
longer errors; a literal trailing --detach needs `--`. Help text updated; tests
revised + extended (test/agent-cli.test.ts).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(sync): honest live-sync status + progress-aware stall-abort (#1950)

Finishes the #2255 honest-freshness story for two gaps it left.

(a) `gbrain sources status` printed "idle" while a sync proc held the per-source
lock (the reported bug). New shared liveSyncStatus() helper in db-lock.ts reads
the SAME live-lock signal `gbrain doctor` uses; runStatus now shows "running"
(BACKFILL column + a sync_running field in --json) and suppresses the misleading
"never synced" warning while a sync is live. One helper, so the surfaces can't
drift (doctor/status retrofit tracked as a follow-up).

(b) A sync wedged-but-alive kept refreshing its lock heartbeat (it fires on its
own timer) and hadn't hit the wall-clock deadline, so only a manual pkill freed
it. New in-band stall watchdog keys off FORWARD IMPORT PROGRESS (progress.tick),
not the heartbeat: if no file completes for GBRAIN_SYNC_STALL_ABORT_SECONDS
(default 900s), it aborts via a controller composed into opts.signal, so the
drain returns partial() (last_commit unchanged, next run resumes from the
checkpoint) and withRefreshingLock releases the lock. Limits, documented in
code: a single file slower than the window trips it; a fully starved event loop
won't fire the timer (the wall-clock hard deadline is that backstop).

Tests: liveSyncStatus (live/expired/none/per-source) in db-lock-inspect; the
resolveStallAbortSeconds env matrix in sync-hard-deadline.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* feat(status): version field + per-section --deadline-ms budget (#1984)

`gbrain status` had no version in its JSON envelope and could hang on a slow
connection with no way to get a partial answer. Two additions:

- version: the StatusReport JSON now carries the local gbrain CLI version so a
  poller can pin behavior to a build. Thin-client also surfaces remote_version
  (the brain server's version), and the get_status_snapshot MCP op reports its
  version for that parity.
- --deadline-ms=N / --fast: a shared wall-clock budget. Each section is raced
  against the REMAINING budget via Promise.race (NOT process-watchdog, which
  SIGKILLs and can't return partial output), so one slow/hung section can't
  strand the snapshot — it's marked stale and the rest still return. The
  envelope gains partial:true + stale_sections[]; exit code stays 0 (a snapshot
  was produced). Invalid --deadline-ms → exit 2.

Tests: parseDeadlineFlag + withSectionDeadline (hermetic), the usage-error exit,
version presence in the PGLite envelope, and the op's version key.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* fix(sync): report stall_timeout distinctly + document in-flight limit (#1950)

Pre-landing review (codex + adversarial): the stall watchdog aborted opts.signal
but the per-iteration abort checks returned partial('timeout'), collapsing a
wedge-reap into a user --timeout/SIGINT so JSON consumers couldn't tell them
apart. Add a 'stall_timeout' reason (set via a stallAborted flag) on the three
import-loop abort sites; deletes/renames-phase and checkpoint sites stay 'timeout'.
Sharpen the watchdog comment: the abort is observed BETWEEN files, so a hang
inside a single importFile is not interrupted until it returns (TODO: thread a
cancellation signal through importFile).

* fix(agent): `--` escape suppresses trailing-switch hoisting anywhere (#1738)

Pre-landing review: the leading-flag loop breaks at the first positional, so the
`escaped` flag only fired for a leading `--`. A `--` placed after a positional
left trailing-switch hoisting active, so `agent run note -- body --detach`
silently detached and dropped the `--` as junk. Suppress hoisting whenever a
literal `--` appears in the prompt. Regression test added.

* fix(status): deadline-ms usage-error + scoped stale_sections + cancel losing remote call (#1984)

Pre-landing review (codex): (1) bare `--deadline-ms` with no value silently fell
through to no-budget/--fast instead of a usage error; (2) thin-client timeout
reported both sync+cycle stale even under `--section sync`, naming a section the
caller excluded (local path was already correct); (3) the section race abandoned
the remote promise locally but didn't cancel the in-flight MCP call — pass the
budget as timeoutMs so the losing side actually cancels. Regression test added.

* v0.42.52.0 fix(reliability): autopilot dead-job storm + supervisor wedge + sync/status/minion reliability (#2194 #2227 #1994 #1737 #1738 #1950 #1984)

Bundles the already-reviewed autopilot/supervisor stabilization (#2194 #2227
#1994: cycle split, per-source failure cooldown, fan-out clamp, degraded
supervisor retry, DB-lock live-supervisor detection) with four operational
fixes: minion timeout attempt-accounting (#1737), agent-run trailing-flag
parsing (#1738), honest live-sync sources status + progress-aware stall
watchdog (#1950), and status version + --deadline-ms partial result (#1984).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

* docs: document GBRAIN_SYNC_STALL_ABORT_SECONDS env knob (#1950)

Post-ship doc sync (/document-release): add the sync stall watchdog env var to
the CLAUDE.md sync-tuning table (Five → Six knobs) + regenerate the llms bundle.

* test: quarantine #2249 fanout tests as *.serial (R1 env-isolation) (#2194)

The cherry-picked autopilot-fanout-clamp + doctor-autopilot-fanout-concurrency
tests mutate process.env.GBRAIN_AUDIT_DIR in beforeEach/afterEach, which the
check:test-isolation R1 lint flags (parallel shards load multiple files per
process). Rename to *.serial.test.ts (sanctioned quarantine — they run under
--max-concurrency=1) instead of restructuring the reviewed test bodies. No logic
change; both files stay green (9 tests). Fixes the failing verify CI check.

---------

Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-21 06:36:43 -07:00

152 lines
6.8 KiB
TypeScript

/**
* #2194 fix #2 — failure cooldown (the storm-breaker).
*
* A source whose autopilot-cycle keeps failing re-dispatched every 5-min tick
* (only SUCCESS gated dispatch), so the same handful of sources failed and
* re-fanned-out forever — 200+ dead jobs/24h. The cooldown backs a failed
* source off with bounded exponential delay, read at dispatch from minion_jobs
* (dead/failed rows) AND re-checked at claim time (codex #5). A success clears
* it (codex #7). These tests pin the pure math, the engine query, the
* null-source guard (codex #6), and the dispatch/claim-time gates.
*/
import { describe, test, expect, beforeAll, afterAll, beforeEach } from 'bun:test';
import { PGLiteEngine } from '../src/core/pglite-engine.ts';
import { resetPgliteState } from './helpers/reset-pglite.ts';
import {
cooldownMinForCount,
isInFailureCooldown,
readRecentSourceFailures,
isSourceInCooldown,
selectSourcesForDispatch,
resolveFailureCooldownOpts,
type SourceFailure,
type CooldownOpts,
} from '../src/commands/autopilot-fanout.ts';
import type { SourceRow } from '../src/core/engine.ts';
const OPTS: CooldownOpts = { baseMin: 10, capMin: 120 };
describe('cooldownMinForCount — bounded exponential', () => {
test('grows 10, 20, 40, 80 then caps at 120', () => {
expect(cooldownMinForCount(1, OPTS)).toBe(10);
expect(cooldownMinForCount(2, OPTS)).toBe(20);
expect(cooldownMinForCount(3, OPTS)).toBe(40);
expect(cooldownMinForCount(4, OPTS)).toBe(80);
expect(cooldownMinForCount(5, OPTS)).toBe(120); // 160 capped to 120
expect(cooldownMinForCount(99, OPTS)).toBe(120);
});
test('zero/negative count or disabled base → 0', () => {
expect(cooldownMinForCount(0, OPTS)).toBe(0);
expect(cooldownMinForCount(3, { baseMin: 0, capMin: 120 })).toBe(0);
});
});
describe('isInFailureCooldown — pure decision', () => {
const now = Date.UTC(2026, 5, 16, 12, 0, 0);
const ago = (min: number) => new Date(now - min * 60_000);
test('no failure record → not in cooldown', () => {
expect(isInFailureCooldown(undefined, null, now, OPTS)).toBe(false);
});
test('disabled (baseMin 0) → never in cooldown', () => {
expect(isInFailureCooldown({ count: 5, lastFailedAt: ago(1) }, null, now, { baseMin: 0, capMin: 120 })).toBe(false);
});
test('failed 5min ago, count 1 (cooldown 10) → in cooldown', () => {
expect(isInFailureCooldown({ count: 1, lastFailedAt: ago(5) }, null, now, OPTS)).toBe(true);
});
test('failed 15min ago, count 1 (cooldown 10) → recovered by time', () => {
expect(isInFailureCooldown({ count: 1, lastFailedAt: ago(15) }, null, now, OPTS)).toBe(false);
});
test('success at/after the latest failure → cleared (codex #7)', () => {
const failure: SourceFailure = { count: 3, lastFailedAt: ago(5) };
expect(isInFailureCooldown(failure, ago(4), now, OPTS)).toBe(false); // success 4min ago > fail 5min ago
});
test('success BEFORE the latest failure, still in window → suppressed', () => {
const failure: SourceFailure = { count: 3, lastFailedAt: ago(5) };
expect(isInFailureCooldown(failure, ago(30), now, OPTS)).toBe(true);
});
});
describe('selectSourcesForDispatch — cooldown bucket', () => {
const src = (id: string): SourceRow => ({ id, name: id, config: {} } as SourceRow);
test('a stale source in cooldown is held in skippedCooldown, not dispatched', () => {
const sources = [src('a'), src('b')];
const failures = new Map<string, SourceFailure>([
['a', { count: 1, lastFailedAt: new Date(Date.now() - 60_000) }], // 1min ago, cooldown 10min
]);
const r = selectSourcesForDispatch(sources, 4, Date.now(), 60, failures, OPTS);
expect(r.dispatch.map(s => s.id)).toEqual(['b']);
expect(r.skippedCooldown.map(s => s.id)).toEqual(['a']);
});
});
describe('readRecentSourceFailures + isSourceInCooldown (PGLite)', () => {
let engine: PGLiteEngine;
beforeAll(async () => {
engine = new PGLiteEngine();
await engine.connect({});
await engine.initSchema();
}, 30000);
afterAll(async () => { await engine.disconnect(); });
beforeEach(async () => { await resetPgliteState(engine); });
async function addJob(status: string, sourceId: string | null, finishedMinAgo: number): Promise<void> {
const finished = new Date(Date.now() - finishedMinAgo * 60_000).toISOString();
const data = sourceId === null ? {} : { source_id: sourceId };
await engine.executeRaw(
`INSERT INTO minion_jobs (name, status, data, finished_at) VALUES ('autopilot-cycle', $1, $2, $3)`,
[status, data, finished],
);
}
test('groups dead/failed jobs by source with count + max(finished_at)', async () => {
await addJob('dead', 'repo-a', 5);
await addJob('failed', 'repo-a', 2);
await addJob('dead', 'repo-b', 10);
await addJob('completed', 'repo-a', 1); // not counted
const map = await readRecentSourceFailures(engine, { sinceMin: 120 });
expect(map.get('repo-a')?.count).toBe(2);
expect(map.get('repo-b')?.count).toBe(1);
expect(map.has('repo-a')).toBe(true);
// last failed is the most recent of the two (2 min ago).
const lastA = map.get('repo-a')!.lastFailedAt.getTime();
expect(Date.now() - lastA).toBeLessThan(4 * 60_000);
});
test('null source_id rows are excluded (codex #6)', async () => {
await addJob('dead', null, 3);
await addJob('dead', 'repo-c', 3);
const map = await readRecentSourceFailures(engine, { sinceMin: 120 });
expect(map.has('repo-c')).toBe(true);
expect([...map.keys()].some(k => !k)).toBe(false);
expect(map.size).toBe(1);
});
test('failures older than the window are not counted', async () => {
await addJob('dead', 'repo-old', 500); // way outside a 120min window
const map = await readRecentSourceFailures(engine, { sinceMin: 120 });
expect(map.has('repo-old')).toBe(false);
});
test('isSourceInCooldown: recent failure → true; cleared after a success stamp', async () => {
await engine.executeRaw(
`INSERT INTO sources (id, name, config, created_at) VALUES ('repo-cd', 'r', '{}'::jsonb, now())`, [],
);
await addJob('dead', 'repo-cd', 1); // 1 min ago, count 1 → 10min cooldown
expect(await isSourceInCooldown(engine, 'repo-cd')).toBe(true);
// Operator repairs + a successful cycle stamps last_source_cycle_at NOW.
await engine.updateSourceConfig('repo-cd', { last_source_cycle_at: new Date().toISOString() });
expect(await isSourceInCooldown(engine, 'repo-cd')).toBe(false);
});
test('isSourceInCooldown returns false when cooldown disabled (failure_cooldown_min=0)', async () => {
await engine.setConfig('autopilot.failure_cooldown_min', '0');
await addJob('dead', 'repo-dis', 1);
expect(await isSourceInCooldown(engine, 'repo-dis')).toBe(false);
const opts = await resolveFailureCooldownOpts(engine);
expect(opts.baseMin).toBe(0);
});
});