Skip to content

test(timers): speed up setTimeout.test.js and tighten its assertions - #38493

Open
robobun wants to merge 4 commits into
mainfrom
farm/361ee08f/speed-up-settimeout-test
Open

test(timers): speed up setTimeout.test.js and tighten its assertions#38493
robobun wants to merge 4 commits into
mainfrom
farm/361ee08f/speed-up-settimeout-test

Conversation

@robobun

@robobun robobun commented Aug 14, 2026

Copy link
Copy Markdown
Collaborator

Problem

  • test/js/web/timers/setTimeout.test.js is a serial-phase file that takes 34-36s on the debian 13 x64 ASAN lane (builds 95391, 95331) and 6s on every other lane.
  • Under a local debug build (bun bd test) it takes 152-163s, and the three doesn't leak when ... inside its own callback tests fail: the fixture keyed its ASAN RSS limit off the binary name bun-asan, so bun-debug (also ASAN) got the 10 MB limit and measured ~140 MB.
  • Debug-build time breakdown: the three leak fixtures 40-51s each, GC of many id-accessed timers 4.9s, CPU usage #7790 3.3s (a fixed 3s sleep), timers-fixture-unref.js 2.3s (1.9s of it loading test/js/node/test/common), plus 21 child processes started one after another.
  • The ASAN RSS check in the leak fixture guards nothing: with the timers: release heap ref when setTimeout is cleared or refreshed inside its own callback #30058 leak reintroduced locally, the old fixture reports a 138.3 MB delta under debug+ASAN against 139.9-142.0 MB without the leak. Freed blocks stay resident in the ASAN quarantine, so RSS moves the same either way. On the ASAN lane the leaked TimeoutObjects are caught by LeakSanitizer at child exit, which does not care how many timers the fixture creates.

