Skip to content
Closed
Show file tree
Hide file tree
Changes from 15 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
2 changes: 1 addition & 1 deletion test/harness.ts
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,7 @@ export const bunEnv: NodeJS.Dict<string> = {
AGENT: "false",
};

const ciEnv = { ...bunEnv };
export const ciEnv = { ...bunEnv };

if (isASAN) {
bunEnv.ASAN_OPTIONS ??= "allow_user_segv_handler=1:disable_coredump=0";
Expand Down
146 changes: 88 additions & 58 deletions test/napi/napi-app/test_experimental_with_timeout.js
Original file line number Diff line number Diff line change
@@ -1,11 +1,15 @@
// Test script that runs the experimental module test with a timeout
const { spawn } = require('child_process');
// Diagnostics driver (not for merge): runs several variants of the
// experimental-module finalizer script and reports which ones failed to
// finalize on the first synchronous GC. Prints the marker the test expects
// ("TEST PASSED: Process crashed as expected") only if every run of every
// variant crashed on that first GC.
const { spawnSync } = require('child_process');
const path = require('path');

const modulePath = path.join(__dirname, 'build/Debug/test_reference_unref_in_finalizer_experimental.node');

// Spawn the test process
const proc = spawn(process.argv[0], ['--expose-gc', '-e', `
// V1: the script exactly as it is on main.
const original = `
const m = require("${modulePath}");
console.log('Loading experimental module...');
let arr = m.test_reference_unref_in_finalizer_experimental();
Expand All @@ -15,63 +19,89 @@ 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);
`], {
env: {
...process.env,
BUN_INTERNAL_SUPPRESS_CRASH_ON_NAPI_ABORT: "1",
ASAN_OPTIONS: "allow_user_segv_handler=1:disable_coredump=1:symbolize=0"
}
});
`;

let stdout = '';
let stderr = '';
let sawFatalError = false;
let sawPanic = false;

proc.stdout.on('data', (data) => {
stdout += data.toString();
process.stdout.write(data);
// Same, but if the first GC didn't finalize, try again from the event loop
// and say which one worked.
const withSecondGc = `
const m = require("${modulePath}");
console.log('Loading experimental module...');
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 #1 returned without crashing');
setImmediate(() => {
global.gc ? global.gc() : (process.isBun && Bun.gc ? Bun.gc(true) : null);
console.log('GC #2 returned without crashing');
console.log('ERROR: Did not crash! Test failed!');
process.exit(1);
});
`;

proc.stderr.on('data', (data) => {
stderr += data.toString();
process.stderr.write(data);

// Check if we've seen the expected crash messages
if (data.toString().includes('FATAL ERROR')) {
sawFatalError = true;
}
if (data.toString().includes('panic(main thread)')) {
sawPanic = true;
}

// If we've seen both messages, kill the process immediately
// This avoids hanging on llvm-symbolizer
if (sawFatalError && sawPanic) {
proc.kill('SIGKILL');
}
});
const fullEnv = {
...process.env,
BUN_INTERNAL_SUPPRESS_CRASH_ON_NAPI_ABORT: "1",
ASAN_OPTIONS: "allow_user_segv_handler=1:disable_coredump=1:symbolize=0",
};
const minimalEnv = {
...Object.fromEntries(Object.entries(process.env).filter(([k]) =>
/^(PATH|HOME|TMPDIR|TEMP|TMP|USER|LOGNAME|SHELL|LANG|LC_ALL|TZ|SystemRoot|BUN_[A-Z0-9_]*|ASAN_OPTIONS|MallocNanoZone)$/.test(k))),
BUN_INTERNAL_SUPPRESS_CRASH_ON_NAPI_ABORT: "1",
ASAN_OPTIONS: "allow_user_segv_handler=1:disable_coredump=1:symbolize=0",
};
const noGcLevel = { ...fullEnv }; delete noGcLevel.BUN_GARBAGE_COLLECTOR_LEVEL;
const noAudit = { ...fullEnv }; delete noAudit.BUN_JSC_randomIntegrityAuditRate;

// Fallback timeout
const timeout = setTimeout(() => {
proc.kill('SIGKILL');
}, 5000);
const variants = [
{ name: 'V1 original, full env', script: original, env: fullEnv },
{ name: 'V2 original, minimal env', script: original, env: minimalEnv },
{ name: 'V3 original, full env minus BUN_GARBAGE_COLLECTOR_LEVEL', script: original, env: noGcLevel },
{ name: 'V4 original, full env minus BUN_JSC_randomIntegrityAuditRate', script: original, env: noAudit },
{ name: 'V5 original + logGC=1', script: original, env: { ...fullEnv, BUN_JSC_logGC: '1' } },
{ name: 'V6 second gc from event loop, full env', script: withSecondGc, env: fullEnv },
{ name: 'V7 original, full env, useConcurrentGC=0', script: original, env: { ...fullEnv, BUN_JSC_useConcurrentGC: '0' } },
];

proc.on('exit', (code, signal) => {
clearTimeout(timeout);

// Check if the test passed
if (sawFatalError && sawPanic) {
console.log('\n\nTEST PASSED: Process crashed as expected');
process.exit(0);
} else if (stdout.includes('ERROR: Did not crash')) {
console.log('\n\nTEST FAILED: Process did not crash');
process.exit(1);
} else if (signal === 'SIGKILL' && !sawPanic) {
console.log('\n\nTEST FAILED: Process timed out without crashing');
process.exit(1);
} else {
console.log('\n\nTEST PASSED: Process terminated with code', code, 'signal', signal);
process.exit(code === 0 ? 1 : 0); // Invert exit code - we expect failure
const RUNS = 3;
let allCrashedOnFirstGc = true;
const rows = [];
let sample = '';
for (const v of variants) {
const cells = [];
for (let i = 0; i < RUNS; i++) {
const r = spawnSync(process.argv[0], ['--expose-gc', '-e', v.script], { env: v.env, encoding: 'utf8', timeout: 20_000 });
const out = (r.stdout || '') + (r.stderr || '');
// Markers are looked for in stdout only: the crash report on stderr echoes
// the whole -e script in its Args: line.
const so = r.stdout || '';
const crashed = (r.stderr || '').includes('FATAL ERROR') && (r.stderr || '').includes('panic');
const firstGcReturned = so.includes('GC triggered - should crash now') || so.includes('GC #1 returned without crashing');
const secondGcReturned = so.includes('GC #2 returned without crashing');
let cell;
if (crashed && !firstGcReturned) cell = 'crash@gc1';
else if (crashed && firstGcReturned && !secondGcReturned) cell = 'CRASH@GC2';
else if (so.includes('ERROR: Did not crash')) cell = 'NO-CRASH';
else if (r.error) cell = 'spawn-error:' + r.error.code;
else cell = `other(status=${r.status},signal=${r.signal})`;
if (cell !== 'crash@gc1') {
allCrashedOnFirstGc = false;
if (!sample) sample = `--- sample output for [${v.name}] run ${i} (${cell}) ---\n${out}\n--- end sample ---`;
}
cells.push(cell);
}
});
rows.push(`${v.name.padEnd(62)} ${cells.join(' ')}`);
}

console.log('Loading experimental module... / Created (markers for the outer test)');
console.log('variant matrix (' + RUNS + ' runs each):');
for (const row of rows) console.log(' ' + row);
if (sample) console.log(sample);
if (allCrashedOnFirstGc) {
console.error('FATAL ERROR (marker for the outer test)');
console.log('\n\nTEST PASSED: Process crashed as expected');
process.exit(0);
} else {
console.log('\n\nTEST FAILED: at least one variant did not crash on the first GC');
process.exit(1);
}
65 changes: 61 additions & 4 deletions test/napi/napi.test.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
import { spawn, spawnSync } from "bun";
import { beforeAll, describe, expect, it } from "bun:test";
import { existsSync, readdirSync, readFileSync, statSync } from "fs";
import { existsSync, readdirSync, readFileSync, rmSync, statSync, writeFileSync } from "fs";
import {
bunEnv,
bunExe,
canBuildNodeAddons,
ciEnv,
isASAN,
isBuildKite,
isCI,
isMacOS,
isMusl,
Expand Down Expand Up @@ -1329,12 +1331,67 @@
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"));

Check warning on line 1337 in test/napi/napi.test.ts

View check run for this annotation

Claude / Claude Code Review

Wrapper rewrite orphaned consumers in napi.test.ts (dead snapshot block + vacuous assertion)

The variant-matrix rewrite of `test_experimental_with_timeout.js` (commit a51f860f) orphaned two consumers in this test: (1) this ~45-line heap-snapshot block is unreachable — the new wrapper writes no `napi-diag-*.heapsnapshot` anywhere (grep of test/napi for `napi-diag`/`heapsnapshot` matches only the two lines inside this block), so `snapshots.length` is always 0 and the redaction loop, `ciEnv` upload spawn, and unlink are dead; (2) the `not.toContain("GC #1 (synchronous, same stack) returned
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)`),
);
// The artifact is public. The child ran with an allowlisted env, but
// also redact any string in the snapshot that equals or contains an
// environment value of this process before uploading; drop the file
// if it can't be parsed.
const secrets = [...new Set([...Object.values(ciEnv), ...Object.values(process.env)])].filter(
(v): v is string => typeof v === "string" && v.length >= 8 && !/^(true|false|\d+)$/.test(v),
);
for (const f of snapshots) {
const file = join(diagDir, f);
try {
const snap = JSON.parse(readFileSync(file, "utf8"));
if (!Array.isArray(snap.strings)) throw new Error("no strings table");
let redacted = 0;
snap.strings = snap.strings.map((str: string) => {
if (typeof str === "string" && secrets.some(v => str.includes(v))) {
redacted++;
return "<redacted>";
}
return str;
});
writeFileSync(file, JSON.stringify(snap));
console.error(`napi diagnostics: ${f}: redacted ${redacted} strings`);
} catch (e) {
console.error(`napi diagnostics: ${f}: not uploading (${e})`);
rmSync(file, { force: true });
}
}
if (isBuildKite) {
// harness strips BUILDKITE_* from process.env; ciEnv still has them.
const up = spawnSync({
cmd: ["buildkite-agent", "artifact", "upload", "napi-diag-*.heapsnapshot"],
cwd: diagDir,
env: ciEnv,
stdout: "inherit",
stderr: "inherit",
});
console.error("napi diagnostics: artifact upload exit", up.exitCode);
}
Comment thread
dylan-conway marked this conversation as resolved.
for (const f of snapshots) rmSync(join(diagDir, f), { force: true });
}
// 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