gate-lease: an uncontended run logs "acquired after" when its lock call is slow, failing the "two concurrent runs serialize" test under load #2369

Problem

scripts/gate-lease.test.mjs › "two concurrent runs serialize: the second starts after the first ends" fails intermittently when the machine is loaded — for example while other sessions' local:gate runs are executing — and so turns the mandatory pre-push gate red on a diff that touches nothing under scripts/.

Observed on 2026-09-14 in a worktree for #2208, whose gate queued 4m31s behind another session's gate and then failed at test:scripts while two other gates were still running on the machine:

✖ two concurrent runs serialize: the second starts after the first ends (926.784042ms)
  AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
  2 !== 1
      at TestContext.<anonymous> (scripts/gate-lease.test.mjs:222:10)

Line 222 is the assertion that exactly one gate-lease: acquired after … line was logged. Two were. The same file passed 20/20 on each of three isolated re-runs immediately afterwards.

Cause

Each test uses its own freshDir() lease directory, so the real gates are not contending for this lock — the failure is timing, not overlap.

In runUnderLease (scripts/gate-lease.mjs:412-425), waited is the wall time of the whole acquireLease call, including a successful first properLockfile.lock(), and the "acquired after" line is logged when waited >= pollMs. The test passes pollMs: 25. So on a loaded machine the uncontended first run's mkdir + holder-record work can take ≥25ms, and it logs acquired after 0s exactly as the genuinely-waiting second run does.

The same measurement drives the (waited … first) suffix on the released after line (:471), so this is not only a test defect: a real gate that never queued can report gate-lease: acquired after 0s. / released after 43s (waited 0s first) whenever its lock call is slow, which misreports the thing the message exists to tell you.

Expected

"Acquired after" / "waited first" are reported only when the run actually waited on a holder — i.e. acquireLease failed at least once and looped — independent of how long an uncontended acquire takes. The test's acquired after count is then deterministic under any load.

A likely shape: have acquireLease report whether it looped (it already tracks announced), and gate both messages on that rather than on waited >= pollMs. Per #1596, the fix is to measure the right thing, not to widen pollMs in the test.

Reproduce

Load the machine (e.g. run npm run local:gate in two other worktrees with INSPECTOR_SKIP_GATE_LEASE=1, or any CPU/IO stressor), then loop node --test scripts/gate-lease.test.mjs until it fails at :222. Alternatively, inject a ≥pollMs delay into the fs passed to properLockfile.lock for the first run only — that reproduces it deterministically and makes a good regression test.