diff --git a/src/jsc/VirtualMachine.rs b/src/jsc/VirtualMachine.rs index c703da179be9..abdca2d758f2 100644 --- a/src/jsc/VirtualMachine.rs +++ b/src/jsc/VirtualMachine.rs @@ -2412,6 +2412,7 @@ impl VirtualMachine { if self.is_watcher_enabled() { // accessed here (no overlapping `&mut EventLoop`). self.event_loop_mut().perform_gc(); + self.run_entry_point_body(self.pending_internal_promise.unwrap_or(promise)); loop { let Some(p) = self.pending_internal_promise else { break; @@ -2435,12 +2436,40 @@ impl VirtualMachine { return Ok(promise); } self.event_loop_mut().perform_gc(); + self.run_entry_point_body(promise); self.wait_for_promise(jsc::AnyPromise::Internal(promise)); } Ok(self.pending_internal_promise.unwrap_or(promise)) } + /// Run the entry point's synchronous body with a full tick, then the timers + /// phase. + /// + /// `tick()` evaluates the module body (on the microtask queue) and reports + /// rejections exactly as the wait loop would, so nothing about exception or + /// unhandled-rejection handling changes. It does dispatch the task queue, so + /// a port message or I/O completion the body queued still runs before the + /// timers phase; `setImmediate` callbacks wait in the immediate queue, which + /// `auto_tick` drains, so the timers phase runs ahead of them. `uv_run` + /// opens with `uv__run_timers`. + fn run_entry_point_body(&mut self, evaluation: *mut JSInternalPromise) { + // `tick()`'s tail reports rejections and bumps `unhandled_error_counter` + // at exactly the pre-existing point, so reading it afterwards is a pure + // read. Snapshot: the test-runner call sites reuse the VM across files. + let unhandled_before = self.unhandled_error_counter; + self.tick(); + // SAFETY: `evaluation` is a live JSC heap cell returned by + // `reload_entry_point*` and kept alive by the module loader. A body that + // threw rejects it, and a body that left an unhandled rejection bumped + // the counter; neither reaches a timers phase in Node. + let threw = crate::JSPromise::status_ptr(evaluation) == crate::js_promise::Status::Rejected; + if threw || self.unhandled_error_counter > unhandled_before { + return; + } + self.event_loop_mut().drain_expired_timers(); + } + /// Drain pending tasks/microtasks if the event loop is not currently /// re-entered. Convenience used after top-level evaluation on /// the `bun -e` path. @@ -4573,6 +4602,12 @@ impl VirtualMachine { ) -> Result<*mut JSInternalPromise, bun_core::Error> { let promise = self.reload_entry_point(entry_path)?; self.event_loop_mut().perform_gc(); + // Deliberately not `run_entry_point_body`: a worker's body has to evaluate + // inside the termination-aware wait below, which stops before the next + // `tick()` once `terminate()` lands. Evaluating it on the microtask queue + // instead lets a `tick()` start with the termination exception already + // pending, and its first task dispatch trips `scope.assertNoException()`. + // `web_worker.rs` runs the timers phase before it enters the loop. self.event_loop_mut() .wait_for_promise_with_termination(jsc::AnyPromise::Internal(promise)); if let Some(worker) = self.worker_ref() { @@ -4593,6 +4628,7 @@ impl VirtualMachine { // pending_internal_promise can change if hot module reloading is enabled if self.is_watcher_enabled() { self.event_loop_mut().perform_gc(); + self.run_entry_point_body(self.pending_internal_promise.unwrap_or(promise)); loop { let Some(p) = self.pending_internal_promise else { break; @@ -4616,6 +4652,7 @@ impl VirtualMachine { return Ok(promise); } self.event_loop_mut().perform_gc(); + self.run_entry_point_body(promise); self.wait_for_promise(jsc::AnyPromise::Internal(promise)); } diff --git a/src/jsc/event_loop.rs b/src/jsc/event_loop.rs index 46763240a0e1..62bf682c3155 100644 --- a/src/jsc/event_loop.rs +++ b/src/jsc/event_loop.rs @@ -185,6 +185,9 @@ unsafe extern "Rust" { /// `WTFTimer::run` — `timer` is an erased `*mut bun_runtime::timer::WTFTimer`. /// Defined in `bun_runtime::dispatch`. Link-time resolved. fn __bun_run_wtf_timer(timer: *mut (), vm: *mut VirtualMachine); + /// `timer::All::drain_timers`: fire every timer whose deadline has passed. + /// Defined in `bun_runtime::dispatch`. Link-time resolved. + fn __bun_drain_expired_timers(vm: *mut VirtualMachine); /// Tag-specific shutdown release for a queued-but-never-run task. Called /// from `release_queued_tasks_for_shutdown` (after `shutdown_for_exit`, /// before `destructOnExit`) for every entry left in `self.tasks`. @@ -463,6 +466,24 @@ impl EventLoop { } } + /// Fire every timer whose deadline has already passed: libuv's timers phase. + /// + /// `auto_tick` runs it at the end of an iteration rather than the start, so + /// the cyclic order matches `uv_run`'s for every iteration but the first. + /// Callers about to enter the loop for the first time run one themselves + /// (after a `tick()` that evaluated the entry body), so a timer that + /// expired while the entry point was still running dispatches before the + /// `setImmediate` callbacks it queued. Task-queue work the body queued is + /// dispatched by that `tick()` first. + pub fn drain_expired_timers(&mut self) { + // The real `timer::All` lives in `bun_runtime` (cycle), so the body + // dispatches through `__bun_drain_expired_timers` (link-time extern). + let vm = self.vm(); + // SAFETY: `vm` is the live owning VM; the definer no-ops when this + // thread has no `RuntimeState` (bun_jsc unit tests). + unsafe { __bun_drain_expired_timers(vm) }; + } + pub fn tick_concurrent_with_count(&mut self) -> usize { self.update_counts(); diff --git a/src/jsc/web_worker.rs b/src/jsc/web_worker.rs index ceb045b8f5e6..b200c392b958 100644 --- a/src/jsc/web_worker.rs +++ b/src/jsc/web_worker.rs @@ -1132,6 +1132,19 @@ impl WebWorker { let _ = vm.global().vm().run_gc(false); } + // `uv_run` opens with `uv__run_timers`, so a timer that expired while the + // worker's entrypoint ran synchronously is due before the `setImmediate` + // callbacks it queued alongside it. Only `setImmediate` is reordered + // here: a MessagePort or fs completion the body queued dispatches inside + // the `tick()` of the wait above, the same as `--preload`. The two guards + // match the `is_event_loop_alive()` check below, so the entrypoint never + // fires a timer on a path that otherwise exits: skip once `terminate()` + // has landed (firing a callback would re-enter JS with the termination + // exception pending), and skip when the body left an unhandled error. + if !self.has_requested_terminate() && vm.unhandled_error_counter == 0 { + vm.event_loop_mut().drain_expired_timers(); + } + // Always do a first tick so we call CppTask without delay after // dispatchOnline. vm.as_mut().tick(); diff --git a/src/runtime/dispatch.rs b/src/runtime/dispatch.rs index 9ddfc8c0454b..048b536e7fbb 100644 --- a/src/runtime/dispatch.rs +++ b/src/runtime/dispatch.rs @@ -894,6 +894,17 @@ pub(crate) unsafe fn __bun_run_wtf_timer( unsafe { crate::timer::WTFTimer::run(real, vm) } } +/// `__bun_drain_expired_timers` body: run the timers phase over this thread's +/// `timer::All`. No-op before `init_runtime_state` (bun_jsc unit tests). +/// +/// # Safety +/// `vm` is the live per-thread VM and stays live across the JS callbacks +/// `drain_timers` fires. +#[unsafe(no_mangle)] +pub(crate) unsafe fn __bun_drain_expired_timers(vm: *mut bun_jsc::virtual_machine::VirtualMachine) { + crate::timer::timer::drain_timers_export(vm) +} + // ════════════════════════════════════════════════════════════════════════════ // EventLoopTimer dispatch // ════════════════════════════════════════════════════════════════════════════ diff --git a/test/js/node/timers/node-timers.test.ts b/test/js/node/timers/node-timers.test.ts index a33cb72f4642..b7b4cba426db 100644 --- a/test/js/node/timers/node-timers.test.ts +++ b/test/js/node/timers/node-timers.test.ts @@ -1,6 +1,6 @@ import jsc from "bun:jsc"; import { describe, expect, it, mock, test } from "bun:test"; -import { bunEnv, bunExe, isWindows } from "harness"; +import { bunEnv, bunExe, isWindows, tempDir } from "harness"; import path from "node:path"; import { clearInterval, clearTimeout, promises, setImmediate, setInterval, setTimeout } from "node:timers"; import { promisify } from "util"; @@ -245,3 +245,107 @@ describe.each(["with", "without"])("setImmediate %s timers running", mode => { it("should defer microtasks when an exception is thrown in an immediate", async () => { expect(["run", path.join(import.meta.dir, "timers-immediate-exception-fixture.js")]).toRun(); }); + +describe.concurrent("an already-expired timer runs before the first check phase", () => { + // Block well past the 1ms deadline so the timer is unambiguously expired by + // the time the event loop is entered. libuv opens every `uv_run` iteration + // with the timers phase, so the timer runs before the `setImmediate` queued + // next to it. Task-queue work such as a MessagePort self-post or a completed + // fs read is dispatched by the entry tick before the timers phase. + const blockPastTheDeadline = `const start = Date.now(); while (Date.now() - start < 10) {}`; + + test.concurrent("before setImmediate", async () => { + using dir = tempDir("timers-phase-order", { + "index.js": ` + const order = []; + process.on("exit", () => console.log(JSON.stringify(order))); + setTimeout(() => order.push("timeout"), 1); + setImmediate(() => order.push("immediate")); + ${blockPastTheDeadline} + `, + }); + + await using proc = Bun.spawn({ + cmd: [bunExe(), "index.js"], + cwd: String(dir), + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + + if (exitCode !== 0) { + expect(stderr).toBe(""); + } + expect(stdout.trim()).toBe(JSON.stringify(["timeout", "immediate"])); + expect(exitCode).toBe(0); + }); + + test("inside a worker", async () => { + const worker = new Worker(new URL("timers-phase-order-worker-fixture.js", import.meta.url).href); + const { promise, resolve, reject } = Promise.withResolvers(); + worker.onmessage = event => resolve(event.data); + worker.onerror = reject; + + try { + expect(await promise).toEqual(["timeout", "immediate"]); + } finally { + await worker.terminate(); + } + }); + + test("inside a test file, same as under `bun run`", async () => { + using dir = tempDir("timers-phase-order-test", { + "order.test.js": ` + const { test, expect } = require("bun:test"); + const order = []; + setTimeout(() => order.push("timeout"), 1); + setImmediate(() => order.push("immediate")); + ${blockPastTheDeadline} + test("the expired timer ran first", () => { + console.log("order=" + JSON.stringify(order)); + expect(order).toEqual(["timeout", "immediate"]); + }); + `, + }); + + await using proc = Bun.spawn({ + cmd: [bunExe(), "test", "order.test.js"], + cwd: String(dir), + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + + if (exitCode !== 0) { + expect(stderr).toBe(""); + } + expect(stdout).toContain(`order=${JSON.stringify(["timeout", "immediate"])}`); + expect(exitCode).toBe(0); + }); + + // An entry point that throws rejects the module promise and exits without + // entering the loop, as Node does; the timer never fires. + test.concurrent("but not when the entry point throws", async () => { + using dir = tempDir("timers-phase-order-throw", { + "index.js": ` + setTimeout(() => console.log("timer fired"), 1); + ${blockPastTheDeadline} + throw new Error("boom"); + `, + }); + + await using proc = Bun.spawn({ + cmd: [bunExe(), "index.js"], + cwd: String(dir), + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + + expect(stderr).toContain("boom"); + expect({ stdout, exitCode }).toEqual({ stdout: "", exitCode: 1 }); + }); +}); diff --git a/test/js/node/timers/timers-phase-order-worker-fixture.js b/test/js/node/timers/timers-phase-order-worker-fixture.js new file mode 100644 index 000000000000..955a87e87ec1 --- /dev/null +++ b/test/js/node/timers/timers-phase-order-worker-fixture.js @@ -0,0 +1,18 @@ +const order = []; +const report = () => { + if (order.length === 2) postMessage(order); +}; + +setTimeout(() => { + order.push("timeout"); + report(); +}, 1); +setImmediate(() => { + order.push("immediate"); + report(); +}); + +// Block past the 1ms deadline so the timer is expired before the worker's event +// loop is entered. +const start = Date.now(); +while (Date.now() - start < 10) {}