Fix

  • Leak fixture: takes a batch count and prints a JSON report. Every build without ASAN (release, and debug builds on Windows / x64 macOS) keeps the old workload (100 measured batches) and the 10 MB bound, so those configurations check exactly what they checked before. ASAN builds run one batch per mode and the test enables LeakSanitizer for the child itself (the same three variables the CI runner sets for the ASAN lane, with the same print_suppressions=0, since a structural leak covered by leaksan.supp would otherwise be listed on stderr), so bun bd test on Linux and arm64 macOS detects the leak too. All builds additionally assert the workload ran, protectedTimeouts === 0, and that fewer than 100 Timeout wrappers survive the final GC (2-4 observed; retention leaves thousands). Timeout 90s -> 60s (the non-ASAN debug configuration needs ~10s).
  • One setTimeout-unref-fixture.js replaces seven fixtures (five spawnSync tests and the two Returning a Promise tests): every scenario is armed at once and the exit handler reports how often each callback ran; the test asserts the exact report. Node prints the identical report. Making one unref() ineffective changes two counts, so a regression is a diff, not a hang. The one scenario that cannot share a process, unref().ref() keeping the loop alive (any other ref'd timer would mask a no-op ref()), stays a separate child (setTimeout -> unref -> ref works, a -e script that exits 1 unless the re-ref'd timer runs; verified to exit 1 with Timeout.prototype.ref replaced by a no-op).
  • Related open PRs touching the leak fixture, none of which this depends on: test: surface ASAN status to leak fixtures via bunEnv #35081 fixes the bun-asan name check in this and ten other fixtures by widening the ASAN RSS bound, which per the measurement above still cannot distinguish a leak under ASAN; Have condition-gated drive loops ref the event loop so unref'd timers fire without spinning #32014 and timers: root the event-loop-delay histogram, fix aliased-&mut in timer drain, arm uv timer on the owning VM's loop #31837 carry small edits to the same fixture. If the release-RSS / ASAN-LeakSanitizer split here is the policy wanted for the other fixtures, the environment block belongs in test/harness.ts next to isASAN; it is kept local here so this PR stays a single-file change.
  • CPU usage #7790: the child measures its own CPU over a 300ms window with a far-off timer pending and the test asserts under 50%, the shape of the epoll test below it. Spinning reads ~100%, idle reads ~0.2% release / ~3% debug+ASAN, and the bound no longer includes startup cost. Subprocess.resourceUsage(), which this test was the main exerciser of, is still checked: total === user + system, and total is at least the process.cpuUsage() total the child printed before exiting (same kernel counters read later).
  • timers-fixture-unref.js (shared with setInterval.test.js): mustCall inlined with the same contract; a mismatch prints the call site and exits 1. 2.3s -> 0.35s on debug.
  • Child-spawning tests that measure nothing are it.concurrent, in two groups; the CPU and latency tests stay sequential and, since bun starts a sequential test only after the preceding concurrent group drains, still run alone. The protected-count test stays sequential as well.
  • Refresh tests await the fires they check instead of sleeping 100-300ms, assert each refresh() return value and the exact fire counts, and assert from the test body. The "no extra fire" checks rest on deadline order (a wrong re-arm is due before the timer the test waits on), not on margins.
  • All children go through bunRun/toSpawn: stderr exactly empty (the WARNING: ASAN interferes filter matched text no current build prints; other tests here already asserted ""), stdout compared exactly. The quantization and GC children use console.log; process.stdout's lazy setup is ~0.9s per child on debug. The GC test's workload and bound are unchanged since its thin margin is against the unfixed numbers.
  • Verification (Linux x64 unless noted):
    • bun bd test test/js/web/timers/setTimeout.test.js (debug+ASAN): 152.4s / 162.9s with 3 failures before; 12.3-14.9s, 30-31 pass, over eleven runs after (the slower runs had other work going on in the container; the head adds one test).
    • Windows x64 debug build, which is not ASAN (bun bd test there): 40.7s on main, 14.8s on this branch, 27 pass + 3 Linux-only skips; the leak modes take 8.6-10.6s each and overlap. With the timers: release heap ref when setTimeout is cleared or refreshed inside its own callback #30058 leak reintroduced in that build the fixture reports rssDeltaMB 100.1-100.9 against 1.1-1.9 clean, with liveTimeouts/protectedTimeouts unchanged, so the RSS bound is the detector there and heapStats indeed cannot be.
    • Same with the ASAN lane's environment (detect_leaks=1, test/leaksan.supp, BUN_DESTRUCT_VM_ON_EXIT=1, --timeout 270000): 30 pass in 14.0s, every child LeakSanitizer-clean.
    • USE_SYSTEM_BUN=1 bun test ... (release, full leak workload and RSS bound): 6.27s before, 2.0-2.4s after.
    • Child processes: 21 before, all serial; 16 after, 6 of them serial.
    • CI, build 96032 (per-file cost from the shard logs, the way scripts/update-test-durations.mjs measures it; test/expected-durations.json has the file at 32.3s asan / 7.5s default / 5.9s windows): 7.4s on the asan lane, 6.3s on debian x64, 1.6s on windows x64. As the modified file it ran first on its shards, so the two Linux numbers include ~4.3-4.5s of shard start-up before the first test finished; the tests themselves span 3.0s (asan) and 1.8s (debian) of those.
    • timers: release heap ref when setTimeout is cleared or refreshed inside its own callback #30058 leak reintroduced in timer_object_internals.rs (reverted before pushing): all three leak tests fail on bun bd test (debug+ASAN) with Direct leak of 960000 byte(s) in 2000 object(s) from TimeoutObject::init_with / All::set_timeout.
    • setInterval.test.js: the shared fixture passes on debug and release; its doesn't leak memory test times out on debug exactly as on main (test(timers): speed up setInterval.test.js and tighten its assertions #35750 covers it).
    • Windows x64, release canary (USE_SYSTEM_BUN=1, test-only change so no build needed): 27 pass, 3 skip (the Linux-only epoll tests), 1.43s, stable over five runs; the leak fixture at the full workload reports rssDeltaMB 0.7-0.8 and liveTimeouts 3-4 there, and the unref fixture prints the same report as on Linux and node.

