Skip to content

test(sync): stop watchAndSync tests flaking on slow CI runners - #94

Merged
sjsyrek merged 3 commits into
mainfrom
fix/flaky-watch-test
Jul 27, 2026
Merged

test(sync): stop watchAndSync tests flaking on slow CI runners#94
sjsyrek merged 3 commits into
mainfrom
fix/flaky-watch-test

Conversation

@sjsyrek

@sjsyrek sjsyrek commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

Summary

Stops the watchAndSync test block intermittently failing CI on unrelated PRs. Addresses bead sync-94ua.

The problem

Four sightings, always a 10s test timeout, never an assertion, hitting a different test in the block each time:

PR Date Runtime Test
#81 (inquirer) Jun 30 Node 22 config cache across watch ticks › includes the .deepl-sync.yaml config file itself…
#91 (commander) Jul 27 Node 24 same test
#93 (clean script) Jul 27 Node 24 should log the number of watched patterns

#81 and #91 both passed on plain re-run with no code change. Each occurrence costs a re-run and, worse, destroys signal — during a release you cannot distinguish a flake from a real regression.

Root cause

The block runs in ~1.8s locally but was observed at 10.8–10.9s on CI, with 232 suites competing for ~4 cores on a shared runner. It was sitting on jest's 10s default, so an arbitrary test tipped over each time. Runner CPU starvation, not a hang.

Changes Made

  1. jest.setTimeout(30_000) for the block — the headroom it actually needs. These are the heaviest tests in the file, each driving a full watch lifecycle through fake timers.

  2. flushWatchSetup waits on an observable readiness signal rather than a fixed round count:

    - for (let i = 0; i < 250; i++) { await Promise.resolve(); await jest.advanceTimersByTimeAsync(0); }
    + while (mockWatcherOn.mock.calls.length === 0) { /* bounded, throws with state */ }
    + for (let i = 0; i < SETTLE_ROUNDS; i++) { ... }

    Sound because attachDebouncedWatchLoop calls watcher.on('change'/'add') in the same synchronous continuation as process.on('SIGINT', …) (sync-command.ts:394–420) — so listeners-attached implies the handler each test uses for shutdown is registered. A fixed count could under-wait; this cannot. Two-phase so all 21 call sites keep working: 14 are re-invocations after change events that need the drain, and readiness is already true for those.

  3. Settle rounds 250 → 25 — every test passes with as few as 5 (measured), so 25 keeps a 5× margin.

On method — why the previous fixes didn't stick

The in-file comment records an escalation of 20 → 50 → 250 rounds, each assuming the budget was too small. Suite duration is flat across 250/25/5 rounds (1.80s / 1.95s / 1.40s), so widening it could never have helped.

Four further hypotheses were tested and disproven:

Hypothesis Disproof
Slow sweepStaleBackups I/O exhausts the budget Its projectRoot is /test, which does not exist → readdir ENOENTs immediately
Hang in controller.shutdown() Microtask-only: resolved-mock close(), empty backup set
Flush rounds expensive under load Measured 0.00ms per 250 rounds
CPU contention Old code passed 12/12 under 16 spinners on 11 cores

Test Coverage

The block's 49 tests pass. The new diagnostic path is verified by sabotage — forcing readiness never to arrive yields:

watchAndSync setup did not attach watcher listeners within 50 flush rounds
(chokidar.watch calls: 1). Either setup is genuinely hung, or this test
exercises the early-return path where no watcher is created…

instead of a mute timeout.

Verified on Node 24.18.0:

block only              49/49 pass
I/O + CPU contention    20/20 pass  (6 find walks, 4 dd+sync writers, 4 spinners)
npm run lint            pass
npm run type-check      pass
npm test                232 suites / 5501 tests pass

Honest limitation

The flake could not be reproduced locally. Roughly 58 runs across five contention profiles — CPU-only, I/O+CPU, full-suite, and a deliberately starved 5-round budget — produced exactly one failure, whose identity was lost. So this targets the signature the evidence supports rather than a reproduction, and I would not claim it is proven until CI has run it repeatedly.

That is precisely why change 2 matters beyond correctness: if the mechanism turns out to be a genuine stall rather than starvation, the next occurrence will say so explicitly instead of prompting a sixth guess.

Backward Compatibility

No production code touched — test file and changelog only.
✅ All 21 flushWatchSetup call sites unchanged and passing.
⚠️ A genuinely hung setup in this block now surfaces after 30s rather than 10s, but with a diagnostic rather than a bare timeout.
Breaking changes: none.

Size: Small ✓

One test file, one changelog entry. No source changes.

sjsyrek added 3 commits July 27, 2026 16:41
The watchAndSync block intermittently failed CI on unrelated dependency
PRs (#81 Jun 30 Node 22, #91 and #93 Jul 27 Node 24), always as a 10s
test timeout and never as an assertion, hitting a different test each
time. Both #81 and #91 passed on plain re-run with no code change.

Three changes, in order of importance:

1. jest.setTimeout(30_000) for the block. The suite runs in ~1.8s locally
   but was observed at 10.8-10.9s on GitHub runners with 232 suites
   competing for ~4 cores — i.e. sitting on the 10s default, which tipped
   an arbitrary test over each time. This is the headroom the block
   actually needed.

2. flushWatchSetup now waits for an observable readiness signal
   (mockWatcherOn having been called) instead of burning a fixed round
   count, then drains a settle budget. attachDebouncedWatchLoop calls
   watcher.on() in the same synchronous continuation as the
   process.on('SIGINT') registration, so listeners-attached implies the
   handler each test uses for shutdown is registered. A fixed count could
   under-wait; this cannot. On a genuine stall it throws with the pending
   state instead of timing out mutely.

3. Settle rounds 250 -> 25. Every test in the block passes with as few as
   5 (measured), so 25 keeps a 5x margin.

On method: the historical escalation was 20 -> 50 -> 250 rounds, each
assuming the budget was too small. Suite duration is flat across
250/25/5 rounds, so widening it could never have worked. Four further
hypotheses were tested and disproven — slow sweepStaleBackups I/O (its
projectRoot '/test' does not exist, so readdir ENOENTs immediately), a
hang in controller.shutdown() (microtask-only), expensive flush rounds
(0.00ms per 250), and CPU contention (old code passed 12/12 under 16
spinners on 11 cores). Details in bead sync-94ua.

Honest limitation: the flake could not be reproduced locally — ~58 runs
across five contention profiles (CPU, I/O+CPU, full-suite, starved
budget) produced one failure whose identity was lost. So this targets the
signature the evidence supports rather than a reproduction, and the new
diagnostic ensures the next occurrence identifies itself.

Verified: 49 tests in the block pass; 20/20 under combined I/O and CPU
contention; lint, type-check, and 5501 tests green on Node 24.18.0.
@sjsyrek
sjsyrek merged commit 8233543 into main Jul 27, 2026
2 checks passed
@sjsyrek
sjsyrek deleted the fix/flaky-watch-test branch July 28, 2026 12:15
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant