Conversation
WalkthroughThe PR updates Buildkite test-log parsing for ANSI output, retries, timestamps, serial phases, and parallel summaries. It exports ChangesBuildkite timing analysis
Possibly related PRs
Suggested reviewers: 🚥 Pre-merge checks | ✅ 4✅ Passed checks (4 passed)
Comment |
|
Updated 8:14 AM PT - Jul 31st, 2026
✅ @robobun, your commit 94fadaec17df2799a699b1b0eb0fbf99fe984444 passed in 🧪 To try this PR locally: bunx bun-pr 35418That installs a local version of the PR into your bun-35418 --bun |
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
There was a problem hiding this comment.
LGTM — corrects a real measurement bug in a dev-tooling script, with tests.
What was reviewed:
- Verified against
scripts/runner.node.mjs: concurrent phase usesconsole.log(grouptitle)(no---), serial usesstartGroup, and theRunning N parallel-safe/Endgroup headers and[attempt #N]/- <error>retry labels all exist as the new regexes expect. - Parser logic mirrors the existing implementation in
scripts/update-test-durations.mjs(same header regex, same 500 ms concurrent clamp, same boundary-close pattern). import.meta.mainguard correctly isolates the fetch/aggregate path so importingparseLogfrom the test has no side effects;test/internal/is the established home for tooling tests.
Extended reasoning...
Overview
Fixes scripts/ci-slowest-tests.ts, an offline BuildKite-log analysis script, so it stops mis-attributing the entire parallel-safe test phase's wall clock to the last serial test on each shard. The change rewrites parseLog to (a) match [N/M] path headers with or without the --- group prefix, (b) close open spans at the --- Running N parallel-safe and --- End group boundaries, (c) clamp concurrent-phase spans to 500 ms since header gaps there are dispatch deltas not per-file wall clock, and (d) treat retry/error labels as delimiters so retry backoff isn't charged to either attempt. The rest of the file is moved verbatim under an import.meta.main guard so parseLog can be exported and unit-tested. A new test/internal/ci-slowest-tests.test.ts covers the three shapes: serial→parallel transition, retry attempts with Windows path separators, and shards with empty/absent parallel phases.
Security risks
None. This is a local developer script that parses CI log text and prints a table; it does not ship in the runtime, touches no auth/crypto/permissions, and the only network access (BuildKite log fetch) is unchanged and gated behind import.meta.main.
Level of scrutiny
Low. This is internal tooling in scripts/, not runtime or user-facing code. The worst failure mode is a wrong slow-test report. I cross-checked every claim in the PR description against the actual producer (scripts/runner.node.mjs lines 617–645, 882, 937) and the sibling parser it aligns with (scripts/update-test-durations.mjs lines 66–101) — the header formats, ANSI wrapping, retry label shape, and group-boundary strings all match exactly. The isPath extension regex correctly rejects path - code 1 retry labels while accepting .ts/.tsx/.js/.jsx/.cjs/.mjs/.cts/.mts/.json.
Other factors
- The new tests assert exact millisecond values derived from the synthetic fixtures (not loose bounds), cover CRLF (
\r\r\n) and LF line endings, Windows backslash normalization, and the[attempt #N]suffix stripping. - The bulk of the diff is indentation from wrapping existing code in
if (import.meta.main) { ... }; the fetch/aggregate/output logic is byte-identical. test/internal/already hosts similar tooling tests (expected-durations.test.ts,powershell-escape.test.ts), so placement follows convention.- No prior human or bot review comments to address; CI build #79541 is in progress but this change requires no native rebuild.
There was a problem hiding this comment.
LGTM — internal CI tooling fix with a clear root cause and matching tests.
What was reviewed:
- Verified against
scripts/runner.node.mjsthat serial headers go throughstartGroup(--- [N/M]) while parallel-safe headers are bareconsole.log— the old regex's mandatory---did miss them. - Confirmed
--- Running N parallel-safeand--- Endare the actual group boundaries emitted bystartGroupinutils.mjs, so the new close points are correct. - Checked the retry-label path:
[N/M] path - <error>fails the trailing-extensionisPathcheck and correctly acts as a delimiter without accruing backoff time. import.meta.mainguard keeps theci:slowestpackage script working; only caller is the new test.
Extended reasoning...
Overview
This PR fixes scripts/ci-slowest-tests.ts, an internal diagnostic script that scrapes BuildKite logs to rank test files by wall-clock time. The old header regex required the --- group prefix, which runner.node.mjs only emits for the serial phase (via startGroup); the parallel-safe phase prints bare [N/M] path lines. As a result the last serial file on every shard was charged the entire parallel phase. The fix strips ANSI, matches headers with or without --- , closes open spans at the --- Running N parallel-safe / --- End group boundaries, clamps concurrent-phase spans to 500 ms (they're inter-dispatch deltas, not per-file wall clock), and treats retry/error labels as delimiters so the random retry backoff isn't attributed to either attempt. parseLog is now exported behind import.meta.main and covered by three unit tests in test/internal/ci-slowest-tests.test.ts.
Security risks
None. This is a developer-local diagnostic script that reads BuildKite logs and prints a table. It does not run in CI's test path, does not touch runtime code, and processes only trusted CI log output. No new external inputs or network surfaces were introduced.
Level of scrutiny
Low. scripts/ci-slowest-tests.ts is dev tooling — it feeds the ci:slowest package script and the slowest-tests skill, not the shipped binary. Worst-case failure is a wrong slow-test report. I cross-checked every log-format assumption against scripts/runner.node.mjs and scripts/utils.mjs: startGroup prints --- ${title} on BuildKite, concurrent runTest uses plain console.log(grouptitle), the retry label is [N/M] title - <error>, and the terminal groups are literally Running N parallel-safe tests (K-wide) and End. All match the new regexes.
Other factors
- The bulk of the diff is indentation from wrapping the CLI body in
if (import.meta.main); the logic change is confined toparseLog. - Tests exercise the exact failure modes described (parallel-phase absorption, retry backoff exclusion, Windows path normalization, empty-parallel and no-parallel shard termination) with strong
toBeassertions on millisecond values, and were shown passing underbun bd testin the PR evidence. - Grep confirms no other importer of this file besides the new test, so exporting
parseLogand adding theimport.meta.mainguard does not affect thebun run ci:slowestentry point. - The PR description includes before/after numbers from a real build (#79247) demonstrating the fix (79 524 ms → 4 838 ms for the misattributed file, entry count 1113 → 2732).
|
CI status: Remaining red lanes are unrelated to this diff (which only touches
All four review threads have been addressed (three applied in 96e8f93, one withdrawn). Ready for review. |
…t serial test parseLog measured each file as (next-header - this-header) but only matched the `--- [N/M] path` form. runner.node.mjs prints parallel-safe headers without the `--- ` prefix, so the last serial file on every shard absorbed the entire parallel phase (79.5s reported for a 4.8s test on build 79247). Match the header with or without `--- `, close the open span at the `--- Running N parallel-safe tests` / `--- End` group boundaries, clamp concurrent-phase spans (they are inter-dispatch deltas, not wall clock), and drop the retry backoff between a failure label and the next attempt. This matches the parseLog already used by scripts/update-test-durations.mjs. parseLog is now exported behind an import.meta.main guard so the new test/internal/ci-slowest-tests.test.ts can exercise it directly.
…ibling parsers Since #36175, runner.node.mjs also emits: --- napi prebuild: N addon(s), Xs --- [A-B/M] K files in parallel (Nx) [N/M] <path> (X.XXs) (bucket per-file summary) none of which match '^--- [N/M] <path>'. Close the open span on any '--- ' group header so the test preceding the bucket is not charged the whole bucket run, and read the inline '(X.XXs)' timing from bucket summary lines. buildkite-slow-tests.js and update-test-durations.mjs share the same header contract and get the same fix.
118dbdc to
1b8991a
Compare
robobun
changed the title
|
Rebased onto main and extended to cover the runner output added in #36175 (merged after this PR was opened): the Applied the same fix to Verified against build #86086 (see updated PR body). |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 4
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@scripts/buildkite-slow-tests.js`:
- Around line 34-39: Update the non-“--- ” branch in the parser around the
timed-header handling to recognize bare “[N/M] <path>” parallel headers emitted
by runner.node.mjs. Record each as a concurrent span using its path and the
existing inter-dispatch duration logic, clamping that duration to 500 ms, while
preserving the current summary-line parsing and continue behavior.
In `@scripts/ci-slowest-tests.ts`:
- Around line 48-82: Flush the final open test span when log parsing reaches EOF
by tracking the most recent APC timestamp and invoking the parser’s close
operation after the loop in scripts/ci-slowest-tests.ts lines 48-82. Apply the
equivalent last-timestamp tracking and finalization in
scripts/buildkite-slow-tests.js lines 27-55 before building testGroups, and call
emit(lastTs) in scripts/update-test-durations.mjs lines 79-113 before returning
out; preserve existing boundary handling.
- Around line 60-66: Update the timed-summary handling in the slowest-tests
parser to validate the captured name as a test file before adding it to out.
Align this check with the extension validation used by the sibling
update-test-durations parser, and only update out, concurrent, and continue for
valid test-file names; otherwise let the normal parsing path handle the line.
In `@test/internal/ci-slowest-tests.test.ts`:
- Line 34: Update the assertion for test/js/node/test/parallel/p3.js to use
exact equality with 500 via toBe, replacing the weaker upper-bound check while
preserving the existing fixture and test structure.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: ASSERTIVE
Plan: Pro
Run ID: b7dc4dc3-a887-4e8d-ae04-43dce061f5ae
📒 Files selected for processing (4)
scripts/buildkite-slow-tests.jsscripts/ci-slowest-tests.tsscripts/update-test-durations.mjstest/internal/ci-slowest-tests.test.ts
…ary path - flush the open span at end-of-log in all three parsers so a job killed or timed out mid-run still records the last file instead of dropping it - require a test-file extension in the parallel-bucket summary name, matching update-test-durations.mjs - assert toBe(500) for the clamped parallel-safe span (fixture is deterministic) and cover the truncated-log case
There was a problem hiding this comment.
LGTM — internal CI-tooling fix with good test coverage.
Checked: the import.meta.main wrap in ci-slowest-tests.ts is a pure indent of the existing CLI body; the broadened --- boundary in update-test-durations.mjs cannot over-close because [N/M] headers hit the hdr branch first and [A-B/M] bucket headers do not match \[\d+\/\d+\]. The subprocess test drains stdout/stderr/exited concurrently and uses tempDir/bunEnv per harness conventions. All CodeRabbit findings were addressed in 96e8f93 or withdrawn.
Extended reasoning...
Overview
This PR fixes three internal BuildKite log parsers (scripts/ci-slowest-tests.ts, scripts/buildkite-slow-tests.js, scripts/update-test-durations.mjs) that were mis-attributing entire batch phases (parallel-safe tests, napi prebuild, parallel buckets) to whichever serial test happened to run immediately before them. The fix: any --- group header now closes the open timing span, [N/M] headers match with or without the --- prefix, parallel-bucket (X.XXs) summary lines use their inline timing, concurrent-dispatch spans are clamped to 500 ms, and retry/error labels close but don't open spans. parseLog is exported behind an import.meta.main guard so test/internal/ci-slowest-tests.test.ts (new) can drive it directly with synthetic fixtures; a subprocess test covers buildkite-slow-tests.js.
Security risks
None. These are developer-run CI analysis scripts that read BuildKite job logs and write reports/JSON. No user-facing surface, no runtime code, no auth/crypto/permissions.
Level of scrutiny
Low. This is internal tooling under scripts/ — the worst failure mode is an inaccurate slow-test report or suboptimal shard bin-packing in expected-durations.json (which update-test-durations.mjs already mitigates via median-of-5-builds and a >1000-paths sanity guard). Nothing here ships in the bun binary or affects user code.
Other factors
- The bug-hunting system found no issues.
- All four CodeRabbit findings were resolved: EOF flush of the open span in all three parsers (with a truncated-log fixture), exact
toBe(500)clamp assertion, test-file-extension gate on the timed-summary regex; the fourth (record bare parallel-safe headers inbuildkite-slow-tests.js) was correctly rebutted and withdrawn — the--- Running N parallel-safe testsheader already reachesclose(ts), and clamped inter-dispatch deltas would never survive the script's> 1 sfilter anyway. - The
if (import.meta.main)block is a pure re-indent of the existing CLI code — I diffed it visually and the logic is unchanged. - The new test file lives alongside existing internal-tooling tests (
test/internal/expected-durations.test.ts, etc.), follows harness conventions (tempDir,bunEnv,bunExe, concurrent pipe drain, exit-code asserted last), and asserts exact values on deterministic fixtures. - PR body documents verification against real build #86086 logs showing the misattribution fixed (22554 ms → 57 ms, etc.) and file-count going from 63 → 829.
…update-test-durations.mjs Closing the open span on any '--- ' line also matched test stdout that slipped past pipeTestStdout's sanitiser: unified-diff '--- a/<file>' inside bun-patch.test.ts (under-counted by ~33% on build #86086) and '--- ps ---' / '--- logs ---' from test/docker/index.ts inside test/package.json (~58%). Limit the boundary to the startGroup titles runner.node.mjs actually emits and cover the false positives in the fixture. Export parseLog from update-test-durations.mjs behind an entrypoint check so the test can run the same fixture through the parser CI shard bin-packing consumes.
There was a problem hiding this comment.
LGTM — well-scoped fix to internal CI log parsers with thorough test coverage.
What was reviewed:
- Verified the
isPhaseGroupHeaderallowlist againstscripts/runner.node.mjs— all sixstartGroupphase titles (napi prebuild,[A-B/M]bucket, parallel-safe, End, Summary, Received-exiting) are covered; the one uncoveredstartGroup(<path> - N failing in the parallel batch) only fires after the timed-summary lines when no span is open, so it needs no boundary handling. - Checked the
import.meta.main/process.argv[1]entrypoint guards and thestrict: false+ deferred token check inupdate-test-durations.mjs— importing for tests no longer triggers CLI side-effects or exits. - All four CodeRabbit threads are resolved (EOF flush, exact clamp assertion, timed-summary extension check applied; bare-header recording correctly declined for
buildkite-slow-tests.jssince its> 1 sfilter would drop them anyway).
Extended reasoning...
Overview
This PR fixes three internal CI log-parsing scripts (scripts/ci-slowest-tests.ts, scripts/buildkite-slow-tests.js, scripts/update-test-durations.mjs) that measure per-test-file wall-clock time from BuildKite's APC-timestamped log lines. The bug: the old regex only recognized --- [N/M] <path> headers with a literal [90m SGR, so any other phase header (--- Running N parallel-safe tests, --- napi prebuild:, --- [A-B/M] K files in parallel, bare [N/M] concurrent-dispatch lines, retry/error labels) was invisible, and whichever serial test preceded such a phase was charged the entire following batch — e.g. a 41 ms test reported as 22.5 s. The fix strips ANSI upfront, recognizes all header shapes runner.node.mjs emits, uses an allowlist of phase-header titles (rather than any --- ) to avoid false positives from unified-diff --- a/<file> lines in test stdout, records inline (X.XXs) timings from parallel-bucket summaries, clamps concurrent inter-dispatch deltas to 500 ms, and flushes the open span at EOF for truncated logs. Both parseLog functions are now exported behind entrypoint guards so a new test/internal/ci-slowest-tests.test.ts can exercise all three parsers against shared fixtures.
Security risks
None. These are developer-run and scheduled CI-tooling scripts that read BuildKite logs and print/write timing tables. No runtime code, no user input surface, no auth/crypto/permissions.
Level of scrutiny
Low. This is internal tooling, not shipped in the bun binary. The worst-case failure mode is a mis-ranked slow-test report or a slightly skewed expected-durations.json (which is median-of-5-builds and guarded by a paths.size < 1000 sanity check). I cross-checked the phase-header allowlist against the actual startGroup(...) calls in scripts/runner.node.mjs at HEAD and every phase title is covered; the one startGroup not in the allowlist (<path> - N failing in the parallel batch, line 1102) only prints after the timed-summary lines have already closed the span.
Other factors
- Comprehensive test coverage: the new test file exercises the parallel-safe phase, parallel-bucket phase with inline timings, retry/error labels with backoff, Windows path separators, truncated logs, and stray
---false positives (--- a/index.js,--- ps ---). It also runsbuildkite-slow-tests.jsend-to-end as a subprocess. - All four CodeRabbit review threads are resolved (three applied, one correctly withdrawn with reasoning).
- CI: the new test passes on every lane; remaining red is an unrelated native segfault.
- The
import.meta.mainrefactor andstrict: falseinparseArgsare the minimal changes needed to make the parsers importable without running the CLI or exiting on missingBUILDKITE_API_TOKEN.
|
Re-checked this branch's On main,
With this branch the top of the list is |
Both slow-test parsers (scripts/ci-slowest-tests.ts and scripts/update-test-durations.mjs) measured a file as the gap between its `[N/M] <path>` header and the next header they recognized. Every other header runner.node.mjs emits (`--- napi prebuild:`, the `--- [A-B/M] K files in parallel` bucket, `--- Running N parallel-safe`, `--- End`, `--- Summary`, `--- Received <signal>, exiting`) was invisible, so the serial test that happened to run before one of them was charged the whole phase that followed. - Those phase headers close the open span. The check is an allowlist of the titles the runner emits, not any `--- ` line, because streamed test output can still contain `--- a/<file>` or `--- ps ---`. - `[N/M] <path>` matches with or without the `--- ` prefix. Bucket summary lines `[N/M] <path> (X.XXs)` use the inline timing. Concurrent dispatch spans are clamped to 500 ms. - Retry/error labels (`<path> - code 1`) are a boundary that opens no span, so the retry backoff lands on neither attempt. - A truncated log (no `--- End`) charges the open span to the last timestamp seen instead of dropping it. Both scripts export parseLog behind an entrypoint guard, and test/internal/ci-slowest-tests.test.ts exercises them against the same header fixtures. scripts/buildkite-slow-tests.js from #35418 is gone from main (#39581) and is not restored. Regenerated test/expected-durations.json with the combined parser from builds 108915, 108911, 108910, 108909, 108906.
…sers, regenerate the table (#41070) ### Problem - `windows-aarch64-11-test-bun` packs its 8 shards with the timings of the windows x64 lane. Its serial files run about 2x slower and not uniformly (`bundler/bundler_compile.test.ts` is 222s there, 48s in the x64 column). One shard carries 922s of work against a 610s mean. This lane finished last in 46 of the 47 completed builds since #40993 merged, so it sets the build time: the median build went from 1342s to 1386s while the linux lanes got faster (x64 glibc slowest shard 233s to 178s). - The slow-test log parsers (`scripts/update-test-durations.mjs`, `scripts/ci-slowest-tests.ts`) only recognize `[N/M] <path>` headers. Every other header the runner emits (`--- napi prebuild:`, the `--- [A-B/M] K files in parallel` bucket, `--- Running N parallel-safe`) is invisible, so the serial file that runs right before one is charged the whole phase that follows. In source build 108642 this hit 19 of 20 linux shards and 8 of 8 windows shards (`js/valkey/unit/basic-operations.test.ts` recorded as 111.6s on windows, real 0.1s). 11 of the phantom entries are 10s or more in the default column, so `--skip-slower-than=10000` dropped those files from the darwin PR lanes. ### Fix - Add a `windows-aarch64` column, measured from `windows-aarch64-11-test-bun`. `runner.node.mjs` picks it for the windows-aarch64 step and falls back to `windows`, then the other columns, for a file that lacks one. - Fold in the parser fixes from #35418 (this PR supersedes it): the runner's phase headers close the open span (an allowlist of the titles the runner emits, since test output can contain `--- a/<file>`), bucket summary lines use their inline `(X.XXs)` timing, retry labels open no span, and a truncated log keeps its last open span. Both scripts export `parseLog` behind an entrypoint guard, and `test/internal/ci-slowest-tests.test.ts` runs them against the same fixtures. `scripts/buildkite-slow-tests.js` from #35418 was deleted from main in #39581 and is not restored. - Regenerate `test/expected-durations.json` with the combined parser from builds 108915, 108911, 108910, 108909, 108906 (`node scripts/update-test-durations.mjs --builds 5`, 5906 entries). - Verified: `bun bd test test/internal/ci-slowest-tests.test.ts` (18 pass). Replaying the LPT packing against per-file costs measured on three other windows-aarch64 runs (builds 108785, 108786, 108801) gives a slowest shard of 673s with the new column, against 922s with the table on main (610s is the floor). Column selection checked for every step key. ### Background - `runner.node.mjs` bin-packs test files across `--max-shards` with LPT (longest file first into the least loaded bin) using `test/expected-durations.json`. Every shard computes the same assignment from the same input, so the shards need no coordination. - The table has one column per lane with distinct timing: `default` (linux x64 debian), `asan`, `musl`, `windows`. Every other lane uses the nearest column (darwin uses `default`). - Per-file cost comes from the `_bk;t=<ms>` timestamps Buildkite prefixes to each log line: the gap between one `[N/M] <path>` group header and the next header. The parallel bucket runs one `bun test --parallel` for many files and prints `[N/M] <path> (X.XXs)` per file afterwards. - The untiered darwin PR lanes pass `--skip-slower-than=10000`, which drops a file when its column cost is 10s or more. - `.buildkite/update-test-durations.yml` regenerates the file on a schedule and uploads it as an artifact. A human commits it. <details><summary>Notes</summary> Measurement: Buildkite REST job timings for 95 builds created after the merge of #40993 (09:17 UTC, 2026-08-31). 64 builds include the new table (GitHub compare status `ahead`), 31 PR builds still ran on the old one. Same fleet, same hours. Median of the slowest shard per lane, old table to new table: | lane | old | new | |---|---|---| | linux-x64-debian-13 | 233s | 178s | | linux-x64-asan | 437s | 387s | | linux-aarch64-debian-13 | 255s | 230s | | linux-x64-ubuntu-2504 | 232s | 178s | | musl (both arches) | 271-282s | 281-294s | | windows-x64-2019 | 491s | 468s | | windows-aarch64-11 | 829s | 887s | | darwin-aarch64-any | 534s | 581s (2 shards, balanced per shard: 506s and 518s) | | build start to last test finished | 1342s | 1386s | windows-aarch64 per-shard medians with the old table: `456 523 594 572 477 375 823 526` (shard 6 slowest in 177 of 188 builds). With the table from #40993: `447 404 575 892 521 651 416 453` (shard 3 slowest in 49 of 49). The runner estimated that shard at 429s. Largest windows-aarch64 costs in the new column (s): bundler_compile 219, serve-body-leak 154, expo 114, v8 97, test-fs-read-stream-pos 90, napi 85. Bucket header bug, source build 108642, default column (parsed vs real): websocket-proxy-tunnel-client-leak 17.6 vs 0.0, valkey/integration/complex-operations 32.8 vs 0.1, regression/issue/24850 15.7 vs 0.1, sql-mysql-bigint-out-of-range 24.4 vs 0.3. Windows column: valkey/unit/basic-operations 122.5 vs 0.1, regression/issue/28632 76.3 vs 0.1. In the logs checked, the `--- napi prebuild:` header carries the same timestamp as the next file header, so it misattributes nothing today; the allowlist still covers it. From #35418, against build 86086 logs: `test/js/bun/test/fake-timers/sinonjs/issue-2086.test.ts` parsed at 22554 ms before, 57 ms after (bun's own timer: 41 ms). `test/regression/issue/24850.test.ts` 60575 ms before, 61 ms after. Unique files found in one windows shard: 63 before, 829 after (the old `ci-slowest-tests.ts` regex required a literal `[90m` SGR and the `--- ` prefix). Side effect: `scripts/update-parallel-allowlist.mjs` takes the slowest column per file. With the new column, 10 files that are under 15s on every other lane are over 15s on windows-aarch64 and will leave the parallel allowlist at its next regeneration (for example `js/bun/spawn/spawn-noread-leak.test.ts` at 38.7s). That is the stated intent of that check. The regenerated default column has 44 entries at 10s or more against 55 on main. Files that the darwin PR lanes skipped because of phantom entries and now run again: websocket-proxy.test.ts, websocket-proxy-tunnel-client-leak, websocket-proxy-tunnel-upgrade-leak, regression/issue/24850, regression/issue/patch-bounds-check, cli/install/bun-install-proxy. </details> <!-- robobun:evidence:begin --> --- **[stamp-90s]** gate passed · iteration 2 · 6 files touched <details><summary>passes on PR (with fix)</summary> ```console Test-only change. Debug/ASAN (expected pass): $ bun bd test 'test/internal/ci-slowest-tests.test.ts' $ BUN_DEBUG_QUIET_LOGS=1 bun scripts/build.ts --profile=debug --quiet test test/internal/ci-slowest-tests.test.ts bun test v1.4.1 (a6c4cc2) test/internal/ci-slowest-tests.test.ts: (pass) scripts/ci-slowest-tests.ts parseLog > does not charge the parallel-safe phase to the last serial test [28.64ms] (pass) scripts/ci-slowest-tests.ts parseLog > sums retry attempts and normalizes Windows path separators [6.28ms] (pass) scripts/ci-slowest-tests.ts parseLog > closes the last serial test at the parallel-phase group header when no parallel headers follow [11.47ms] (pass) scripts/ci-slowest-tests.ts parseLog > does not charge the parallel-bucket phase to the preceding serial test [12.70ms] (pass) scripts/ci-slowest-tests.ts parseLog > ignores stray `--- ` lines that are test output, not group headers [7.17ms] (pass) phase-header boundary > true --- napi prebuild: 3 addon(s), 23.9s [1.37ms] (pass) phase-header boundary > true --- [52-257/829] 206 files in parallel (3×) [0.32ms] (pass) phase-header boundary > true --- Running 444 parallel-safe tests (3-wide) [0.19ms] (pass) phase-header boundary > true --- End [0.18ms] (pass) phase-header boundary > true --- Summary [0.18ms] (pass) phase-header boundary > true --- Received SIGTERM, exiting... [0.18ms] (pass) phase-header boundary > false --- a/index.js [0.20ms] (pass) phase-header boundary > false --- ps --- [0.17ms] (pass) phase-header boundary > false --- logs --- [0.17ms] (pass) phase-header boundary > false ------ [0.18ms] (pass) phase-header boundary > false --- [0.27ms] (pass) phase-header boundary > false --- [52/829] test/a.test.ts [0.19ms] (pass) scripts/update-test-durations.mjs parseLog > does not charge napi prebuild or the parallel-bucket phase to the preceding serial test [17.04ms] 18 pass 0 fail 24 expect() calls Ran 18 tests across 1 file. [2.22s] Exit: 0 ``` </details> <details><summary>diff hotspot</summary> ``` scripts/ci-log-phase.mjs | 32 + scripts/ci-slowest-tests.ts | 282 +- scripts/runner.node.mjs | 18 +- scripts/update-test-durations.mjs | 116 +- test/expected-durations.json | 49849 +++++++++++++++++-------------- test/internal/ci-slowest-tests.test.ts | 196 + 6 files changed, 28355 insertions(+), 22138 deletions(-) ``` </details> **gate history** · 3 passed · 0 rejected · iteration 2 <details><summary>evidence per changed file</summary> ``` file reads edits tests scripts/ci-log-phase.mjs 0 1 0 scripts/ci-slowest-tests.ts 1 1 0 scripts/runner.node.mjs 4 1 0 scripts/update-test-durations.mjs 4 6 0 test/expected-durations.json 0 0 0 test/internal/ci-slowest-tests.test.ts 3 4 0 ``` </details> <!-- robobun:evidence:end -->
1 participant
Problem
scripts/ci-slowest-tests.tsandscripts/buildkite-slow-tests.jsmeasure a file's wall clock as the gap between its[N/TOTAL] <path>header and the next one. Both required the BuildKite---group prefix and a literal[90mgray SGR:scripts/runner.node.mjsemits several other headers that this regex treats as invisible, so whichever serial test happens to precede them is charged the entire phase that follows:--- Running N parallel-safe testsparallelSafeTestsphase start--- Running 444 parallel-safe tests (3-wide)[N/M] <path>(no---)runTestdispatch[258/829] test/js/.../test-foo.ts--- napi prebuild: ...maybePrebuildNapi--- napi prebuild: 3 addon(s), 23.9s--- [A-B/M] K files in parallelrunParallelBucket(#36175)--- [52-257/829] 206 files in parallel (3×)[N/M] <path> (X.XXs)(no---)runParallelBucketper-file summary[52/829] test/bake/... (0.00s)--- [N/M] <path> - <error>--- [16/829] test/... - code 1Observed on build #86086,
:windows: 2019 x64shard 0:parseLog reported
issue-2086.test.tsat 22554 ms; bun's own summary says 41 ms. Same log, one shard earlier:test/regression/issue/24850.test.tsat [51/829] was charged ~60 s for thenapi prebuildand parallel-bucket phase that followed it; bun's own summary says 44 ms.scripts/update-test-durations.mjsalready handled the parallel-safe phase but not thenapi prebuild/[A-B/M]headers, so it had the same misattribution for the test preceding the bucket (mitigated by median-of-5-builds).Fix
parseLogin both slow-test scripts, and the boundary check inupdate-test-durations.mjs:[N/M]phase headers (napi prebuild:,[A-B/M] K files in parallel,Running N parallel-safe,End,Summary,Received ... exiting) close the open span. This is an allowlist rather than "any---" becausepipeTestStdout's sanitiser is not airtight: on build #86086 abun patchdiff (--- a/index.js) andtest/docker/index.tscoordinator output (--- ps ---) both reached the log verbatim and would otherwise truncate the enclosing test's span.[N/M] <path>matches with or without the---prefix[N/M] <path> (X.XXs)bucket summary lines use the inline timing directly[N/M] <path>spans are clamped to 500 ms (inter-dispatch deltas of an N-wide pool, not wall clock)<path> - code 1) are boundaries that do not open a new span, so the 5-15 s retry backoff lands on neither attempt--- End) charges the still-open span to the last timestamp seen instead of dropping itci-slowest-tests.tsandupdate-test-durations.mjsexportparseLogbehind an entrypoint guard sotest/internal/ci-slowest-tests.test.tscan exercise all three parsers against the same header fixtures.Verification
test/internal/ci-slowest-tests.test.tscovers each header form (including the--- a/<file>/--- ps ---false positives). Against real build #86086 logs:test/js/bun/test/fake-timers/sinonjs/issue-2086.test.ts(windows 2019 x64)test/regression/issue/24850.test.ts(windows 2019 x64)test/regression/issue/28632.test.ts(debian 13 aarch64)test/cli/install/bun-patch.test.ts(debian 13 x64-asan)End-to-end across all 162 test-bun jobs in #86086,
issue-2086.test.tsis now at rank 5212 (0.06 s); top 5 are genuinely slow files (compile-asset-bunfs 452 s, bundler_compile 121 s, expo 113 s, v8 109 s, serve-error-handler-stream 103 s).[stamp-90s] gate passed · iteration 6 · 4 files touched
passes on PR (with fix)
diff hotspot
gate history · 5 passed · 0 rejected · iteration 6
evidence per changed file