Background

  • ASAN quarantine: AddressSanitizer holds freed blocks (256 MB by default) so later use-after-free is caught; they stay in RSS, so under ASAN freeing and leaking a small object look the same to an RSS delta.
  • LeakSanitizer: part of the ASAN runtime; at exit it reports heap blocks nothing points to and exits non-zero. scripts/runner.node.mjs turns it on (detect_leaks=1 plus test/leaksan.supp) for every test file not listed in test/no-validate-leaksan.txt, and children spawned with bunEnv inherit it. BUN_DESTRUCT_VM_ON_EXIT=1 tears the VM down first, which is what makes the exit scan take ~0.1s instead of ~3s on a debug build.
  • TimeoutObject: the refcounted native box behind a JS Timeout. timers: release heap ref when setTimeout is cleared or refreshed inside its own callback #30058 left one refcount behind when a callback cleared/refreshed/converted its own timer, so the box (~100 bytes on release, ~500 on debug builds) leaked while the JS wrapper was still collected; heapStats therefore cannot see that leak, RSS or LeakSanitizer is needed.
  • Concurrent groups: consecutive it.concurrent tests run together; a plain it starts after the group finishes (src/runtime/test_runner/Execution.rs). CI runs files with --timeout 90s (270s on ASAN), so the 5s default only applies when running a file by hand.
  • bunRun/toSpawn (test/harness.ts): spawn bun with bunEnv; toSpawn(expected?) asserts exit 0, empty stderr and optionally the exact trimmed stdout, printing both streams on failure.
Per-test debug-build timings, before -> after
test before after
leak fixture x3 40.4-51.0s each, serial, failing 1.35-1.6s each, concurrent (8.6-10.6s each on a debug build without ASAN)
GC of many id-accessed timers 4.89s 4.15-4.4s
CPU usage #7790 3.31s 0.64s
canceling with unref, close, _idleTimeout, _onTimeout 2.28s 0.35-0.53s
five spawnSync tests + two promise fixtures 7 children, ~2.1s serial 1 child, 0.35s
setTimeout(1) quantization 1.22s 0.40-0.44s
four refresh tests 0.88s serial 0.17s concurrent
fire -> unref -> ref x2 0.67s serial concurrent with the above

Release (USE_SYSTEM_BUN=1) leak fixture at the unchanged 100-batch workload: rssDeltaMB 0-1, liveTimeouts 3-4, protectedTimeouts 0, 0.25-0.43s per mode.

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.
@coderabbitai

coderabbitai Bot commented Aug 14, 2026

Copy link
Copy Markdown
Contributor

Warning

Review limit reached

@robobun, you've reached your PR review limit, so we couldn't start this review.

Next review available in: 1 minute

Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available.
You're only billed for reviews past your plan's rate limits ($0.25/file).

How can I continue?

After more reviews become available, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews.

How do review limits work?

CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability.

For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window.

Please refer docs for additional details.

Review details
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: ASSERTIVE

Plan: Pro

Run ID: 0a76f963-a313-417d-8b2b-7821194ac63a

📥 Commits

Reviewing files that changed from the base of the PR and between 032b8db and 1ab6620.

📒 Files selected for processing (11)
  • test/js/web/timers/setTimeout-clear-in-callback-leak-fixture.js
  • test/js/web/timers/setTimeout-cpu-fixture.js
  • test/js/web/timers/setTimeout-unref-fixture-2.js
  • test/js/web/timers/setTimeout-unref-fixture-3.js
  • test/js/web/timers/setTimeout-unref-fixture-4.js
  • test/js/web/timers/setTimeout-unref-fixture-5.js
  • test/js/web/timers/setTimeout-unref-fixture-6.js
  • test/js/web/timers/setTimeout-unref-fixture-7.js
  • test/js/web/timers/setTimeout-unref-fixture.js
  • test/js/web/timers/setTimeout.test.js
  • test/js/web/timers/timers-fixture-unref.js

Comment @coderabbitai help to get the list of available commands.

@robobun

robobun commented Aug 14, 2026

Copy link
Copy Markdown
Collaborator Author

Status: ready for review (head 1ab6620). CI: builds 96032 and 96314 are green on every lane that ran (the listed red is retried flakes in unrelated files); the two darwin 14 aarch64 shards expired without ever getting an agent, which is happening to every build in the pipeline right now, so macOS has not run in CI for this PR (the file was run by hand on Linux and Windows, see below). Per-file cost on the asan lane in CI: 7.4s, of which ~4.3s is shard start-up because the modified file runs first (32.3s in test/expected-durations.json); 6.3s on debian x64, 1.6s on windows.

Reproduced the slowness locally with bun bd test test/js/web/timers/setTimeout.test.js (debug+ASAN, Linux x64): 152.4s and 162.9s, with the three leak tests failing at 40-51s each. With this branch the same command takes 12.3-14.9s (all pass), 14.0s with the ASAN lane's LeakSanitizer environment, USE_SYSTEM_BUN=1 (release) goes from 6.27s to 2.0-2.4s, and a Windows x64 debug build (no ASAN) goes from 40.7s on main to 14.8s. Child processes 21 -> 16, serial ones 21 -> 6.

The leak fixture was also checked against the bug it guards, with the #30058 leak put back into timer_object_internals.rs locally: on the debug+ASAN build all three leak tests fail with a LeakSanitizer report naming TimeoutObject::init_with; on the Windows debug build (RSS path) the fixture reports ~100 MB against 1-2 MB clean. The old fixture's RSS delta under ASAN was the same with and without the leak (138 MB vs 140-142 MB).

Review follow-ups so far: ceb7258 keeps the RSS check on every build without ASAN (review comment above); 1ab6620 gives the unref().ref() keep-alive check its own process again, since other ref'd timers in the combined fixture would have masked a no-op ref(), and adds print_suppressions=0 to the LeakSanitizer fallback. Details in the PR description.

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.
Comment thread test/js/web/timers/setTimeout.test.js Outdated
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.
@robobun

robobun commented Aug 14, 2026

Copy link
Copy Markdown
Collaborator Author
Updated 7:05 AM PT - Aug 14th, 2026

@robobun, your commit ceb7258 has some failures in Build #96032 (All Failures)


🧪   To try this PR locally:

bunx bun-pr 38493

That installs a local version of the PR into your bun-38493 executable, so you can run:

bun-38493 --bun

@claude claude Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM — the follow-up commit (ceb7258) addresses the debug-without-ASAN gap: the RSS check is now keyed on !isASAN alone, so Windows and x64-macOS debug builds run the full 100-batch workload against the 10 MB bound, and the comment above the block now names that configuration explicitly.

What was reviewed:

  • Traced each of the seven deleted setTimeout-unref-fixture-*.js scenarios to a counter in the consolidated fixture; the exact-count report preserves (and in the this-binding case strengthens) what each old fixture asserted.
  • Verified bunRun/toSpawn in test/harness.ts match the usage here (array argv, env spread over bunEnv, exit-0 + empty-stderr + optional exact-trimmed-stdout).
  • Checked that dropping the isLinux guard on leakFixtureEnv (now purely isASAN) is safe for arm64-macOS ASAN builds; verifier agents ruled this out independently.
Extended reasoning...

Overview

Test-only refactor of test/js/web/timers/setTimeout.test.js and its fixtures: consolidates seven setTimeout-unref-fixture-*.js files into one exit-report fixture, rewrites the #30058 leak fixture to print a JSON report and use LeakSanitizer under ASAN / RSS otherwise, replaces the fixed-3s CPU test with a self-measured 300 ms window, inlines a minimal mustCall in timers-fixture-unref.js to avoid ~2 s of Node-common loading, converts the sleep-based refresh tests to await-the-condition, and moves independent subprocess tests to it.concurrent. No runtime code touched.

Delta since my prior review

My earlier inline comment flagged that the branching leakFixtureMeasuresRss = !isASAN && !isDebug left debug builds without ASAN (Windows, x64 macOS) with neither the RSS bound nor LeakSanitizer. Commit ceb7258 changes the gate to leakFixtureBatches = isASAN ? 1 : 100 and if (!isASAN) expect(rssDeltaMB).toBeLessThan(10), so those builds now run the full workload with the RSS check restored. The block comment was rewritten to name all three configurations, the fixture header documents the ~100 MB debug-no-ASAN leak signature, the per-test timeout was raised to 60 s to cover the 8-10 s debug run, and the now-unused isDebug import was dropped. This fully resolves the concern.

Security risks

None — no auth, crypto, network, or parsing of untrusted input; changes are confined to test fixtures and assertions.

Level of scrutiny

