Skip to content

test(serve): speed up serve.test.ts (~34s to ~16s release) and tighten its assertions - #39042

Open
robobun wants to merge 1 commit into
mainfrom
farm/07dbff6f/speed-up-serve-test
Open

test(serve): speed up serve.test.ts (~34s to ~16s release) and tighten its assertions#39042
robobun wants to merge 1 commit into
mainfrom
farm/07dbff6f/speed-up-serve-test

Conversation

@robobun

@robobun robobun commented Aug 15, 2026

Copy link
Copy Markdown
Collaborator

Problem

  • test/js/bun/http/serve.test.ts takes 25-33s on every CI lane (33s on debian x64 ASAN in build 97275, 25s on the aarch64 release lane), so most of the time is waiting, not running.
  • Release profile before (34.4s locally): should reset timeout after writes 15.0s, allow custom timeout per request 10.0s, should allow use of custom timeout 6.5-8s. They are in one it.concurrent group, so they cost ~15s of wall clock on every lane. Each one slept for a fixed 10-15s on top of uSockets' 4s timeout sweep.
  • Next in line: the two 1000 uploads & downloads ... do not leak ReadableStream cases (2.0s + 2.2s release, 23s + 25s in this container's debug build). Each of their requests asked for a full collection twice: Bun.gc(false) and, under the BUN_GARBAGE_COLLECTOR_LEVEL=1 that the CI runner sets, the per-request expect() (every matcher schedules a collection in that mode). That was ~40% of their time; the loop also ran 1024 requests, not the 1000 it asserts on.
  • Then the request body backpressure describe (6 cases, ~0.4s each, all of it waiting for an upload to plateau), the two proxying RSS cases (1.1s + 0.7s, each a subprocess with a fixed 500ms stall) and four subprocess-only tests right after the timeout group, all running one after another.
  • Weak spots in the same tests: request body and signal life cycle ended in expect().pass(), the timeout tests had unawaited .resolves / .rejects assertions, and the leak test stopped at the first wrong digest.

Fix

  • Timeout tests: uSockets checks timeouts once every 4s and arms them in whole sweeps (idleTimeout 1..4 fires at the next sweep, 5..8 at the one after), so each test now leaves one request unanswered and waits for the server to close it instead of sleeping:
    • should allow use of custom timeout (idleTimeout: 1): the stalled streaming response must be closed (client sees ECONNRESET, server sees req.signal abort); /ok is then served right after that sweep, so it has a whole sweep interval to complete and also shows the server still works after timing a request out.
    • should reset timeout after writes (idleTimeout: 5, two sweeps, because a one-sweep timeout fires at the next sweep whether or not a write re-armed it): the stream writes every 100ms; an unanswered canary is opened only after the stream has started, so its timeout is armed no earlier than the stream's. Once the canary is closed, the stream has outlived the sweep that would have closed it without the resets. The test then stops the stream itself and checks status, that the stream request was never aborted, and that the body holds exactly the chunks that were written.
    • allow custom timeout per request (idleTimeout: 1, server.timeout(req, 60)): the canary is opened after the long request has raised its own timeout; once the canary is closed the long request must still be unaborted, and is only then released and checked for status and body.
    • In both canary tests the release is driven from the test body after the client has seen the canary fail. Releasing from the canary's server-side abort event does not work: that event fires inside the sweep, the handler's response is written before the sweep reaches the other socket, and the write re-arms it (verified: that variant passed with server.timeout() removed).
    • Each rewritten test was checked against the regression it guards by removing the behaviour under test (stream writes removed; server.timeout() call removed): both variants fail at the toBe(false) abort assertions, at the same sweep that closes the canary. Output in the details below.
    • The group now takes one or two sweeps: 4-8s depending on the sweep phase (5.9s in the release run below, 0.3s / 1.1s / 4.5s for the three tests in the debug run). The 4s sweep period is the floor for this approach; test(fetch): speed up fetch.test.ts (~30s to ~12s release) and tighten its assertions #38470 does the same for fetch.test.ts. The original per-test timeouts (15s / 20s / 20s) are kept, which also leaves room if Bun.serve: make idleTimeout a floor so it never fires early #33610 adds a sweep to every timeout.
  • Leak test: collects every fourth completed request (so collections still happen while the rest of the batch is in flight), runs exactly count requests, and asserts { completed, wrongDigests } once at the end. The post-GC ReadableStream count assertion is unchanged. This is where the file's expect() count drops (3802 to 1759).
  • Concurrency: the four subprocess-only tests after the timeout group are it.concurrent and so join that group (they finish inside its sweep wait); request body backpressure is describe.concurrent (each case has its own server and socket, and a plateau check can only end early if the upload stops, which is the property under test); the RSS pair is it.concurrent.each (separate subprocesses, RSS is per process), with its explicit timeout raised from 10s to 15s since the two fixtures now share the CPU. The other plateau tests move 32-128MB each on the test thread, so they were left sequential: concurrently they were not faster in the debug build, only closer to the 5s local default timeout.
  • Assertions: life cycle test checks all 640 responses are 200 (bodies are still left unread, which is what the test exercises); timeout tests check status and body via one toEqual, the unanswered request's code: "ECONNRESET" (also for the stalled stream, matching what fetch: reject network errors as TypeError('fetch failed' / 'terminated') with the system error as cause #35988 proposes for that line) and that the request under test was not aborted; leak test reports the request count and every wrong digest.
  • Verified (this container; debug builds here are several times slower than CI):
    • bun bd test test/js/bun/http/serve.test.ts: 141.3s before, 111.6s after. With the CI runner's env (BUN_GARBAGE_COLLECTOR_LEVEL=1, BUN_JSC_randomIntegrityAuditRate=1.0): 155.1s before, 121.6s after.
    • USE_SYSTEM_BUN=1 bun test test/js/bun/http/serve.test.ts (release): 34.4s before, 16.2s and 16.3s after.
    • The tests touched here plus the rest of their concurrent group, 6 runs in a loop on the debug build: green every time (timeout tests landing anywhere between 0.3s and 2.5s / 4.5s and 6.9s depending on sweep phase).
    • The failing set is identical before and after and is this container's environment: server.requestIP > v6 (no IPv6), root range port(#7187) (running as root), #6583 (localhost resolves to the other family than the server bound), only serves /bun:info to loopback clients (egress proxy). The release binary additionally fails reload() that drops the node:http handler, which needs serve: add ServerConfig.is_node_http_server and key the node:http lifecycle paths on it #38755 and passes on the debug build.
  • it.concurrent(name, fn) with a title longer than prettier's line width re-indents the does not dispatch a pipelined request ... test; git diff -w shows the real changes (124 insertions, 77 deletions).
  • Of the 54 open PRs that touch this file, 52 still apply on top of this branch exactly as they do on main (checked by applying each PR's serve.test.ts patch to both versions). The two that do not, Bun.serve: make idleTimeout a floor so it never fires early #33610 and fetch: reject network errors as TypeError('fetch failed' / 'terminated') with the system error as cause #35988, both edit the assertions of the old should allow use of custom timeout test that this PR rewrites; the code-based assertion here already covers what fetch: reject network errors as TypeError('fetch failed' / 'terminated') with the system error as cause #35988 changes that line to.

Background

  • Bun.serve's idleTimeout and server.timeout(req, s) are uSockets socket timeouts. uSockets only walks its sockets every LIBUS_TIMEOUT_GRANULARITY (4) seconds and us_socket_timeout(s, seconds) stores now_tick + ceil(seconds / 4), so a 1s timeout fires at the next sweep (0-4s later, exactly 4s when this test's sockets are the ones that start the sweep timer) and a 5s one at the second sweep. Every write to the response re-arms the socket with the same value, which is what should reset timeout after writes tests and why it needs a two-sweep value. When a timeout fires uSockets force-closes the socket; a pending request sees req.signal abort and Bun's fetch() rejects with code: "ECONNRESET" (the ConnectionClosed mapping in FetchTasklet.rs), whether or not the head had been sent.
  • A request opened after another one has its timeout armed at the same tick or later, so "request B was closed by its timeout" implies "a sweep ran that would also have closed request A unless A's timeout had been reset or raised". That is the only ordering the rewritten tests rely on; they do not depend on the length of a tick.
  • Bun's fetch() retries an idempotent request once if a pooled keep-alive connection closes under it, but never on a fresh connection (allow_retry is only set when a pooled socket is reused, HTTPContext.rs). Each server here is new and its first connection is still busy when the canary is sent, so the canary always uses a fresh connection and its close is reported, not retried.
  • it.concurrent tests run together with the it.concurrent / describe.concurrent tests declared directly before and after them; a plain it in between is a barrier, and so is the end of a describe block (checked with a small probe file: tests declared after a describe block closes start a new batch, .each does not). That is why the four subprocess tests, which follow the timeout group at top level, join it, while the backpressure describe and the RSS pair each form their own batch. The CI runner passes --timeout=90000 (x3 on ASAN), and an explicit per-test timeout overrides that, which is why the only explicit timeout on a newly concurrent test was raised rather than added anywhere else.
Simulated regressions, debug build

Stream writes removed from should reset timeout after writes, and server.timeout(req, 60) removed from allow custom timeout per request (the real tests were run in the same file for comparison):

error: expect(received).toBe(expected)
Expected: false
Received: true
(fail) MUTATION per-request (must fail) [4134.84ms]
(pass) allow custom timeout per request [4224.84ms]
(pass) should allow use of custom timeout [4401.60ms]
error: expect(received).toBe(expected)
Expected: false
Received: true
(fail) MUTATION reset (must fail) [8103.94ms]
(pass) should reset timeout after writes [8189.55ms]

The earlier variant that released the long request from the canary's server-side abort event passed without server.timeout(), which is why the release now comes from the test body after the client has observed the canary's failure.

Release profile after (16.3s total)
5873ms  should reset timeout after writes            (group wall clock; the other two landed at ~1.9s in the same run)
1937ms  1000 uploads ... > direct
1835ms  1000 uploads ... > default
1108ms  bounds memory ... chunked                    (runs together with content-length, 728ms)
1063ms  request body backpressure > Bun.write        (the describe's 6 cases run together)
 349ms  type: direct stream awaiting flush(true) ...
 340ms  resumes a backpressured Response(ReadableStream) ...
 338ms  applies backpressure to a Response(ReadableStream) body ...

What is left is the 4-8s sweep floor of the timeout group, ~3.8s of the two leak cases (768KB uploaded and hashed per request; their payload size is what makes the request body arrive in more than one chunk, so it was left alone), and ~4s spread across the remaining ~280 tests.

The three idleTimeout tests slept for a fixed 10-15s on top of uSockets'
4s timeout sweep and dominated the file on every lane. They now leave
one request unanswered on purpose and wait for the server to close it:
a request opened after the one under test has its timeout armed no
earlier, so its close proves the tested request survived a sweep it
would otherwise not have. The concurrent group they belong to drops
from ~15s to one or two sweeps (4-8s).

The ReadableStream leak test asked for a full collection after every
one of its 1000 requests (explicitly, and again through the per-request
expect() under BUN_GARBAGE_COLLECTOR_LEVEL), which was about 40% of its
time; it now collects every fourth request and checks the digests once.
It also ran 1024 requests instead of the 1000 it reports.

Independent tests that only spawn a subprocess, or that spend their time
waiting for an upload to plateau, run concurrently: the four subprocess
tests next to the timeout group, the request body backpressure describe
and the two proxying RSS cases.

Assertions: the React life cycle test checks that all 640 responses are
200 instead of expect().pass(); the timeout tests check status, body,
that the request under test was not aborted server-side and that the
unanswered one was closed with ECONNRESET; the leak test reports every
wrong digest and the request count.

Locally: bun bd test 141.3s -> 111.6s (155.1s -> 121.6s with the CI
env), release 34.4s -> 16.2s.
@coderabbitai

coderabbitai Bot commented Aug 15, 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: 2 minutes

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: 7a3d322b-77b8-42fd-b3e4-1f7d17b53c3c

📥 Commits

Reviewing files that changed from the base of the PR and between 88a6398 and 1092f82.

📒 Files selected for processing (1)
  • test/js/bun/http/serve.test.ts

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

@robobun

robobun commented Aug 15, 2026

Copy link
Copy Markdown
Collaborator Author
Updated 12:00 PM PT - Aug 15th, 2026

@robobun, your commit 1092f82 has some failures in Build #98079 (All Failures)


🧪   To try this PR locally:

bunx bun-pr 39042

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

bun-39042 --bun

@robobun

robobun commented Aug 15, 2026

Copy link
Copy Markdown
Collaborator Author

Status: test-only change, measured locally on the same binaries before and after.

run before after
bun bd test test/js/bun/http/serve.test.ts (debug + ASAN) 141.3s 111.6s
same, with the CI runner's env (BUN_GARBAGE_COLLECTOR_LEVEL=1) 155.1s 121.6s
USE_SYSTEM_BUN=1 bun test ... (release) 34.4s 16.2s

Dominant before: the three idleTimeout tests (~15s of wall clock as one concurrent group on every lane), then the two ReadableStream leak cases. Same four environment-specific failures in this container before and after (IPv6, root port, localhost family, egress proxy); everything touched here passes on both builds. The rewritten timeout tests were checked against simulated regressions (details in the PR description). CI timing for the file on this PR's build will be added here once it has run.

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

I reviewed this PR and didn't find any bugs. The three timeout tests are rewritten around uSockets' 4s sweep semantics (canary request instead of fixed sleep) — the reasoning is thorough and mutation-tested, but since these guard real regressions and the correctness depends on sweep-ordering and fetch-retry assumptions, a human sign-off on the new approach would still be worthwhile.

What was reviewed:

  • Timeout rewrites: canary is opened after the tested request's timeout is armed, release happens from the test body after the client observes the canary close — checked this preserves the invariant each test guards.
  • Leak-test loop: now runs exactly count requests (was 1024), post-GC ReadableStream count assertion is unchanged.
  • New it.concurrent / describe.concurrent blocks: each has its own server/subprocess, no shared mutable state between them.
  • request body and signal life cycle: bodies still intentionally unread, now asserts all 640 statuses instead of expect().pass().
Extended reasoning...

Overview

Test-only change to test/js/bun/http/serve.test.ts (~124 insertions, ~77 deletions ignoring whitespace). No production code is touched. The PR:

  • Rewrites three idleTimeout / server.timeout() tests to await a canary request's server-side close instead of sleeping 10-15s, cutting the concurrent group's wall clock from ~15s to one or two 4s uSockets sweeps.
  • Reduces per-request GC in the 1000 uploads & downloads leak test (every 4th completion instead of every request), fixes the loop to run exactly 1000 requests instead of 1024, and moves the digest assertion to a single toEqual at the end.
  • Replaces expect().pass() in the request-body/signal life-cycle test with a status check on all 640 responses.
  • Marks four subprocess-only tests, the request body backpressure describe, and the proxying-RSS pair as concurrent; raises the RSS pair's per-test timeout from 10s to 15s to account for shared CPU.
  • One test body is re-indented by prettier due to the longer it.concurrent(...) wrapper; no logic change there.

Security risks

None. This is a test file; no auth, crypto, or user-facing surface is touched.

Level of scrutiny

Medium-high despite being test-only. REVIEW.md is explicit that weakening or de-flaking a test must keep asserting the property the original protected, and that a correct-but-slow test still gets changes-requested — so speed-ups are welcome, but the timeout tests here are rewritten around a non-obvious invariant ("a canary opened after request A has its timeout armed no earlier, so its close proves A survived a sweep it otherwise would not have"). The author has mutation-tested both rewritten tests (removing the stream writes / removing server.timeout()) and shown they fail at the expected assertion, and has explained why releasing from the server-side abort event would produce a false pass. That is exactly the verification the review guide asks for. Still, the approach depends on uSockets sweep ordering, fetch() never retrying on a fresh connection, and it.concurrent grouping semantics — all documented in the PR body, but subtle enough that a maintainer familiar with the uSockets layer should confirm.

Other factors

  • The bug-hunting system found no issues.
  • The newly-concurrent tests each own their server or subprocess; the request body backpressure describe's plateau check is per-socket and the RSS pair measures per-subprocess RSS, so concurrency does not share state that could cross-contaminate results. The four subprocess tests moved to it.concurrent are pure spawn-and-assert with no shared globals.
  • The leak test's core assertion (ReadableStream count after Bun.gc(true)) is unchanged; only the in-loop GC cadence and the digest reporting changed.
  • Unawaited .resolves/.rejects in the old timeout tests are now properly awaited, and the stalled-stream error is asserted as { code: "ECONNRESET" } rather than a message regex — both are strict tightenings.
  • CI build #98079 was still running at review time; given the timing-sensitive nature and the number of newly-concurrent tests, the cross-platform CI results are the real gate here and worth a human check before merge.

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