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

fix(#471): make perf-407 lock-buffer-alloc test deterministic via clock-seam; remove real-worker race (#472)

Browse Source 
Co-authored-by: CI Rebase Check <ci@gsd-redux>
Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Tom Boucher
2026-05-29 13:20:32 -04:00
committed by GitHub
parent b735f270c5
commit e22596be04
1 changed files with 119 additions and 171 deletions
Download Patch File Download Diff File Expand all files Collapse all files

290
tests/perf-407-planning-lock-buffer-alloc.test.cjs
View File

@@ -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
);
}
);