From cb261ebcf67e5b697e438a0d80a202eeb07f5bc5 Mon Sep 17 00:00:00 2001 From: robobun <117481402+robobun@users.noreply.github.com> Date: Fri, 14 Aug 2026 12:19:38 +0000 Subject: [PATCH 1/4] test(timers): speed up setTimeout.test.js and tighten its assertions The file took 34-36s on the debian x64 ASAN lane against 6s elsewhere, and 150-160s under a local debug build, where the three leak tests also failed because the fixture keyed its ASAN RSS threshold off the binary name. - Leak fixture: RSS cannot tell a freed TimeoutObject from a leaked one under ASAN (the freed block sits in the quarantine; 200k timers grow RSS by ~140 MB either way), so ASAN and debug builds now run one batch per mode and rely on LeakSanitizer at child exit, which the test turns on itself (CI already does for the lane). Release builds keep the 100 batch workload and the 10 MB bound. The fixture prints a JSON report and the test asserts the workload size, protected count, live wrapper count and (on release) the RSS delta. - The five spawnSync unref fixtures and the two promise fixtures become one fixture that arms every scenario at once and reports how often each callback ran; the test asserts the exact report. - CPU usage #7790: measure the idle window in-process as a CPU/wall ratio instead of sleeping for 3s and bounding whole-process CPU, which depended on startup cost. resourceUsage() is still exercised, now against the child's own reading. - timers-fixture-unref.js: inline mustCall() instead of loading node/test/common (~2s on a debug build); failures name the call site. - Child-spawning tests that do not measure anything are it.concurrent; the CPU and latency measurements stay sequential. The refresh tests await the fires they care about instead of fixed 100-300ms waits and assert from the test body. - All children are run through bunRun/toSpawn with exact stdout and empty stderr; the quantization and GC children use console.log rather than process.stdout (whose lazy setup is ~0.9s on a debug build). bun bd test test/js/web/timers/setTimeout.test.js: 152-163s (3 failing) before, 12.3-13.0s after. Release: 6.3s before, 2.0-2.2s after. 21 child processes, all serial, before; 15 after, 6 of them serial. --- ...tTimeout-clear-in-callback-leak-fixture.js | 69 ++- test/js/web/timers/setTimeout-cpu-fixture.js | 3 - .../web/timers/setTimeout-unref-fixture-2.js | 14 - .../web/timers/setTimeout-unref-fixture-3.js | 12 - .../web/timers/setTimeout-unref-fixture-4.js | 8 - .../web/timers/setTimeout-unref-fixture-5.js | 5 - .../web/timers/setTimeout-unref-fixture-6.js | 1 - .../web/timers/setTimeout-unref-fixture-7.js | 1 - .../js/web/timers/setTimeout-unref-fixture.js | 62 ++- test/js/web/timers/setTimeout.test.js | 510 ++++++++---------- test/js/web/timers/timers-fixture-unref.js | 19 +- 11 files changed, 333 insertions(+), 371 deletions(-) delete mode 100644 test/js/web/timers/setTimeout-cpu-fixture.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-2.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-3.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-4.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-5.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-6.js delete mode 100644 test/js/web/timers/setTimeout-unref-fixture-7.js diff --git a/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js b/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js index 53ba75418e39..e5493978cf63 100644 --- a/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js +++ b/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js @@ -3,27 +3,33 @@ // before the callback runs; any transition away from .FIRED during the callback // (cancel() -> .CANCELLED, or reschedule() -> .ACTIVE via refresh/convertToInterval) left // the heap ref unreleased because the post-callback cleanup only checked for .FIRED. +// +// Usage: [batches] +// +// Runs `batches` batches of BATCH timers after warming up, then prints one JSON line: +// timers timers created in the measured batches +// rssDeltaMB RSS growth over the measured batches (~0 when nothing leaks; each +// leaked TimeoutObject is ~100 bytes, so 100 batches leak ~20 MB) +// liveTimeouts Timeout wrappers still on the JS heap after a full GC +// protectedTimeouts Timeout wrappers still pinned by the native side +// setTimeout.test.js asserts the report. const mode = process.argv[2]; if (mode !== "clear" && mode !== "refresh" && mode !== "repeat") { - throw new Error("usage: "); + throw new Error("usage: [batches]"); +} +const batches = process.argv.length > 3 ? Number(process.argv[3]) : 100; +if (!Number.isInteger(batches) || batches < 1) { + throw new Error("batches must be a positive integer, got " + process.argv[3]); } -// ASAN's quarantine retains freed allocations (default 256 MB) so RSS deltas -// run far higher under bun-asan; widen the threshold to avoid false positives. -const isASAN = process.execPath.includes("bun-asan"); const rss = - process.platform === "darwin" && typeof Bun !== "undefined" && typeof Bun.unsafe.memoryFootprint === "function" + process.platform === "darwin" && typeof Bun.unsafe.memoryFootprint === "function" ? Bun.unsafe.memoryFootprint : process.memoryUsage.rss; const BATCH = 2_000; -function gc() { - if (typeof Bun !== "undefined") Bun.gc(true); - else if (typeof globalThis.gc !== "undefined") globalThis.gc(); -} - async function runBatch() { let remaining = BATCH; const { promise, resolve } = Promise.withResolvers(); @@ -58,34 +64,27 @@ async function runBatch() { } } await promise; - gc(); + Bun.gc(true); } -// warmup -for (let i = 0; i < 15; i++) await runBatch(); -gc(); +for (let i = 0; i < Math.min(batches, 15); i++) await runBatch(); +Bun.gc(true); const initial = rss(); -for (let i = 0; i < 100; i++) await runBatch(); -gc(); +// These batches run from promise continuations, which matters on ASAN builds: test/leaksan.supp +// suppresses leaks allocated synchronously from module top-level code (the first warmup batch), +// so the measured batches are the ones LeakSanitizer reports leaked TimeoutObjects from. +for (let i = 0; i < batches; i++) await runBatch(); +Bun.gc(true); const final = rss(); -const deltaMB = (final - initial) / 1024 / 1024; -console.log("mode:", mode); -console.log("initial RSS:", (initial / 1024 / 1024) | 0, "MB"); -console.log("final RSS:", (final / 1024 / 1024) | 0, "MB"); -console.log("delta:", deltaMB.toFixed(1), "MB"); -if (globalThis.Bun) { - const heapStats = require("bun:jsc").heapStats(); - if (heapStats.protectedObjectTypeCounts.Timeout) { - throw new Error("Expected 0 protected Timeout but received " + heapStats.protectedObjectTypeCounts.Timeout); - } -} - -// Before the fix, 100 * 2_000 leaked TimeoutObjects (~100 bytes each) ≈ 20 MB. -// After the fix the delta is ~0 MB (noise). The ASAN threshold accounts for -// quarantine + debug-assertions overhead (release-asan compiles with -// debug-assertions on, which adds live code paths ASAN instruments). -if (deltaMB > (isASAN ? 192 : 10)) { - throw new Error("Memory leak detected: RSS grew by " + deltaMB.toFixed(1) + " MB"); -} +const { objectTypeCounts, protectedObjectTypeCounts } = require("bun:jsc").heapStats(); +console.log( + JSON.stringify({ + mode, + timers: batches * BATCH, + rssDeltaMB: Math.round(((final - initial) / 1024 / 1024) * 10) / 10, + liveTimeouts: objectTypeCounts.Timeout ?? 0, + protectedTimeouts: protectedObjectTypeCounts.Timeout ?? 0, + }), +); diff --git a/test/js/web/timers/setTimeout-cpu-fixture.js b/test/js/web/timers/setTimeout-cpu-fixture.js deleted file mode 100644 index 534aaa43a0bf..000000000000 --- a/test/js/web/timers/setTimeout-cpu-fixture.js +++ /dev/null @@ -1,3 +0,0 @@ -setTimeout(() => { - console.log("Test ran"); -}, 3_000); // we use 3s so we can reproduce better the issue #7790 diff --git a/test/js/web/timers/setTimeout-unref-fixture-2.js b/test/js/web/timers/setTimeout-unref-fixture-2.js deleted file mode 100644 index 66bc7ba09cc6..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-2.js +++ /dev/null @@ -1,14 +0,0 @@ -process.exitCode = 1; -setTimeout(() => { - console.log("TEST FAILED!"); -}, 100) - .ref() - .unref(); - -setTimeout(function () { - // this one should always run - process.exitCode = 0; - if (typeof this?.refresh !== "function") { - process.exitCode = 1; - } -}, 1); diff --git a/test/js/web/timers/setTimeout-unref-fixture-3.js b/test/js/web/timers/setTimeout-unref-fixture-3.js deleted file mode 100644 index 9afd73e5872b..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-3.js +++ /dev/null @@ -1,12 +0,0 @@ -process.exitCode = 1; -setTimeout(() => { - setTimeout(() => { - process.exitCode = 1; - }, 999_999); - process.exitCode = 1; -}, 100).unref(); - -setTimeout(() => { - // this one should always run - process.exitCode = 0; -}, 1); diff --git a/test/js/web/timers/setTimeout-unref-fixture-4.js b/test/js/web/timers/setTimeout-unref-fixture-4.js deleted file mode 100644 index ff260db0c712..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-4.js +++ /dev/null @@ -1,8 +0,0 @@ -process.exitCode = 1; - -setTimeout(() => { - console.log("TEST PASSED!"); - process.exitCode = 0; -}, 1) - .unref() - .ref(); diff --git a/test/js/web/timers/setTimeout-unref-fixture-5.js b/test/js/web/timers/setTimeout-unref-fixture-5.js deleted file mode 100644 index e5caa1be4766..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-5.js +++ /dev/null @@ -1,5 +0,0 @@ -setTimeout(() => { - console.log("TEST FAILED!"); -}, 100) - .ref() - .unref(); diff --git a/test/js/web/timers/setTimeout-unref-fixture-6.js b/test/js/web/timers/setTimeout-unref-fixture-6.js deleted file mode 100644 index 41aba5b12759..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-6.js +++ /dev/null @@ -1 +0,0 @@ -setTimeout(() => new Promise(() => {}), 0); diff --git a/test/js/web/timers/setTimeout-unref-fixture-7.js b/test/js/web/timers/setTimeout-unref-fixture-7.js deleted file mode 100644 index c47fc08d27de..000000000000 --- a/test/js/web/timers/setTimeout-unref-fixture-7.js +++ /dev/null @@ -1 +0,0 @@ -setTimeout(() => new Promise(() => {}), 0).unref(); diff --git a/test/js/web/timers/setTimeout-unref-fixture.js b/test/js/web/timers/setTimeout-unref-fixture.js index d33361c6b48f..0900a0f65e98 100644 --- a/test/js/web/timers/setTimeout-unref-fixture.js +++ b/test/js/web/timers/setTimeout-unref-fixture.js @@ -1,16 +1,48 @@ -const timer = setTimeout(() => { - process.exit(1); -}, 999_999_999); -if (timer.unref() !== timer) throw new Error("Expected timer.unref() === timer"); - -var ranCount = 0; -process.exitCode = 1; -const going2Refresh = setTimeout(() => { - if (ranCount < 1) going2Refresh.refresh(); - ranCount++; - - if (ranCount === 2) { - process.exitCode = 0; - console.log("SUCCESS"); - } +// Arms every ref/unref scenario at once. The ref'd timers must run, the unref'd ones must +// not run and must not keep the process alive: once the ref'd timers are done the event +// loop has to wind down by itself. The exit handler reports how often each callback ran; +// setTimeout.test.js asserts the exact report. An unref'd timer that wrongly keeps the +// loop alive fires 100ms later and shows up in the report as a non-zero count. +const ran = { + "unref()": 0, + "ref().unref()": 0, + "unref().ref()": 0, + "refresh() inside the callback": 0, + "this is the Timeout": 0, + "callback returning a pending promise": 0, + "unref'd callback returning a pending promise": 0, +}; + +const unrefd = setTimeout(() => ran["unref()"]++, 100); +if (unrefd.unref() !== unrefd) throw new Error("unref() must return the timer"); + +const reffed = setTimeout(() => ran["ref().unref()"]++, 100); +if (reffed.ref() !== reffed) throw new Error("ref() must return the timer"); +reffed.unref(); + +setTimeout(() => ran["unref().ref()"]++, 1) + .unref() + .ref(); + +// refresh() from inside the callback re-arms the one-shot timer once, so it runs twice. +const refreshing = setTimeout(() => { + if (++ran["refresh() inside the callback"] === 1) refreshing.refresh(); +}, 1); + +const self = setTimeout(function () { + if (this === self) ran["this is the Timeout"]++; +}, 1); + +// A never-settling promise returned from the callback must not keep the loop alive. +setTimeout(() => { + ran["callback returning a pending promise"]++; + return new Promise(() => {}); }, 1); + +// The ref'd 1ms timers above keep the loop alive long enough for this one to fire too. +setTimeout(() => { + ran["unref'd callback returning a pending promise"]++; + return new Promise(() => {}); +}, 1).unref(); + +process.on("exit", () => console.log(JSON.stringify(ran))); diff --git a/test/js/web/timers/setTimeout.test.js b/test/js/web/timers/setTimeout.test.js index 80f321077823..c6994318ac5a 100644 --- a/test/js/web/timers/setTimeout.test.js +++ b/test/js/web/timers/setTimeout.test.js @@ -2,7 +2,7 @@ import { spawnSync } from "bun"; import { timerInternals } from "bun:internal-for-testing"; import { heapStats } from "bun:jsc"; import { describe, expect, it } from "bun:test"; -import { bunEnv, bunExe, bunRun, isLinux, isWindows, tempDirWithFiles } from "harness"; +import { bunEnv, bunExe, bunRun, isASAN, isDebug, isLinux, isWindows, tempDirWithFiles } from "harness"; import path from "node:path"; it("setTimeout", async () => { @@ -202,52 +202,29 @@ it("order of setTimeouts", done => { Promise.resolve().then(maybeDone(() => nums.push(1))); }); -it("setTimeout -> refresh", () => { - const { exitCode, stdout } = spawnSync({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-unref-fixture.js")], - env: bunEnv, - }); - expect(exitCode).toBe(0); - expect(stdout.toString()).toBe("SUCCESS\n"); -}); - -it("setTimeout -> unref -> ref works", () => { - const { exitCode, stdout } = spawnSync({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-unref-fixture-4.js")], - env: bunEnv, - }); - expect(exitCode).toBe(0); - expect(stdout.toString()).toBe("TEST PASSED!\n"); -}); - -it("setTimeout -> ref -> unref works, even if there is another timer", () => { - const { exitCode, stdout } = spawnSync({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-unref-fixture-2.js")], - env: bunEnv, - }); - expect(exitCode).toBe(0); - expect(stdout.toString()).toBe(""); -}); - -it("setTimeout -> ref -> unref works", () => { - const { exitCode, stdout } = spawnSync({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-unref-fixture-5.js")], - env: bunEnv, - }); - expect(exitCode).toBe(0); - expect(stdout.toString()).toBe(""); -}); - -it("setTimeout -> unref doesn't keep event loop alive forever", () => { - const { exitCode, stdout } = spawnSync({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-unref-fixture-3.js")], - env: bunEnv, - }); - expect(exitCode).toBe(0); - expect(stdout.toString()).toBe(""); -}); +// The tests below that spawn a process are it.concurrent so their children start together; +// the CPU and latency measurements further down stay sequential so nothing runs alongside them. + +it.concurrent( + "setTimeout -> ref/unref/refresh decide which timers run and whether the process stays alive", + async () => { + // The fixture arms every scenario at once and reports how often each callback ran when the + // process exits, which it must do on its own once the ref'd timers have run. + const result = await bunRun(path.join(import.meta.dir, "setTimeout-unref-fixture.js")); + expect(result).toSpawn(); + expect(JSON.parse(result.stdout)).toEqual({ + "unref()": 0, + "ref().unref()": 0, + "unref().ref()": 1, + "refresh() inside the callback": 2, + "this is the Timeout": 1, + "callback returning a pending promise": 1, + "unref'd callback returning a pending promise": 1, + }); + }, +); -it("setTimeout -> fire -> unref -> ref does not keep the event loop alive", async () => { +it.concurrent("setTimeout -> fire -> unref -> ref does not keep the event loop alive", async () => { // After a one-shot timer has fired it is destroyed; calling .unref() then .ref() // must not leak an event-loop ref. Previously this would hang forever. const src = ` @@ -272,7 +249,7 @@ it("setTimeout -> fire -> unref -> ref does not keep the event loop alive", asyn expect(exitCode).toBe(0); }); -it("setImmediate -> fire -> unref -> ref does not keep the event loop alive", async () => { +it.concurrent("setImmediate -> fire -> unref -> ref does not keep the event loop alive", async () => { const src = ` const im = setImmediate(() => {}); setTimeout(() => { @@ -295,66 +272,66 @@ it("setImmediate -> fire -> unref -> ref does not keep the event loop alive", as expect(exitCode).toBe(0); }); -it("setTimeout should refresh N times", done => { +it.concurrent("setTimeout should refresh N times", async () => { + const { promise, resolve } = Promise.withResolvers(); + const refreshReturnedTimer = []; let count = 0; - let timer = setTimeout(() => { - count++; - expect(timer.refresh()).toBe(timer); - }, 50); - - setTimeout(() => { - clearTimeout(timer); - try { - expect(count).toBeGreaterThanOrEqual(isWindows ? 4 : 5); - } finally { - done(); - } - }, 300); -}); - -it("setTimeout if refreshed before run, should reschedule to run later", done => { - let start = Date.now(); - let timer = setTimeout(() => { - let end = Date.now(); - expect(end - start).toBeGreaterThan(120); - done(); - }, 100); - - setTimeout(() => { - timer.refresh(); - }, 50); + const timer = setTimeout(() => { + if (++count === 5) return resolve(); + refreshReturnedTimer.push(timer.refresh() === timer); + }, 10); + await promise; + expect(count).toBe(5); + expect(refreshReturnedTimer).toEqual([true, true, true, true]); }); -it("setTimeout should refresh after already been run", done => { - let count = 0; - let timer = setTimeout(() => { - count++; - }, 50); - +it.concurrent("setTimeout if refreshed before run, should reschedule to run later", async () => { + const { promise, resolve } = Promise.withResolvers(); + const timer = setTimeout(() => resolve(performance.now()), 100); + let refreshedAt; setTimeout(() => { + refreshedAt = performance.now(); timer.refresh(); - }, 100); - - setTimeout(() => { - expect(count).toBe(2); - done(); - }, 300); -}); - -it("setTimeout should not refresh after clearTimeout", done => { - let count = 0; - let timer = setTimeout(() => { - count++; }, 50); - + const firedAt = await promise; + // Without the refresh the timer fires at its original deadline, ~50ms after refreshedAt. + expect(firedAt - refreshedAt).toBeGreaterThanOrEqual(95); +}); + +it.concurrent("setTimeout should refresh after already been run", async () => { + let fired = 0; + let onFire = () => {}; + const nextFire = () => new Promise(resolve => (onFire = resolve)); + const timer = setTimeout(() => { + fired++; + onFire(); + }, 10); + + await nextFire(); + expect(fired).toBe(1); + + // Refresh from a later macrotask, once the fired timer has been fully torn down (refreshing + // from inside the callback is the separate path covered by the leak fixture below). + await new Promise(resolve => setImmediate(resolve)); + const refired = nextFire(); + expect(timer.refresh()).toBe(timer); + await refired; + expect(fired).toBe(2); + + // The refreshed one-shot must not keep firing. A wrong third fire would be due 10ms after + // the second one, so it would run before this 20ms timer does. + await new Promise(resolve => setTimeout(resolve, 20)); + expect(fired).toBe(2); +}); + +it.concurrent("setTimeout should not refresh after clearTimeout", async () => { + let fired = 0; + const timer = setTimeout(() => fired++, 10); clearTimeout(timer); - - timer.refresh(); - - setTimeout(() => { - expect(count).toBe(0); - done(); - }, 100); + expect(timer.refresh()).toBe(timer); + // Had refresh() re-armed the cleared timer, it would be due before this 20ms timer. + await new Promise(resolve => setTimeout(resolve, 20)); + expect(fired).toBe(0); }); it("setTimeout Timeout objects are unprotected after called", async () => { @@ -393,15 +370,44 @@ it("setTimeout Timeout objects are unprotected after called", async () => { }); it("setTimeout CPU usage #7790", async () => { - const process = Bun.spawn({ - cmd: [bunExe(), "run", path.join(import.meta.dir, "setTimeout-cpu-fixture.js")], + // A pending setTimeout used to make the event loop spin at 100% CPU until it fired. The child + // measures its own CPU over a 300ms window during which a far-off timer is pending; the window + // opens after a setImmediate so that startup work is not counted. + await using proc = Bun.spawn({ + cmd: [ + bunExe(), + "-e", + `const pending = setTimeout(() => {}, 200_000); + setImmediate(() => { + const wall0 = process.hrtime.bigint(); + const cpu0 = process.cpuUsage(); + setTimeout(() => { + const { user, system } = process.cpuUsage(cpu0); + const wallUs = Number((process.hrtime.bigint() - wall0) / 1000n); + clearTimeout(pending); + const lifetime = process.cpuUsage(); + console.log(JSON.stringify({ cpuUs: user + system, wallUs, lifetimeCpuUs: lifetime.user + lifetime.system })); + }, 300); + });`, + ], env: bunEnv, - stdout: "inherit", + stdout: "pipe", + stderr: "pipe", }); - const code = await process.exited; - expect(code).toBe(0); - const stats = process.resourceUsage(); - expect(stats.cpuTime.total / BigInt(1e6)).toBeLessThan(1); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + const { cpuUs, wallUs, lifetimeCpuUs } = JSON.parse(stdout); + expect(wallUs).toBeGreaterThanOrEqual(250_000); + // Spinning reads ~100%. Sleeping properly it reads ~0.2% on release and ~3% on debug+ASAN. + expect((cpuUs / wallUs) * 100, `cpuUs=${cpuUs} wallUs=${wallUs}`).toBeLessThan(50); + expect(exitCode).toBe(0); + + // Subprocess.resourceUsage() was added together with this test (#7792) and this is where it is + // exercised: the child's whole-lifetime CPU time in microseconds, which cannot be less than + // what the child itself read via process.cpuUsage() just before exiting. + const { cpuTime } = proc.resourceUsage(); + expect(cpuTime.total).toBe(cpuTime.user + cpuTime.system); + expect(Number(cpuTime.total)).toBeGreaterThanOrEqual(lifetimeCpuUs); }); // The epoll_pwait(2) fallback (kernels <5.11, gVisor, seccomp-blocked @@ -411,9 +417,8 @@ it("setTimeout CPU usage #7790", async () => { // setInterval(1) spends most of the window asleep. // https://man7.org/linux/man-pages/man2/epoll_wait.2.html it.skipIf(!isLinux)("epoll_pwait fallback does not busy-spin on sub-ms timers", async () => { - await using proc = Bun.spawn({ - cmd: [ - bunExe(), + const result = await bunRun( + [ "-e", `const wall0 = process.hrtime.bigint(); const cpu0 = process.cpuUsage(); @@ -429,23 +434,15 @@ it.skipIf(!isLinux)("epoll_pwait fallback does not busy-spin on sub-ms timers", } }, 1);`, ], - env: { ...bunEnv, BUN_FEATURE_FLAG_DISABLE_EPOLL_PWAIT2: "1" }, - stdout: "pipe", - stderr: "pipe", - }); - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - const filteredStderr = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(filteredStderr).toBe(""); - const { ticks, cpuUs, wallUs } = JSON.parse(stdout); + { BUN_FEATURE_FLAG_DISABLE_EPOLL_PWAIT2: "1" }, + ); + expect(result).toSpawn(); + const { ticks, cpuUs, wallUs } = JSON.parse(result.stdout); const cpuPercent = (cpuUs / wallUs) * 100; // Busy-spinning puts cpuUs ~= wallUs (100%). Sleeping properly it is a - // small fraction (~5% release). 50% gives wide headroom for ASAN/debug. + // small fraction (~5% release, ~23% debug+ASAN, where each tick costs more). expect(cpuPercent, `ticks=${ticks} cpuUs=${cpuUs} wallUs=${wallUs}`).toBeLessThan(50); expect(ticks).toBeGreaterThan(0); - expect(exitCode).toBe(0); }); // EINTR retry used to re-issue the full timeout (on both epoll_pwait and @@ -490,9 +487,8 @@ __attribute__((constructor)) static void arm(void) { ["epoll_pwait2", {}], ["epoll_pwait fallback", { BUN_FEATURE_FLAG_DISABLE_EPOLL_PWAIT2: "1" }], ])("%s: setTimeout fires on time under signal storm", async (_name, extraEnv) => { - await using proc = Bun.spawn({ - cmd: [ - bunExe(), + const result = await bunRun( + [ "-e", `const s = process.hrtime.bigint(); setTimeout(() => { @@ -500,94 +496,91 @@ __attribute__((constructor)) static void arm(void) { process.exit(0); }, 200);`, ], - env: { ...bunEnv, ...extraEnv, LD_PRELOAD: soPath }, - stdout: "pipe", - stderr: "pipe", - }); - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - const filteredStderr = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(filteredStderr).toBe(""); - const { ms } = JSON.parse(stdout); + { ...extraEnv, LD_PRELOAD: soPath }, + ); + expect(result).toSpawn(); + const { ms } = JSON.parse(result.stdout); // Without the fix this lands ~900-1000 ms; with it, ~200-210 ms. expect(ms).toBeWithin(200, 500); - expect(exitCode).toBe(0); }); }); -it.concurrent("Returning a Promise in setTimeout doesnt keep the event loop alive forever", async () => { - expect(await bunRun(path.join(import.meta.dir, "setTimeout-unref-fixture-6.js"))).toSpawn(); -}); - -it.concurrent("Returning a Promise in setTimeout (unref'd) doesnt keep the event loop alive forever", async () => { - expect(await bunRun(path.join(import.meta.dir, "setTimeout-unref-fixture-7.js"))).toSpawn(); -}); - it.concurrent("setTimeout canceling with unref, close, _idleTimeout, and _onTimeout", async () => { - expect(await bunRun([path.join(import.meta.dir, "timers-fixture-unref.js"), "setTimeout"])).toSpawn(); -}); - + // The fixture exits non-zero and names the callback if any of them ran the wrong number of times. + expect(await bunRun([path.join(import.meta.dir, "timers-fixture-unref.js"), "setTimeout"])).toSpawn(""); +}); + +// RSS is only a usable leak signal on a release build: under ASAN the freed blocks stay resident +// in the quarantine, so 200k timers grow RSS by the same ~140 MB whether or not the TimeoutObjects +// get freed, and a debug build needs ~40s to churn through that many timers anyway. Those builds +// run one batch per mode and rely on LeakSanitizer instead: a TimeoutObject still allocated when +// the child exits is reported on stderr and fails the exit code. The CI runner sets the same +// variables for the whole ASAN lane (scripts/runner.node.mjs); setting them here as well makes a +// plain `bun bd test` catch the leak too. BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the +// scan, which is what CI does and what keeps the scan at ~0.1s rather than ~3s. +const leakFixtureMeasuresRss = !isASAN && !isDebug; +const leakFixtureBatches = leakFixtureMeasuresRss ? 100 : 1; +const leakFixtureEnv = isASAN + ? { + ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), + LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, + BUN_DESTRUCT_VM_ON_EXIT: "1", + } + : {}; for (const mode of ["clear", "refresh", "repeat"]) { - it(`setTimeout doesn't leak when ${mode} is called inside its own callback`, async () => { - await using proc = Bun.spawn({ - cmd: [bunExe(), path.join(import.meta.dir, "setTimeout-clear-in-callback-leak-fixture.js"), mode], - env: bunEnv, - stdout: "pipe", - stderr: "pipe", - }); - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - const filteredStderr = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(filteredStderr).toBe(""); - expect(stdout).toContain("delta:"); - expect(exitCode).toBe(0); - }, 90_000); + it.concurrent( + `setTimeout doesn't leak when ${mode} is called inside its own callback`, + async () => { + const result = await bunRun( + [path.join(import.meta.dir, "setTimeout-clear-in-callback-leak-fixture.js"), mode, String(leakFixtureBatches)], + leakFixtureEnv, + ); + expect(result).toSpawn(); + const { liveTimeouts, rssDeltaMB, ...report } = JSON.parse(result.stdout); + expect(report).toEqual({ mode, timers: leakFixtureBatches * 2000, protectedTimeouts: 0 }); + // A few wrappers survive the final GC via conservative stack scanning (2-4 observed); + // retaining the fired timers would leave thousands. + expect(liveTimeouts).toBeLessThan(100); + // Each leaked TimeoutObject is ~100 bytes, so 100 leaking batches grow RSS by ~20 MB; + // without a leak the delta is 0-1 MB. + if (leakFixtureMeasuresRss) expect(rssDeltaMB).toBeLessThan(10); + }, + // Passes in ~1.3s on debug+ASAN; when it does leak, symbolizing the LeakSanitizer report + // against a debug binary takes another ~5s, and that report is the useful failure output. + 30_000, + ); } -it("setTimeout does not leak a pending exception when emitting a timeout warning throws", async () => { +it.concurrent("setTimeout does not leak a pending exception when emitting a timeout warning throws", async () => { // The out-of-range timeout warning queues a process.nextTick, which reads process._exiting. // If that read throws, the exception must not be left pending on the VM when setTimeout - // returns — otherwise debug builds hit releaseAssertNoException(). - await using proc = Bun.spawn({ - cmd: [ - bunExe(), - "-e", - ` - process.nextTick(() => {}); - Object.defineProperty(process, "_exiting", { - get() { throw new TypeError("boom"); }, - configurable: true, - }); - const t = setTimeout(() => {}, 1e100); - clearTimeout(t); - console.log("survived"); - `, - ], - env: bunEnv, - stdout: "pipe", - stderr: "pipe", - }); - - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - - expect(stderr).not.toContain("boom"); - expect(stdout.trim()).toBe("survived"); - expect(exitCode).toBe(0); -}); - -it("clearTimeout with a numeric id is a no-op after a timeout promoted to an interval is cleared and collected", async () => { - // A setTimeout whose numeric id has been observed via `+timer` registers itself in the - // setTimeout id map. Assigning `_repeat` promotes it to a setInterval after its first - // fire. Once the timer is cleared and its wrapper is collected, the id-map entry must be - // gone from whichever map it was inserted into, so that a later clearTimeout(id) with the - // raw number is a harmless no-op instead of resolving to the freed timer. - await using proc = Bun.spawn({ - cmd: [ - bunExe(), + // returns, otherwise debug builds hit releaseAssertNoException(). The throw also aborts the + // warning itself, so stderr stays empty. + const result = await bunRun([ + "-e", + ` + process.nextTick(() => {}); + Object.defineProperty(process, "_exiting", { + get() { throw new TypeError("boom"); }, + configurable: true, + }); + const t = setTimeout(() => {}, 1e100); + clearTimeout(t); + console.log("survived"); + `, + ]); + expect(result).toSpawn("survived"); +}); + +it.concurrent( + "clearTimeout with a numeric id is a no-op after a timeout promoted to an interval is cleared and collected", + async () => { + // A setTimeout whose numeric id has been observed via `+timer` registers itself in the + // setTimeout id map. Assigning `_repeat` promotes it to a setInterval after its first + // fire. Once the timer is cleared and its wrapper is collected, the id-map entry must be + // gone from whichever map it was inserted into, so that a later clearTimeout(id) with the + // raw number is a harmless no-op instead of resolving to the freed timer. + const result = await bunRun([ "-e", ` async function main() { @@ -627,59 +620,35 @@ it("clearTimeout with a numeric id is a no-op after a timeout promoted to an int }, ); `, - ], - env: bunEnv, - stdout: "pipe", - stderr: "pipe", - }); - - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - - const stderrLines = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(stderrLines).toBe(""); - expect(stdout).toBe("converted: ok\nsurvived\n"); - expect(exitCode).toBe(0); -}); + ]); + expect(result).toSpawn("converted: ok\nsurvived"); + }, +); it("setTimeout(1) is not quantized to the ~15.6ms Windows system tick", async () => { // Subprocess so no other in-process work has raised the Windows tick // resolution; median of 50 so a single scheduler hiccup on a busy CI // runner does not fail the assertion. - await using proc = Bun.spawn({ - cmd: [ - bunExe(), - "-e", - ` - const samples = []; - for (let i = 0; i < 50; i++) { - const t0 = process.hrtime.bigint(); - await new Promise(r => setTimeout(r, 1)); - samples.push(Number(process.hrtime.bigint() - t0) / 1e6); - } - samples.sort((a, b) => a - b); - const median = samples[samples.length >> 1]; - process.stdout.write(JSON.stringify({ median, min: samples[0] })); - `, - ], - env: bunEnv, - stdout: "pipe", - stderr: "pipe", - }); - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - const filteredStderr = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(filteredStderr).toBe(""); - const { median, min } = JSON.parse(stdout); + const result = await bunRun([ + "-e", + ` + const samples = []; + for (let i = 0; i < 50; i++) { + const t0 = process.hrtime.bigint(); + await new Promise(r => setTimeout(r, 1)); + samples.push(Number(process.hrtime.bigint() - t0) / 1e6); + } + samples.sort((a, b) => a - b); + const median = samples[samples.length >> 1]; + console.log(JSON.stringify({ median, min: samples[0] })); + `, + ]); + expect(result).toSpawn(); + const { median, min } = JSON.parse(result.stdout); // Before: median ~15.6ms. After: median ~1-2ms. 8ms splits the two with // plenty of headroom for CI jitter. Also assert we never fire early. expect(median).toBeLessThan(8); expect(min).toBeGreaterThanOrEqual(1); - expect(exitCode).toBe(0); }); // Reading a timer's numeric id (`+t`, `${t}`, obj[t]=x, any Symbol.toPrimitive @@ -689,39 +658,28 @@ it("setTimeout(1) is not quantized to the ~15.6ms Windows system tick", async () // O(n^2). 20k such timers froze the loop for ~2-3 s on release, tens of // seconds at 30k+. Node: ~5 ms for 200k. With swap_remove() the sweep is O(n). it("GC of many id-accessed timers is not quadratic", async () => { - await using proc = Bun.spawn({ - cmd: [ - bunExe(), - "-e", - ` - const N = 20000; - for (let i = 0; i < N; i++) { - const t = setTimeout(() => {}, 3_600_000); - Number(t); // mint the id-map entry via Symbol.toPrimitive - clearTimeout(t); - } - const t0 = performance.now(); - Bun.gc(true); - const ms = performance.now() - t0; - process.stdout.write(JSON.stringify({ ms: Math.round(ms) })); - `, - ], - env: bunEnv, - stdout: "pipe", - stderr: "pipe", - }); - const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - const filteredStderr = stderr - .split("\n") - .filter(l => l && !l.startsWith("WARNING: ASAN interferes")) - .join("\n"); - expect(filteredStderr).toBe(""); - const { ms } = JSON.parse(stdout); + // Creating the 20k timers is itself ~4s on debug+ASAN, hence the raised timeout. + const result = await bunRun([ + "-e", + ` + const N = 20000; + for (let i = 0; i < N; i++) { + const t = setTimeout(() => {}, 3_600_000); + Number(t); // mint the id-map entry via Symbol.toPrimitive + clearTimeout(t); + } + const t0 = performance.now(); + Bun.gc(true); + const ms = performance.now() - t0; + console.log(JSON.stringify({ ms: Math.round(ms) })); + `, + ]); + expect(result).toSpawn(); + const { ms } = JSON.parse(result.stdout); // Before: ~2100-3400 ms release, far more on debug+ASAN (quadratic in N). // After: <10 ms release, ~100-170 ms debug+ASAN (linear). 1500 ms splits // the two with ~9x headroom over the fixed debug+ASAN number. expect(ms).toBeLessThan(1500); - expect(exitCode).toBe(0); }, 30_000); it("timer heap clock is monotonic, not wall-clock", () => { diff --git a/test/js/web/timers/timers-fixture-unref.js b/test/js/web/timers/timers-fixture-unref.js index d69ea64ddf11..cdba9303e741 100644 --- a/test/js/web/timers/timers-fixture-unref.js +++ b/test/js/web/timers/timers-fixture-unref.js @@ -1,4 +1,21 @@ -const { mustCall } = require("../../node/test/common"); +// Same contract as node's common.mustCall(), inlined because loading ../../node/test/common +// takes ~2s on a debug build, more than the timers below take to run. +const calls = []; +function mustCall(fn = () => {}, exact = 1) { + const entry = { site: new Error().stack.split("\n")[2].trim(), exact, actual: 0 }; + calls.push(entry); + return function (...args) { + entry.actual++; + return fn.apply(this, args); + }; +} +process.on("exit", () => { + for (const { site, exact, actual } of calls) { + if (actual === exact) continue; + console.error(`Expected exactly ${exact} call(s), got ${actual}: ${site}`); + process.exitCode = 1; + } +}); var setTimer; if (process.argv[2] === "setTimeout") { From 3c3804d8d0c6a740393489e464046e63ba299ca6 Mon Sep 17 00:00:00 2001 From: robobun <117481402+robobun@users.noreply.github.com> Date: Fri, 14 Aug 2026 12:36:23 +0000 Subject: [PATCH 2/4] test(timers): only enable LeakSanitizer for the leak fixture on Linux The only ASAN CI lane is Linux and that is where the LeakSanitizer path was verified; an ASAN debug build on macOS keeps the small workload without the explicit LSAN environment. --- test/js/web/timers/setTimeout.test.js | 22 ++++++++++++---------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/test/js/web/timers/setTimeout.test.js b/test/js/web/timers/setTimeout.test.js index c6994318ac5a..0919d47453e2 100644 --- a/test/js/web/timers/setTimeout.test.js +++ b/test/js/web/timers/setTimeout.test.js @@ -515,18 +515,20 @@ it.concurrent("setTimeout canceling with unref, close, _idleTimeout, and _onTime // get freed, and a debug build needs ~40s to churn through that many timers anyway. Those builds // run one batch per mode and rely on LeakSanitizer instead: a TimeoutObject still allocated when // the child exits is reported on stderr and fails the exit code. The CI runner sets the same -// variables for the whole ASAN lane (scripts/runner.node.mjs); setting them here as well makes a -// plain `bun bd test` catch the leak too. BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the -// scan, which is what CI does and what keeps the scan at ~0.1s rather than ~3s. +// variables for the whole ASAN lane (scripts/runner.node.mjs; the only ASAN lane is Linux, hence +// the isLinux guard); setting them here as well makes a plain `bun bd test` catch the leak too. +// BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the scan, which is what CI does and what keeps +// the scan at ~0.1s rather than ~3s. const leakFixtureMeasuresRss = !isASAN && !isDebug; const leakFixtureBatches = leakFixtureMeasuresRss ? 100 : 1; -const leakFixtureEnv = isASAN - ? { - ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), - LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, - BUN_DESTRUCT_VM_ON_EXIT: "1", - } - : {}; +const leakFixtureEnv = + isASAN && isLinux + ? { + ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), + LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, + BUN_DESTRUCT_VM_ON_EXIT: "1", + } + : {}; for (const mode of ["clear", "refresh", "repeat"]) { it.concurrent( `setTimeout doesn't leak when ${mode} is called inside its own callback`, From ceb72582ebea5efd289845d48b01aba6d2096fde Mon Sep 17 00:00:00 2001 From: robobun <117481402+robobun@users.noreply.github.com> Date: Fri, 14 Aug 2026 13:02:49 +0000 Subject: [PATCH 3/4] test(timers): keep the RSS leak check on every build without ASAN Keying the RSS check off !isDebug as well left debug builds without ASAN (Windows, x64 macOS) running one batch with neither the RSS check nor LeakSanitizer. Every build without ASAN now runs the 100 batch workload against the 10 MB bound; on a Windows debug build that takes 8-10s per mode (the modes run concurrently), grows RSS by 1-2 MB, and by ~100 MB with the #30058 leak reintroduced. ASAN builds on any platform take the one-batch LeakSanitizer path; bun maintains LSan suppressions for macOS, so the Linux-only guard is gone too. --- ...tTimeout-clear-in-callback-leak-fixture.js | 5 +- test/js/web/timers/setTimeout.test.js | 50 +++++++++---------- 2 files changed, 27 insertions(+), 28 deletions(-) diff --git a/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js b/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js index e5493978cf63..5dbc54d6f754 100644 --- a/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js +++ b/test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js @@ -8,8 +8,9 @@ // // Runs `batches` batches of BATCH timers after warming up, then prints one JSON line: // timers timers created in the measured batches -// rssDeltaMB RSS growth over the measured batches (~0 when nothing leaks; each -// leaked TimeoutObject is ~100 bytes, so 100 batches leak ~20 MB) +// rssDeltaMB RSS growth over the measured batches: 0-2 MB over 100 batches when nothing +// leaks; with the leak above, ~20 MB on a release build (~100 bytes per +// TimeoutObject) and ~100 MB on a debug build without ASAN // liveTimeouts Timeout wrappers still on the JS heap after a full GC // protectedTimeouts Timeout wrappers still pinned by the native side // setTimeout.test.js asserts the report. diff --git a/test/js/web/timers/setTimeout.test.js b/test/js/web/timers/setTimeout.test.js index 0919d47453e2..88d0596fec7b 100644 --- a/test/js/web/timers/setTimeout.test.js +++ b/test/js/web/timers/setTimeout.test.js @@ -2,7 +2,7 @@ import { spawnSync } from "bun"; import { timerInternals } from "bun:internal-for-testing"; import { heapStats } from "bun:jsc"; import { describe, expect, it } from "bun:test"; -import { bunEnv, bunExe, bunRun, isASAN, isDebug, isLinux, isWindows, tempDirWithFiles } from "harness"; +import { bunEnv, bunExe, bunRun, isASAN, isLinux, isWindows, tempDirWithFiles } from "harness"; import path from "node:path"; it("setTimeout", async () => { @@ -510,25 +510,24 @@ it.concurrent("setTimeout canceling with unref, close, _idleTimeout, and _onTime expect(await bunRun([path.join(import.meta.dir, "timers-fixture-unref.js"), "setTimeout"])).toSpawn(""); }); -// RSS is only a usable leak signal on a release build: under ASAN the freed blocks stay resident -// in the quarantine, so 200k timers grow RSS by the same ~140 MB whether or not the TimeoutObjects -// get freed, and a debug build needs ~40s to churn through that many timers anyway. Those builds -// run one batch per mode and rely on LeakSanitizer instead: a TimeoutObject still allocated when -// the child exits is reported on stderr and fails the exit code. The CI runner sets the same -// variables for the whole ASAN lane (scripts/runner.node.mjs; the only ASAN lane is Linux, hence -// the isLinux guard); setting them here as well makes a plain `bun bd test` catch the leak too. -// BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the scan, which is what CI does and what keeps -// the scan at ~0.1s rather than ~3s. -const leakFixtureMeasuresRss = !isASAN && !isDebug; -const leakFixtureBatches = leakFixtureMeasuresRss ? 100 : 1; -const leakFixtureEnv = - isASAN && isLinux - ? { - ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), - LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, - BUN_DESTRUCT_VM_ON_EXIT: "1", - } - : {}; +// On builds without ASAN (release, and debug builds on Windows and x64 macOS) RSS is the leak +// signal: over the fixture's 100 batches the delta is 0-2 MB when the TimeoutObjects are freed and +// ~20 MB or more when they leak (see the fixture), at ~0.3s per mode on release and ~8-10s on a +// debug build. Under ASAN the freed blocks stay resident in the quarantine, so 200k timers grow RSS +// by the same ~140 MB whether or not they are freed. ASAN builds therefore run a single batch and +// rely on LeakSanitizer instead: a TimeoutObject still allocated when the child exits is reported +// on stderr and fails the exit code. The CI runner sets the same three variables for the whole ASAN +// lane (scripts/runner.node.mjs); setting them here as well makes a plain `bun bd test` catch the +// leak too. BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the scan, as CI does, which keeps the +// scan at ~0.1s instead of ~3s. +const leakFixtureBatches = isASAN ? 1 : 100; +const leakFixtureEnv = isASAN + ? { + ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), + LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, + BUN_DESTRUCT_VM_ON_EXIT: "1", + } + : {}; for (const mode of ["clear", "refresh", "repeat"]) { it.concurrent( `setTimeout doesn't leak when ${mode} is called inside its own callback`, @@ -543,13 +542,12 @@ for (const mode of ["clear", "refresh", "repeat"]) { // A few wrappers survive the final GC via conservative stack scanning (2-4 observed); // retaining the fired timers would leave thousands. expect(liveTimeouts).toBeLessThan(100); - // Each leaked TimeoutObject is ~100 bytes, so 100 leaking batches grow RSS by ~20 MB; - // without a leak the delta is 0-1 MB. - if (leakFixtureMeasuresRss) expect(rssDeltaMB).toBeLessThan(10); + if (!isASAN) expect(rssDeltaMB).toBeLessThan(10); }, - // Passes in ~1.3s on debug+ASAN; when it does leak, symbolizing the LeakSanitizer report - // against a debug binary takes another ~5s, and that report is the useful failure output. - 30_000, + // ~1.5s on debug+ASAN, 8-10s on a debug build without ASAN. When the fixture does leak under + // ASAN, symbolizing the LeakSanitizer report against a debug binary takes another ~5s, and that + // report is the failure output worth waiting for. + 60_000, ); } From 1ab6620de91e665360109b0ac33881477c67be6a Mon Sep 17 00:00:00 2001 From: robobun <117481402+robobun@users.noreply.github.com> Date: Fri, 14 Aug 2026 17:22:53 +0000 Subject: [PATCH 4/4] test(timers): keep the unref -> ref keep-alive check alone in its process Whether ref() re-refs the event loop is only observable when the timer is the only thing keeping the process alive; inside the combined fixture the other ref'd timers would let the callback run even with a no-op ref(), so that case is its own child again (exit code 1 unless the callback runs), and the combined fixture no longer lists it. The LSAN_OPTIONS fallback used by a plain `bun bd test` now carries print_suppressions=0 like the CI runner's value, otherwise a structural leak covered by test/leaksan.supp would print a "Suppressions used" block and fail the empty-stderr assertion. --- .../js/web/timers/setTimeout-unref-fixture.js | 19 +++++++-------- test/js/web/timers/setTimeout.test.js | 24 +++++++++++++++---- 2 files changed, 28 insertions(+), 15 deletions(-) diff --git a/test/js/web/timers/setTimeout-unref-fixture.js b/test/js/web/timers/setTimeout-unref-fixture.js index 0900a0f65e98..3926d5ef4734 100644 --- a/test/js/web/timers/setTimeout-unref-fixture.js +++ b/test/js/web/timers/setTimeout-unref-fixture.js @@ -1,12 +1,15 @@ -// Arms every ref/unref scenario at once. The ref'd timers must run, the unref'd ones must -// not run and must not keep the process alive: once the ref'd timers are done the event -// loop has to wind down by itself. The exit handler reports how often each callback ran; -// setTimeout.test.js asserts the exact report. An unref'd timer that wrongly keeps the -// loop alive fires 100ms later and shows up in the report as a non-zero count. +// Arms every scenario at once. The ref'd timers must run, the unref'd ones must not run and +// must not keep the process alive: once the ref'd timers are done the event loop has to wind +// down by itself. The exit handler reports how often each callback ran; setTimeout.test.js +// asserts the exact report. An unref'd timer that wrongly keeps the loop alive fires 100ms +// later and shows up in the report as a non-zero count. +// +// Whether .ref() keeps the loop alive can only be observed by a timer that is alone in the +// process (anything else that is ref'd would mask a no-op ref()), so that case is a separate +// test in setTimeout.test.js rather than a scenario here. const ran = { "unref()": 0, "ref().unref()": 0, - "unref().ref()": 0, "refresh() inside the callback": 0, "this is the Timeout": 0, "callback returning a pending promise": 0, @@ -20,10 +23,6 @@ const reffed = setTimeout(() => ran["ref().unref()"]++, 100); if (reffed.ref() !== reffed) throw new Error("ref() must return the timer"); reffed.unref(); -setTimeout(() => ran["unref().ref()"]++, 1) - .unref() - .ref(); - // refresh() from inside the callback re-arms the one-shot timer once, so it runs twice. const refreshing = setTimeout(() => { if (++ran["refresh() inside the callback"] === 1) refreshing.refresh(); diff --git a/test/js/web/timers/setTimeout.test.js b/test/js/web/timers/setTimeout.test.js index 88d0596fec7b..6627c61f0253 100644 --- a/test/js/web/timers/setTimeout.test.js +++ b/test/js/web/timers/setTimeout.test.js @@ -215,7 +215,6 @@ it.concurrent( expect(JSON.parse(result.stdout)).toEqual({ "unref()": 0, "ref().unref()": 0, - "unref().ref()": 1, "refresh() inside the callback": 2, "this is the Timeout": 1, "callback returning a pending promise": 1, @@ -224,6 +223,17 @@ it.concurrent( }, ); +it.concurrent("setTimeout -> unref -> ref works", async () => { + // The re-ref'd timer is the only thing in the process, so the process only lives long enough + // for the callback to flip the exit code if ref() really keeps the event loop alive again. + const result = await bunRun([ + "-e", + `process.exitCode = 1; + setTimeout(() => { process.exitCode = 0; }, 1).unref().ref();`, + ]); + expect(result).toSpawn(""); +}); + it.concurrent("setTimeout -> fire -> unref -> ref does not keep the event loop alive", async () => { // After a one-shot timer has fired it is destroyed; calling .unref() then .ref() // must not leak an event-loop ref. Previously this would hang forever. @@ -517,14 +527,18 @@ it.concurrent("setTimeout canceling with unref, close, _idleTimeout, and _onTime // by the same ~140 MB whether or not they are freed. ASAN builds therefore run a single batch and // rely on LeakSanitizer instead: a TimeoutObject still allocated when the child exits is reported // on stderr and fails the exit code. The CI runner sets the same three variables for the whole ASAN -// lane (scripts/runner.node.mjs); setting them here as well makes a plain `bun bd test` catch the -// leak too. BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the scan, as CI does, which keeps the -// scan at ~0.1s instead of ~3s. +// lane (scripts/runner.node.mjs), in which case they are inherited through bunEnv; the fallbacks +// below give a plain `bun bd test` the same setup, so it catches the leak too. print_suppressions=0 +// matters for the exact-empty-stderr assertion: structural leaks covered by test/leaksan.supp would +// otherwise be listed on stderr. BUN_DESTRUCT_VM_ON_EXIT frees the JS heap before the scan, as CI +// does, which keeps the scan at ~0.1s instead of ~3s. const leakFixtureBatches = isASAN ? 1 : 100; const leakFixtureEnv = isASAN ? { ASAN_OPTIONS: [bunEnv.ASAN_OPTIONS, "detect_leaks=1"].filter(Boolean).join(":"), - LSAN_OPTIONS: bunEnv.LSAN_OPTIONS ?? `suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, + LSAN_OPTIONS: + bunEnv.LSAN_OPTIONS ?? + `print_suppressions=0:suppressions=${path.join(import.meta.dir, "../../../leaksan.supp")}`, BUN_DESTRUCT_VM_ON_EXIT: "1", } : {};