Skip to content

bun test --reporter=junit: print testcase time straight from the nanosecond count - #39276

Open
robobun wants to merge 1 commit into
mainfrom
farm/5e9a316a/junit-trimmed-precision
Open

robobun wants to merge 1 commit into
mainfrom
farm/5e9a316a/junit-trimmed-precision

Conversation

@robobun

@robobun robobun commented Aug 16, 2026 •

Copy link
Copy Markdown
Collaborator

Problem

  • bun test --reporter=junit can emit <testcase ... time="0." ...>, a bare trailing dot, for any testcase whose measured duration is above 0 but below half a microsecond. On the released 1.4.0 the (unnamed) hook entries of a describe.skip containing a beforeAll hit it on every run (50 of 50 in the probe below); exactly 0ns prints time="0" and longer durations print e.g. time="0.00003".
  • Cause: write_test_case (src/runtime/cli/test_command.rs) divides elapsed_ns by 1e6 and then by 1000. The double rounding makes the value print with noise under {} (30us comes out as 0.000029999999999999997, about a quarter of all nanosecond counts are affected), so the line goes through bun_fmt::trimmed_precision::<6> (src/bun_core/fmt.rs) to hide that. That formatter prints the truncated whole part and then unconditionally writes "." followed by the remainder's {:.6} digits with trailing zeros trimmed; a remainder that rounds to 0.000000 leaves "0.", and one that rounds up to 1.000000 loses the carry (0.9999996 prints as "0.").
  • write_test_case is the formatter's only caller. The sibling time attributes (<testsuite> in end_test_suite, <testsuites> in write_to_file and in test/parallel/aggregate.rs) already divide the nanosecond count by NS_PER_S once and print it with {}, and come out clean (time="0.004340491" in the probe below).