Medium. The diff is large (~500 lines) and reshapes how a leak regression is detected, which is safety-net-adjacent, but it ships no runtime code. I focused on whether every deleted assertion still has an equivalent-or-stronger replacement: each old fixture's exit-code/stdout invariant maps to a specific key in the new fixture's exact-count JSON report; the leak fixture keeps the release-build 100-batch/10 MB check unchanged and adds liveTimeouts/protectedTimeouts assertions on top; the CPU test still exercises Subprocess.resourceUsage() with a tighter invariant (total = user + system and total ≥ lifetimeCpuUs); the refresh tests now assert exact fire counts rather than toBeGreaterThanOrEqual.

Other factors

The PR description documents extensive verification (ten debug+ASAN runs, ASAN-lane env, release, Windows release canary, and reintroducing the #30058 leak to confirm all three modes fail with a TimeoutObject::init_with LSAN report). bunRun/toSpawn semantics in test/harness.ts match every call site. The bug-hunting system found no issues this run, and the one candidate it examined (dropping the isLinux guard on leakFixtureEnv) was refuted.

…cess

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.

@claude claude Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM — the debug-without-ASAN gap I flagged earlier is addressed in ceb7258 (RSS check now keyed on !isASAN alone, verified on a Windows debug build against the reintroduced #30058 leak), and 1ab6620 correctly keeps the unref().ref() keep-alive check in its own process.

What was reviewed:

  • Merged unref fixture: traced each of the seven deleted fixtures to a scenario in the new report; the one that must run alone (unref().ref()) is a separate -e test.
  • Leak fixture branching: non-ASAN builds keep the 100-batch / 10 MB RSS bound; ASAN builds get the same LSan env CI sets, with print_suppressions=0 so the empty-stderr assertion holds; test/leaksan.supp path resolves.
  • bunRun/toSpawn semantics in harness.ts match what the tests rely on (exit 0, stderr exactly empty, optional exact stdout).
  • Concurrent grouping: the in-process heapStats protected-count test and the CPU/latency tests stay sequential between the two concurrent groups.
Extended reasoning...

Overview

Test-only change to test/js/web/timers/setTimeout.test.js and its fixtures: consolidates seven single-scenario unref fixtures into one that reports per-scenario callback counts, moves the leak fixture's assertions into the test (JSON report) with the RSS bound applied on every non-ASAN build and LeakSanitizer enabled for the child on ASAN builds, replaces the fixed 3s CPU sleep with a 300 ms self-measured window, rewrites the four refresh tests to await fires instead of sleeping, inlines a minimal mustCall in timers-fixture-unref.js, and marks the subprocess-spawning tests it.concurrent in two groups with the CPU/latency/heapStats tests kept sequential between them. No production code is touched.

Security risks

None. Test-only; child processes are spawned via bunRun with bunEnv; the only added env is ASAN/LSAN options and BUN_DESTRUCT_VM_ON_EXIT for the leak fixture, mirroring what scripts/runner.node.mjs already sets on the ASAN lane.

Level of scrutiny

Moderate — it rewrites tests that guard specific past regressions (#30058, #7790, epoll EINTR, id-map GC), so the check is that each rewritten test still catches the bug it was written for. The PR description and follow-up commit provide direct evidence for the load-bearing ones: #30058 reintroduced locally fails all three leak tests on debug+ASAN via LSan and on a Windows debug build via the 100 MB vs 1-2 MB RSS delta; the CPU test's 50% bound sits between ~0.2-3% idle and ~100% spinning; the merged unref fixture prints the identical report under Node.

Other factors

My earlier review (the debug-no-ASAN configuration ending up with neither RSS nor LSan) was acknowledged and fixed in ceb7258 with measurements on the platform in question, and the thread is resolved. I confirmed bunRun merges the extra env over bunEnv and toSpawn asserts exit 0 + empty stderr (+ exact stdout when given), which is what the tightened assertions depend on. The concurrent-group placement leaves the in-process heapStats().protectedObjectTypeCounts test and the timing-sensitive CPU/quantization/GC tests sequential, so they still run alone. The bug-hunting pass found nothing, and CI build 96032 shows the file at 7.4s (asan) / 6.3s (debian) / 1.6s (windows) versus 32.3s / 7.5s / 5.9s in expected-durations.json.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant