From b9f57ae1de50ba9d3d70ed7113d2de4fe94b382e Mon Sep 17 00:00:00 2001 From: Danyang Chen Date: Sun, 25 Oct 2026 23:24:49 +0800 Subject: [PATCH] test(follow-through): keep a real-clock floor under a mocked-clock wait (#1192) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `waitFor` bounded the mocked branch by rounds alone: 20000 `tick(1)` + `setImmediate` rounds are about 70 ms of real time, while the relay chain it waits on does real work (the `inflight.json` / `state.json` writes, the Session flush, resolving the Agent). A loaded runner burned the whole budget before the call landed, which is what failed `a group turn cut off by a restart` on the first merge_group entry of #1190 and kicked that pull request out of the queue. The mocked branch keeps ticking the mocked clock every round — only a tick moves it, so a wall-clock deadline must not decide that race (#821) — and continues past `rounds` until the real-clock deadline the real branch already uses. The round count is a floor under the budget, not a deadline: no `setTimeout` goes in front of the mocked clock, and `Date.now()` is not frozen by `mock.timers.enable({ apis: ['setTimeout'] })`. The new case mocks the clock, waits for a 100 ms real timer with `rounds = 1`, and passes only because of the floor: removing the floor turns that one case red and leaves the other 18 green. Docs-not-needed: only `core/test/follow-through.test.js` and its generated patch hunk change; no owned path, no behavior or contract. --- core/test/follow-through.test.js | 24 +++++++++++++++++++++++- patches/ds-bot/0001-core-fixes.patch | 28 +++++++++++++++++++++++++--- 2 files changed, 48 insertions(+), 4 deletions(-) diff --git a/core/test/follow-through.test.js b/core/test/follow-through.test.js index e25893dd0..1bffc4ca6 100644 --- a/core/test/follow-through.test.js +++ b/core/test/follow-through.test.js @@ -93,6 +93,9 @@ const freshHome = (t) => { }) return home } +// The real clock, taken before any case mocks it: a wait has to outlive its round budget when the +// work it waits on is real rather than a mocked delay (#1192). +const realSetTimeout = setTimeout // The timers a case mocked, if any. A wait must advance that clock: `setImmediate` rounds alone can // never fire a mocked `setTimeout`, so a wall-clock deadline would decide a race the test controls (#821). let mockedTimers @@ -117,7 +120,15 @@ const waitFor = async (check, rounds = 20000) => { while (!check() && Date.now() < deadline) await new Promise(resolve => setTimeout(resolve, REAL_WAIT_STEP_MS)) return check() } - for (let i = 0; i < rounds && !check(); i++) { + // Every round still ticks the mocked clock, because only a tick moves it — but a tick cannot rush + // the real work the relay chain does (`inflight.json`/`state.json` writes, the Session flush, + // resolving the Agent), and 20000 `setImmediate` turns are ~70 ms of real time. So the round count + // is a floor under the budget, not a deadline: keep waiting until the real clock's deadline too + // (#1192 — a loaded runner burned all 20000 rounds before the relay call landed and kicked #1190 + // out of the merge queue). `Date.now()` is not frozen by `mock.timers.enable({ apis: ['setTimeout'] + // })`, and this puts no `setTimeout` in front of the mocked clock (#821). + const deadline = Date.now() + REAL_WAIT_MS + for (let i = 0; !check() && (i < rounds || Date.now() < deadline); i++) { mockedTimers.tick(1) await new Promise(resolve => setImmediate(resolve)) } @@ -507,6 +518,17 @@ test('a real-clock wait outlives its round budget (#1012)', async () => { assert.equal(await waitFor(() => later, 5), true) }) +test('a mocked-clock wait keeps a real-clock floor under its round budget (#1192)', async (t) => { + mockTimers(t) + // One round is a tick plus one `setImmediate` — microseconds — so a mocked wait given a small + // budget used to give up long before real work landed; a loaded runner then burned all 20000 + // rounds while the relay chain was still writing `state.json`. 100 ms of real work is the + // smallest honest stand-in, and the mocked clock cannot advance it: the timer is the real one. + let landed = false + realSetTimeout(() => { landed = true }, 100) + assert.equal(await waitFor(() => landed, 1), true) +}) + test('a written tool call is told apart from text about one', () => { assert.equal(writesToolCall(WRITTEN), true) assert.equal(writesToolCall('\na.md'), true) diff --git a/patches/ds-bot/0001-core-fixes.patch b/patches/ds-bot/0001-core-fixes.patch index 01ac2b453..e76c10388 100644 --- a/patches/ds-bot/0001-core-fixes.patch +++ b/patches/ds-bot/0001-core-fixes.patch @@ -6547,7 +6547,7 @@ diff --git a/test/follow-through.test.js b/test/follow-through.test.js started.set(home, [...(started.get(home) ?? []), host]) return host } -@@ -72,15 +72,46 @@ const freshHome = (t) => { +@@ -72,15 +72,57 @@ const freshHome = (t) => { t.after(async () => { await Promise.all((started.get(home) ?? []).map(host => host.stop())) started.delete(home) @@ -6560,6 +6560,9 @@ diff --git a/test/follow-through.test.js b/test/follow-through.test.js - const until = Date.now() + 3000 - while (!check() && Date.now() < until) await new Promise(resolve => setImmediate(resolve)) - assert.ok(check(), 'condition not reached') ++// The real clock, taken before any case mocks it: a wait has to outlive its round budget when the ++// work it waits on is real rather than a mocked delay (#1192). ++const realSetTimeout = setTimeout +// The timers a case mocked, if any. A wait must advance that clock: `setImmediate` rounds alone can +// never fire a mocked `setTimeout`, so a wall-clock deadline would decide a race the test controls (#821). +let mockedTimers @@ -6584,7 +6587,15 @@ diff --git a/test/follow-through.test.js b/test/follow-through.test.js + while (!check() && Date.now() < deadline) await new Promise(resolve => setTimeout(resolve, REAL_WAIT_STEP_MS)) + return check() + } -+ for (let i = 0; i < rounds && !check(); i++) { ++ // Every round still ticks the mocked clock, because only a tick moves it — but a tick cannot rush ++ // the real work the relay chain does (`inflight.json`/`state.json` writes, the Session flush, ++ // resolving the Agent), and 20000 `setImmediate` turns are ~70 ms of real time. So the round count ++ // is a floor under the budget, not a deadline: keep waiting until the real clock's deadline too ++ // (#1192 — a loaded runner burned all 20000 rounds before the relay call landed and kicked #1190 ++ // out of the merge queue). `Date.now()` is not frozen by `mock.timers.enable({ apis: ['setTimeout'] ++ // })`, and this puts no `setTimeout` in front of the mocked clock (#821). ++ const deadline = Date.now() + REAL_WAIT_MS ++ for (let i = 0; !check() && (i < rounds || Date.now() < deadline); i++) { + mockedTimers.tick(1) + await new Promise(resolve => setImmediate(resolve)) + } @@ -6816,7 +6827,7 @@ diff --git a/test/follow-through.test.js b/test/follow-through.test.js const WRITTEN = 'Checking now.\n\n\n\nGet-ChildItem E:\\\n\n\n' test('a tool call written as text gets one more turn on the same round slot', async (t) => { -@@ -283,6 +283,18 @@ test('in its own chat, a Bot that wrote a tool call as text is asked to make it' +@@ -283,6 +283,29 @@ test('in its own chat, a Bot that wrote a tool call as text is asked to make it' assert.match(text(retry), /^\[Your last reply wrote a tool call as text, so nothing ran\]/) }) @@ -6831,6 +6842,17 @@ diff --git a/test/follow-through.test.js b/test/follow-through.test.js + setTimeout(() => { later = true }, 50) + assert.equal(await waitFor(() => later, 5), true) +}) ++ ++test('a mocked-clock wait keeps a real-clock floor under its round budget (#1192)', async (t) => { ++ mockTimers(t) ++ // One round is a tick plus one `setImmediate` — microseconds — so a mocked wait given a small ++ // budget used to give up long before real work landed; a loaded runner then burned all 20000 ++ // rounds while the relay chain was still writing `state.json`. 100 ms of real work is the ++ // smallest honest stand-in, and the mocked clock cannot advance it: the timer is the real one. ++ let landed = false ++ realSetTimeout(() => { landed = true }, 100) ++ assert.equal(await waitFor(() => landed, 1), true) ++}) + test('a written tool call is told apart from text about one', () => { assert.equal(writesToolCall(WRITTEN), true)