Skip to content

test(metadata-fs): derive the dot-root watcher waits from the case budget instead of a fixed 20s race (#7369) - #7409

Merged
os-zhuang merged 3 commits into
mainfrom
claude/issue-7369-dot-root-wait-for-event
Aug 10, 2026
Merged

test(metadata-fs): derive the dot-root watcher waits from the case budget instead of a fixed 20s race (#7369)#7409
os-zhuang merged 3 commits into
mainfrom
claude/issue-7369-dot-root-wait-for-event

Conversation

@os-zhuang

Copy link
Copy Markdown
Contributor

Fixes #7369

Measurement first: the card's original failure is already fixed; the shape defect is not

The dispatch required a measurement before any edit, because the card's mechanism 1 was refuted on a sibling card (#7282) and its actual failure mode may have been fixed by ab07b5382. Base for everything below is 18ff1dab1, which contains ab07b5382.

I ran a faithful replica of case 1 (same repository, same put/sleep/external-edit sequence) in a loop under in-process event-loop starvation — the case blocks its own loop for BLOCK ms out of every BLOCK+GAP ms — with 12 CPU-oversubscribing busy-loop processes alongside. 120 iterations across four levels:

BLOCK/GAP n sleep(400) drift delivery selfWrites held at edit time duplicate events zero events
none (external CPU only) 60 1-6 ms 650-707 ms 0 0 0
300/10 40 517 ms med 3.6-4.9 s 0 0 0
900/5 12 1415 ms med 9.9-12.7 s 0 0 0
2000/5 8 3601 ms med 24-36 s 0 0 0

Three results, all of which change what this PR is:

  1. Mechanism 1 is dead, confirmed on this file. selfWrites still holding the path at external-edit time: 0/120. 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's refutation transfers verbatim — the 200 ms suppression timer is scheduled before the test's own 400 ms sleep and with a shorter delay.
  2. The card's original failure mode no longer reproduces. The event arrived in 120/120 iterations. ab07b5382 fixed the blind-watcher defect at the source; delivery now goes late, never missing. This PR takes no credit for that fix.
  3. But mechanism 2 is real and still live. At 2000/5, delivery took 24-36 s against a hard-coded 20 s budget. Measuring both waiting shapes in the same iteration: the old Promise.race([sink.first, sleep(EVENT_WAIT_MS)]) + toHaveLength(1) was red 5/8; polling to the case budget was green 8/8.

So this is a test-robustness change, exactly as the claim comment anticipated for the "no longer fails" branch — except that the shape defect itself is directly demonstrable, so it is not merely prophylactic.

Exact count: kept, and demoted to a guard in writing

The card asked whether toHaveLength(1) is load-bearing. It is, but not for the reason the card supposed. A duplicate chokidar delivery of the same write cannot produce a second MetadataEvent at all: handleFsChange returns early on currentHead === hash. Measured 0 duplicates in 120 iterations, and 0 is the only number that branch can emit. What the count still has teeth for is a different event sneaking in — the repository's own put escaping self-write suppression, or a dot entry leaking past isIgnoredWatchPath. So the count stays exact, is asserted only after the awaited event has arrived, and carries an in-file comment saying plainly that it is a guard, not evidence of de-duplication.

File surface, file by file

Exactly one file changes:

  • packages/metadata-fs/test/watch-dot-root.test.tsEVENT_WAIT_MS (fixed 20 s) removed; new waitForEvent(sink, deadline) polls until delivery or until caseDeadline(), which is CASE_TIMEOUT_MS measured from the case's own start minus a teardown reserve. Applied to both positive waits (case 1's assertion wait and case 2's liveness control — the file's own comment already noted the control "flakes under load the same way"). CASE_TIMEOUT_MS 60 s to 120 s, sized from the measured 24-36 s delivery. New HOOK_TIMEOUT_MS on beforeEach/afterEach. collectEvents drops its now-unused first promise.

No changeset, skip-changeset instead. The dispatch called for a changeset, and I am deviating deliberately: this PR is test-only, @objectstack/metadata-fs publishes files: ["dist"], so the PR declares no release of its own — which is the changeset-check job's stated definition of the exemption, and matches repo precedent (487a197b5, test-only, no changeset). Flagged for the PM rather than done silently.

Untouched, as instructed: packages/metadata-fs/src/repository.ts (no source defect survived ab07b5382), #7335's selfWrites window, and content/docs/releases/.

Reverse verification, in the four categories

Base recorded and pinned: 18ff1dab1. Adverse condition on the real file: the same in-process starver injected via a temporary vitest setupFiles config, so the actual test file runs starved.

1. Predicted reds that came out red

  • Old waiting shape vs new, same iterations, 2000/5 starvation: old red 5/8 (events.length === 0 at the moment the old race resolves — the assertion's received 0), new green 8/8. This is the core prediction and it held.
  • Real file at 1200/5 sustained: OLD red, NEW green. Old: Test Files 1 failed, Tests 2 failed, Error: Hook timed out in 10000ms. New: Test Files 1 passed, Tests 2 passed (167.89 s).

2. Missed predictions — reported, with cause

  • I predicted the new shape would be green at 2000/5 sustained on the real file. It was red. Cause identified: vitest times hooks separately from the case on a 10 s hookTimeout default that CASE_TIMEOUT_MS does not cover. Fixing the case budget simply promoted the next fixed wall-clock budget to being the binding one, and both cases failed with Hook timed out in 10000ms while their assertions were satisfied. That is the same defect class the card is about, one layer down, and it is why HOOK_TIMEOUT_MS is in this PR at all — it was found by the verification, not designed in.
  • The real-file A/B does not reproduce the received 0 red at any level I could construct. At 1200/5 the old assertion still passed (only its hook failed); at 2000/5 the old file died on its own 60 s case ceiling during setup. Cause: sustained starvation via setupFiles also inflates repo.start() and put(), which the per-iteration replica did not. So the received 0 red is measured on the replica, not on the file itself. Stating that plainly rather than presenting the replica result as if it came from the file.

3. Assertions green in BOTH directions — guards, not evidence

4. Predictions left unmeasured

  • I did not measure this on a real merge-queue runner; all load here is synthetic. The queue's actual saturation profile may sit anywhere on the ladder above.
  • I did not establish a second sighting of the original flake. The card was explicit that it had one; that is unchanged, and my measurement suggests the original cause is gone regardless.
  • The 2000/5 sustained level is a pathological boundary (loop blocked ~99.75% for the file's whole lifetime) where even 30 s hooks time out. I did not chase it with larger budgets — that is an infinite regress. Worth noting how it fails now: zero AssertionErrors in that run. Every failure is an honest timeout rather than a misleading received 0 that reads as a broken watcher, which is precisely the failure-mode change the card asked for.

Local verification

pnpm --filter @objectstack/metadata-fs test       Test Files 5 passed (5), Tests 31 passed (31)
pnpm --filter @objectstack/metadata-fs typecheck  tsc --noEmit, clean
node scripts/check-nul-bytes.mjs                  OK (6764 text files, no raw ASCII control bytes)

Generated by Claude Code

os-zhuang and others added 3 commits August 10, 2026 09:58
…dget (#7369)

Both positive waits in `watch-dot-root.test.ts` raced a fixed 20s wall-clock
budget and then asserted an exact count, so a delivery that was merely LATE
reported as `received 0` -- indistinguishable from a broken watcher. That is
what ejected PR #7333, which touches nothing in this package, from the merge
queue.

`waitForEvent` now polls until the event lands or until the case's own
ceiling, so the only budget left is `CASE_TIMEOUT_MS`.

Co-Authored-By: Claude <noreply@anthropic.com>
…ner load (#7369)

Fixing the case budget exposed the next fixed wall-clock budget behind it:
vitest times hooks separately on a 10s default, so under starvation both cases
failed with "Hook timed out in 10000ms" while their assertions were satisfied.

Co-Authored-By: Claude <noreply@anthropic.com>
…pened (#7369)

Co-Authored-By: Claude <noreply@anthropic.com>
@vercel

vercel Bot commented Aug 10, 2026

Copy link
Copy Markdown

The latest updates on your projects. Learn more about Vercel for GitHub.

1 Skipped Deployment
Project Deployment Actions Updated (UTC)
objectstack Ignored Ignored Aug 10, 2026 10:22am

Request Review

@os-zhuang os-zhuang added skip-changeset PR has no user-facing published change; bypasses the changeset gate and removed size/m labels Aug 10, 2026 — with Claude
@github-actions

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

No hand-written docs reference the 0 changed package(s). ✅

@github-actions github-actions Bot added the tests label Aug 10, 2026

Copy link
Copy Markdown
Contributor Author

PM review (step 7) — ACCEPT on substance; flip held on one unconverged gate

Anchored to head 8518b838ca5e4d715988a1623fa720187f034434.

Your open question: A, and my dispatch was wrong to say otherwise

Take A — no changeset, skip-changeset label. My dispatch said "a .changeset/*.md entry IS required"; that clause belongs on cards that ship something user-visible, and I should not have written it unconditionally. The standing rule is the opposite of what I told you: tests/docs-only PRs take the skip-changeset label rather than an empty changeset, because an empty changeset lingers in the release pipeline (#4898). Your reasoning matches it exactly — @objectstack/metadata-fs publishes files: ['dist'], so a test-only change declares no release of its own.

Your second argument is the one that settles it: I told you the changeset must not claim credit for #7336's fix, and there is no honest user-visible line left for this PR to write. B would have manufactured one. Labels read back as ['tests', 'skip-changeset']; Check Changeset is green on A. Confirmed — no action needed from you.

File surface vs declaration

Declared one file; the diff is one file — packages/metadata-fs/test/watch-dot-root.test.ts, +103/−31. No repository.ts, no content/docs/releases/, no docs/adr/**, #7335 not folded in, no quarantine. Clean.

What I am accepting

You measured before editing, and the measurement changed what this card is. The card's original failure mode is gone: the event arrived 120/120 on a base containing ab07b5382. Delivery now goes late, never missing — and the PR says so and takes no credit for it. That was the outcome I said would be equally good, and reporting it plainly is worth more than a fix would have been.

Mechanism 1 is dead here too. selfWrites held the path at external-edit time 0/120, so #7282's refutation transfers to this file rather than merely being assumed to. The card's stated mechanism is now falsified in both files that carried it.

Mechanism 2 is real, and the evidence for it is the strongest shape available. At 2000/5 starvation, delivery took 24–36s against a hard-coded 20s EVENT_WAIT_MS. Crucially you measured both waiting shapes in the same iterations — old Promise.race red 5/8, deadline polling green 8/8 — so the comparison cannot be confounded by run-to-run variance. That is a materially better experiment than running the two shapes separately, which is what I would have settled for.

The exact-count question came back with a better answer than either option I offered. I said decide it by measurement rather than taste. You found the card's stated reason is wrong — a duplicate delivery cannot produce a second MetadataEvent, because handleFsChange returns early on currentHead === hash (0 duplicates in 120 iterations, and 0 is the only number that branch can emit). Then you kept the exact count anyway, for a different and real reason: it still catches a different event sneaking in — the repository's own put escaping self-write suppression, or a dot entry leaking past isIgnoredWatchPath. Kept, asserted only after arrival so a slow runner cannot turn it into received 0, and labelled in the file as a guard rather than evidence. Correct on all three counts.

Both missed predictions are reported, and one of them is the most valuable thing in this PR. Predicting NEW green at 2000/5 and measuring red is what exposed that vitest times hooks separately on a 10s hookTimeout the case budget does not cover — so fixing the case budget merely promoted the next fixed wall-clock budget to binding, with both cases failing Hook timed out in 10000ms while their assertions were satisfied. HOOK_TIMEOUT_MS is in this PR because verification found it, not because anyone designed it in. A run that had stopped at "the case budget is fixed now" would have shipped a fix that moves the flake rather than removing it.

The second missed prediction is reported with a distinction most reports would blur. The received 0 red could not be reproduced on the real file at any starvation level — at 1200/5 the old assertion still passed, and at 2000/5 the old file died on its own 60s ceiling during setup, because sustained starvation also inflates repo.start()/put() in a way the per-iteration replica does not. You state explicitly that the red is measured on the replica and decline to present it as coming from the file. That is exactly the honesty this lane's reverse-verification standard is for.

And the hardening is demonstrated on the real artifact, not only the replica — adverse-condition A/B at 1200/5 sustained: OLD Test Files 1 failed (1), Tests 2 failed (2) / Hook timed out in 10000ms; NEW 2 passed (2) in 167.89s.

The in-file documentation carries its own evidence, which is what makes this durable: the measurement table lives in the waitForEvent docblock, the ⛔ never-restore-a-fixed-budget rule names #7333 as the PR that ejection cost, and QUIET_WINDOW_MS is honest that "you cannot wait for an absence — and that is a real limit, not a solved problem" rather than pretending the negative case is now sound.

#7408 is the right split. Case 2's 4s quiet window degrading to a false pass under load — passing more reliably the more loaded the runner is — is a genuinely inverted failure mode, and the sound fix restructures what case 2 measures. Folding it in would have made this PR's reverse verification attributable to two changes.

Why the flip is held

TypeScript Type Check is still in_progress on this head (started 10:22:32Z). Everything else is success or path-skipped: ESLint, Build Core, Test Core 1/3·2/3·3/3 + rollup, Dogfood Regression Gate 3/3 + rollup, Dogfood Verify CLI, Temporal Conformance (live PG + MySQL), Check Changeset, Check PR Size, Console Pin Freshness, ADR maintainer approval, No other open PR may claim the same issue.

Reporting at draft-PR time with gates recorded honestly as in_progress is the contract working as intended — CI convergence, the ready-flip and landing are mine, not yours. ⛔ Nothing further is needed from you; do not poll this. I hold a timer and will flip to ready + auto-merge (SQUASH) once that job's conclusion reads success.


Generated by Claude Code

@os-zhuang
os-zhuang marked this pull request as ready for review August 10, 2026 10:46
@os-zhuang
os-zhuang added this pull request to the merge queue Aug 10, 2026
Merged via the queue into main with commit 2c4056b Aug 10, 2026
32 checks passed
@os-zhuang
os-zhuang deleted the claude/issue-7369-dot-root-wait-for-event branch August 10, 2026 10:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

skip-changeset PR has no user-facing published change; bypasses the changeset gate tests

Projects

None yet

1 participant