Skip to content

metadata-fs watcher tests are merge-queue flaky, and #7208's 20s deadline hardening did NOT fix it — the event is suppressed, not late #7282

Description

@os-zhuang

Filed from PR #7261 (an unrelated packages/objectql test-only change) after a merge-queue ejection.
Unassigned — recording, not claiming.

The signature

FAIL test/fs-behavior.test.ts > FileSystemRepository — on-disk semantics
     > chokidar: external file change emits an update event

Confirmed flaky per the triage bot's checklist item 2 — the same signature has now ejected two
different PRs
, one of which does not touch packages/metadata-fs at all:

when (UTC) PR queue run signature
03:16 #7208 31351599963 fs-behavior.test.ts › chokidar external edit
03:42 #7208 31352802812 watch-dot-root.test.ts › dot-rooted external edit
04:33 #7261 31355694872 fs-behavior.test.ts › chokidar external edit

The part that matters: the hardening was already in place

#7208's third-attempt patch (3a9f5b880, merged as 684ab22 at 04:12:38) raised every positive
watcher wait to EVENT_WAIT_MS = 20_000, and its own comment set a standing rule: "if this attempt
ejects again on a watcher-timing signature… the flaky-family card gets filed."
This is that card.

PR #7261's queue build was based on b8e9fe27 (04:19:50), which has 684ab22 as an ancestor
(verified with git merge-base --is-ancestor). Reading the file as actually built in the queue's
merge commit 5c6a299d:

$ git show 5c6a299d:packages/metadata-fs/test/fs-behavior.test.ts | grep -n EVENT_WAIT_MS
33:const EVENT_WAIT_MS = 20_000;
125:    await Promise.race([collectorDone, sleep(EVENT_WAIT_MS)]);

The test failed with a 20-second deadline. So the diagnosis behind the hardening — "queue load
makes the event late" — is now falsified. A 6.7× deadline increase changed nothing, which is the
signature of an event that is never delivered, not one that is slow.

A mechanism that fits (read from source; not executed)

Two constants interact badly, and they are in production code rather than in the test:

// repository.ts — watcher
usePolling: true, interval: 1000, awaitWriteFinish: { stabilityThreshold: 50, pollInterval: 20 }

// repository.ts — self-write suppression, on every put()
this.selfWrites.add(file);
setTimeout(() => this.selfWrites.delete(file), 200);   // fixed wall-clock timer

The test does put() (a self-write), sleeps 300ms to clear the 200ms suppression, then edits the
file externally and expects exactly one event.

With polling at 1000ms, chokidar does not observe the two writes separately — it compares state
once per tick, so a put() at t≈0 and an external edit at t≈300ms are both visible as one change
at the t≈1000ms poll. Whether that single event is delivered or dropped depends on whether file is
still in selfWrites when the poll lands. Under queue load the 200ms setTimeout is a wall-clock
timer on a saturated event loop — if it fires late (or the poll lands early), the coalesced event is
suppressed as a self-write, and because it was the only event the external edit will ever
produce, no later event exists to wait for.

That explains the 20s result exactly: waiting longer cannot recover an event that was swallowed.

Predictions worth checking before trusting this: the failure should be all-or-nothing rather than
marginal (it is — collected is empty, not late), and it should get more likely as interval
(1000ms) grows relative to the 200ms suppression window.

Suggested directions

Deadline widening is already spent; these attack the actual coupling:

  1. Make suppression content-keyed, not time-keyed — clear selfWrites when the hash the watcher
    reads matches the hash we wrote, so an external edit can never be mistaken for our own write no
    matter how the timers land. Removes the race rather than widening it.
  2. Have the test await the self-write's own settling before making the external edit, instead of
    sleep(300) guessing at the 200ms timer.
  3. Lower interval for tests so poll granularity stops coalescing distinct writes — narrows the
    window but does not close it.
  4. Failing all that, quarantine the watcher-timing family so it stops ejecting unrelated PRs from the
    merge queue.

(1) looks like the real fix; (2) is the cheap one that would stop the bleeding.

Blast radius

This is not confined to metadata-fs's own PRs — it ejected #7261, a one-file test-only change in
packages/objectql with no dependency path to metadata-fs (which depends only on
@objectstack/metadata-core and chokidar). Every ejection rebuilds every PR behind it in the
queue; the bot recorded 7 failed queue builds in 24h.

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions