bun:test fake timers: schedule a zero-delay timer armed by a timer callback 1ms later
Problem
- Under
jest.useFakeTimers(),advanceTimersByTime()andrunOnlyPendingTimers()never return when a timer callback arms the next timer with no delay: anAbortSignal.timeout(0)armed again by its ownabortlistener, or awhile (!done) await Bun.sleep(0)loop. Bun spins inside one host call, so no test timeout fires. Fuzz-found, no user report. FakeTimers::execute_until(src/runtime/test_runner/timers/FakeTimers.rs:274) fires every timer due at or before its target. Such a timer lands on the current fake instant, so it is due again.
Fix
- While a fake timer's callback runs, a timer armed with no delay gets 1ms (
FakeTimers::min_delay_ms). Both arm sites that accept 0 use it:AbortSignal::Timeout::init(newRuntimeHooksslot) andTimerObjectInternals::reschedule(Bun.sleep). @sinonjs/fake-timershas this rule (addTimer:delay || (duringTick ? 1 : 0)). Each re-armed timer is 1ms later, so the drain ends. Real timers and interval re-arms do not change.- Verified:
test/js/bun/test/fake-timers/fake-timers.test.ts(11 new cases, 8 fail without the fix). Also the rest of that directory,test-timers,sleep, cron,web/abort. - Self-reviewed: 15 concerns raised, 9 addressed, 5 needed no change, 1 rejected.
Background
- The
jesttimer controls pop due timers from a fake heap and run each throughFakeTimers::fire, which first sets the fake clock. setTimeout(fn, 0)is always 1ms. OnlyAbortSignal.timeout(0)andBun.sleep(0)arm with no delay.RuntimeHooksis the function table through whichbun_jsc(AbortSignal) calls up intobun_runtime(the timer heap).- With no event loop task on the stack (the first tests of a file),
firealso drains the callback's microtasks. TheBun.sleep(0)loop re-arms there.
Notes
Repro (the bound keeps it from hanging):
const { jest } = Bun.jest();
jest.useFakeTimers();
let fires = 0;
const arm = () =>
AbortSignal.timeout(0).addEventListener("abort", () => {
if (++fires < 20000) arm();
});
arm();
jest.advanceTimersByTime(1); // same with jest.runOnlyPendingTimers()
console.log(fires, performance.now());
| 1.4.3 | this PR | lolex 5.1.2, setTimeout(fn, 0) re-armed | |
|---|---|---|---|
advanceTimersByTime(1) / tick(1) | 20000 fires, all at 0 | 2 fires, at 0 and 1 | 2 fires, at 0 and 1 |
runOnlyPendingTimers() / runToLast() | 20000 fires, all at 0 | 1 fire, at 0 | 1 fire, at 0 |
advanceTimersToNextTimer() twice / next() twice | fires at 0 and 0 | fires at 0 and 1 | fires at 0 and 1 |
The Bun.sleep(0) loop, as the first test of a file: setTimeout(() => (done = true), 3), then (async () => { while (!done) await Bun.sleep(0); })(), then advanceTimersByTime(5). 1.4.3 polls forever at instant 0. This PR polls at 0, 0, 1, 2 and returns with the clock at 5. After a test that awaited a real timer, the controls run inside an event loop task and do not drain microtasks between timers. There the loop never spun, and it does not change.
Behavior changes beyond the hang. Each equals what setTimeout(fn, 0) already does in Bun and in Jest:
- An
AbortSignal.timeout(0)that a fake timer callback arms fires 1ms after that callback. Before, it fired at the same fake instant, inside the sameadvanceTimersByTime()call. - A
Bun.sleep(0)(any value below 1) that a fake timer callback calls resolves 1ms after that callback. advanceTimersToNextTimer()moves the clock to the re-armed timer, 1ms later. Before, the clock stayed.
The rule is on the requested delay, and not on the deadline. A first version compared the deadline with the fake clock in All::insert. That also moved a setInterval(fn, 10) whose callback calls advanceTimersByTime(10) (its next deadline equals the clock) from 10, 20, 30 to 10, 21, 31, and an _idleStart write that lands on the clock. Neither is a zero delay. Two of the new tests hold the interval case.
firing is a depth counter and not a flag. A listener can call a nested timer control, which fires another timer and returns into the listener. A flag is clear from then on, and a zero-delay timer that the listener arms afterwards spins the outer drain again. One of the new tests covers this. The count spans the whole EventLoopTimer::fire call, which includes the microtask drain on return.
Timer control calls that still do not return, and where they stand:
runAllTimers()with a timer that always re-arms (setInterval,Bun.cron, the repro above). Unbounded by design, in Jest too. Jest stops attimerLimit. #34325 added that cap and is closed. This PR does not changerunAllTimers().tick()has no loop limit in Jest or sinon, so a count cap onexecute_untilis not the right shape.- A callback that writes
_idleStartso that a timer is due at the current instant, in a cycle. That is an explicit absolute deadline. Not changed. - The test timeout cannot interrupt any synchronous spin: #30598, #21277. That is the rejected review concern. It is a backstop for all of these, and a separate change.
Related PRs. None of them is a prerequisite. Each pair needs a textual merge only:
- #42045 (never move the fake clock backwards) changes
fire()andadvance_timers_by_time. Its tests arm no zero-delay timer, so this change cannot move their values. - #38740 (per-VM fake clock) moves the clock into
FakeTimers. It also covers a callback that installs the fake clock again. - #41571 adds an
execute_until(now)step toadvanceTimersToNextTimer(). Without this rule that step has the same hang. - #40187 (timer: remove unsafe) rewrites the timer module.
node:test mock.timers (#32631) is a separate implementation in src/js/internal/test_runner/mock_timers.ts. It replaces AbortSignal.timeout with its own timers and has its own tick(). This PR does not touch it.
Suites run on the debug ASAN build: test/js/bun/test/fake-timers/ (the sinon port gives the same pass, fail and todo sets with --todo as 1.4.3), test/js/bun/test/test-timers.test.ts, test/js/bun/util/sleep.test.ts, test/js/bun/cron/in-process-cron.test.ts, test/js/bun/cron/cron-local-time.test.ts, test/regression/issue/26284.test.ts, test/regression/issue/25869.test.ts, test/js/third_party/jsonwebtoken/, test/js/web/abort/, the fake timers case of test/cli/test/isolation.test.ts, test/internal/source-lints/, and cargo clippy -p bun_jsc -p bun_runtime. test/js/web/timers/setTimeout.test.js, setInterval.test.js and timer-gc-roots.test.ts have 5 failures on my machine under the debug ASAN build (RSS thresholds and one 5s timeout). The same 5 fail with src/ at main.
[human-review] gate passed · iteration 0 · 6 files touched
fails on main (without fix)
ASAN without fix: 8 FAILED
$ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test "--reporter=junit" "--reporter-outfile=/tmp/pr_gate.xml" test/js/bun/test/fake-timers/fake-timers.test.ts
bun test v1.4.3 (09bb54630)
test/js/bun/test/fake-timers/fake-timers.test.ts:
(pass) fake timers [25.32ms]
(pass) advanceTimersToNextTimer > one setTimeout [9.05ms]
(pass) advanceTimersToNextTimer > setInterval [8.07ms]
(pass) advanceTimersToNextTimer > sorted timeouts [13.08ms]
(pass) advanceTimersToNextTimer > alternating intervals [9.95ms]
(pass) advanceTimersByTime > setInterval [6.35ms]
(pass) advanceTimersByTime > advanceTimersByTime(NaN) throws and does not move the clock [5.91ms]
(pass) advanceTimersByTime > advanceTimersByTime(-1) throws and does not move the clock [1.24ms]
(pass) advanceTimersByTime > advanceTimersByTime(Infinity) throws and does not move the clock [0.91ms]
(pass) advanceTimersByTime > advanceTimersByTime(4294967296) throws and does not move the clock [1.47ms]
(pass) runOnlyPendingTimers > two setIntervals [7.85ms]
(pass) runAllTimers > two setIntervals [9.60ms]
(pass) getTimerCount > returns correct count of pending timers [8.65ms]
(pass) getTimerCount > throw
... (truncated)
release without fix: 8 FAILED
bun test v1.4.3-canary.1 (09bb54630)
test/js/bun/test/fake-timers/fake-timers.test.ts:
(pass) fake timers [10.41ms]
(pass) advanceTimersToNextTimer > one setTimeout [0.14ms]
(pass) advanceTimersToNextTimer > setInterval [0.09ms]
(pass) advanceTimersToNextTimer > sorted timeouts [0.11ms]
(pass) advanceTimersToNextTimer > alternating intervals [0.08ms]
(pass) advanceTimersByTime > setInterval [0.07ms]
(pass) advanceTimersByTime > advanceTimersByTime(NaN) throws and does not move the clock [0.10ms]
(pass) advanceTimersByTime > advanceTimersByTime(-1) throws and does not move the clock
(pass) advanceTimersByTime > advanceTimersByTime(Infinity) throws and does not move the clock
(pass) advanceTimersByTime > advanceTimersByTime(4294967296) throws and does not move the clock
(pass) runOnlyPendingTimers > two setIntervals [0.13ms]
(pass) runAllTimers > two setIntervals [0.07ms]
(pass) getTimerCount > returns correct count of pending timers [0.06ms]
(pass) getTimerCount > throws error if fake timers not active [0.02ms]
(pass) clearAllTimers > clears all pending timers [0.05ms]
(pass) clearAllTimers > throws error if fake timers not active [0.02ms]
(pass) AbortSignal.timeout
... (truncated)
passes on PR (with fix)
ASAN with fix: all passed
$ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test "--reporter=junit" "--reporter-outfile=/tmp/pr_gate.xml" test/js/bun/test/fake-timers/fake-timers.test.ts
bun test v1.4.3 (09bb54630)
test/js/bun/test/fake-timers/fake-timers.test.ts:
(pass) fake timers [26.39ms]
(pass) advanceTimersToNextTimer > one setTimeout [9.05ms]
(pass) advanceTimersToNextTimer > setInterval [8.23ms]
(pass) advanceTimersToNextTimer > sorted timeouts [13.11ms]
(pass) advanceTimersToNextTimer > alternating intervals [10.00ms]
(pass) advanceTimersByTime > setInterval [6.67ms]
(pass) advanceTimersByTime > advanceTimersByTime(NaN) throws and does not move the clock [6.56ms]
(pass) advanceTimersByTime > advanceTimersByTime(-1) throws and does not move the clock [1.29ms]
(pass) advanceTimersByTime > advanceTimersByTime(Infinity) throws and does not move the clock [0.91ms]
(pass) advanceTimersByTime > advanceTimersByTime(4294967296) throws and does not move the clock [1.56ms]
(pass) runOnlyPendingTimers > two setIntervals [8.18ms]
(pass) runAllTimers > two setIntervals [9.79ms]
(pass) getTimerCount > returns correct count of pending timers [8.87ms]
(pass) getTimerCount > thro
... (truncated)
release with fix: all passed
$ bun scripts/build.ts --profile=release
[configured] bun-profile → bun (stripped)
target linux-x64-gnu
build type Release
build dir ./build/release
revision b23c2c8090
features baseline
23 deps, 131 codegen, 1176 objects in 692ms
ninja: Entering directory `/workspace/bun/build/release'
[1/1248] install /workspace/bun
bun install v1.4.3-canary.1 (09bb54630)
Checked 22 installs across 61 packages (no changes) [14.00ms]
[2/1248] install /workspace/bun/packages/bun-error
bun install v1.4.3-canary.1 (09bb54630)
Checked 1 install across 2 packages (no changes) [1.00ms]
[3/1248] gen ErrorCode+*.h
[4/1248] gen bindgenv2
[5/1248] install /workspace/bun/src/node-fallbacks
bun install v1.4.3-canary.1 (09bb54630)
Checked 111 installs across 104 packages (no changes) [4.00ms]
[6/1248] fetch zlib
[zlib] up to date
[7/1248] fetch tinycc
[tinycc] up to date
[8/1247] fetch libjpeg-turbo
[libjpeg-turbo] up to date
[9/1220] gen node-fallbacks/react-refresh.js
Bundled 1 module in 7ms
react-refresh.js 4.81 KB (entry point)
[10/1220] gen .bind.ts → GeneratedBindings.cpp
[11/1220] gen bake.{client,server,error}.js
-> bake.client.js, bake.server
... (truncated)
diff hotspot
src/jsc/AbortSignal.rs | 1 +
src/jsc/VirtualMachine.rs | 9 ++
src/runtime/jsc_hooks.rs | 11 ++
src/runtime/test_runner/timers/FakeTimers.rs | 13 ++
src/runtime/timer/timer_object_internals.rs | 5 +-
test/js/bun/test/fake-timers/fake-timers.test.ts | 189 ++++++++++++++++++++++-
6 files changed, 226 insertions(+), 2 deletions(-)
gate history · 1 passed · 0 rejected · iteration 0
evidence per changed file
file reads edits tests
src/jsc/AbortSignal.rs 2 2 24
src/jsc/VirtualMachine.rs 4 5 23
src/runtime/jsc_hooks.rs 2 3 23
src/runtime/test_runner/timers/FakeTimers.rs 3 7 22
src/runtime/timer/timer_object_internals.rs 3 1 22
test/js/bun/test/fake-timers/fake-timers.test.ts 5 5 22