golem15/msd-core
3
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

test(#2650): bound the stall-watch fan-out with the class norm that reddened windows shard 1/3 (#3671)

Browse Source 
* test(#2650): failing-first coverage for the mis-sized stall-watch bound

Lands the regression matrix before the fix. Two assertions fail deterministically on this commit because the helper still calls raw spawnSync with a hard-coded 10000ms bound:

1. The process seam is never reached, so a mock.method spy on it records nothing and the class-norm bound cannot be observed.

2. A raw spawnSync result carries no outcome/timedOut field at all — which is precisely why the windows shard 1/3 failure printed 'null !== 0' instead of naming the timeout or the bound it exceeded.

The bound is sized for the wrong class of call. extractStallHelpersBash slices the entire bash fence, whose runtime-launcher preamble resolves gsd-tools.cjs and really runs two config-get lines — two Node spawns, measured 236ms against 2ms for the fallback the existing comment claims fires (118x). tests/helpers/timeouts.cjs already owns this class as HOOK_FANOUT_TIMEOUT_MS and its comment records the identical failure on PR #3285.

Refs #2650

* test(#2650): bound the stall-watch fan-out with the class norm and report it typed

Drives the failing-first coverage from 15aaef4a7 green (5 failures -> 0). runBashScript now routes through tests/helpers/process-seam.cjs instead of a hand-rolled spawnSync, which CONTRIBUTING.md already requires of anything that shells out.

The bound moves from a hard-coded 10000ms literal to HOOK_FANOUT_TIMEOUT_MS. That constant already exists for exactly this shape — a bash invocation that fans out to nested subprocesses — and its own comment records the identical failure on PR #3285: a bound sized for the wrong class, not a slow machine. This script is that shape: the extracted fence opens with the runtime-launcher preamble, which resolves gsd-tools.cjs and really runs two config-get lines.

The result is now typed. spawnSync reports a kill as status:null, so an exceeded bound reached the call sites as 'null !== 0' — naming neither the timeout nor the bound it exceeded. OUTCOME.TIMED_OUT names itself. status is still aliased from exitCode so the five existing assertions read unchanged.

Corrects the comment that caused the mis-sizing: it claimed gsd_run is undefined so the '|| echo' fallback fires. It is not — the preamble defines it, and the two Node spawns are real (236ms vs 2ms, 118x). They are deliberately left in place; removing them would change what the extracted script executes.

Also drops two now-dead '{ timeout: 10000 }' call-site options. The seam reads only its own documented keys, so those would have been silently ignored while still reading as a 10s bound.

Refs #2650

* test(#2650): make the boundary test a real value-domain boundary

Standards review flagged that the previous 'bound boundary' test repeated the TIMED_OUT arm the test above it already covers, and was not a limit-1/limit/limit+1 in any meaningful sense — an exact-millisecond timing edge would have been a race, not a boundary.

Replaced with a boundary on the VALUE DOMAIN of the bound itself: 0 and -1 must be rejected with TypeError, and 1 (the smallest positive value) must be accepted. Zero is the load-bearing case — spawnSync reads it as 'no timeout at all', which is exactly the unbounded-spawn hazard local/no-unbounded-spawn exists to prevent, so the seam rejects it rather than honouring it.

Also asserts the rejection path does not leak the script temp dir, since the throw escapes through runBashScript's finally. Soak: zero=TypeError, negative=TypeError, one=no-throw, leaked dirs=0.

Refs #2650

---------

Co-authored-by: sim <sim@local>
This commit is contained in:
Tom Boucher
2026-08-19 12:04:24 -04:00
committed by GitHub
parent 8d1f770dfe
commit dae134b960
1 changed files with 134 additions and 14 deletions
Download Patch File Download Diff File Expand all files Collapse all files

148
tests/plan-phase-stall-detection.test.cjs
View File

@@ -34,12 +34,15 @@
* gsd-core/bin/shared/config-schema.manifest.json, docs/CONFIGURATION.md
*/
const { describe, test } = require('node:test');
const { describe, test, mock } = require('node:test');
const assert = require('node:assert/strict');
const { spawnSync } = require('node:child_process');
const { runNode } = require('./helpers/process-seam.cjs');
// Required as a MODULE OBJECT, not destructured, so `mock.method(processSeam, 'runHook', …)`
// can observe what runBashScript actually passes to the seam. tests/helpers.cjs:221-224
// documents this same pattern for runNode.
const processSeam = require('./helpers/process-seam.cjs');
const { runNode, OUTCOME } = processSeam;
const { toLegacyResult } = require('./helpers/git-fixture.cjs');
const { PROBE_TIMEOUT_MS } = require('./helpers/timeouts.cjs');
const { PROBE_TIMEOUT_MS, HOOK_FANOUT_TIMEOUT_MS } = require('./helpers/timeouts.cjs');
const fs = require('node:fs');
const os = require('node:os');
const path = require('node:path');
@@ -156,15 +159,45 @@ function extractStallHelpersBash() {
* @param {string[]} [args] positional args passed to the script (become
* $1, $2, ... inside it) — empty when the caller embeds values directly
* into the script text instead (e.g. via JSON.stringify).
* @param {object} [opts] extra spawnSync options (e.g. `{ timeout }`),
* merged over the `{ encoding: 'utf-8' }` default.
* @param {object} [opts] extra process-seam options (`{ timeoutMs, cwd, env, input,
* killSignal }`), merged over the defaults below. NOTE the key is `timeoutMs`, not
* spawnSync's `timeout` — the seam reads only its own documented options, so a stray
* `timeout` key is silently ignored rather than honoured.
*/
function runBashScript(script, args = [], opts = {}) {
const scriptDir = fs.mkdtempSync(path.join(os.tmpdir(), 'gsd-2650-sh-'));
try {
const scriptPath = path.join(scriptDir, 'script.sh');
fs.writeFileSync(scriptPath, `#!/usr/bin/env bash\n${script}`, { mode: 0o755 });
return spawnSync('bash', [scriptPath, ...args], { encoding: 'utf-8', timeout: 10000, ...opts });
// Through the process seam, never a hand-rolled spawnSync (CONTRIBUTING.md:
// "Anything that shells out goes through tests/helpers/process-seam.cjs"). Two
// things that buys, both of which the raw call lacked:
//
// 1. HOOK_FANOUT_TIMEOUT_MS — the class norm for a bash invocation that FANS OUT
// to nested subprocesses. This script does exactly that: the extracted fence
// opens with the runtime-launcher preamble, which resolves gsd-tools.cjs and
// really runs two `gsd_run query config-get` lines, i.e. two Node spawns
// (measured 236ms vs 2ms for the fallback shape). The old hard-coded 10000ms
// was sized for a cheap probe and was exceeded at 10006ms on
// `full test (windows-latest, 24, shard 1/3)`. timeouts.cjs records the same
// failure mode on PR #3285: a bound sized for the wrong class, not a slow machine.
//
// 2. A typed `outcome`. spawnSync reports a kill as `status: null`, so an exceeded
// bound reached the call sites as `null !== 0` — naming neither the timeout nor
// the bound. OUTCOME.TIMED_OUT names itself.
//
// Looked up on the module object (`processSeam.runHook`) rather than destructured, so
// a test can observe the options actually passed — same rationale as
// tests/helpers.cjs:221-224 for runNode.
const result = processSeam.runHook(scriptPath, args, {
interpreter: 'bash',
timeoutMs: HOOK_FANOUT_TIMEOUT_MS,
...opts,
});
// `status` is aliased from `exitCode` by toLegacyResult so the existing assertions in
// this file keep reading the shape they were written against; `outcome`/`timedOut`
// are additive, and are what make a bound failure self-describing.
return { ...toLegacyResult(result), outcome: result.outcome, timedOut: result.timedOut };
} finally {
cleanup(scriptDir);
}
@@ -263,11 +296,19 @@ describe('bug #2650 plan-phase stall detection — gsd_stall_should_recover (pur
});
describe('bug #2650 plan-phase stall detection — gsd_stall_watch (real execution, not just the pure classifier)', () => {
// Sourcing the extracted script without `gsd_run` defined naturally exercises
// the `|| echo "<default>"` fallback already in the config-get lines (command
// lookup fails -> non-zero exit -> the `||` branch fires), so
// PLANNER_STALL_INTERVAL_MINUTES/PLANNER_STALL_THRESHOLD_MINUTES start at their
// real defaults (5/10) here; each test overrides them afterward for speed.
// CORRECTION (#2650 follow-up): an earlier version of this comment claimed the
// extracted script runs WITHOUT `gsd_run` defined, so the `|| echo "<default>"`
// fallback in the config-get lines fires. That is false, and it is why the spawn
// bound below was mis-sized. extractStallHelpersBash slices the ENTIRE ```bash
// fence, which opens with the runtime-launcher preamble; that preamble finds
// gsd-core/bin/gsd-tools.cjs from the repo root and DEFINES gsd_run, so both
// config-get lines really spawn Node. Verified: `gsd_run defined: function`,
// GSD_TOOLS=<repo>/gsd-core/bin/gsd-tools.cjs. The resolved values are then
// discarded anyway — runWatch overrides both PLANNER_STALL_* vars right after the
// helpers, and runShouldRecover passes them as arguments — so the two spawns are
// dead cost that the bound must nonetheless accommodate. They are deliberately NOT
// removed here: dropping them would change what the extracted script executes and
// weaken the "the shipped fence is runnable end to end" property these tests carry.
let helpersBash;
let tmp;
@@ -287,7 +328,7 @@ describe('bug #2650 plan-phase stall detection — gsd_stall_watch (real executi
const call = `gsd_stall_watch ${JSON.stringify(String(dispatchTs))} ${JSON.stringify(outputFile)} ${JSON.stringify(artifactGlob)}` +
markers.map((m) => ` ${JSON.stringify(m)}`).join('');
const script = `${helpersBash}\n${overrides}${call}\n`;
return runBashScript(script, [], { timeout: 10000 });
return runBashScript(script, []);
}
test('marker present in the real output file (via real grep, interval=0 so sleep is instant) -> marker_received', (t) => {
@@ -374,7 +415,7 @@ describe('bug #2650 plan-phase stall detection — gsd_stall_watch (real executi
const call = `gsd_stall_watch ${JSON.stringify(String(now))} ${JSON.stringify(missingOutputFile)} ${JSON.stringify(glob)}` +
` ${JSON.stringify('## PLANNING COMPLETE')}`;
const script = `${helpersBash}\n${overrides}${call}\n`;
const result = runBashScript(script, [], { timeout: 10000 });
const result = runBashScript(script, []);
assert.equal(result.status, 0, result.stderr);
assert.equal(result.stdout.trim(), 'active');
});
@@ -598,3 +639,82 @@ describe('bug #2650 plan-phase — all five planner/plan-checker spawns dispatch
assert.doesNotMatch(patternMapperSection, /gsd_stall_watch/, 'pattern-mapper spawn must remain a plain blocking call (out of scope per Agent Brief)');
});
});
// ─────────────────────────────────────────────────────────────────────────────
// #2650 follow-up: the spawn bound was sized for the wrong CLASS of call.
//
// runBashScript hard-coded `timeout: 10000`. The script it runs is not a cheap
// probe: extractStallHelpersBash slices the ENTIRE ```bash fence, whose runtime-launcher
// preamble resolves gsd-tools.cjs and really runs two `gsd_run query config-get` lines —
// two full Node spawns (measured 236ms vs 2ms for the fallback the old comment claimed
// fires: 118x). On `full test (windows-latest, 24, shard 1/3)` that bound was exceeded at
// 10006ms and spawnSync's kill surfaced as `status: null`, which the call site asserted
// as `null !== 0` — a message naming neither the timeout nor the bound.
//
// tests/helpers/timeouts.cjs already owns this exact class (HOOK_FANOUT_TIMEOUT_MS), and
// its comment records the identical failure on PR #3285: "a bound sized for the wrong
// class, not a slow machine."
// ─────────────────────────────────────────────────────────────────────────────
describe('#2650 follow-up: runBashScript bounds and reports a bash fan-out correctly', () => {
test('bounds the fan-out with the class norm, and an explicit override still wins', (t) => {
t.after(() => mock.restoreAll());
const seen = [];
mock.method(processSeam, 'runHook', (target, args, opts) => {
seen.push(opts);
return { outcome: OUTCOME.EXITED, exitCode: 0, stdout: '', stderr: '', timedOut: false, signal: null, killed: false, code: null };
});
runBashScript('echo hi\n');
assert.equal(seen.length, 1,
'runBashScript must route through the process seam (CONTRIBUTING.md: never a hand-rolled spawnSync in a suite)');
assert.equal(seen[0].timeoutMs, HOOK_FANOUT_TIMEOUT_MS,
`default bound must be the bash-fan-out class norm (${HOOK_FANOUT_TIMEOUT_MS}ms), not a probe-sized literal; got ${seen[0].timeoutMs}`);
assert.equal(seen[0].interpreter, 'bash', 'the seam must be told to run the script under bash');
runBashScript('echo hi\n', [], { timeoutMs: 1234 });
assert.equal(seen[1].timeoutMs, 1234, 'an explicit timeoutMs must override the class norm');
});
test('an exceeded bound reports TIMED_OUT, not a bare null status', () => {
// A real sleep against a deliberately tiny bound. The assertion is on the
// CLASSIFICATION, never on elapsed time.
const result = runBashScript('sleep 5\n', [], { timeoutMs: 250 });
assert.equal(result.outcome, OUTCOME.TIMED_OUT,
`an exceeded bound must name itself; got outcome=${result.outcome} status=${result.status}`);
assert.equal(result.timedOut, true, 'timedOut must be true when the bound is exceeded');
});
test('a genuine non-zero exit is EXITED, never confused with a timeout', () => {
const result = runBashScript('exit 3\n');
assert.equal(result.outcome, OUTCOME.EXITED,
'a prompt non-zero exit is an EXITED outcome, not a timeout');
assert.equal(result.status, 3, 'the real exit code must survive');
assert.equal(result.timedOut, false, 'a real exit must not be reported as timed out');
});
test('boundary: a non-positive bound is rejected, never silently run unbounded', () => {
// limit-1 / limit / limit+1 on the VALUE DOMAIN of the bound, not on wall-clock
// timing — the previous test already covers the exceeded-bound classification, and
// an exact-millisecond timing edge would be a race, not a boundary.
//
// Zero is the load-bearing case: spawnSync reads `timeout: 0` as "no timeout at
// all", which is precisely the unbounded-spawn hazard local/no-unbounded-spawn
// exists to prevent (CONTRIBUTING.md: "`timeout: 0` — Node reads zero as *no
// timeout*"). The seam rejects it instead of honouring it.
assert.throws(() => runBashScript('exit 0\n', [], { timeoutMs: 0 }), TypeError,
'limit: zero must be rejected, never read as unbounded');
assert.throws(() => runBashScript('exit 0\n', [], { timeoutMs: -1 }), TypeError,
'limit-1: a negative bound must be rejected');
assert.doesNotThrow(() => runBashScript('exit 0\n', [], { timeoutMs: 1 }),
'limit+1: the smallest positive bound is valid and must be accepted');
// The helper must still clean up its temp dir when the seam throws — the throw
// escapes through runBashScript's `finally`, which is what makes the rejection safe
// to rely on rather than a resource leak.
const before = fs.readdirSync(os.tmpdir()).filter((n) => n.startsWith('gsd-2650-sh-')).length;
assert.throws(() => runBashScript('exit 0\n', [], { timeoutMs: 0 }), TypeError);
const after = fs.readdirSync(os.tmpdir()).filter((n) => n.startsWith('gsd-2650-sh-')).length;
assert.equal(after, before, 'a rejected bound must not leak the script temp dir');
});
});