test: stop CLI-spawn timeouts from flaking the release gate (#114)

Four tests failed intermittently under parallel load while passing in ~0.6s
idle. All the same cause: a spawn bound sized for an unloaded machine.

  cli: franklin task tail reconciles stale queued tasks   5045ms  (bound 5000)
  cli: franklin task cancel <runId> kills running task    5841ms  (bound 5000)
  cli: franklin task wait reconciles stale queued tasks   5048ms  (bound 5000)
  franklin skills --json emits a parseable structure      8037ms  (bound 8000)

The durations were the bound firing, not the work taking that long — the same
tests run in ~640ms when the machine is idle. `node dist/index.js` boots the
whole CLI (config load, MCP discovery, wallet init) before the subcommand runs,
and that startup balloons under concurrency.

Three things were wrong beyond the number:

1. The failures were undiagnosable. On timeout spawnSync returns status:null
   with empty stderr, so `assert.equal(result.status, 0, result.stderr)` printed
   "null !== 0" and named nothing. First time I hit this I could not tell what
   had failed. assertCliExit() now says it exceeded the bound and that a loaded
   machine is the likely cause.

2. skills.local.mjs had two bounds fighting: runCli defaulted to 8000ms while
   the tests around it declared { timeout: 15_000 }, so the inner one always
   won and the declared one never applied. Two call sites had already been
   patched to timeoutMs: 15_000 individually — the usual sign that the default,
   not the call site, is what's wrong.

3. One test told the CLI `--timeout 10000` under a 5000ms spawn bound, so the
   harness would have killed the process before the behaviour under test could
   finish. It only passed because the task goes 'lost' almost immediately.

Both files now use CLI_SPAWN_TIMEOUT_MS = 20_000, matching what test/local.mjs
already used for its other CLI-spawning tests ({ timeout: 20_000 }); 5s and 8s
were the outliers.

A flaky test in a release gate is worse than a slow one: it teaches you to wave
the next real failure past as "just that one again". Verified with two suites
running concurrently — the condition that produced the original failures —
636 pass on both.

Co-authored-by: 1bcMax <195689928+1bcMax@users.noreply.github.com>

Author: VickyXAI

test/local.mjs

@@ -7625,6 +7625,31 @@ test('startDetachedTask: returns runId immediately, child completes async', asyn
   }
 });
 
