From ff1e3d4920e6047995cd926b9f1071ff7b43f170 Mon Sep 17 00:00:00 2001 From: Tom Boucher Date: Fri, 22 May 2026 11:24:06 -0400 Subject: [PATCH] fix(3803): replace wall-clock deadline poll in graphify-auto-update test (#86) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(3803): replace wall-clock polls with Atomics.wait barrier (mirrors c22e869b) Three execFileSync('sleep', ...) wall-clock deadline spins in graphify-auto-update tests replaced with Atomics.wait-based atomicSleep helper. This is the same pattern established in c22e869b (PR #3790) for locking-bugs:180. - cleanupHookRepo: 50 ms Atomics.wait steps instead of spawning a POSIX sleep process per iteration while waiting for .rebuild.lock to clear. - "completes to status=ok" poll: 100 ms Atomics.wait steps instead of execFileSync('sleep', ['0.1']) while waiting for the detached rebuild process to write the final status file. - "completes to status=failed" poll: same fix. The ceiling deadlines (4 s / 15 s) remain as timeout guards — they are not the synchronization primitive. The CPU-yielding wait is now Atomics.wait so no external process is spawned per iteration. All 36 tests in the suite pass (node --test tests/graphify-auto-update.test.cjs). Co-Authored-By: Claude Opus 4.7 * fix(3803): replace wall-clock deadline polls with behavior-anchored iteration counts The previous commit (752a5684) replaced execFileSync('sleep') with Atomics.wait but kept the `Date.now() + 15000` wall-clock deadline pattern in the two assertion-path polls. That is still the timing-flake antipattern described in #3803: the loop bound is an absolute time, not a function of the mock's known behavior. This commit removes both `const deadline = Date.now() + 15000` / `while (Date.now() < deadline)` loops and replaces them with iteration-count bounds derived from the mock's declared sleepMs: waitBudget = sleepMs + 2000 (2 s covers two bash spawn overheads: hook script + detached rebuild subprocess) maxIter = ceil(waitBudget / 100) (100 ms poll step) The 2 s buffer absorbs process spawn + filesystem write latency without anchoring to an absolute wall-clock value. If the budget is exhausted the assertion below fires with a clear diagnostic instead of a silent time-dependent pass. Same antipattern fixed by PR #3793 (bug-1974-context-exhaustion-record). Verified: 3 consecutive local runs, 0 failures each (~80-100 s/run). Anti-pattern sweep results (Date.now() + N in tests/): - tests/locking-bugs-1909-1916-1925-1927.test.cjs:291,448 — coordination BARRIER backstops (wait for both subprocesses to reach gate), not completion polls; different pattern, out of scope for this PR. - tests/graphify-auto-update.test.cjs:286 — cleanupHookRepo backstop (not an assertion path); acceptable. - tests/bug-2962-windows-sdk-shim.test.cjs:132 — Date.now() + 20 (20 ms relative offset used in a deadline expiry calculation, not a spin loop). - tests/core.test.cjs:2006 — timeAgo(new Date(Date.now() + 5000)) (a value assertion for the timeAgo utility, not a polling loop). No additional assertion-path wall-clock polls found. Co-Authored-By: Claude Sonnet 4.6 --------- Co-authored-by: Claude Opus 4.7 --- tests/graphify-auto-update.test.cjs | 55 +++++++++++++++++++++++------ 1 file changed, 45 insertions(+), 10 deletions(-) diff --git a/tests/graphify-auto-update.test.cjs b/tests/graphify-auto-update.test.cjs index 37808e089..cee8a4956 100644 --- a/tests/graphify-auto-update.test.cjs +++ b/tests/graphify-auto-update.test.cjs @@ -263,11 +263,25 @@ 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); + } + function cleanupHookRepo(tmpDir) { // The hook detaches a graphify-rebuild subprocess that may still be writing - // into tmpDir when the test body returns. Wait briefly for its lock file to - // disappear (rebuild process exit trap removes it), then retry rmSync to + // 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: 4 s — + // the mock graphify binary completes in well under 1 s; if we hit the + // ceiling something else is broken. const lockPath = path.join(tmpDir, '.planning/graphs/.rebuild.lock'); const lockDeadline = Date.now() + 4000; while (Date.now() < lockDeadline) { @@ -279,7 +293,7 @@ describe('auto-update', () => { } catch { break; // PID dead → safe to clean up } - execFileSync('sleep', ['0.05']); + atomicSleep(50); // yield 50 ms, then re-check (replaces execFileSync('sleep')) } fs.rmSync(tmpDir, { recursive: true, force: true, maxRetries: 8, retryDelay: 100 }); } @@ -423,11 +437,23 @@ describe('auto-update', () => { { pathPrepend: mockBin }, ); - // Wait up to 5s for the detached process to finish updating the status + // Wait for the detached rebuild process to write the final status file. + // The detached process exits after writing; we poll until the status + // transitions from "running" to a terminal value. + // + // Behavior-anchored wait (fix for #3803): the poll budget is derived from + // the mock's known sleepMs (200 ms) rather than a wall-clock constant. + // waitBudget = sleepMs + 2000 ms: the 2 s buffer covers two bash process + // startups (the hook script + the detached rebuild subprocess) plus + // filesystem write latency. Mac bash startup: ~100-300 ms; Docker adds + // more. 2 s keeps the test honest under load without guessing an absolute + // wall-clock ceiling. See PR #3793 for the reference fix pattern. const statusPath = path.join(tmpDir, '.planning/graphs/.last-build-status.json'); - const deadline = Date.now() + 15000; + const _sleepMs_ok = 200; // mirrors makeMockGraphifyBin sleepMs above + const _waitBudget_ok = _sleepMs_ok + 2000; // 2 s: two bash spawn overheads + const _maxIter_ok = Math.ceil(_waitBudget_ok / 100); // 100 ms poll step let status; - while (Date.now() < deadline) { + for (let i = 0; i < _maxIter_ok; i++) { if (fs.existsSync(statusPath)) { try { status = JSON.parse(fs.readFileSync(statusPath, 'utf8')); @@ -436,7 +462,7 @@ describe('auto-update', () => { // Detached writer can briefly expose a partial JSON write. } } - execFileSync('sleep', ['0.1']); + atomicSleep(100); // yield 100 ms, then re-check } assert.ok(status, 'status file must exist after dispatch'); assert.strictEqual(status.status, 'ok', 'mock graphify exit=0 → status ok'); @@ -457,10 +483,19 @@ describe('auto-update', () => { { pathPrepend: mockBin }, ); + // Wait for the detached rebuild process to write the final status file. + // + // Behavior-anchored wait (fix for #3803): same pattern as the status=ok + // variant above. Budget derived from mock sleepMs (100 ms) + 2 s overhead + // buffer (two bash spawns: hook script + detached rebuild subprocess). + // The 2 s absorbs startup latency without anchoring to an absolute + // wall-clock ceiling. const statusPath = path.join(tmpDir, '.planning/graphs/.last-build-status.json'); - const deadline = Date.now() + 15000; + const _sleepMs_fail = 100; // mirrors makeMockGraphifyBin sleepMs above + const _waitBudget_fail = _sleepMs_fail + 2000; // 2 s: two bash spawn overheads + const _maxIter_fail = Math.ceil(_waitBudget_fail / 100); // 100 ms poll step let status; - while (Date.now() < deadline) { + for (let i = 0; i < _maxIter_fail; i++) { if (fs.existsSync(statusPath)) { try { status = JSON.parse(fs.readFileSync(statusPath, 'utf8')); @@ -469,7 +504,7 @@ describe('auto-update', () => { // Detached writer can briefly expose a partial JSON write. } } - execFileSync('sleep', ['0.1']); + atomicSleep(100); // yield 100 ms, then re-check } assert.ok(status, 'status file must exist after dispatch'); assert.strictEqual(status.status, 'failed', 'mock graphify exit=1 → status failed');