diff --git a/scripts/build/deps/webkit.ts b/scripts/build/deps/webkit.ts index b83fd45a6ad5..882cb00685b8 100644 --- a/scripts/build/deps/webkit.ts +++ b/scripts/build/deps/webkit.ts @@ -3,7 +3,7 @@ * for local mode. Override via `--webkit-version=` to test a branch. * From https://github.com/oven-sh/WebKit releases. */ -export const WEBKIT_VERSION = "171babe26c3b330ac0263d1bed3550571908c838"; +export const WEBKIT_VERSION = "autobuild-preview-pr-398-9b999ae9"; /** * WebKit (JavaScriptCore) — the JS engine. diff --git a/scripts/runner.node.mjs b/scripts/runner.node.mjs index b6e5bddf8b2e..529b6fe3b03b 100755 --- a/scripts/runner.node.mjs +++ b/scripts/runner.node.mjs @@ -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 diff --git a/src/jsc/bindings/ZigGlobalObject.cpp b/src/jsc/bindings/ZigGlobalObject.cpp index 3022c09cafe3..f8a67624d4e3 100644 --- a/src/jsc/bindings/ZigGlobalObject.cpp +++ b/src/jsc/bindings/ZigGlobalObject.cpp @@ -1,6 +1,18 @@ #include "root.h" #include "ZigGlobalObject.h" +#include "JavaScriptCore/HeapSnapshotBuilder.h" +#include "JavaScriptCore/HeapProfiler.h" +#include "JavaScriptCore/ConservativeRoots.h" +#include "JavaScriptCore/MachineStackMarker.h" +#include "JavaScriptCore/HeapIterationScope.h" +#include "JavaScriptCore/MarkedSpaceInlines.h" +#include "JavaScriptCore/StackVisitor.h" +#include +#include +#if !OS(WINDOWS) +#include +#endif #include "MessagePort.h" #include "helpers.h" #include "JavaScriptCore/ArgList.h" @@ -3251,11 +3263,376 @@ void GlobalObject::addBuiltinGlobals(JSC::VM& vm) /// `globalThis.gc()` is an alias for `Bun.gc(true)` /// Note that `vm` is a `VirtualMachine*` extern "C" size_t Bun__gc(void* vm, bool sync); + +// Diagnostics branch only: when /tmp/bun-napi-diag-request exists, `gc()` +// additionally writes a JSC GC-debugging heap snapshot (which records, per +// live cell, the root that marked it) to /tmp/bun-napi-diag-.json. Keyed +// on a file rather than argv/env so the process under test is byte-for-byte +// the same as the one that fails. +static constexpr size_t kBelowSpBytes = 256 * 1024; +static uintptr_t bunNapiDiagBelowSpCopy[kBelowSpBytes / sizeof(uintptr_t)]; +static uintptr_t* bunNapiDiagBelowSpFrom = nullptr; +static void* bunNapiDiagLastStackTopBefore = nullptr; +// Callee-saved registers as they were on entry to gc()'s host function: these +// propagate unchanged into the collector and are part of the captured register +// state that the conservative scan visits. +static uintptr_t bunNapiDiagCalleeSaved[12]; +static const char* const bunNapiDiagCalleeSavedNames[12] = { +#if CPU(X86_64) + "rbx", "rbp", "r12", "r13", "r14", "r15", "", "", "", "", "", "" +#elif CPU(ARM64) + "x19", "x20", "x21", "x22", "x23", "x24", "x25", "x26", "x27", "x28", "fp", "" +#else + "", "", "", "", "", "", "", "", "", "", "", "" +#endif +}; +#if CPU(X86_64) +#define BUN_NAPI_DIAG_CAPTURE_CALLEE_SAVED() \ + do { \ + asm volatile("movq %%rbx, %0" : "=m"(bunNapiDiagCalleeSaved[0])); \ + asm volatile("movq %%rbp, %0" : "=m"(bunNapiDiagCalleeSaved[1])); \ + asm volatile("movq %%r12, %0" : "=m"(bunNapiDiagCalleeSaved[2])); \ + asm volatile("movq %%r13, %0" : "=m"(bunNapiDiagCalleeSaved[3])); \ + asm volatile("movq %%r14, %0" : "=m"(bunNapiDiagCalleeSaved[4])); \ + asm volatile("movq %%r15, %0" : "=m"(bunNapiDiagCalleeSaved[5])); \ + } while (0) +#elif CPU(ARM64) +#define BUN_NAPI_DIAG_CAPTURE_CALLEE_SAVED() \ + do { \ + asm volatile("str x19, %0" : "=m"(bunNapiDiagCalleeSaved[0])); \ + asm volatile("str x20, %0" : "=m"(bunNapiDiagCalleeSaved[1])); \ + asm volatile("str x21, %0" : "=m"(bunNapiDiagCalleeSaved[2])); \ + asm volatile("str x22, %0" : "=m"(bunNapiDiagCalleeSaved[3])); \ + asm volatile("str x23, %0" : "=m"(bunNapiDiagCalleeSaved[4])); \ + asm volatile("str x24, %0" : "=m"(bunNapiDiagCalleeSaved[5])); \ + asm volatile("str x25, %0" : "=m"(bunNapiDiagCalleeSaved[6])); \ + asm volatile("str x26, %0" : "=m"(bunNapiDiagCalleeSaved[7])); \ + asm volatile("str x27, %0" : "=m"(bunNapiDiagCalleeSaved[8])); \ + asm volatile("str x28, %0" : "=m"(bunNapiDiagCalleeSaved[9])); \ + asm volatile("str x29, %0" : "=m"(bunNapiDiagCalleeSaved[10])); \ + } while (0) +#else +#define BUN_NAPI_DIAG_CAPTURE_CALLEE_SAVED() \ + do { \ + } while (0) +#endif + +__attribute__((no_sanitize("address"), noinline)) static void bunNapiDiagWhereAreTheRoots(JSC::VM& vm, JSC::CallFrame* callFrame) +{ + // 1. Every live cell start address after the gc() that just ran. + WTF::HashSet liveCells; + { + JSC::HeapIterationScope scope(vm.heap); + vm.heap.objectSpace().forEachLiveCell(scope, [&](JSC::HeapCell* cell, JSC::HeapCell::Kind kind) { + if (kind == JSC::HeapCell::JSCell) + liveCells.add(reinterpret_cast(cell)); + return IterationStatus::Continue; + }); + } + auto describe = [&](uintptr_t p) -> const char* { + return reinterpret_cast(p)->className().characters(); + }; + fprintf(stderr, "[napi-diag] live JS cells: %u\n", liveCells.size()); + + // A word "hits" a cell if it points anywhere in [cell, cell+64): that covers + // interior pointers (ConservativeRoots cellAlign()s them) and, for our + // 16-byte JSArray, the [cell+16, cell+24] "butterfly just past the previous + // object" case that genericAddPointer maps back onto the cell to the left. + // The offset is reported so over-matches can be discounted by hand. + static size_t bunNapiDiagLastOff; + bunNapiDiagLastOff = 0; + auto interesting = [&](uintptr_t v, uintptr_t& base) -> const char* { + base = 0; + if (v < 4096 || v == UINTPTR_MAX) + return nullptr; + uintptr_t aligned = v & ~uintptr_t(7); + for (size_t off = 0; off <= 56; off += 8) { + if (aligned < off + 4096) + break; + if (liveCells.contains(aligned - off)) { + base = aligned - off; + bunNapiDiagLastOff = v - base; + break; + } + } + if (!base) + return nullptr; + const char* cls = describe(base); + if (strcmp(cls, "Array") && strcmp(cls, "Object") && strcmp(cls, "NapiClass") && strcmp(cls, "NapiPrototype") && strcmp(cls, "NapiHandleScopeImpl")) + return nullptr; + return cls; + }; + + // 2. VM-owned conservatively scanned buffers (Heap::gatherVMRoots). + { + JSC::ConservativeRoots vmRoots(vm.heap); +#if ENABLE(DFG_JIT) + vm.gatherScratchBufferRoots(vmRoots); +#endif + fprintf(stderr, "[napi-diag] VM scratch-buffer conservative roots: %zu; checkpoint OSR side state present: %d\n", vmRoots.size(), (int)vm.hasCheckpointOSRSideState()); + for (size_t i = 0; i < vmRoots.size(); ++i) { + auto p = reinterpret_cast(vmRoots.roots()[i]); + if (p < 16 || p == UINTPTR_MAX) continue; + fprintf(stderr, "[napi-diag] vmroot %p %s\n", (void*)p, liveCells.contains(p) ? describe(p) : "(not a live cell start)"); + } + } + + // 3. JS/native frame layout, so stack hits can be attributed. + fprintf(stderr, "[napi-diag] frames (top first):\n"); + JSC::StackVisitor::visit(callFrame, vm, [&](JSC::StackVisitor& visitor) -> IterationStatus { + auto name = visitor->functionName().utf8(); + auto* cb = visitor->codeBlock(); + fprintf(stderr, "[napi-diag] frame callFrame=%p callerFrame=%p %s%s codeType=%d bc#%u regs=%d\n", + (void*)visitor->callFrame(), (void*)visitor->callerFrame(), name.data(), + visitor->isNativeFrame() ? " [native]" : "", cb ? (int)cb->codeType() : -1, + visitor->bytecodeIndex().offset(), cb ? (int)cb->numCalleeLocals() : -1); + return IterationStatus::Continue; + }); + + // 4. Words on this thread's machine stack, from here up to the origin, + // that equal (or point 8 bytes into) a live cell. + volatile uintptr_t marker = 0; + uintptr_t* sp = const_cast(&marker); + uintptr_t* origin = static_cast(WTF::Thread::currentSingleton().stack().origin()); + fprintf(stderr, "[napi-diag] scanning machine stack %p..%p (%zu words)\n", (void*)sp, (void*)origin, (size_t)(origin - sp)); + unsigned hits = 0; + for (uintptr_t* w = sp; w < origin; ++w) { + uintptr_t base; + const char* cls = interesting(*w, base); + if (!cls) + continue; + ++hits; + fprintf(stderr, "[napi-diag] stack[%p] (origin-0x%zx) = %p -> %s @%p +%zu\n", (void*)w, (size_t)((origin - w) * sizeof(uintptr_t)), (void*)*w, cls, (void*)base, bunNapiDiagLastOff); + } + fprintf(stderr, "[napi-diag] stack words pointing at Array/Object/Napi* cells: %u\n", hits); + + // 4'. Native frame layout above (and including) this frame, via the frame + // pointer chain, with return addresses symbolized, so a hit can be + // attributed to the frame that owns the slot. Then re-list the hits with + // the owning frame and a few neighbouring words. + { + struct NativeFrame { + uintptr_t* fp; + const char* name; + uintptr_t ret; + }; + WTF::Vector chain; + uintptr_t* fp = static_cast(__builtin_frame_address(0)); + while (fp && fp < origin && chain.size() < 120) { + uintptr_t ret = fp[1]; + Dl_info info; + const char* name = (dladdr(reinterpret_cast(ret), &info) && info.dli_sname) ? info.dli_sname : "?"; + chain.append({ fp, name, ret }); + uintptr_t* next = reinterpret_cast(fp[0]); + if (next <= fp) break; + fp = next; + } + fprintf(stderr, "[napi-diag] native frames (fp chain, innermost first):\n"); + for (auto& f : chain) + fprintf(stderr, "[napi-diag] fp=%p (origin-0x%zx) ret=%p %s\n", (void*)f.fp, (size_t)((origin - f.fp) * sizeof(uintptr_t)), (void*)f.ret, f.name); + for (uintptr_t* w = sp; w < origin; ++w) { + uintptr_t base; + const char* cls = interesting(*w, base); + if (!cls) continue; + // owning frame: the innermost chain entry whose fp is above w is the CALLEE boundary; + // the slot belongs to the frame whose fp is the first one >= w. + const char* owner = "?"; + uintptr_t* ownerFp = nullptr; + const char* calleeName = "?"; + for (size_t i = 0; i < chain.size(); ++i) { + if (chain[i].fp >= w) { + ownerFp = chain[i].fp; + owner = i + 1 < chain.size() ? chain[i + 1].name : "(outermost)"; + calleeName = chain[i].name; + break; + } + } + fprintf(stderr, "[napi-diag] HIT stack[%p] = %p -> %s @%p +%zu ; slot is in the frame of [%s] (fp=%p, fp-0x%zx), which had called [%s]\n", + (void*)w, (void*)*w, cls, (void*)base, bunNapiDiagLastOff, owner, (void*)ownerFp, ownerFp ? (size_t)((ownerFp - w) * sizeof(uintptr_t)) : (size_t)0, calleeName); + fprintf(stderr, "[napi-diag] neighbours:"); + for (int d = -4; d <= 4; ++d) + if (w + d >= sp && w + d < origin) fprintf(stderr, " [%+d]=%p", d, (void*)w[d]); + fprintf(stderr, "\n"); + // What is at the cell the word literally points into (base + off rounded to 16)? + uintptr_t pointee = (*w) & ~uintptr_t(0xF); + fprintf(stderr, "[napi-diag] word&~0xF=%p is %s\n", (void*)pointee, liveCells.contains(pointee) ? describe(pointee) : (liveCells.contains(pointee - 8) ? "8 bytes into a live cell" : "not a live cell start (free/dead slot or interior)")); + } + } + + // 4a. Every thread registered with this heap's MachineThreads (each one is + // suspended and its registers + stack [sp, origin) conservatively + // scanned by every collection). Report them, and any word anywhere in + // their stack range that points at the interesting cells. + { + auto& machineThreads = vm.heap.machineThreads(); + Locker locker { machineThreads.getLock() }; + const auto& threads = machineThreads.threads(locker); + fprintf(stderr, "[napi-diag] threads registered with the heap: %u (current uid %u)\n", threads.size(), WTF::Thread::currentSingleton().uid()); + for (auto& threadRef : threads) { + WTF::Thread& t = threadRef.get(); + bool isCurrent = &t == &WTF::Thread::currentSingleton(); + uintptr_t* lo = static_cast(t.stack().end()); + uintptr_t* hi = static_cast(t.stack().origin()); + fprintf(stderr, "[napi-diag] thread uid=%u%s stack=%p..%p\n", t.uid(), isCurrent ? " [current]" : "", (void*)lo, (void*)hi); + if (isCurrent) + continue; + unsigned th = 0; + for (uintptr_t* w = lo + 512; w < hi; ++w) { // skip the guard-ish bottom + uintptr_t base; + const char* cls = interesting(*w, base); + if (!cls) continue; + if (++th <= 40) + fprintf(stderr, "[napi-diag] other-thread stack[%p] (origin-0x%zx) = %p -> %s @%p +%zu\n", (void*)w, (size_t)((hi - w) * sizeof(uintptr_t)), (void*)*w, cls, (void*)base, bunNapiDiagLastOff); + } + fprintf(stderr, "[napi-diag] words on that thread's stack pointing at Array/Object/Napi* cells: %u\n", th); + } + } + + // 4b. Callee-saved registers on entry to gc()'s host function. + for (int i = 0; i < 12; ++i) { + if (!bunNapiDiagCalleeSavedNames[i][0]) continue; + uintptr_t base; + const char* cls = interesting(bunNapiDiagCalleeSaved[i], base); + fprintf(stderr, "[napi-diag] callee-saved %s = %p%s%s +%zu\n", bunNapiDiagCalleeSavedNames[i], (void*)bunNapiDiagCalleeSaved[i], cls ? " -> " : "", cls ? cls : "", cls ? bunNapiDiagLastOff : (size_t)0); + } + + // 5. The dead region below gc()'s frame as it was BEFORE the collection + // (this is what the collector's own frames were laid over), and vm.lastStackTop + // at that moment (sanitizeStackForVM only zeroes [lastStackTop, sp)). + fprintf(stderr, "[napi-diag] vm.lastStackTop before gc: %p (gc frame ~%p; %s)\n", bunNapiDiagLastStackTopBefore, (void*)sp, + (uintptr_t)bunNapiDiagLastStackTopBefore < (uintptr_t)sp ? "DEEPER than gc frame: sanitize could zero below" : "not deeper: sanitize zeroed nothing below gc frame"); + if (bunNapiDiagBelowSpFrom) { + unsigned below = 0; + size_t n = kBelowSpBytes / sizeof(uintptr_t); + for (size_t i = 0; i < n; ++i) { + uintptr_t base; + const char* cls = interesting(bunNapiDiagBelowSpCopy[i], base); + if (!cls) continue; + ++below; + uintptr_t* where = bunNapiDiagBelowSpFrom + i; + fprintf(stderr, "[napi-diag] pre-gc below-sp[%p] (gcframe-0x%zx) = %p -> %s @%p +%zu\n", (void*)where, (size_t)((sp - where) * sizeof(uintptr_t)), (void*)bunNapiDiagBelowSpCopy[i], cls, (void*)base, bunNapiDiagLastOff); + } + fprintf(stderr, "[napi-diag] pre-gc words BELOW gc()'s frame pointing at Array/Object/Napi* cells: %u (region %p..%p)\n", below, (void*)bunNapiDiagBelowSpFrom, (void*)(bunNapiDiagBelowSpFrom + n)); + } + // 6. Same region now (what the collector left). + { + unsigned belowNow = 0; + uintptr_t* from = sp - kBelowSpBytes / sizeof(uintptr_t); + uintptr_t* limit = static_cast(WTF::Thread::currentSingleton().stack().end()); + if (from < limit + 4096) from = limit + 4096; + for (uintptr_t* w = from; w < sp; ++w) { + uintptr_t base; + const char* cls = interesting(*w, base); + if (!cls) continue; + ++belowNow; + fprintf(stderr, "[napi-diag] post-gc below-sp[%p] (gcframe-0x%zx) = %p -> %s @%p +%zu\n", (void*)w, (size_t)((sp - w) * sizeof(uintptr_t)), (void*)*w, cls, (void*)base, bunNapiDiagLastOff); + } + fprintf(stderr, "[napi-diag] post-gc words BELOW gc()'s frame pointing at Array/Object/Napi* cells: %u\n", belowNow); + } + fflush(stderr); +} + +__attribute__((noinline)) static void bunNapiDiagMaybeDumpHeap(JSC::VM& vm, JSC::CallFrame* callFrame) +{ +#if OS(WINDOWS) + return; +#else + if (access("/tmp/bun-napi-diag-request", F_OK) != 0) + return; + fprintf(stderr, "[napi-diag] gc() returned\n"); + fflush(stderr); + bunNapiDiagWhereAreTheRoots(vm, callFrame); + fprintf(stderr, "[napi-diag] building GC-debugging snapshot (runs another full GC)\n"); + fflush(stderr); + vm.ensureHeapProfiler(); + auto& heapProfiler = *vm.heapProfiler(); + heapProfiler.clearSnapshots(); + JSC::HeapSnapshotBuilder builder(heapProfiler, JSC::HeapSnapshotBuilder::SnapshotType::GCDebuggingSnapshot); + builder.buildSnapshot(); + WTF::String json = builder.json(); + char path[128]; + snprintf(path, sizeof(path), "/tmp/bun-napi-diag-%d.json", getpid()); + if (FILE* f = fopen(path, "w")) { + auto utf8 = json.utf8(); + fwrite(utf8.data(), 1, utf8.length(), f); + fclose(f); + fprintf(stderr, "[napi-diag] wrote %s (%zu bytes)\n", path, utf8.length()); + } else { + fprintf(stderr, "[napi-diag] could not open %s\n", path); + } + fflush(stderr); +#endif +} + +// Diagnostics: copy of the dead stack region below gc()'s frame taken before +// the collection runs (see the statics above bunNapiDiagWhereAreTheRoots). +// Pre-GC: report every word between this frame and the stack origin that +// points at / into / just past a live JSArray, so a run in which the following +// collection finalizes (and aborts) still shows what the scan was about to see. +__attribute__((no_sanitize("address"), noinline)) static void bunNapiDiagPreGcLiveScan(JSC::VM& vm) +{ + WTF::HashSet arrays; + { + JSC::HeapIterationScope scope(vm.heap); + vm.heap.objectSpace().forEachLiveCell(scope, [&](JSC::HeapCell* cell, JSC::HeapCell::Kind kind) { + if (kind == JSC::HeapCell::JSCell && static_cast(cell)->type() == JSC::ArrayType) + arrays.add(reinterpret_cast(cell)); + return IterationStatus::Continue; + }); + } + volatile uintptr_t marker = 0; + uintptr_t* sp = const_cast(&marker); + uintptr_t* origin = static_cast(WTF::Thread::currentSingleton().stack().origin()); + unsigned hits = 0; + for (uintptr_t* w = sp; w < origin; ++w) { + uintptr_t v = *w; + if (v < 4096 || v == UINTPTR_MAX) + continue; + uintptr_t aligned = v & ~uintptr_t(7); + for (size_t off = 0; off <= 32; off += 8) { + if (aligned < off + 4096) + break; + uintptr_t base = aligned - off; + if (!arrays.contains(base)) + continue; + ++hits; + fprintf(stderr, "[napi-diag] PRE-GC stack[%p] (origin-0x%zx) = %p -> Array @%p +%zu (addr mod 16 = %zu => %s)\n", + (void*)w, (size_t)((origin - w) * sizeof(uintptr_t)), (void*)v, (void*)base, (size_t)(v - base), + (size_t)(base & 15), (base & 8) ? "PreciseAllocation" : "MarkedBlock"); + break; + } + } + fprintf(stderr, "[napi-diag] PRE-GC live JSArrays: %u; stack words at/into/just past one: %u\n", arrays.size(), hits); + fflush(stderr); +} + +__attribute__((no_sanitize("address"), noinline)) static void bunNapiDiagCaptureBelowSp(JSC::VM& vm) +{ + volatile uintptr_t marker = 0; + uintptr_t* sp = const_cast(&marker); + uintptr_t* from = sp - kBelowSpBytes / sizeof(uintptr_t); + uintptr_t* limit = static_cast(WTF::Thread::currentSingleton().stack().end()); + if (from < limit + 4096) + from = limit + 4096; + bunNapiDiagBelowSpFrom = from; + for (size_t i = 0; from + i < sp && i < kBelowSpBytes / sizeof(uintptr_t); ++i) + bunNapiDiagBelowSpCopy[i] = from[i]; + bunNapiDiagLastStackTopBefore = vm.lastStackTop(); +} + JSC_DEFINE_HOST_FUNCTION(functionJsGc, (JSC::JSGlobalObject * global, JSC::CallFrame* callFrame)) { + BUN_NAPI_DIAG_CAPTURE_CALLEE_SAVED(); Zig::GlobalObject* globalObject = defaultGlobalObject(global); +#if !OS(WINDOWS) + if (access("/tmp/bun-napi-diag-request", F_OK) == 0) { + bunNapiDiagPreGcLiveScan(JSC::getVM(global)); + bunNapiDiagCaptureBelowSp(JSC::getVM(global)); + } +#endif Bun__gc(globalObject->bunVM(), true); + bunNapiDiagMaybeDumpHeap(JSC::getVM(global), callFrame); return JSValue::encode(jsUndefined()); } diff --git a/test/harness.ts b/test/harness.ts index a6c07623ec17..ef872ea9bb98 100644 --- a/test/harness.ts +++ b/test/harness.ts @@ -87,7 +87,7 @@ export const bunEnv: NodeJS.Dict = { AGENT: "false", }; -const ciEnv = { ...bunEnv }; +export const ciEnv = { ...bunEnv }; if (isASAN) { bunEnv.ASAN_OPTIONS ??= "allow_user_segv_handler=1:disable_coredump=0"; diff --git a/test/napi/napi-app/test_experimental_with_timeout.js b/test/napi/napi-app/test_experimental_with_timeout.js index 8bd34862370e..952a1c0da268 100644 --- a/test/napi/napi-app/test_experimental_with_timeout.js +++ b/test/napi/napi-app/test_experimental_with_timeout.js @@ -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(); @@ -15,63 +19,116 @@ 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 = ''; +const fs = require('fs'); +const DIAG_REQUEST = '/tmp/bun-napi-diag-request'; +for (const v of variants) { + const cells = []; + for (let i = 0; i < RUNS; i++) { + // For the first run of V1 only, ask the (diagnostics-patched) binary to + // dump a GC-debugging heap snapshot from inside gc(). Keyed on a file so + // the child's argv/env stay byte-identical to the failing configuration. + const wantDump = v === variants[0] && i === 0; + try { if (wantDump) fs.writeFileSync(DIAG_REQUEST, ''); else fs.rmSync(DIAG_REQUEST, { force: true }); } catch {} + const r = spawnSync(process.argv[0], ['--expose-gc', '-e', v.script], { env: v.env, encoding: 'utf8', timeout: 60_000 }); + try { fs.rmSync(DIAG_REQUEST, { force: true }); } catch {} + if (wantDump) { + // Always surface the child's [napi-diag] lines for V1 run 0, pass or fail: + // the outer test prints this file unconditionally. + try { + fs.writeFileSync(path.join(__dirname, 'napi-diag-pregc.txt'), + `V1 run 0 (pid ${r.pid}, status=${r.status}, signal=${r.signal}):\n` + + (r.stderr || '').split('\n').filter(l => l.includes('[napi-diag]')).join('\n') + '\n'); + } catch {} + const dump = `/tmp/bun-napi-diag-${r.pid}.json`; + if (fs.existsSync(dump)) { + const dest = path.join(__dirname, `napi-diag-${r.pid}.heapsnapshot`); + fs.renameSync(dump, dest); + console.log(`[napi-diag] snapshot from V1 run 0 (pid ${r.pid}) saved to ${dest} (${fs.statSync(dest).size} bytes)`); + } else { + console.log(`[napi-diag] no snapshot file for pid ${r.pid} (stderr: ${JSON.stringify((r.stderr || '').split('\n').filter(l => l.includes('napi-diag')))})`); + } + } + 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; + const se = r.stderr || ''; + if (crashed && se.includes('[napi-diag] gc() returned') && !se.includes('[napi-diag] wrote')) cell = 'CRASH@SNAPSHOT-GC'; + else 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); } -}); \ No newline at end of file + 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); +} diff --git a/test/napi/napi.test.ts b/test/napi/napi.test.ts index eed5a385af46..db1ec7eaa2d6 100644 --- a/test/napi/napi.test.ts +++ b/test/napi/napi.test.ts @@ -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, @@ -1329,12 +1331,78 @@ describe.concurrent.skipIf(!canBuildNodeAddons())("napi", () => { 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 pregc = join(diagDir, "napi-diag-pregc.txt"); + if (existsSync(pregc)) { + console.error("napi diagnostics (pre-GC scan, V1 run 0):\n" + readFileSync(pregc, "utf8")); + rmSync(pregc, { force: true }); + } + const snapshots = readdirSync(diagDir).filter(f => f.startsWith("napi-diag-") && f.endsWith(".heapsnapshot")); + 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")); + // V8 format keeps every string in `strings`; JSC's GC-debugging + // format keeps cell labels (incl. JSString contents) in `labels` + // and names in `nodeClassNames` / `edgeNames`. + const tables = ["strings", "labels", "nodeClassNames", "edgeNames"].filter(k => Array.isArray(snap[k])); + if (!tables.length) throw new Error("no string tables"); + let redacted = 0; + for (const k of tables) { + snap[k] = snap[k].map((str: string) => { + if (typeof str === "string" && secrets.some(v => str.includes(v))) { + redacted++; + return ""; + } + 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); + } + 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); // The marker must NOT have actually been printed. Only check stdout: the // fixture prints the marker via console.log (stdout), while stderr contains