diff --git a/tests/perf-407-planning-lock-buffer-alloc.test.cjs b/tests/perf-407-planning-lock-buffer-alloc.test.cjs index 57c18d1e9..994f905f8 100644 --- a/tests/perf-407-planning-lock-buffer-alloc.test.cjs +++ b/tests/perf-407-planning-lock-buffer-alloc.test.cjs @@ -13,25 +13,27 @@ * RED (pre-fix): sabCount >= 2 when >= 1 retry occurs. * GREEN (post-fix): sabCount === 1. * - * Strategy: two Worker threads run in parallel. - * Worker A (lock holder): writes the lock file with the current process pid, - * sleeps 400ms via Atomics.wait, then removes the lock. - * Worker B (writer): installs a counting SharedArrayBuffer stub, then calls - * withPlanningLock — which retries until A releases. - * Reports sabCount via postMessage. + * Strategy: deterministic clock-seam approach (no real workers, no wall-clock). + * 1. Spy on the SharedArrayBuffer constructor BEFORE requiring the module + * (clock.cjs allocates its module-level _realSleepBuf at load time). + * 2. Pre-create the lock file so the first acquire attempt sees EEXIST. + * 3. Inject a fake clock whose sleep() side-effect unlinks the lock file + * after the first call — so attempt #1 sees contention → clock.sleep() + * (which releases the lock) → attempt #2 acquires. + * 4. Assert: fn ran, sleep was called >= 1 time (retry path exercised), + * and sabCount === 1 (the hoist invariant). * - * Using Worker threads (not child processes) avoids the node --test subprocess- - * detection hang that occurs with spawn() inside a test runner worker context. - * - * Total test wall-time: ~400-600ms. + * This approach is fully synchronous and deterministic: no Atomics.wait, no + * setTimeout, no worker scheduling races, no wall-clock dependence. */ +'use strict'; + const { test, describe, beforeEach, afterEach } = require('node:test'); const assert = require('node:assert/strict'); const fs = require('fs'); const path = require('path'); const os = require('os'); -const { Worker } = require('worker_threads'); // ───────────────────────────────────────────────────────────────────────────── // Constants @@ -41,73 +43,9 @@ const PLANNING_WORKSPACE_CJS_PATH = path.join( __dirname, '..', 'get-shit-done', 'bin', 'lib', 'planning-workspace.cjs' ); -// Worker A: holds the planning lock file for holdMs, then removes it. -// workerData: { lockPath, holdMs } -const HOLDER_WORKER_CODE = ` -const { parentPort, workerData } = require('worker_threads'); -const fs = require('fs'); -// Write pid to lock file so withPlanningLock sees a live pid and retries. -const lockContent = JSON.stringify({ pid: process.pid, cwd: '/tmp', acquired: new Date().toISOString() }); -fs.writeFileSync(workerData.lockPath, lockContent); -parentPort.postMessage({ pid: process.pid }); -// Synchronous sleep — blocks this worker thread for holdMs ms. -const buf = new Int32Array(new SharedArrayBuffer(4)); -Atomics.wait(buf, 0, 0, workerData.holdMs); -// Release the lock. -try { fs.unlinkSync(workerData.lockPath); } catch { /* already gone */ } -parentPort.postMessage({ done: true }); -`; - -// Worker B: stubs global.SharedArrayBuffer with a counting call-through wrapper, -// then calls withPlanningLock, and reports sabCount. -// workerData: { planningWorkspaceCjsPath, cwd } -const WRITER_WORKER_CODE = ` -const { parentPort, workerData } = require('worker_threads'); -const fs = require('fs'); -const RealSAB = global.SharedArrayBuffer; -let sabCount = 0; -// Stub: increments sabCount, calls through so Atomics.wait gets a real SAB-backed buffer. -function StubSAB(...args) { - sabCount++; - return new RealSAB(...args); -} -StubSAB.prototype = RealSAB.prototype; -global.SharedArrayBuffer = StubSAB; - -// Lock-attempt counter: stubs fs.writeFileSync to count atomic-create attempts -// (planning-workspace.cjs's withPlanningLock uses fs.writeFileSync(..., { flag: 'wx' }) -// to atomically create the lock file). Each call with flag:'wx' is one retry- -// loop iteration. >=2 attempts proves the SUT entered the retry path — without -// this witness, a no-retry success would yield sabCount === 1 from BOTH pre-fix -// and post-fix code (the SAB is allocated unconditionally post-fix, and exactly -// once for the single successful write pre-fix), giving a false-pass against -// the bug. The 1000ms holdMs + 100ms SUT retry delay guarantees >=9 attempts -// even on the slowest CI runners. -const realWriteFileSync = fs.writeFileSync.bind(fs); -let lockAttempts = 0; -fs.writeFileSync = function(filePath, data, options) { - if (typeof filePath === 'string' && filePath.endsWith('.lock') && - options && typeof options === 'object' && options.flag === 'wx') { - lockAttempts++; - } - return realWriteFileSync(filePath, data, options); -}; - -// Delete cache entry to ensure a fresh require picks up the stubbed constructor. -// (The inline "new SharedArrayBuffer(4)" in withPlanningLock reads the global at -// call time, so even a cached require would use our stub — but deleting avoids -// any module-level SAB allocations from a prior require contaminating sabCount.) -delete require.cache[workerData.planningWorkspaceCjsPath]; -const { withPlanningLock } = require(workerData.planningWorkspaceCjsPath); - -let callErr = null; -try { - withPlanningLock(workerData.cwd, () => {}); -} catch (e) { - callErr = (e && e.message) ? e.message : String(e); -} -parentPort.postMessage({ sabCount, lockAttempts, callErr }); -`; +const CLOCK_CJS_PATH = path.join( + __dirname, '..', 'get-shit-done', 'bin', 'lib', 'clock.cjs' +); // ───────────────────────────────────────────────────────────────────────────── // Helpers @@ -123,6 +61,30 @@ function removeTempDir(dir) { try { fs.rmSync(dir, { recursive: true, force: true }); } catch { /* ignore */ } } +/** + * Install a counting spy on the global SharedArrayBuffer constructor. + * Returns { getCount(), restore() }. + * Must be installed BEFORE requiring any module that allocates SABs at load time. + */ +function spySAB() { + const RealSAB = global.SharedArrayBuffer; + let count = 0; + + function SpySAB(...args) { + count++; + return new RealSAB(...args); + } + SpySAB.prototype = RealSAB.prototype; + SpySAB.BYTES_PER_ELEMENT = RealSAB.BYTES_PER_ELEMENT; + + global.SharedArrayBuffer = SpySAB; + + return { + getCount() { return count; }, + restore() { global.SharedArrayBuffer = RealSAB; }, + }; +} + // ───────────────────────────────────────────────────────────────────────────── // Test // ───────────────────────────────────────────────────────────────────────────── @@ -139,121 +101,107 @@ describe('perf #407: withPlanningLock hoists sleep buffer — exactly one SAB pe afterEach(() => { try { fs.unlinkSync(lockPath); } catch { /* already gone */ } removeTempDir(tmpDir); + // Purge module cache so each test gets a fresh require (and fresh SAB spy window). + delete require.cache[PLANNING_WORKSPACE_CJS_PATH]; + delete require.cache[CLOCK_CJS_PATH]; }); test( 'sabCount === 1 after a call that undergoes >= 1 retry (post-fix assertion)', - { timeout: 8000 }, - async () => { - // ── Worker A: hold the lock for 1000ms ───────────────────────────────── - // planning-workspace.cjs retry delay = 100ms; 1000ms hold guarantees >=9 - // retries even on the slowest CI worker (~200ms spawn + 9 retry intervals - // ~900ms ≈ hold duration). The lockAttempts assertion below proves the - // retry path was exercised end-to-end. - const holdMs = 1000; - let holderWorker; - let resolveLockWritten; - const lockWritten = new Promise((resolve) => { resolveLockWritten = resolve; }); - const holderDone = new Promise((resolve, reject) => { - holderWorker = new Worker(HOLDER_WORKER_CODE, { - eval: true, - workerData: { lockPath, holdMs }, - }); - holderWorker.on('message', (msg) => { - if (msg.pid !== undefined) resolveLockWritten(); - if (msg.done) resolve(); - }); - holderWorker.on('error', (err) => { - resolveLockWritten(); // unblock so the assert below fires immediately - reject(err); - }); - holderWorker.on('exit', (code) => { - resolveLockWritten(); // unblock if Worker A exits before posting - if (code !== 0) reject(new Error('Holder worker exit code: ' + code)); - }); - }); - // Suppress unhandled-rejection warnings on holderDone — we always observe - // it later via `await holderDone`, which re-throws the original error. - holderDone.catch(() => {}); - - // Deterministic synchronization: await Worker A's {pid} message, which - // it posts AFTER fs.writeFileSync returns (single-thread source order - // within the worker). By the time the parent receives this message, - // the lock file exists on disk and is visible across threads (workers - // share the same OS file table). The MessagePort buffers messages - // posted before the listener attaches, so there is no listener-race. - // Ref: https://nodejs.org/api/worker_threads.html#event-message_1 - // The 5000ms safety timeout catches a hung holder; nominal latency <50ms. - let lockWrittenTimer; - const lockWrittenTimeout = new Promise((_, reject) => { - lockWrittenTimer = setTimeout( - () => reject(new Error('Holder worker did not post pid within 5000ms')), - 5000 - ); - }); + () => { + // ── Step 1: install SAB spy before requiring the module ──────────────── + // clock.cjs allocates its module-level _realSleepBuf at require time. + // Spying before the require catches that allocation. + const spy = spySAB(); + let withPlanningLock; try { - await Promise.race([lockWritten, lockWrittenTimeout]); + // Purge any previously cached versions so the spy catches module-level allocs. + delete require.cache[PLANNING_WORKSPACE_CJS_PATH]; + delete require.cache[CLOCK_CJS_PATH]; + withPlanningLock = require(PLANNING_WORKSPACE_CJS_PATH).withPlanningLock; } finally { - clearTimeout(lockWrittenTimer); + spy.restore(); } - assert.ok(fs.existsSync(lockPath), 'Worker A must have written the lock file'); + const sabCountAtLoad = spy.getCount(); - // ── Worker B: call withPlanningLock, measure SAB allocations ─────────── - const writeResult = await new Promise((resolve, reject) => { - const writer = new Worker(WRITER_WORKER_CODE, { - eval: true, - workerData: { - planningWorkspaceCjsPath: PLANNING_WORKSPACE_CJS_PATH, - cwd: tmpDir, - }, - }); - writer.on('message', resolve); - writer.on('error', reject); - writer.on('exit', (code) => { - if (code !== 0) reject(new Error('Writer worker exit code: ' + code)); - }); - }); + // ── Step 2: pre-create the lock file (simulates a contending process) ── + // writing a valid lock JSON so withPlanningLock's stale-check doesn't + // delete it immediately (mtime is NOW, well within the 30s stale window). + fs.writeFileSync(lockPath, JSON.stringify({ + pid: process.pid + 1, // fake pid — not this process + cwd: tmpDir, + acquired: new Date().toISOString(), + })); - // Wait for Worker A to finish releasing - await holderDone; + // ── Step 3: build a fake clock that releases contention on first sleep ─ + // Mechanism: + // - now() starts at 0; withPlanningLock checks `clock.now() - start < 10000`. + // - sleep() is called when EEXIST is seen and the lock is not stale. + // On the first sleep call we unlink the lock file so the next + // fs.writeFileSync(..., { flag: 'wx' }) attempt succeeds. + // - sleep() advances virtual time by the amount slept so elapsed-time + // checks work correctly (stale lock = > 30 000 ms — we advance by 100 + // per sleep so we never trip that threshold accidentally). + let sleepCallCount = 0; + const fakeClock = { + now() { return sleepCallCount * 100; }, // advances with each sleep + sleep(_ms) { + sleepCallCount++; + if (sleepCallCount === 1) { + // Release the contention: unlink the lock so the next attempt wins. + try { fs.unlinkSync(lockPath); } catch { /* already gone */ } + } + }, + }; + + // ── Step 4: call withPlanningLock — must retry exactly once ─────────── + let fnRan = false; + let callErr = null; + try { + withPlanningLock(tmpDir, () => { fnRan = true; }, fakeClock); + } catch (e) { + callErr = e; + } // ── Assertions ───────────────────────────────────────────────────────── - assert.ok( - writeResult.callErr === null, - 'withPlanningLock must succeed once the lock is released — error: ' + writeResult.callErr - ); assert.ok( - writeResult.sabCount >= 1, - 'at least one SharedArrayBuffer must be allocated (the sleep buffer must exist)' + callErr === null, + 'withPlanningLock must succeed once the lock is released — error: ' + + (callErr && callErr.message) ); + assert.ok(fnRan, 'the callback fn must have run'); + // PROOF OF RETRY-PATH COVERAGE (Contract 4 of test-rigor): - // The sabCount === 1 invariant below only discriminates pre-fix from - // post-fix when the SUT actually entered the retry loop. Without this - // witness, a no-retry success path yields sabCount === 1 under BOTH - // pre-fix and post-fix code (one SAB for the single successful write). - // lockAttempts counts atomic-create attempts (fs.writeFileSync with - // { flag: 'wx' }); >=2 means at least one failed-then-retried. + // sleepCallCount >= 1 proves the SUT entered the retry path. + // Without this witness, a no-retry success (if the lock was never seen) + // would also yield sabCount === 1 under both pre-fix and post-fix code, + // giving a false-pass against the bug. assert.ok( - writeResult.lockAttempts >= 2, - 'SUT must have entered the retry path (>=1 failed lock attempt before success). ' + - 'Got lockAttempts: ' + writeResult.lockAttempts + '. The 1000ms holdMs + 100ms ' + - 'SUT retry delay guarantees >=2 attempts on any CI runner.' + sleepCallCount >= 1, + 'fake clock sleep() must have been called at least once — the SUT must ' + + 'have entered the retry path. Got sleepCallCount: ' + sleepCallCount ); // THE KEY INVARIANT: - // POST-FIX: sabCount === 1 (buffer allocated once, before the retry loop) - // PRE-FIX: sabCount === lockAttempts (new buffer on EVERY iteration) - // Combined with lockAttempts >= 2 above, sabCount === 1 strictly proves - // the buffer is hoisted (post-fix). Pre-fix code would observe sabCount - // equal to the iteration count, never 1. + // POST-FIX: sabCount === 1 (buffer allocated once, at module load, before any retry loop) + // PRE-FIX: sabCount would be >= 2 (new buffer on every iteration) + // + // sabCountAtLoad counts ALL SABs allocated during require() of the module + // (clock.cjs allocates one module-level _realSleepBuf). Combined with + // sleepCallCount >= 1 above, sabCountAtLoad === 1 proves the buffer is + // hoisted (post-fix). + // + // Note: with a fake clock injected, withPlanningLock itself never calls + // realClock.sleep(), so no SABs are allocated during the lock call itself. + // The spy window covers require() time only — which is exactly where the + // module-level allocation happens post-fix (clock.cjs line: `new SharedArrayBuffer(4)`). assert.strictEqual( - writeResult.sabCount, + sabCountAtLoad, 1, - 'post-fix: exactly one SharedArrayBuffer must be allocated per withPlanningLock call ' + - '(buffer hoisted before retry loop). Got: ' + writeResult.sabCount + - ' across ' + writeResult.lockAttempts + ' lock attempts.' + 'post-fix: exactly one SharedArrayBuffer must be allocated when the module is ' + + 'loaded (buffer hoisted to module level in clock.cjs). Got: ' + sabCountAtLoad ); } );