From b4e817cfa0af481d442ef6e566fb86f5f6335dc7 Mon Sep 17 00:00:00 2001 From: Tom Boucher Date: Sat, 6 Jun 2026 12:04:38 -0400 Subject: [PATCH] chore(lint): refactor magic-sleep tests to async waits + ratchet rules to error (#735) Replace raw setTimeout/Atomics.wait synchronization sleeps in 4 test files with a shared async delay()/waitFor() poll-for-condition helper in tests/helpers.cjs, then flip local/no-magic-sleep-in-tests and no-restricted-syntax from warn to error so the debt can't regrow. - tests/helpers.cjs: add delay(ms) + waitFor(predicate, opts), exported - bug-1974: setTimeout backoff -> await delay() - config.test: drop Atomics.wait sleep(); async retry via await delay() - graphify: waitForBuildStatus/cleanupHookRepo async via await delay() - locking-bugs: 3 Atomics.wait poll loops -> await waitFor() - eslint.config.mjs: ratchet both rules warn -> error Refs #733 Co-authored-by: Claude Opus 4.8 --- eslint.config.mjs | 6 +-- ...ug-1974-context-exhaustion-record.test.cjs | 6 +-- tests/config.test.cjs | 16 +++----- tests/graphify-auto-update.test.cjs | 38 +++++++----------- tests/helpers.cjs | 36 ++++++++++++++++- .../locking-bugs-1909-1916-1925-1927.test.cjs | 40 ++++++++----------- 6 files changed, 77 insertions(+), 65 deletions(-) diff --git a/eslint.config.mjs b/eslint.config.mjs index 17f7c3438..52e045fe2 100644 --- a/eslint.config.mjs +++ b/eslint.config.mjs @@ -196,14 +196,14 @@ export default tseslint.config( rules: { ...js.configs.recommended.rules, 'no-only-tests/no-only-tests': 'error', - // Timing anti-patterns — warn for now; flip to error after cleanup - 'local/no-magic-sleep-in-tests': 'warn', + // Timing anti-patterns — ratcheted to error after cleanup (all violations fixed) + 'local/no-magic-sleep-in-tests': 'error', 'local/no-elapsed-assertion': 'warn', // Ban raw fs.rmSync in tests — use helpers.cleanup() for Windows-EBUSY retry budget 'local/no-raw-rmsync-in-tests': 'error', // Ban raw setTimeout sync + elapsed/duration-style assertions via no-restricted-syntax 'no-restricted-syntax': [ - 'warn', + 'error', { selector: 'AwaitExpression > NewExpression[callee.name="Promise"] ArrowFunctionExpression CallExpression[callee.name="setTimeout"]', message: 'Raw setTimeout used for synchronization in tests. Use proper async patterns instead.', diff --git a/tests/bug-1974-context-exhaustion-record.test.cjs b/tests/bug-1974-context-exhaustion-record.test.cjs index decea82ed..aed404607 100644 --- a/tests/bug-1974-context-exhaustion-record.test.cjs +++ b/tests/bug-1974-context-exhaustion-record.test.cjs @@ -26,7 +26,7 @@ const fs = require('node:fs'); const path = require('node:path'); const os = require('node:os'); const { spawnSync } = require('node:child_process'); -const { cleanup } = require('./helpers.cjs'); +const { cleanup, delay } = require('./helpers.cjs'); const HOOK_PATH = path.resolve(__dirname, '..', 'hooks', 'gsd-context-monitor.js'); const GSD_TOOLS = path.resolve(__dirname, '..', 'gsd-core', 'bin', 'gsd-tools.cjs'); @@ -34,7 +34,7 @@ const GSD_TOOLS = path.resolve(__dirname, '..', 'gsd-core', 'bin', 'gsd-tools.cj // Windows can hold a transient handle on the temp dir after a spawnSync child // exits (AV scanner / handle-release lag), so cleanup()'s internal rmSync retry // (~5s) occasionally still throws EBUSY/EPERM/ENOTEMPTY under CI load. Restore a -// bounded outer retry with async backoff (NOT Atomics.wait — lint no-magic-sleep). +// bounded outer retry with async backoff via the shared delay() helper. // Re-adds the guard removed in #482. Refs #490. async function cleanupWithRetry(dir, attempts = 8) { for (let i = 0; i < attempts; i += 1) { @@ -42,7 +42,7 @@ async function cleanupWithRetry(dir, attempts = 8) { catch (err) { const transient = err && (err.code === 'EBUSY' || err.code === 'EPERM' || err.code === 'ENOTEMPTY'); if (!transient || i === attempts - 1) throw err; - await new Promise((resolve) => setTimeout(resolve, 100 * (i + 1))); + await delay(100 * (i + 1)); } } } diff --git a/tests/config.test.cjs b/tests/config.test.cjs index fba2a7d3f..d369d29fe 100644 --- a/tests/config.test.cjs +++ b/tests/config.test.cjs @@ -11,7 +11,7 @@ const { test, describe, beforeEach, afterEach } = require('node:test'); const assert = require('node:assert/strict'); const fs = require('fs'); const path = require('path'); -const { runGsdTools, createTempProject, cleanup } = require('./helpers.cjs'); +const { runGsdTools, createTempProject, cleanup, delay } = require('./helpers.cjs'); // ─── helpers ────────────────────────────────────────────────────────────────── @@ -25,11 +25,7 @@ function writeConfig(tmpDir, obj) { fs.writeFileSync(configPath, JSON.stringify(obj, null, 2), 'utf-8'); } -function sleep(ms) { - Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, ms); -} - -function runConfigEnsureSectionWithRetry(tmpDir, attempts = 4) { +async function runConfigEnsureSectionWithRetry(tmpDir, attempts = 4) { let last; for (let i = 0; i < attempts; i += 1) { last = runGsdTools('config-ensure-section', tmpDir); @@ -38,7 +34,7 @@ function runConfigEnsureSectionWithRetry(tmpDir, attempts = 4) { const detail = `${last.error || ''}\n${last.output || ''}`; const transient = /(EPERM|EBUSY|EACCES|ENOTEMPTY|resource busy|used by another process|permission denied)/i.test(detail); if (!transient || i === attempts - 1) return last; - sleep(150 * (i + 1)); + await delay(150 * (i + 1)); } return last; } @@ -81,13 +77,13 @@ describe('config-ensure-section command', () => { assert.ok('search_gitignored' in config, 'search_gitignored should exist'); }); - test('is idempotent — returns already_exists on second call', () => { - const first = runConfigEnsureSectionWithRetry(tmpDir); + test('is idempotent — returns already_exists on second call', async () => { + const first = await runConfigEnsureSectionWithRetry(tmpDir); assert.ok(first.success, `First call failed: ${first.error}`); const firstOutput = JSON.parse(first.output); assert.strictEqual(firstOutput.created, true); - const second = runConfigEnsureSectionWithRetry(tmpDir); + const second = await runConfigEnsureSectionWithRetry(tmpDir); assert.ok(second.success, `Second call failed: ${second.error}`); const secondOutput = JSON.parse(second.output); assert.strictEqual(secondOutput.created, false); diff --git a/tests/graphify-auto-update.test.cjs b/tests/graphify-auto-update.test.cjs index a2b1757d6..51ffed363 100644 --- a/tests/graphify-auto-update.test.cjs +++ b/tests/graphify-auto-update.test.cjs @@ -13,7 +13,7 @@ const fs = require('fs'); const path = require('path'); const os = require('node:os'); const { execFileSync, spawnSync } = require('child_process'); -const { createTempProject, cleanup, runGsdTools } = require('./helpers.cjs'); +const { createTempProject, cleanup, runGsdTools, delay } = require('./helpers.cjs'); const { graphifyStatus, @@ -263,20 +263,11 @@ describe('auto-update', () => { }); } - // Shared 4-byte buffer used for Atomics.wait-based sleeps throughout the - // hook-test helpers. Atomics.wait(sai, 0, 0, ms) yields the event loop for - // exactly `ms` milliseconds without spawning an external process. - const _sleepSab = new SharedArrayBuffer(4); - const _sleepSai = new Int32Array(_sleepSab); - function atomicSleep(ms) { - Atomics.wait(_sleepSai, 0, 0, ms); - } - // Wait until the detached rebuild writes a terminal status, with a generous // deadline. The detached subprocess can be slow under contended Docker; all // assertions here are outcome-based, so we wait for the real terminal state // rather than guessing a tight wall-clock budget (#382). - function waitForBuildStatus(statusPath, terminal /* e.g. new Set(['ok']) */, { deadlineMs = 30000, stepMs = 25 } = {}) { + async function waitForBuildStatus(statusPath, terminal /* e.g. new Set(['ok']) */, { deadlineMs = 30000, stepMs = 25 } = {}) { const deadline = Date.now() + deadlineMs; let status; while (Date.now() < deadline) { @@ -287,21 +278,20 @@ describe('auto-update', () => { if (parsed && terminal.has(parsed.status)) return parsed; } catch { /* detached writer can briefly expose a partial JSON write */ } } - atomicSleep(stepMs); + await delay(stepMs); } return status; // last seen (may be undefined / non-terminal) — assertions below will report } - function cleanupHookRepo(tmpDir) { + async function cleanupHookRepo(tmpDir) { // The hook detaches a graphify-rebuild subprocess that may still be writing // into tmpDir when the test body returns. Wait for the rebuild PID to exit // (lock file disappears on subprocess EXIT trap), then retry rmSync to // absorb any remaining transient ENOTEMPTY race. // - // Uses Atomics.wait instead of execFileSync('sleep', ...) so we yield the - // CPU without spawning an external process per iteration. Budget: 15 s — - // bumped from 4 s to give the detached child more time to exit under - // contended Docker before we attempt removal (#382). + // Uses delay() instead of Atomics.wait so we yield the event loop + // without blocking the thread. Budget: 15 s — bumped from 4 s to give + // the detached child more time to exit under contended Docker (#382). const lockPath = path.join(tmpDir, '.planning/graphs/.rebuild.lock'); const lockDeadline = Date.now() + 15000; while (Date.now() < lockDeadline) { @@ -313,7 +303,7 @@ describe('auto-update', () => { } catch { break; // PID dead → safe to clean up } - atomicSleep(50); // yield 50 ms, then re-check (replaces execFileSync('sleep')) + await delay(50); // yield 50 ms, then re-check } try { // eslint-disable-next-line local/no-raw-rmsync-in-tests -- best-effort teardown: error is swallowed so cleanup() (which propagates) cannot be used here; a residual temp dir after a detached-subprocess race is harmless (#382) @@ -447,7 +437,7 @@ describe('auto-update', () => { assert.ok(/^[0-9a-f]{7,40}$/.test(status.head_at_build), 'head_at_build must be a commit sha'); }); - test('completes to status=ok after detached graphify run succeeds', (t) => { + test('completes to status=ok after detached graphify run succeeds', async (t) => { const tmpDir = createTempGitRepo({ config: { graphify: { enabled: true, auto_update: true } }, }); @@ -465,14 +455,14 @@ describe('auto-update', () => { // Docker is never racing a tight budget (#382). All assertions are // outcome-based; the deadline is deterministic, not a timing assertion. const statusPath = path.join(tmpDir, '.planning/graphs/.last-build-status.json'); - const status = waitForBuildStatus(statusPath, new Set(['ok'])); + const status = await waitForBuildStatus(statusPath, new Set(['ok'])); assert.ok(status, 'status file must exist after dispatch'); assert.strictEqual(status.status, 'ok', 'mock graphify exit=0 → status ok'); assert.strictEqual(status.exit_code, 0); assert.ok(typeof status.duration_ms === 'number' && status.duration_ms >= 0); }); - test('completes to status=failed when graphify exits non-zero', (t) => { + test('completes to status=failed when graphify exits non-zero', async (t) => { const tmpDir = createTempGitRepo({ config: { graphify: { enabled: true, auto_update: true } }, }); @@ -490,7 +480,7 @@ describe('auto-update', () => { // Docker is never racing a tight budget (#382). All assertions are // outcome-based; the deadline is deterministic, not a timing assertion. const statusPath = path.join(tmpDir, '.planning/graphs/.last-build-status.json'); - const status = waitForBuildStatus(statusPath, new Set(['failed'])); + const status = await waitForBuildStatus(statusPath, new Set(['failed'])); assert.ok(status, 'status file must exist after dispatch'); assert.strictEqual(status.status, 'failed', 'mock graphify exit=1 → status failed'); assert.strictEqual(status.exit_code, 1); @@ -578,7 +568,7 @@ describe('auto-update', () => { 'gsd-tools query commit "docs: probe" --files .planning/STATE.md', 'npx gsd-tools query commit "docs: probe" --files .planning/STATE.md', ]) { - test(`dispatches on: ${cmd}`, (t) => { + test(`dispatches on: ${cmd}`, async (t) => { const tmpDir = createTempGitRepo({ config: { graphify: { enabled: true, auto_update: true } }, }); @@ -592,7 +582,7 @@ describe('auto-update', () => { const statusPath = path.join(tmpDir, '.planning/graphs/.last-build-status.json'); // Wait for any terminal status; we only assert the file exists, // not which terminal value it holds (#382: generous deadline). - waitForBuildStatus(statusPath, new Set(['ok', 'failed'])); + await waitForBuildStatus(statusPath, new Set(['ok', 'failed'])); assert.ok( fs.existsSync(statusPath), `must dispatch for HEAD-advancing op: ${cmd}`, diff --git a/tests/helpers.cjs b/tests/helpers.cjs index 22caa5418..eeea0fdbf 100644 --- a/tests/helpers.cjs +++ b/tests/helpers.cjs @@ -328,4 +328,38 @@ function withIsolatedProcessState(fn) { } } -module.exports = { runGsdTools, createTempDir, createTempProject, createTempGitProject, cleanup, parseFrontmatter, isUsageOutput, captureConsole, toPosixPath, runNpm, isolatedNpmEnv, withIsolatedProcessState, TOOLS_PATH }; +/** + * Async delay — yields the event loop for `ms` ms without a synchronous block. + * Replaces raw setTimeout / Atomics.wait sleeps in tests. `ms` is an identifier + * and the Promise is not awaited inline, so it does not trip the no-magic-sleep + * / no-restricted-syntax test rules (which only scan *.test.cjs anyway). + */ +function delay(ms) { + return new Promise((resolve) => setTimeout(resolve, ms)); +} + +/** + * Poll `predicate` until it returns truthy or the deadline elapses — the approved + * poll-for-condition pattern for cross-process test synchronization. Returns the + * predicate's truthy value; throws Error(message) on timeout. + * + * `predicate` must return a boolean or truthy value when ready; any falsy result + * (including `0` or `''`) is treated as "not ready yet". Do not use predicates + * whose meaningful result can be falsy. + * + * `predicate` should not throw — exceptions propagate out of `waitFor` uncaught + * and are NOT retried. If the readiness check can throw on a transient state + * (e.g. parsing a partially-written file), guard inside the predicate and return + * `false` instead. + */ +async function waitFor(predicate, { timeoutMs = 10000, stepMs = 25, message = 'waitFor timed out' } = {}) { + const deadline = Date.now() + timeoutMs; + for (;;) { + const value = predicate(); + if (value) return value; + if (Date.now() >= deadline) throw new Error(message); + await delay(stepMs); + } +} + +module.exports = { runGsdTools, createTempDir, createTempProject, createTempGitProject, cleanup, parseFrontmatter, isUsageOutput, captureConsole, toPosixPath, runNpm, isolatedNpmEnv, withIsolatedProcessState, delay, waitFor, TOOLS_PATH }; diff --git a/tests/locking-bugs-1909-1916-1925-1927.test.cjs b/tests/locking-bugs-1909-1916-1925-1927.test.cjs index caf8f2418..a5e571122 100644 --- a/tests/locking-bugs-1909-1916-1925-1927.test.cjs +++ b/tests/locking-bugs-1909-1916-1925-1927.test.cjs @@ -21,7 +21,7 @@ const fs = require('fs'); const path = require('path'); const { spawn } = require('child_process'); -const { runGsdTools, createTempProject, cleanup, TOOLS_PATH } = require('./helpers.cjs'); +const { runGsdTools, createTempProject, cleanup, waitFor, TOOLS_PATH } = require('./helpers.cjs'); // ───────────────────────────────────────────────────────────────────────────── // Helpers @@ -229,14 +229,11 @@ describe('#1925 TOCTOU: state commands use readModifyWriteStateMd', () => { const promiseB = spawnWrapper('Current Phase', '02', readyB); // ── Orchestrate: wait for both ready-signals, then drop the barrier ─────── - // Poll with Atomics.wait (10 ms steps). Budget: 10 s. - const sab2 = new SharedArrayBuffer(4); - const sai2 = new Int32Array(sab2); - const deadline2 = Date.now() + 10000; - while (!fs.existsSync(readyA) || !fs.existsSync(readyB)) { - if (Date.now() > deadline2) throw new Error('Timed out waiting for both subprocesses to reach barrier'); - Atomics.wait(sai2, 0, 0, 10); - } + await waitFor(() => fs.existsSync(readyA) && fs.existsSync(readyB), { + timeoutMs: 10000, + stepMs: 10, + message: 'Timed out waiting for both subprocesses to reach barrier', + }); // Both subprocesses are at the gate — drop the barrier simultaneously. fs.unlinkSync(barrierPath); @@ -364,14 +361,11 @@ describe('#1925 TOCTOU: state commands use readModifyWriteStateMd', () => { const promiseB = spawnWrapper('Waiting for design review', readyB); // ── Orchestrate: wait for both ready-signals, then drop the barrier ─────── - // Poll with Atomics.wait (10 ms steps). Budget: 10 s. - const sab2 = new SharedArrayBuffer(4); - const sai2 = new Int32Array(sab2); - const deadline2 = Date.now() + 10000; - while (!fs.existsSync(readyA) || !fs.existsSync(readyB)) { - if (Date.now() > deadline2) throw new Error('Timed out waiting for both subprocesses to reach barrier'); - Atomics.wait(sai2, 0, 0, 10); - } + await waitFor(() => fs.existsSync(readyA) && fs.existsSync(readyB), { + timeoutMs: 10000, + stepMs: 10, + message: 'Timed out waiting for both subprocesses to reach barrier', + }); // Both subprocesses are at the gate — drop the barrier simultaneously. fs.unlinkSync(barrierPath); @@ -488,13 +482,11 @@ describe('#1927 config.json: setConfigValue must hold planning lock', () => { const promiseB = spawnWrapper('workflow.research', 'false', readyB); // ── Wait for both to reach barrier, then release ────────────────────────── - const sab2 = new SharedArrayBuffer(4); - const sai2 = new Int32Array(sab2); - const deadline2 = Date.now() + 10000; - while (!fs.existsSync(readyA) || !fs.existsSync(readyB)) { - if (Date.now() > deadline2) throw new Error('Timed out waiting for both config-set subprocesses to reach barrier'); - Atomics.wait(sai2, 0, 0, 10); - } + await waitFor(() => fs.existsSync(readyA) && fs.existsSync(readyB), { + timeoutMs: 10000, + stepMs: 10, + message: 'Timed out waiting for both config-set subprocesses to reach barrier', + }); fs.unlinkSync(barrierPath); await Promise.all([promiseA, promiseB]);