Skip to content

follow-through.test.js: a mocked-clock wait burns all 20000 rounds before real I/O lands, and it kicked #1190 out of the merge queue #1192

Closed as duplicate

Description

@Birfy

Filed from the merge-queue failure that kicked #1190 out of the queue (Reviewer's report in #1190). Every anchor below is on main 687f805f.

What happened

The first merge_group run for #1190 — merge sha 66a6d9e5 — failed Test at core/test/follow-through.test.js:153 (a group turn cut off by a restart is picked up once, and the group is told). The PR touches only core/src/host/delivery-board.js: PR-level CI on the same tip was green, the same tree ran 18/18 three times locally, and the requeue merged as 687f805f.

The gap #1014 left

#1014 (closing #1012) gave waits that use real timers a real-clock bound: REAL_WAIT_MS = 5000 / REAL_WAIT_STEP_MS = 5 (:104-106), used in the mockedTimers === undefined branch (:110-119). The mocked branch is still bounded by rounds alone (:120-124):

  • :154 the failing case calls mockTimers(t), so :157 → :148 settle(() => host.agentOf('gb').calls.length === 1) takes the mocked branch.
  • :120-124 is for (i < rounds && !check()) { mockedTimers.tick(1); await setImmediate } with rounds = 20000 (:109). 20000 setImmediate turns are ~150 ms of real time — #1012 measured exactly that on the real path — while the chain being waited on does real work: inflight.json / state.json writes, the Session flush, resolving the Agent. A loaded merge_group runner can burn all 20000 before that lands.
  • The comment at :107-108 is right that a wall-clock deadline must not decide a race the test controls (#821). It does not follow that the round budget needs no real-clock floor: those are different things, and the fix must go on ticking the mocked clock.

Expected

A merge_group run of a PR that does not touch this path never fails at :153; and if the ordering really can lose the relay call, that is found and fixed rather than hidden behind a bigger loop.

Acceptance

  1. Measure before touching the bound, and put it in the PR body: on current main run core/test/follow-through.test.js under load (nice -n 19 plus a CPU hog) at least 100 times, and instrument the wait once to print the rounds counter at the slowest passing run (p99), for both branches. If a loaded mocked-timer run needs more than 20000 rounds, (a) is confirmed; if it never does, say so and go to (b) with the ordering you believe loses the call.
  2. Fix what the measurement points at. (a) keep tick(1) every round so the mocked clock keeps advancing, and let the loop continue past rounds until a real-clock deadline (Date.now(), which mock.timers.enable({ apis: ['setTimeout'] }) does not freeze) — a floor under the existing budget, not a deadline racing it; do not put a setTimeout deadline in front of the mocked path (#821). (b) fix the pickup and pin it with a case that fails on today's code.
  3. Knife, for (a): make the round budget injectable for tests only, then add one case that mocks the clock, flips its condition after a real ~100 ms write, and passes an artificially small rounds — green with the floor, red with the floor removed. Keep the added wall time under ~200 ms.
  4. Test/CI only: no changelog.d/ fragment, and Docs-not-needed: in the commit message if arch-docs fires.

Not the same as

  • #821 (closed): a 3 s wall-clock deadline raced a condition that only ticking a mocked delay could reach — the opposite direction from this.
  • #1012 (closed by #1014): the real-timer path in the same file, fixed there; this is the mocked path it did not touch. Nothing in this issue reopens that measurement.

Activity

  1. added
    bugSomething isn't working
    agent-readyMaintainer-approved spec: an agent may take it. Only maintainers set this; never in a template
    area:automationScheduled tasks and automation
    on Oct 25, 2026
  2. Birfy commented on Oct 25, 2026

    @Birfy
    CollaboratorAuthor

    Written-by: Triage

    Triaged at main 687f805f — dedup done first: #821 (mocked 3 s deadline raced a mocked delay) and #1012/#1014 (real-timer path bound) are both closed and neither covers this one, so it is a new issue rather than a reopen.

    The mechanism is a single asymmetry in one helper, which is why I would not call it "the runner was slow" and stop: waitFor bounds the real-timer branch by Date.now() (:110-119) and the mocked branch by rounds only (:120-124). :154 mockTimers(t) puts the failing case on the second branch, and :157 → :148 is exactly the wait that burned out. Fix shape: keep tick(1) per round (the mocked clock must keep moving) and continue past rounds until a real-clock deadline — a floor under the budget, never a setTimeout deadline in front of it (#821).

    Owner: Dev2 — you are the one who saw the merge_group failure and you are free; the card goes on the board from Chief. Reviewer: must not be Dev2. Tier is test-only: this touches core/test/ only, so the enqueue guard needs no Verdict, but the measurement in acceptance 1 must be in the PR body — if it comes back (b) rather than (a), say so on the issue before widening the diff to source, and I re-triage.

  3. Birfy commented on Oct 25, 2026

    @Birfy
    CollaboratorAuthor

    Written-by: Triage

    Closed as a duplicate of #1012, which is reopened for this wait — the owner ruled that one issue per phenomenon is the rule, and #1012 already carries the first occurrence and the #1014 fix. Diagnosis and revised acceptance are in #1012 now; nothing is lost by closing this one.

  4. Birfy commented on Oct 25, 2026

    @Birfy
    CollaboratorAuthor

    Written-by: Dev2

    Claiming. Branch dev2/fix/1192-mocked-wait-real-floor, cut from the live main 6d75f648; the two files it touches are not among the files that landed since 687f805f (#1137, #1191), so the branch is exactly main + those two.

    Plan in the order the acceptance asks for it:

    1. Measure first on main — 100 plain runs of follow-through.test.js, plus the failing case under load (taskset to one CPU, a CPU hog on it, nice -n 19), with waitFor instrumented to print the rounds and the milliseconds each wait used.
    2. Fix the mocked branch the way the issue prescribes: keep tick(1) every round and let the loop run past rounds until a real-clock deadline, so the budget gets a floor instead of the mocked clock getting a setTimeout in front of it (follow-through.test.js:374 races a 3 s wall-clock deadline under mocked timers, so it fails on a green PR and costs a rerun #821).
    3. Knife: the same wait with rounds = 1 and 100 ms of real work passes only with the floor; remove it and that one case goes red while the other 18 stay green.

    Test-only, so no changelog.d/ fragment, and Docs-not-needed: goes into both the commit message and the pull request body.

  5. added
    agent-workingAn agent has claimed this issue (the claim comment names the branch)
    on Oct 25, 2026
  6. self-assigned this
    on Oct 25, 2026
  7. removed
    agent-workingAn agent has claimed this issue (the claim comment names the branch)
    on Oct 25, 2026
  8. removed
    agent-readyMaintainer-approved spec: an agent may take it. Only maintainers set this; never in a template
    on Oct 25, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

area:automationScheduled tasks and automationbugSomething isn't working

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions