bun:test fake timers: schedule a zero-delay timer armed by a timer callback 1ms later

Merged
RO
2mo ago
+226-2

Problem

  • Under jest.useFakeTimers(), advanceTimersByTime() and runOnlyPendingTimers() never return when a timer callback arms the next timer with no delay: an AbortSignal.timeout(0) armed again by its own abort listener, or a while (!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 (new RuntimeHooks slot) and TimerObjectInternals::reschedule (Bun.sleep).
  • @sinonjs/fake-timers has 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 jest timer controls pop due timers from a fake heap and run each through FakeTimers::fire, which first sets the fake clock.
  • setTimeout(fn, 0) is always 1ms. Only AbortSignal.timeout(0) and Bun.sleep(0) arm with no delay.
  • RuntimeHooks is the function table through which bun_jsc (AbortSignal) calls up into bun_runtime (the timer heap).
  • With no event loop task on the stack (the first tests of a file), fire also drains the callback's microtasks. The Bun.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.3this PRlolex 5.1.2, setTimeout(fn, 0) re-armed
advanceTimersByTime(1) / tick(1)20000 fires, all at 02 fires, at 0 and 12 fires, at 0 and 1
runOnlyPendingTimers() / runToLast()20000 fires, all at 01 fire, at 01 fire, at 0
advanceTimersToNextTimer() twice / next() twicefires at 0 and 0fires at 0 and 1fires 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 same advanceTimersByTime() 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 at timerLimit. #34325 added that cap and is closed. This PR does not change runAllTimers(). tick() has no loop limit in Jest or sinon, so a count cap on execute_until is not the right shape.
  • A callback that writes _idleStart so 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() and advance_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 to advanceTimersToNextTimer(). 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