Fix

  • write_test_case now computes elapsed_ns as f64 / NS_PER_S as f64 and prints it with {}, the same expression the suite attributes use. trimmed_precision loses its only caller and is deleted.
  • Why this is correct: a single division of an exact integer by 1e9 yields the double nearest to a decimal with at most nine fractional digits, and {} prints the shortest representation that round-trips, which is that decimal. So the output is exactly elapsed_ns with the decimal point moved nine places, trailing zeros already absent, never a bare dot, never exponent notation (Rust's Display for floats does not use it), and 0 for 0ns. A standalone check over every count from 0 to 3,000,000ns and 2,000,000 sampled counts up to 48 hours produced no output outside ^\d+(\.\d{1,9})?$; the two-step division produced 17-digit noise for 755,899 of the first 3,000,001.
  • Observable change besides the bug: testcase times are now reported at the clock's resolution (up to nine fractional digits) instead of being rounded to six, matching the suite attributes in the same report. Nothing in the repo pins six digits: the JUnit snapshots strip time=, scripts/runner.node.mjs reads only <testsuite> times via [\d.]+, and the docs state no precision.
  • Tests, in test/js/junit-reporter/junit.test.js: one run whose report mixes zero, measured and sub-microsecond durations, asserting every time attribute on every element matches ^\d+(\.\d{1,9})?$ (rejects both the bare dot and double-rounding noise) and that the skipped entries print 0; and, on Linux (whose CLOCK_MONOTONIC is nanosecond-granular; other platforms' clocks may not be), that at least one of twelve running tests keeps sub-microsecond digits, which the six-digit path can never produce.
    • bun bd test test/js/junit-reporter/junit.test.js: 10 pass.
    • Same command with the two src/ files at main: the sub-microsecond test fails (Expected: true, Received: false), the other 9 pass.
    • bun bd test test/regression/issue/26851.test.ts and the four --reporter=junit cases in test/cli/test/parallel.test.ts pass.
    • cargo check -p bun_core, cargo clippy -p bun_core, cargo fmt --check clean; bun test test/internal/source-lints/: 166 pass.
  • Out of scope, handed off separately: the describe-level <testsuite time> is also wrong (Metrics::add does not sum elapsed_time, and each test is truncated to whole milliseconds before summing). That code is untouched here; bun test: record load errors and unhandled errors in the JUnit report #36218 is editing the neighbouring lines.

Background

  • JUnit's time attribute is a duration in seconds written as a plain decimal; consumers parse it as a float, so nine fractional digits are as valid as six.
  • elapsed_ns is the integer nanosecond count the test runner measures between a sequence starting and completing; entries that never start (skipped tests) report 0.
  • The (unnamed) entries in the probe are the hook entries describe.skip currently reports as testcases (bun:test: don't report beforeAll/afterAll as phantom '(unnamed)' tests in describe.skip/describe.todo #35502 removes them); they are only the easiest way to see sub-microsecond durations today, any fast enough testcase rendered the same way.
Probe: released bun 1.4.0, 50 describe.skip blocks each containing a beforeAll
$ bun test --reporter=junit --reporter-outfile=j.xml x.test.ts
$ grep -o 'time="[^"]*"' j.xml | sort | uniq -c
    100 time="0"
     50 time="0."
      1 time="0.010527884"
      1 time="0.004340491"

Same file with this branch (debug build):

    100 time="0"
      4 time="0.000000455"
      3 time="0.000000448"
      ...
      1 time="0.297068396"
      1 time="0.096280521"
Earlier version of this PR

The first push kept the formatter and fixed it (format the whole value with {:.6}, then trim), exposing it through bun:internal-for-testing to pin the edge cases. Reviewing it showed the formatter only exists to mask the call site's double division, which the sibling attributes avoid by construction, so this version removes the formatter instead of hardening it and needs no test hook.

@coderabbitai

coderabbitai Bot commented Aug 16, 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: 3 minutes

Limit details: You’ve used all 5 included reviews currently available under your plan.

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: dba77cfe-9f8d-4bc6-b260-8eaeba821045

📥 Commits

Reviewing files that changed from the base of the PR and between aec33f5 and 2b9c15d.

📒 Files selected for processing (3)
  • src/bun_core/fmt.rs
  • src/runtime/cli/test_command.rs
  • test/js/junit-reporter/junit.test.js

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

@robobun

robobun commented Aug 16, 2026 •

Copy link
Copy Markdown
Collaborator Author

Status: fix pushed (2b9c15d), waiting on CI.

Reproduced on the released bun 1.4.0 with 50 describe.skip blocks that each contain a beforeAll: every one of the 50 hook entries in the JUnit report rendered as time="0.".

The PR now prints the testcase time straight from the nanosecond count, the way the suite attributes already are, and deletes trimmed_precision (this was its only caller). Verified with test/js/junit-reporter/junit.test.js: with the two src/ files at main the sub-microsecond test fails and the rest pass; with the fix all 10 pass. The first push instead fixed the formatter and added a bun:internal-for-testing hook for it; superseded, see the PR description.

@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 rewrite formats once with {:.N} and trims, which eliminates the whole/remainder split that produced "0.", dropped the carry on 0.9999996, and mishandled negatives/NaN.

Reviewed:

  • Buffer bound: f64::MAX is 309 integral digits; 1+309+1+PRECISION ≤ 384 holds for the only caller (<6> in test_command.rs:691), and the const assert guards future PRECISION values.
  • write_bytes safety: {:.N} on f64 is always ASCII (digits, -, ., NaN, inf), so from_utf8_unchecked is sound; the no-. branch covers PRECISION == 0, NaN and inf.
  • The bun:internal-for-testing hook follows the existing out-of-crate pattern (rustIdentifierPaths entry + dispatch_js2native.rs re-export); is_number() guards as_number().
  • Tests pin the six previously-broken inputs plus unchanged-behavior rows via the direct hook, and the report-level check asserts every time="..." matches ^\d+(\.\d+)?$.
Extended reasoning...

Overview

Rewrites TrimmedPrecisionFormatter::fmt in src/bun_core/fmt.rs to format the whole f64 with a single {:.PRECISION} into a stack buffer, then trim trailing zeros from the fraction (dropping the . if the fraction becomes empty). The old code printed trunc() then re-formatted the remainder separately, which produced "0." when the remainder rounded to 0.000000, silently dropped the carry when it rounded to 1.000000, and produced garbage for negatives/NaN. Adds a bun:internal-for-testing hook (trimmedPrecision) wired through fmt_jsc.rs → generate-js2native.ts → dispatch_js2native.rs so the edge cases can be tested deterministically, since real JUnit runs cannot control measured durations. Tests go in the existing test/js/junit-reporter/junit.test.js.

Security risks

None. The formatter takes an f64 and writes ASCII into a fixed 384-byte stack buffer via std::io::Cursor; the const assert bounds 1 + 309 + 1 + PRECISION ≤ 384. write_bytes uses from_utf8_unchecked, but Rust's {:.N} for f64 produces only ASCII. The test-only JS hook validates is_number() before calling as_number().

Level of scrutiny

Low-to-medium. The only production caller is the JUnit reporter's time="..." attribute (test_command.rs:691), a cosmetic output path — worst case is a malformed decimal string, not a crash or data loss. The new implementation is simpler (one format call, no arithmetic on the remainder) and its contract ("{:.N} with trailing fraction zeros trimmed") is now literal. The 384-byte stack buffer is larger than the old 32 bytes but this runs once per test case, not in a hot loop.

Other factors

The PR description documents that the six edge-case rows fail with only fmt.rs reverted and the unchanged-behavior rows still pass, satisfying the fails-for-the-right-reason requirement. USE_SYSTEM_BUN=1 fails on the missing export. The test hook pattern exactly mirrors neighboring dispatch_js2native.rs entries (e.g. jsc_event_loop_get_active_tasks). No outstanding reviewer comments; CodeRabbit was rate-limited and did not review.

@robobun
robobun force-pushed the farm/5e9a316a/junit-trimmed-precision branch from 236d680 to d224e56 Compare August 16, 2026 06:49
Comment thread src/runtime/cli/test_command.rs Outdated
@robobun

robobun commented Aug 16, 2026 •

Copy link
Copy Markdown
Collaborator Author
Updated 12:03 AM PT - Aug 16th, 2026

⏳ @robobun, your commit 2b9c15d is still building in Build #99241, but has 1 failures so far (All Failures):

…second count

write_test_case divided elapsed_ns by 1e6 and then by 1000, and the
double rounding made the value print with noise, so it went through
bun_fmt::trimmed_precision, which rounds to six digits. That formatter
wrote "." even when every fractional digit rounded away, so a testcase
that took less than half a microsecond was reported as time="0.", and a
fraction that rounded up to 1 lost its carry ("0." for 0.9999996s).

Divide the integer nanosecond count by NS_PER_S once and print it with
{}, which is what the <testsuite> and <testsuites> attributes already
do: the result is an exact decimal with at most nine fractional digits,
so nothing needs trimming. Delete trimmed_precision, whose only caller
this was.
@robobun
robobun force-pushed the farm/5e9a316a/junit-trimmed-precision branch from d224e56 to 2b9c15d Compare August 16, 2026 06:51
@robobun robobun changed the title bun test --reporter=junit: stop rendering sub-microsecond times as time="0." bun test --reporter=junit: print testcase time straight from the nanosecond count Aug 16, 2026
Comment thread src/bun_core/fmt.rs

@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 description now matches the diff, and the change itself is a focused two-line fix plus dead-code deletion.

What was reviewed:

  • Confirmed trimmed_precision/TrimmedPrecisionFormatter have no remaining callers in src/; the deletion is clean.
  • write_test_case now uses the same elapsed_ns as f64 / NS_PER_S as f64 + bare {} expression as end_test_suite (line 611) and write_to_file (line 855); elapsed_ms is still live for the suite-metrics accumulation at line 673.
  • Checked the ≤9-fractional-digit claim: any u64 cast to f64 is an exact integer, integer/10⁹ is a decimal with ≤9 fractional places that round-trips to the computed double, so Ryū's shortest output can never exceed it and never emits exponent notation.
  • Second test's flake risk: needing all 12 nanosecond counts to land on exact microsecond boundaries on a ns-granular clock is negligible; >=17 in the first test is robust to #35502 dropping the hook entries.
Extended reasoning...

Overview

The PR fixes bun test --reporter=junit emitting time="0." for sub-microsecond testcase durations. Three files: src/runtime/cli/test_command.rs swaps the double-divided elapsed_ms / 1000 through trimmed_precision::<6> for a single elapsed_ns / NS_PER_S printed with bare {}; src/bun_core/fmt.rs deletes the now-orphaned TrimmedPrecisionFormatter/trimmed_precision (44 lines, verified no remaining references); test/js/junit-reporter/junit.test.js adds two report-level tests.

Security risks

None. This is decimal formatting of an internally-measured u64 nanosecond count into an XML attribute the reporter already escapes. No user input, no parsing, no allocation, no unsafe.

Level of scrutiny

Low. The effective runtime change is two lines, and it makes write_test_case use the identical expression the sibling <testsuite> and <testsuites> attributes already use in the same file (lines 611, 855) — so the pattern is proven in production. The deletion is pure dead-code removal (grep confirms no other callers). The correctness argument (integer/1e9 → shortest-round-trip decimal has ≤9 fractional digits, Rust Display never emits exponent) holds for the full u64 range, and the PR author verified it empirically over 5M inputs.

Other factors

  • My previous review flagged a stale PR description; the author rewrote it and it now accurately names the deletion and describes the shipped tests. That thread is resolved.
  • The comment-cop bot's feedback (paragraph-long justification comment) was addressed in 2b9c15d — the current diff has no such comment.
  • Tests: the first pins the output shape (^\d+(\.\d{1,9})?$) across every element and the exact-zero cases; the second (Linux-only) is the fail-on-revert probe, correctly gated on the platform whose clock guarantees the observation. The >=17 bound and Object.fromEntries extraction are robust to #35502 removing the (unnamed) hook entries. Subprocess pipes are drained concurrently per REVIEW.md.
  • The one CI failure so far (test/bake/deinitialization.test.ts segfault on Windows x64) is in the dev-server subsystem and unrelated to JUnit formatting or fmt.rs.
  • elapsed_ms remains live (suite metrics accumulation at line 673), so no new dead code is introduced; the PR correctly scopes out the separate Metrics::add truncation bug to #36218.

Jarred-Sumner pushed a commit that referenced this pull request Sep 6, 2026
…he full report (#41423)

### Problem
- `test/regression/issue/26851.test.ts` takes up to 12s on the debian 13
x64-asan lane. It is in the slowest 5 percent of test files. Both tests
spawn a `bun test --bail` child, and they ran one after the other.
- On that lane each child exits 134, not 1. `bun test --bail` exits with
a bare `exit(1)`, so the `BUN_DESTRUCT_VM_ON_EXIT` teardown is skipped
and LeakSanitizer aborts the child after several seconds of report
symbolization (#32183, fix open in #39010). Locally each child takes
0.3s. Under the lane environment it takes 3.8s. The old
`expect(exitCode).not.toBe(0)` hid the abort.
- The old assertions only checked that the JUnit file exists and
contains four substrings. They did not check the counters, the failure
element, the bail message, or the exit code.

### Fix
- Add the file to `test/no-validate-leaksan.txt`, next to
`test/regression/issue/12250.test.ts`, which is on the list for the same
bail exit. The entry is to be removed when #39010 lands. Without
LeakSanitizer the children exit 1 in well under a second.
- Run both tests with `test.concurrent`. Each test owns its tempDir and
its outfile, so the two children overlap. A shared `runBailWithJUnit`
helper does the spawn and reads the report.
- Assert the full JUnit document with `toMatchInlineSnapshot`: the
`testsuites` root with `tests`, `assertions`, `failures` and `skipped`,
one `testsuite` per file that ran, the `testcase` names and lines, and
the `failure` element with its type and message. Only the `time` and
`hostname` attributes are normalized. Assert the child output before the
exit code: stdout is the version banner, stderr has the
`(pass)`/`(fail)` lines, the `Ran N tests across M files.` summary and
`Bailed out after 1 failure`. The exit code is exactly 1.
- Add a second test after the failing one, and a third test file
`c_never.test.ts`. Neither appears in stderr or in the report. This
proves that `--bail` stopped the run and that the report holds only what
ran. Discovery order of the root directory is sorted by name, so
`a_pass` runs before `b_fail`.
- Verified: `bun bd test test/regression/issue/26851.test.ts`. Plain, 3
runs: before 2.66s to 3.14s wall, after 2.27s to 2.44s wall. With the
ASAN lane environment (`BUN_DESTRUCT_VM_ON_EXIT=1`, `detect_leaks=1`):
before 9.53s with both children exiting 134, after the list entry that
environment is not applied. Also passes with `USE_SYSTEM_BUN=1`.

### Background
- `--bail` makes `bun test` stop after the first failing test. #26851
was about the JUnit outfile not being written in that case.
- `test/no-validate-leaksan.txt` lists test files for which
`scripts/runner.node.mjs` does not set `BUN_DESTRUCT_VM_ON_EXIT` and
`detect_leaks=1` on the ASAN lane.
- #33704 also adds `test.concurrent` to this file as part of a broad
speed pass. This PR is scoped to the one file and also strengthens the
assertions.

<details><summary>Notes</summary>

The first CI run (build 110365) failed on the x64-asan lane with exit
code 134 on both tests and 8.7s per test. That is the LeakSanitizer
abort described above. The fix for the bail exit itself is in #39010 and
out of scope here.

The stderr checks use `toContain` rather than a snapshot of the whole
stream. Open PRs #39010, #39276, #38974 and #38265 change parts of the
bail and reporter output, and a whole-stream snapshot would conflict
with them for no gain. The XML snapshot is the thing under test.

The failure body in the XML contains `at fail.test.ts:2:40`. The fixture
sources are built from fixed strings, not indented template literals, so
the column is stable. `test/js/junit-reporter/junit.test.js` snapshots
the same shape on every platform.

</details>

<!-- robobun:evidence:begin -->

---

**[auto-merge]** gate passed · iteration 1 · 2 files touched

<details><summary>passes on PR (with fix)</summary>

```console
Test-only change.

Debug/ASAN (expected pass):
$ bun bd test 'test/regression/issue/26851.test.ts'
$ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test "test/regression/issue/26851.test.ts"
bun test v1.4.3 (e0a2b82)

test/regression/issue/26851.test.ts:
(pass) --bail writes JUnit reporter outfile [356.62ms]
(pass) --bail writes JUnit reporter outfile with multiple files [349.11ms]

 2 pass
 0 fail
 2 snapshots, 15 expect() calls
Ran 2 tests across 1 file. [2.42s]
Exit: 0
```

</details>

<details><summary>diff hotspot</summary>

```
test/no-validate-leaksan.txt        |   3 +
 test/regression/issue/26851.test.ts | 140 +++++++++++++++++++++---------------
 2 files changed, 87 insertions(+), 56 deletions(-)
```

</details>

**gate history** · 3 passed · 0 rejected · iteration 1

<details><summary>evidence per changed file</summary>

```
file                                 reads  edits  tests
test/no-validate-leaksan.txt             1      1     25
test/regression/issue/26851.test.ts      3      5     19
```

</details>

**root cause** · written by the author bot

The regression test for issue #26851 was slow because each of its five
tests spawned a separate `bun test` child one after another, and under
ASAN every child paid several seconds of startup, while the assertions
only checked that the JUnit outfile existed. The fix runs the
independent cases concurrently through a shared runner that captures
stdout, stderr, the exit code and the report once per fixture set, then
asserts the full normalized JUnit document shape, the bail message, the
summary line and the exact exit code. A follow-up strips the CI
environment variables that make the reporter …

<!-- robobun:evidence:end -->

This branch has not been deployed

No deployments
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