Skip to content

Commit e8fc728

Browse files
WatchAndyTWclaude
andcommitted
fix(run): stop silent health-gate failures — the "sometimes it just fails" bug (v0.8.4)
A backend that flunked its `--version` health probe was dropped SILENTLY in run.mjs's fallback loop (`if (!healthy) { fallbackCount++; continue; }`): no lastErr, no failures.log, no status record — just a bare "backend options exhausted; falling back to native" handoff with zero diagnostics. That made transient probe misses look like random "the CLI refused to run" failures. Compounded by two amplifiers in backends.mjs: - health() cached NEGATIVE verdicts for the full 60s TTL, so a single transient probe miss blackholed a working backend for a whole minute. - the `--version` probe ran only ONCE, so one cold-start / AV-scan / ConPTY hiccup scored the backend down. Fix (3 surgical changes, routing contract untouched): 1. run.mjs: a health skip is now LOUD — sets lastErr (→ carried into the handoff reason), writes a `failed` status record (kind:"health"), and appends a structured record to failures.log. 2. backends.mjs health(): cache POSITIVE verdicts only; a negative verdict is never cached → the very next call re-probes and recovers. 3. backends.mjs _healthUncached(): one-shot retry — probe `--version` up to twice before declaring a backend down (happy-path cost ~0). Tests: +2 regression cases (loud kind:"health" skip; one-shot-retry recovers a single flaky --version) → 108/108. Verified by codex through the live relay (VERDICT: PASS, no findings). Doc test-counts 106→108. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
1 parent d5d94a6 commit e8fc728

9 files changed

Lines changed: 129 additions & 24 deletions

File tree

.claude-plugin/marketplace.json

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,7 @@
1010
{
1111
"name": "multi-model-team",
1212
"description": "Delegates token-heavy, self-contained tasks to local CLI backends chosen by task size and type, with credit-exhaustion fallback through the backend chain to native Claude and a glanceable statusline HUD. Routing and shipped backend behavior are configured in config/roster.json; adding a new backend kind requires invoker and health support in code. /team runs a decompose → dispatch → verify → fix → synthesize pipeline; an optional config-gated UserPromptSubmit hook can proactively nudge delegation.",
13-
"version": "0.8.3",
13+
"version": "0.8.4",
1414
"author": {
1515
"name": "WatchAndyTW",
1616
"email": "watchandytw@gmail.com"
@@ -29,5 +29,5 @@
2929
]
3030
}
3131
],
32-
"version": "0.8.3"
32+
"version": "0.8.4"
3333
}