+// Spawning `node dist/index.js` boots the whole CLI — config load, MCP server
+// discovery, wallet init — before the subcommand runs at all. These spawns were
+// capped at 5000ms, and three of them flaked under parallel load on 2026-07-21
+// (task tail / task cancel / task wait). The failure was also undiagnosable:
+// on timeout spawnSync returns status:null with empty stderr, so
+// `assert.equal(result.status, 0, result.stderr.toString())` reported
+// "null !== 0" and said nothing about a timeout. A flaky test in a release gate
+// is worse than a slow one — it trains you to wave the next real failure past.
+//
+// 20s matches what the rest of this file already uses for CLI-spawning tests
+// ({ timeout: 20_000 } at lines 117, 127, 597, ...); 5s was the outlier.
+const CLI_SPAWN_TIMEOUT_MS = 20_000;
+
+/** Assert a spawned CLI exited as expected, naming a timeout as a timeout. */
+function assertCliExit(result, expectedStatus, what) {
+  if (result.error) {
+    const hint = result.error.code === 'ETIMEDOUT'
+      ? ` — exceeded CLI_SPAWN_TIMEOUT_MS (${CLI_SPAWN_TIMEOUT_MS}ms); the machine was likely loaded, not the code broken`
+      : '';
+    assert.fail(`${what}: spawn failed with ${result.error.code || result.error.message}${hint}`);
+  }
+  assert.equal(result.status, expectedStatus,
+    `${what}: expected exit ${expectedStatus}, got ${result.status}\nstderr: ${result.stderr?.toString() ?? ''}`);
+}
+
 test('cli: franklin task list prints recent tasks', async () => {
   const os = await import('node:os');
   const path = await import('node:path');
@@ -7645,9 +7670,9 @@ test('cli: franklin task list prints recent tasks', async () => {
 
     const cli = path.join(process.cwd(), 'dist', 'index.js');
     const result = spawnSync(process.execPath, [cli, 'task', 'list'], {
-      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: 5000,
+      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: CLI_SPAWN_TIMEOUT_MS,
     });
-    assert.equal(result.status, 0, result.stderr.toString());
+    assertCliExit(result, 0, 'task list');
     const out = result.stdout.toString();
     assert.match(out, /t2/);
     assert.match(out, /t1/);
@@ -7683,9 +7708,9 @@ test('cli: franklin task tail <runId> prints log + status', async () => {
 
     const cli = path.join(process.cwd(), 'dist', 'index.js');
     const result = spawnSync(process.execPath, [cli, 'task', 'tail', runId], {
-      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: 5000,
+      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: CLI_SPAWN_TIMEOUT_MS,
     });
-    assert.equal(result.status, 0, result.stderr.toString());
+    assertCliExit(result, 0, 'task tail');
     const out = result.stdout.toString();
     assert.match(out, /line1/);
     assert.match(out, /line2/);
@@ -7722,9 +7747,9 @@ test('cli: franklin task tail reconciles stale queued tasks before printing stat
 
     const cli = path.join(process.cwd(), 'dist', 'index.js');
     const result = spawnSync(process.execPath, [cli, 'task', 'tail', runId], {
-      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: 5000,
+      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: CLI_SPAWN_TIMEOUT_MS,
     });
-    assert.equal(result.status, 0, result.stderr.toString());
+    assertCliExit(result, 0, 'task tail (stale queued)');
     assert.match(result.stdout.toString(), /lost/);
     assert.equal(readTaskMeta(runId).status, 'lost');
   } finally {
@@ -7756,9 +7781,9 @@ test('cli: franklin task cancel <runId> kills running task', async () => {
 
     const cli = path.join(process.cwd(), 'dist', 'index.js');
     const result = spawnSync(process.execPath, [cli, 'task', 'cancel', runId], {
-      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: 5000,
+      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: CLI_SPAWN_TIMEOUT_MS,
     });
-    assert.equal(result.status, 0, result.stderr.toString());
+    assertCliExit(result, 0, 'task cancel');
 
     // Give runner a moment to finalize
     await new Promise(r => setTimeout(r, 1500));
@@ -7828,11 +7853,15 @@ test('cli: franklin task wait reconciles stale queued tasks before blocking', as
     });
 
     const cli = path.join(process.cwd(), 'dist', 'index.js');
+    // The CLI is told to wait up to 10s, so the spawn bound must exceed it —
+    // it was 5000ms, i.e. the harness would have killed the process before the
+    // behaviour under test could finish. That only passed because the task goes
+    // 'lost' almost immediately; a slower reconcile would have failed here for
+    // reasons having nothing to do with `task wait`.
     const result = spawnSync(process.execPath, [cli, 'task', 'wait', runId, '--timeout', '10000'], {
-      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: 5000,
+      env: { ...process.env, FRANKLIN_HOME: fakeHome }, timeout: CLI_SPAWN_TIMEOUT_MS,
     });
-    assert.equal(result.error, undefined, result.error?.message);
-    assert.equal(result.status, 1, result.stderr.toString());
+    assertCliExit(result, 1, 'task wait (stale queued)');
     assert.match(result.stdout.toString(), /lost/);
     assert.equal(readTaskMeta(runId).status, 'lost');
   } finally {

test/skills.local.mjs

@@ -21,7 +21,19 @@ import { formatSkillHints } from '../dist/skills/triggers.js';
 
 const DIST = fileURLToPath(new URL('../dist/index.js', import.meta.url));
 
-function runCli(args, { timeoutMs = 8000, env, cwd } = {}) {
+// Booting `node dist/index.js` runs the whole CLI startup path (config, MCP
+// discovery, wallet init) before the subcommand executes. The default here was
+// 8000ms while the tests around it declare { timeout: 15_000 } — so the inner
+// bound fired first and the declared one never applied. Two call sites had
+// already been patched individually to timeoutMs: 15_000, which is the usual
+// sign that the default, not the call site, is what's wrong.
+//
+// Observed 2026-07-21: `franklin skills --json` failed at 8037ms under parallel
+// load while passing in ~1s idle. Raised to 20s to match what test/local.mjs
+// uses for CLI spawns, so a loaded machine doesn't read as a broken build.
+const CLI_SPAWN_TIMEOUT_MS = 20_000;
+
+function runCli(args, { timeoutMs = CLI_SPAWN_TIMEOUT_MS, env, cwd } = {}) {
   return new Promise((resolve, reject) => {
     const proc = spawn('node', [DIST, ...args], {
       stdio: ['ignore', 'pipe', 'pipe'],
@@ -34,7 +46,10 @@ function runCli(args, { timeoutMs = 8000, env, cwd } = {}) {
     proc.stderr.on('data', (d) => { stderr += d.toString(); });
     const timer = setTimeout(() => {
       proc.kill('SIGTERM');
-      reject(new Error(`Timeout after ${timeoutMs}ms`));
+      reject(new Error(
+        `franklin ${args.join(' ')} exceeded ${timeoutMs}ms. CLI startup is slow ` +
+        `under load; this usually means a busy machine, not broken code.`
+      ));
     }, timeoutMs);
     proc.on('close', (code) => {
       clearTimeout(timer);