Skip to content
Closed
Show file tree
Hide file tree
Changes from 10 commits
Commits
Show all changes
34 commits
Select commit Hold shift + click to select a range
f5ccd47
test(napi): check the experimental-finalizer wrapper's output before …
dylan-conway Aug 8, 2026
940630e
test(napi): put the combined-output assertion first
dylan-conway Aug 8, 2026
9efd638
test(napi): diagnostics — second gc() from the event loop + JSC GC lo…
dylan-conway Aug 8, 2026
741c556
test(napi): diagnostics — dump live napi cell counts on the no-crash …
dylan-conway Aug 8, 2026
7f62e76
test(napi): diagnostics — fail loudly when only the event-loop GC cra…
dylan-conway Aug 9, 2026
7027604
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
880da00
ci: retrigger
dylan-conway Aug 9, 2026
51f1c7e
ci(diagnostics): run napi.test.ts 4x on every darwin x64 shard
dylan-conway Aug 9, 2026
2dcf453
test(napi): diagnostics — heap snapshot after a non-finalizing GC #1,…
dylan-conway Aug 9, 2026
e5946fb
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
9db94de
ci: retrigger
dylan-conway Aug 9, 2026
c0e09cd
test(napi): diagnostics — make the artifact upload reachable (isBuild…
dylan-conway Aug 9, 2026
d59a943
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
a2ee2f3
test(napi): diagnostics — allowlisted child env and redact env values…
dylan-conway Aug 9, 2026
a51f860
test(napi): diagnostics — variant matrix driver (original script/env …
dylan-conway Aug 9, 2026
107543a
diagnostics: gc() writes a GC-debugging heap snapshot (per-cell root …
dylan-conway Aug 9, 2026
b8743ea
diagnostics: report VM conservative roots, frame layout, and live-cel…
dylan-conway Aug 9, 2026
56d5010
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
04afe87
diagnostics: also report vm.lastStackTop and live-cell words in the r…
dylan-conway Aug 9, 2026
0dff607
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
f103e21
diagnostics: capture callee-saved registers on entry to gc(); keep gc…
dylan-conway Aug 9, 2026
2aaae6a
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
f07e513
diagnostics: list heap-registered threads and scan their stacks
dylan-conway Aug 9, 2026
0656ed1
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
011d990
diagnostics: match the conservative scan's real candidate window (int…
dylan-conway Aug 9, 2026
5860983
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
85de86a
diagnostics: attribute stack hits to a named native frame (fp chain +…
dylan-conway Aug 9, 2026
bb4430b
[autofix.ci] apply automated fixes
autofix-ci[bot] Aug 9, 2026
c6ceb9a
diagnostics: run the matrix against oven-sh/WebKit#398
dylan-conway Aug 9, 2026
9a48440
Bump WebKit preview build to autobuild-preview-pr-398-e501c5cb (adds …
dylan-conway Aug 9, 2026
c17e393
diagnostics: pre-GC live-region scan for words at/into/just past a li…
dylan-conway Aug 9, 2026
2f31865
diagnostics: always surface V1 run 0's [napi-diag] lines (pre-GC scan…
dylan-conway Aug 9, 2026
04c4180
Bump WebKit preview build to autobuild-preview-pr-398-9b999ae9 (accep…
dylan-conway Aug 9, 2026
cb60a8a
ci: retrigger (WebKit preview assets fully uploaded)
dylan-conway Aug 9, 2026
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions scripts/runner.node.mjs
Original file line number Diff line number Diff line change
Expand Up @@ -2613,6 +2613,17 @@ function getRelevantTests(cwd, testModifiers, testExpectations) {
filteredTests.push(...availableTests);
}

// Diagnostics branch only: every darwin x64 shard runs napi.test.ts, four
// times, so a single build yields several samples from whichever hosts ran.
if (process.platform === "darwin" && process.arch === "x64" && !filters?.length) {
const napi = availableTests.find(t => t.replaceAll("\\", "/") === "napi/napi.test.ts");
if (napi) {
const rest = filteredTests.filter(t => t !== napi);
filteredTests.length = 0;
filteredTests.push(napi, napi, napi, napi, ...rest);
}
}

// Run docker-backed tests (the prefixes the coordinator prestarts) last in
// the shard: the coordinator kicks off `compose up` for their services when
// the runner starts, but a cold mysqld/postgres takes ~10s to become
Expand Down
28 changes: 25 additions & 3 deletions test/napi/napi-app/test_experimental_with_timeout.js
Original file line number Diff line number Diff line change
Expand Up @@ -12,12 +12,34 @@ let arr = m.test_reference_unref_in_finalizer_experimental();
console.log('Test function returned');
arr = null;
global.gc ? global.gc() : (process.isBun && Bun.gc ? Bun.gc(true) : null);
console.log('GC triggered - should crash now');
console.log('ERROR: Did not crash! Test failed!');
process.exit(1);
console.log('GC #1 (synchronous, same stack) returned without crashing');
if (process.env.NAPI_DIAG_SNAPSHOT) {
// Retaining paths of whatever survived GC #1. (Building the snapshot runs a
// GC of its own; if that one finalizes the objects we crash right here,
// which the test also reports.)
require('fs').writeFileSync(process.env.NAPI_DIAG_SNAPSHOT, Bun.generateHeapSnapshot('v8'));
console.log('wrote heap snapshot after GC #1 to ' + process.env.NAPI_DIAG_SNAPSHOT);
}
setImmediate(() => {
global.gc ? global.gc() : (process.isBun && Bun.gc ? Bun.gc(true) : null);
console.log('GC #2 (from a fresh event-loop turn) returned without crashing');
// Diagnostics for the no-crash path: which napi-related cells are still
// live after two full GCs (a live NapiHandleScopeImpl / counts of Object).
const { heapStats } = require("bun:jsc");
const counts = heapStats().objectTypeCounts;
const pick = {};
for (const k of Object.keys(counts)) if (/napi|Napi|External|^Object$|^Array$|Finaliz|Weak/i.test(k)) pick[k] = counts[k];
console.log('live cells after GC #2: ' + JSON.stringify(pick));
console.log('protected: ' + JSON.stringify(heapStats().protectedObjectTypeCounts));
console.log('ERROR: Did not crash! Test failed!');
process.exit(1);
});
`], {
env: {
...process.env,
NAPI_DIAG_SNAPSHOT: path.join(__dirname, 'napi-diag-' + process.pid + '.heapsnapshot'),
// Diagnostics: one line per GC cycle on stderr (C:<n> = conservative roots visited).
BUN_JSC_logGC: "2",
BUN_INTERNAL_SUPPRESS_CRASH_ON_NAPI_ABORT: "1",
ASAN_OPTIONS: "allow_user_segv_handler=1:disable_coredump=1:symbolize=0"
}
Expand Down
32 changes: 29 additions & 3 deletions test/napi/napi.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1329,12 +1329,38 @@
bunProc.exited,
]);

// The wrapper script should exit with 0 if the test passed
expect(bunExitCode).toBe(0);
// Diagnostics: if the child left heap snapshots behind (it only does so
// when GC #1 failed to finalize), upload them as build artifacts.
const diagDir = join(__dirname, "napi-app");
const snapshots = readdirSync(diagDir).filter(f => f.startsWith("napi-diag-") && f.endsWith(".heapsnapshot"));
Comment thread
dylan-conway marked this conversation as resolved.
if (snapshots.length) {
console.error(
"napi diagnostics: heap snapshots:",
snapshots.map(f => `${f} (${statSync(join(diagDir, f)).size} bytes)`),
);
if (process.env.BUILDKITE) {
const up = spawnSync({
cmd: ["buildkite-agent", "artifact", "upload", "napi-diag-*.heapsnapshot"],
cwd: diagDir,
env: process.env,
stdout: "inherit",
stderr: "inherit",
});
console.error("napi diagnostics: artifact upload exit", up.exitCode);
}

Check failure on line 1350 in test/napi/napi.test.ts

View check run for this annotation

Claude / Claude Code Review

Heap-snapshot diagnostics block: upload gate is dead code, and snapshots leak into the source tree

The `if (process.env.BUILDKITE)` gate is dead code: `test/harness.ts` deletes every `BUILDKITE*` key from `process.env` at import time (harness.ts:111-114), so the artifact upload never runs and `env: process.env` lacks `BUILDKITE_AGENT_ACCESS_TOKEN` anyway — use `isBuildKite` for the gate and export/use `ciEnv` for the spawn env, matching harness.ts:1773-1779. Separately, snapshots are written into the checked-in `test/napi/napi-app/` directory and never unlinked; with `runner.node.mjs` now run
Comment thread
dylan-conway marked this conversation as resolved.
}
// Checked first so a failure prints everything the wrapper and child wrote.
// Diagnostics: also fail (and so print everything, including the GC log)
// when the crash only happened on the second, event-loop-turn GC.
expect(bunStdout + "\n---- stderr ----\n" + bunStderr).not.toContain(
"GC #1 (synchronous, same stack) returned without crashing",
);
expect(bunStdout + "\n---- stderr ----\n" + bunStderr).toContain("TEST PASSED: Process crashed as expected");
expect(bunStdout + bunStderr).toContain("Loading experimental module");
expect(bunStdout + bunStderr).toContain("Created");
expect(bunStderr).toContain("FATAL ERROR");
expect(bunStdout + bunStderr).toContain("TEST PASSED: Process crashed as expected");
// The wrapper script should exit with 0 if the test passed
expect(bunExitCode).toBe(0);
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Comment on lines +1404 to +1405

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.

🟡 The wrapper went from a single async spawn (with a 5s SIGKILL fallback) to 7 variants × 3 runs = 21 sequential spawnSync calls — each a full bunExe() startup + addon dlopen + gc + panic report, with V1 run 0 additionally building a JSC GC-debugging heap snapshot — but the outer it(...) timeout stayed at 25_000. The test is only todoIf(isWindows), so it runs on the linux debug/ASAN lane too, where 21 debug+ASAN spawns can plausibly exceed 25s and time out for a reason unrelated to the flake. Either gate the variant matrix to darwin x64 (where the flake reproduces) or raise the timeout to match the new workload — each child's own spawnSync timeout: 60_000 is currently pre-empted by the outer 25s anyway.

Extended reasoning...

What the bug is

The variant-matrix rewrite of test_experimental_with_timeout.js increased the wrapper's workload roughly 21× without adjusting the outer per-test timeout at napi.test.ts:1408, which remains 25_000 ms.

The old wrapper spawned one child asynchronously, forwarded its output, and sent SIGKILL the moment it saw both FATAL ERROR and panic(main thread) on stderr (with a 5s fallback timer). The new wrapper runs 7 variants × 3 runs = 21 sequential spawnSync calls, each of which:

  • launches a full bunExe() child (process.argv[0]),
  • require()s the native addon,
  • runs a synchronous full GC,
  • panics inside the finalizer via NAPI_ABORT, emitting the crash handler's full metadata block (Args, features, argv, environment fingerprint),
  • and — because spawnSync has no early-kill path — waits for the child to fully exit before starting the next one.

Additionally, V1 run 0 writes /tmp/bun-napi-diag-request, so if that child's first GC doesn't crash, bunNapiDiagMaybeDumpHeap runs bunNapiDiagWhereAreTheRoots (a full-heap live-cell walk plus a word-by-word machine-stack scan) and then builds a full JSC GCDebuggingSnapshot — which itself runs another full GC and serializes every cell's root reason to JSON.

Where it can bite

The test is gated only by it.todoIf(isWindows) (napi.test.ts:1296-1299), so it runs on every POSIX lane — including linux-x64 debug and linux-x64 debug+ASAN, not just the darwin-x64 lane the diagnostics target. REVIEW.md's own numbers say "debug+ASAN runs 10-100x slower"; the PR description quotes ~80ms for the original single-spawn run on release darwin-x64, so a debug+ASAN spawn plausibly takes ~1-1.5s each. At ~1.2s per spawn, 21 sequential spawns already exceed 25s — before accounting for the crash handler's metadata output (which is longer on debug builds, 4096-char Args budget) or CI-agent load.

The per-child spawnSync timeout is 60_000 ms (test_experimental_with_timeout.js:80), which is meaningless because the outer 25s pre-empts it: a single slow child (e.g. V5 with BUN_JSC_logGC=1 writing GC log lines under debug+ASAN) can consume most of the budget on its own.

Why existing code doesn't prevent it

  • The old wrapper's early-SIGKILL-on-panic path is gone; spawnSync waits for the child's natural exit, so each child pays the full crash-handler cost.
  • describe.concurrent doesn't help — all 21 spawns are inside one it(...) body, sequential.
  • The 25_000ms value was sized for the previous wrapper (one spawn + 5s fallback), and nothing in this diff touched it.

Step-by-step proof

  1. On a linux-x64 debug+ASAN lane, the outer test spawns [bunExe(), "napi-app/test_experimental_with_timeout.js"].
  2. The wrapper enters its for (const v of variants) / for (let i = 0; i < 3; i++) nest → 21 iterations.
  3. Each iteration's spawnSync(process.argv[0], ['--expose-gc', '-e', v.script], { timeout: 60_000 }) launches a debug+ASAN bun, which starts up (~several hundred ms under ASAN), dlopens test_reference_unref_in_finalizer_experimental.node, calls gc(), panics via NAPI_ABORT, and writes the full crash-handler metadata to stderr.
  4. spawnSync blocks until the child fully exits — no early kill on seeing panic.
  5. Suppose each iteration averages ~1.3s (well within the 10-100× debug+ASAN multiplier over the ~80ms release baseline). 21 × 1.3s ≈ 27.3s.
  6. The outer test's Jest timer fires at 25_000ms → "thrown: exceeded 25000ms timeout" on a lane unrelated to the darwin-x64 flake being investigated.
  7. runner.node.mjs now runs napi.test.ts 4× back-to-back on darwin x64, so a marginal per-run duration compounds there too — though darwin-x64 release is the fast lane and the more likely victim is linux debug/ASAN.

Impact

Unrelated timeout noise on non-darwin lanes while iterating on this diagnostics branch. That's the exact opposite of what the branch wants: clean CI signal so a genuine TEST FAILED: at least one variant did not crash on the first GC stands out. Not a correctness/data-loss issue, and the author has stated the branch won't merge, so this is a nit.

How to fix

Either is fine (the second is closer to REVIEW.md's "shrink the workload" preference):

  • Raise the timeout to match the new workload, e.g. 21 * 60_000 or a conservative 180_000, so the per-child spawnSync timeout is the operative bound.
  • Gate the matrix to the target lane: wrap the variant loop (or the whole test) in if (process.platform === 'darwin' && process.arch === 'x64') (or it.todoIf(!isMacOS || !isIntelMacOS || isWindows)), so non-darwin lanes keep roughly the original single-spawn cost.


// The marker must NOT have actually been printed. Only check stdout: the
// fixture prints the marker via console.log (stdout), while stderr contains
Expand Down