.claude-plugin/plugin.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
"$schema": "https://json.schemastore.org/claude-code-plugin-manifest.json",
33
"name": "multi-model-team",
44
"displayName": "Multi-Model Team",
5-
"version": "0.8.3",
5+
"version": "0.8.4",
66
"description": "Delegates token-heavy, self-contained tasks to local CLI backends chosen by task size and type, with credit-exhaustion fallback through the backend chain to native Claude and a glanceable statusline HUD. Routing and shipped backend behavior are configured in config/roster.json; adding a new backend kind requires invoker and health support in code. /team runs a decompose → dispatch → verify → fix → synthesize pipeline; an optional config-gated UserPromptSubmit hook can proactively nudge delegation.",
77
"author": {
88
"name": "WatchAndyTW",

CLAUDE.md

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ glanceable statusline HUD.
99
(the agy lane runs under a real pseudo-terminal — ConPTY on Windows, forkpty on POSIX); everything
1010
else is Node stdlib. Cross-platform (Windows/Linux/macOS). `package.json` `"type":"module"`.
1111

12-
**Status:** built, adversarially reviewed, and green. `npm test` passes **106/106** offline
12+
**Status:** built, adversarially reviewed, and green. `npm test` passes **108/108** offline
1313
(no backend calls; live agy/codex behaviour is smoke-tested by hand, not via a `npm test` gate).
1414
Two live backends: **agy** (Gemini)
1515
and **codex** (OpenAI Codex CLI); opencode remains a config-only stub. codex also serves as the
@@ -352,7 +352,7 @@ fallback hop.
352352
## Testing
353353

354354
```bash
355-
npm test # offline: 106/106 routing + unit tests (no backend calls)
355+
npm test # offline: 108/108 routing + unit tests (no backend calls)
356356
```
357357

358358
Keep the suite green. Add cases for any routing or behavior change. Tests live in `test/*.test.mjs`

README.md

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ Multi-model orchestration for Claude Code. Route by task, fan out in parallel, f
88

99
![Node](https://img.shields.io/badge/node-%3E%3D18-339933?logo=node.js&logoColor=white)
1010
![Type](https://img.shields.io/badge/module-ESM-f7df1e)
11-
![Tests](https://img.shields.io/badge/tests-106%2F106%20passing-3fb950)
11+
![Tests](https://img.shields.io/badge/tests-108%2F108%20passing-3fb950)
1212
![Platforms](https://img.shields.io/badge/platform-win%20%7C%20linux%20%7C%20macOS-555)
1313
![Deps](https://img.shields.io/badge/runtime%20deps-1%20(node--pty)-blue)
1414

@@ -302,7 +302,7 @@ docs/INTERFACES.md module interface contract (Node ESM port signatures
302302
## 🧪 Testing
303303

304304
```bash
305-
npm test # offline: 106/106 routing + unit tests (no backend calls)
305+
npm test # offline: 108/108 routing + unit tests (no backend calls)
306306
```
307307

308308
The suite is fully offline — no backend calls. Live agy/codex behaviour is verified by hand (run a

package-lock.json

Lines changed: 2 additions & 2 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

package.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
{
22
"name": "multi-model-team",
3-
"version": "0.8.3",
3+
"version": "0.8.4",
44
"type": "module",
55
"private": true,
66
"description": "Delegates token-heavy, self-contained tasks to local CLI backends (agy/Gemini, codex) chosen by task size and type, with credit-exhaustion fallback to native Claude and a statusline HUD. Node ESM, zero-build, cross-platform (Windows/Linux/macOS).",

src/bin/run.mjs

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -388,10 +388,22 @@ async function main() {
388388

389389
let model = modelForTier(beCfg, D_tier) || modelForTier(beCfg, 'standard');
390390

391-
// Health-gate: an unhealthy backend (or a kind with no invoker) is skipped.
391+
// Health-gate: an unhealthy backend (or a kind with no invoker) is skipped. This used to be a
392+
// SILENT skip — no lastErr, no failures.log, no status record — so a backend that failed its
393+
// `--version` probe vanished into a bare "backend options exhausted" handoff with zero
394+
// diagnostics. That made transient probe misses look like random "the CLI refused to run"
395+
// failures. Now a health skip is LOUD: it names the cause in lastErr (→ handoff reason), appends
396+
// to failures.log, and writes a `failed` status record the orchestrator can poll.
392397
let healthy = false;
393-
try { healthy = await health(beCfg); } catch { healthy = false; }
394-
if (!healthy) { fallbackCount++; continue; }
398+
let healthErr = '';
399+
try { healthy = await health(beCfg); } catch (e) { healthy = false; healthErr = String(e && e.message || e); }
400+
if (!healthy) {
401+
const why = sanitizeErr(healthErr) || `'${be}' version probe failed (binary missing, not authed, or probe timed out)`;
402+
lastErr = `'${be}' health check failed${healthErr ? ` (${sanitizeErr(healthErr)})` : ''}`;
403+
writeStatus(statusFile, callId, { state: 'failed', backend: be, model, tier: D_tier, rule: D_rule, kind: 'health', code: 127, elapsed_ms: 0 });
404+
logFailure({ backend: be, model, tier: D_tier, rule: D_rule, code: 127, durMs: 0, stderr: why, kind: 'health', callId });
405+
fallbackCount++; continue;
406+
}
395407

396408
state.start({ id: callId, backend: be, model, rule: D_rule, inChars });
397409
const startMs = Date.now();

src/lib/backends.mjs

Lines changed: 24 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -412,24 +412,37 @@ async function _healthUncached(backendCfg) {
412412
}
413413

414414
const healthFlag = field(backendCfg, 'health') || '--version';
415-
const res = await runChild([bin, healthFlag], {
416-
hardTimeout: 30_000, // parity with backends.sh `timeout 30`.
417-
keepStdinOpen: false, // version probe: stdin closed (= </dev/null).
418-
});
419-
// Non-empty stdout (CR-stripped) + clean exit. spawnError/ENOENT -> code 127 -> false.
420-
const out = res.stdout.replace(/\r/g, '').trim();
421-
return res.code === 0 && out.length > 0;
415+
// One-shot retry: a SINGLE `--version` probe is flaky on Windows — a cold-start, an AV scan of the
416+
// binary, or a momentary ConPTY hiccup can make it time out or return empty even though a real
417+
// dispatch seconds later would succeed. A false "unhealthy" verdict silently blackholes the backend
418+
// (run.mjs skips it → native handoff). Probe twice before declaring a backend down; a healthy CLI
419+
// answers `--version` in well under a second, so the retry cost on the happy path is zero.
420+
for (let attempt = 0; attempt < 2; attempt++) {
421+
const res = await runChild([bin, healthFlag], {
422+
hardTimeout: 30_000, // parity with backends.sh `timeout 30`.
423+
keepStdinOpen: false, // version probe: stdin closed (= </dev/null).
424+
});
425+
// Non-empty stdout (CR-stripped) + clean exit. spawnError/ENOENT -> code 127 -> false.
426+
const out = res.stdout.replace(/\r/g, '').trim();
427+
if (res.code === 0 && out.length > 0) return true;
428+
}
429+
return false;
422430
}
423431

424-
// TTL-memoized health check. Returns the cached boolean if checked within HEALTH_TTL_MS, else
425-
// re-probes and caches. Keeps the per-hop fallback-chain cost down to one probe per backend per TTL.
432+
// TTL-memoized health check. Caches POSITIVE verdicts only: a healthy backend is trusted for
433+
// HEALTH_TTL_MS (keeps the per-hop fallback cost to one probe per TTL), but a NEGATIVE verdict is
434+
// NEVER cached. A transient probe miss (cold start, AV scan, ConPTY hiccup) therefore costs at most
435+
// one skipped dispatch, not a full TTL window of silent native-handoffs — the very next call
436+
// re-probes and recovers. Asymmetric on purpose: a stale "healthy" is cheap (one real call fails →
437+
// invalidateHealth re-probes), a stale "unhealthy" used to blackhole a working backend for 60s.
426438
export async function health(backendCfg) {
427439
const key = _healthKey(backendCfg);
428440
const cached = _healthCache.get(key);
429441
const now = Date.now();
430-
if (cached !== undefined && (now - cached.ts) < HEALTH_TTL_MS) return cached.ok;
442+
if (cached !== undefined && cached.ok && (now - cached.ts) < HEALTH_TTL_MS) return true;
431443
const ok = await _healthUncached(backendCfg);
432-
_healthCache.set(key, { ok, ts: now });
444+
if (ok) _healthCache.set(key, { ok: true, ts: now });
445+
else _healthCache.delete(key); // never cache a negative verdict; re-probe next call
433446
return ok;
434447
}
435448

test/backends.test.mjs

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -317,6 +317,86 @@ test('run.mjs --cwd --writable: CLI runs IN the worktree cwd and gets the writab
317317
assert.doesNotMatch(body, /read-only/, 'writable mode dropped the read-only sandbox flag');
318318
});
319319

320+
// ── a backend that FAILS its --version health probe is no longer a SILENT skip ────────────────────
321+
// This was the "sometimes it just fails" bug: a backend that flunked health was dropped with no
322+
// lastErr, no failures.log, no status record — just a bare "backend options exhausted" handoff. Now
323+
// a health skip is LOUD: named in the handoff reason, appended to failures.log (kind:"health"), and
324+
// recorded as a failed status. Fake CLI exits non-zero on --version (and everything else) twice.
325+
test('run.mjs: a backend that fails health is logged LOUDLY as kind:"health", not silently skipped', () => {
326+
const d = tmp('ehealth-');
327+
const fake = join(d, process.platform === 'win32' ? 'deadcodex.cmd' : 'deadcodex.sh');
328+
if (process.platform === 'win32') {
329+
// Always exit 7 with a stderr line — including on --version, so the health probe (×2) fails.
330+
writeFileSync(fake, '@echo off\r\necho DEAD_BINARY not authed 1>&2\r\nexit /b 7\r\n');
331+
} else {
332+
writeFileSync(fake, '#!/usr/bin/env bash\necho "DEAD_BINARY not authed" >&2\nexit 7\n');
333+
chmodSync(fake, 0o755);
334+
}
335+
const r = writeRosterVariant(d, 'r.json', (c) => {
336+
c.backends.agy.enabled = false; // only codex in play
337+
c.defaults.quota_fallback = ['codex', 'native:sonnet'];
338+
});
339+
const logDir = join(d, 'logs');
340+
const { stdout, stderr } = runNode(BIN_RUN, {
341+
args: ['--roster', r, '--decision', '{"backend":"codex","model":"","tier":"standard","rule":"team-verify","native":false}', 'review this'],
342+
env: { MMT_BE_BIN: fake, MMT_LOG_DIR: logDir },
343+
});
344+
// 1. Loud stderr banner naming the backend + the health failure kind.
345+
assert.match(stderr, /\[mmt\] ERROR: backend 'codex' \(health\) failed/, 'health skip emits a loud [mmt] ERROR banner');
346+
// 2. Handoff still happens, but now CARRIES the cause instead of a bare "exhausted".
347+
assert.match(stdout, /MMT_NATIVE_HANDOFF/, 'still hands off to native');
348+
assert.match(stdout, /last error:.*codex.*health check failed/i, 'handoff reason names the health failure');
349+
// 3. Durable failures.log record with kind:"health".
350+
const logFile = join(logDir, 'failures.log');
351+
assert.ok(existsSync(logFile), 'failures.log written on a health skip (was silent before)');
352+
const rec = JSON.parse(readFileSync(logFile, 'utf8').trim().split('\n').pop());
353+
assert.equal(rec.backend, 'codex', 'log record names the backend');
354+
assert.equal(rec.kind, 'health', 'log record kind is "health"');
355+
// 4. A failed status record exists (callId is random — glob the calls/ dir).
356+
const callsDir = join(d, 'calls');
357+
assert.ok(existsSync(callsDir), 'status calls/ dir created on a health skip');
358+
const statusFiles = readdirSync(callsDir).filter((f) => f.endsWith('.status.json'));
359+
const st = JSON.parse(readFileSync(join(callsDir, statusFiles[0]), 'utf8').trim());
360+
assert.equal(st.state, 'failed', 'status reflects the failed (health) call');
361+
assert.equal(st.kind, 'health', 'status kind is "health"');
362+
});
363+
364+
// ── health(): a transient probe miss recovers on the NEXT call (negative verdict is never cached) ──
365+
// + one-shot retry: a SINGLE flaky --version no longer scores the backend down. Fake CLI fails its
366+
// FIRST --version (cold-start hiccup) then succeeds — within one health() call the retry recovers it.
367+
test('health(): one-shot retry survives a single flaky --version; negative verdict is not cached', async () => {
368+
const { health, _clearHealthCache } = await import('../src/lib/backends.mjs');
369+
_clearHealthCache();
370+
const d = tmp('hretry-');
371+
const counter = join(d, 'n.txt');
372+
const fake = join(d, process.platform === 'win32' ? 'flaky.cmd' : 'flaky.sh');
373+
if (process.platform === 'win32') {
374+
// First --version invocation exits 1 (no output); every later one prints a version + exit 0.
375+
writeFileSync(fake,
376+
'@echo off\r\n' +
377+
'if not exist "' + counter.replace(/\//g, '\\') + '" ( echo x > "' + counter.replace(/\//g, '\\') + '" & exit /b 1 )\r\n' +
378+
'echo flaky 1.0\r\n' +
379+
'exit /b 0\r\n');
380+
} else {
381+
writeFileSync(fake,
382+
'#!/usr/bin/env bash\n' +
383+
'if [ ! -f "' + counter + '" ]; then echo x > "' + counter + '"; exit 1; fi\n' +
384+
'echo "flaky 1.0"\n');
385+
chmodSync(fake, 0o755);
386+
}
387+
// health() resolves the binary for kind:"codex" via resolveBinary('codex', …) which honors MMT_BE_BIN.
388+
process.env.MMT_BE_BIN = fake;
389+
try {
390+
const cfg = { kind: 'codex', enabled: true, health: '--version' };
391+
// The first attempt's --version fails (exit 1), the in-probe retry succeeds -> healthy in ONE call.
392+
const ok = await health(cfg);
393+
assert.equal(ok, true, 'one-shot retry recovers a single flaky --version within one health() call');
394+
} finally {
395+
delete process.env.MMT_BE_BIN;
396+
_clearHealthCache();
397+
}
398+
});
399+
320400
test('run.mjs (no --writable): CLI gets the read-only sandbox flags (default behaviour unchanged)', () => {
321401
const d = tmp('eread-');
322402
const wt = join(d, 'here');

0 commit comments

Comments
 (0)