diff --git a/src/js/builtins/CommonJS.ts b/src/js/builtins/CommonJS.ts index 31d0360d17ba..145bb9270a6f 100644 --- a/src/js/builtins/CommonJS.ts +++ b/src/js/builtins/CommonJS.ts @@ -7,9 +7,29 @@ export function main() { // This function is bound when constructing instances of CommonJSModule $visibility = "Private"; -export function require(this: JSCommonJSModule, _: string) { - // Do not use $tailCallForwardArguments here, it causes https://github.com/oven-sh/bun/issues/9225 - return $overridableRequire.$apply(this, arguments); +export function require(this: JSCommonJSModule, id: string) { + const ch = require("internal/module_tracing").requireChannel; + if (!ch.hasSubscribers) { + // Do not use $tailCallForwardArguments here, it causes https://github.com/oven-sh/bun/issues/9225 + return $overridableRequire.$apply(this, arguments); + } + const context = { __proto__: null, id, parentFilename: this && this.filename }; + const self = this; + const args = arguments; + const { start, end, error } = ch; + return start.runStores(context, () => { + try { + const result = $overridableRequire.$apply(self, args); + context.result = result; + return result; + } catch (err) { + context.error = err; + error.publish(context); + throw err; + } finally { + end.publish(context); + } + }); } // overridableRequire can be overridden by setting `Module.prototype.require` diff --git a/src/js/internal/module_tracing.ts b/src/js/internal/module_tracing.ts new file mode 100644 index 000000000000..2adf407436d3 --- /dev/null +++ b/src/js/internal/module_tracing.ts @@ -0,0 +1,15 @@ +// node:diagnostics_channel TracingChannels for module loading. +// https://nodejs.org/api/diagnostics_channel.html#built-in-channels +const { tracingChannel } = require("node:diagnostics_channel"); + +const requireChannel = tracingChannel("module.require"); +const importChannel = tracingChannel("module.import"); + +// Called from C++ GlobalObject::moduleLoaderImportModule to wrap a dynamic +// import() once a "tracing:module.*" subscriber exists. +function traceDynamicImport(promise, url, parentURL) { + if (!importChannel.hasSubscribers) return promise; + return importChannel.tracePromise(() => promise, { __proto__: null, parentURL, url }); +} + +export default { requireChannel, importChannel, traceDynamicImport }; diff --git a/src/js/node/diagnostics_channel.ts b/src/js/node/diagnostics_channel.ts index 4c26ff1017fe..60ebb51ccd36 100644 --- a/src/js/node/diagnostics_channel.ts +++ b/src/js/node/diagnostics_channel.ts @@ -9,6 +9,7 @@ const SafeFinalizationRegistry = FinalizationRegistry; const ArrayPrototypeAt = Array.prototype.at; const ArrayPrototypeIndexOf = Array.prototype.indexOf; const ArrayPrototypeSplice = Array.prototype.splice; +const StringPrototypeStartsWith = String.prototype.startsWith; const ObjectGetPrototypeOf = Object.getPrototypeOf; const ObjectSetPrototypeOf = Object.setPrototypeOf; const SymbolHasInstance = Symbol.hasInstance; @@ -58,10 +59,16 @@ class WeakRefMap extends SafeMap { } } +let enableModuleTracing: (() => void) | undefined; + function markActive(channel) { ObjectSetPrototypeOf.$call(null, channel, ActiveChannel.prototype); channel._subscribers = []; channel._stores = new SafeMap(); + // Notify the native dynamic-import hook that it now needs to publish. + if (typeof channel.name === "string" && StringPrototypeStartsWith.$call(channel.name, "tracing:module.")) { + (enableModuleTracing ??= $newCppFunction("NodeDiagnosticsChannel.cpp", "jsEnableModuleTracingSubscribers", 0))(); + } } function maybeMarkInactive(channel) { @@ -281,6 +288,16 @@ class TracingChannel { } } + get hasSubscribers() { + return ( + this.start.hasSubscribers || + this.end.hasSubscribers || + this.asyncStart.hasSubscribers || + this.asyncEnd.hasSubscribers || + this.error.hasSubscribers + ); + } + subscribe(handlers) { for (const name of traceEvents) { if (!handlers[name]) continue; diff --git a/src/jsc/bindings/NodeDiagnosticsChannel.cpp b/src/jsc/bindings/NodeDiagnosticsChannel.cpp new file mode 100644 index 000000000000..3b50dfc64360 --- /dev/null +++ b/src/jsc/bindings/NodeDiagnosticsChannel.cpp @@ -0,0 +1,19 @@ +#include "config.h" + +#include "ZigGlobalObject.h" + +namespace Bun { + +using namespace JSC; + +// Called from node:diagnostics_channel when a subscriber is first added to any +// "tracing:module.*" channel. Flips a one-way de-opt flag so the native +// dynamic-import hook starts routing through the JS tracer. +JSC_DEFINE_HOST_FUNCTION(jsEnableModuleTracingSubscribers, (JSC::JSGlobalObject * globalObject, JSC::CallFrame*)) +{ + auto* global = uncheckedDowncast(globalObject); + global->hasModuleTracingSubscribers = true; + return JSC::JSValue::encode(JSC::jsUndefined()); +} + +} diff --git a/src/jsc/bindings/NodeDiagnosticsChannel.h b/src/jsc/bindings/NodeDiagnosticsChannel.h new file mode 100644 index 000000000000..81eaaf5bd801 --- /dev/null +++ b/src/jsc/bindings/NodeDiagnosticsChannel.h @@ -0,0 +1,9 @@ +#include "config.h" +#include "ZigGlobalObject.h" +#include + +namespace Bun { + +JSC_DECLARE_HOST_FUNCTION(jsEnableModuleTracingSubscribers); + +} diff --git a/src/jsc/bindings/ZigGlobalObject.cpp b/src/jsc/bindings/ZigGlobalObject.cpp index 20ddb6c5147d..1e7d27f2158d 100644 --- a/src/jsc/bindings/ZigGlobalObject.cpp +++ b/src/jsc/bindings/ZigGlobalObject.cpp @@ -2275,6 +2275,18 @@ void GlobalObject::finishCreation(VM& vm) init.set(JSC::JSFunction::create(init.vm, init.owner, wasmStreamingConsumeStreamCodeGenerator(init.vm), init.owner)); }); + m_traceDynamicImportFunction.initLater( + [](const Initializer& init) { + auto scope = DECLARE_THROW_SCOPE(init.vm); + JSValue mod = uncheckedDowncast(init.owner)->internalModuleRegistry()->requireId(init.owner, init.vm, Bun::InternalModuleRegistry::Field::InternalModuleTracing); + RETURN_IF_EXCEPTION(scope, ); + RELEASE_ASSERT(mod.isObject()); + auto prop = mod.getObject()->getIfPropertyExists(init.owner, Identifier::fromString(init.vm, "traceDynamicImport"_s)); + RETURN_IF_EXCEPTION(scope, ); + ASSERT(prop); + init.set(uncheckedDowncast(prop)); + }); + m_nativeMicrotaskTrampoline.initLater( [](const Initializer& init) { init.set(JSFunction::create(init.vm, init.owner, 2, ""_s, functionNativeMicrotaskTrampoline, ImplementationVisibility::Private)); @@ -3511,6 +3523,39 @@ JSC::Identifier GlobalObject::moduleLoaderResolve(JSGlobalObject* jsGlobalObject } } +static JSC::JSPromise* traceDynamicImport(Zig::GlobalObject* globalObject, JSC::JSPromise* promise, JSC::JSString* moduleNameValue, const SourceOrigin& sourceOrigin) +{ + if (!promise) [[unlikely]] + return promise; + + VM& vm = JSC::getVM(globalObject); + auto scope = DECLARE_THROW_SCOPE(vm); + + auto* tracer = globalObject->traceDynamicImportFunction(); + if (scope.exception()) [[unlikely]] { + return JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + } + if (!tracer) [[unlikely]] + return promise; + + JSC::MarkedArgumentBuffer args; + args.append(promise); + args.append(moduleNameValue); + auto& sourceURL = sourceOrigin.url(); + args.append(sourceURL.isEmpty() ? JSC::jsUndefined() : JSC::jsString(vm, sourceURL.string())); + ASSERT(!args.hasOverflowed()); + + auto callData = JSC::getCallData(tracer); + auto result = JSC::profiledCall(globalObject, JSC::ProfilingReason::API, tracer, callData, JSC::jsUndefined(), args); + if (scope.exception()) [[unlikely]] { + return JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + } + + if (result.inherits()) + return static_cast(result.asCell()); + return promise; +} + JSC::JSPromise* GlobalObject::moduleLoaderImportModule(JSGlobalObject* jsGlobalObject, JSModuleLoader*, JSString* moduleNameValue, @@ -3524,6 +3569,8 @@ JSC::JSPromise* GlobalObject::moduleLoaderImportModule(JSGlobalObject* jsGlobalO VM& vm = JSC::getVM(globalObject); auto scope = DECLARE_THROW_SCOPE(vm); + const bool needsTracing = globalObject->hasModuleTracingSubscribers; + { JSC::JSPromise* result = NodeVM::importModule(globalObject, moduleNameValue, parameters, sourceOrigin); RETURN_IF_EXCEPTION(scope, nullptr); @@ -3562,7 +3609,10 @@ JSC::JSPromise* GlobalObject::moduleLoaderImportModule(JSGlobalObject* jsGlobalO auto result = JSC::importModule(globalObject, resolvedIdentifier, JSC::Identifier(), parameters, nullptr, /* deferred */ false, referrerAsyncOrder); if (scope.exception()) [[unlikely]] { - return JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + result = JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + } + if (needsTracing) [[unlikely]] { + RELEASE_AND_RETURN(scope, traceDynamicImport(globalObject, result, moduleNameValue, sourceOrigin)); } return result; } @@ -3601,7 +3651,11 @@ JSC::JSPromise* GlobalObject::moduleLoaderImportModule(JSGlobalObject* jsGlobalO moduleNameZ.deref(); sourceOriginZ.deref(); - return JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + auto* rejected = JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + if (needsTracing) [[unlikely]] { + RELEASE_AND_RETURN(scope, traceDynamicImport(globalObject, rejected, moduleNameValue, sourceOrigin)); + } + return rejected; } if (queryString.isEmpty()) { @@ -3622,7 +3676,11 @@ JSC::JSPromise* GlobalObject::moduleLoaderImportModule(JSGlobalObject* jsGlobalO auto result = JSC::importModule(globalObject, resolvedIdentifier, JSC::Identifier(), WTF::move(parameters), nullptr, /* deferred */ false, referrerAsyncOrder); if (scope.exception()) [[unlikely]] { - return JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + result = JSC::JSPromise::rejectedPromiseWithCaughtException(globalObject, scope); + } + + if (needsTracing) [[unlikely]] { + RELEASE_AND_RETURN(scope, traceDynamicImport(globalObject, result, moduleNameValue, sourceOrigin)); } ASSERT(result); diff --git a/src/jsc/bindings/ZigGlobalObject.h b/src/jsc/bindings/ZigGlobalObject.h index 9f2e8298df95..10dfbb4530f9 100644 --- a/src/jsc/bindings/ZigGlobalObject.h +++ b/src/jsc/bindings/ZigGlobalObject.h @@ -291,6 +291,7 @@ class GlobalObject : public Bun::GlobalScope { JSC::JSFunction* utilInspectStylizeNoColorFunction() const { return m_utilInspectStylizeNoColorFunction.getInitializedOnMainThread(this); } JSC::JSFunction* wasmStreamingConsumeStreamFunction() const { return m_wasmStreamingConsumeStreamFunction.getInitializedOnMainThread(this); } + JSC::JSFunction* traceDynamicImportFunction() const { return m_traceDynamicImportFunction.getInitializedOnMainThread(this); } JSObject* requireFunctionUnbound() const { return m_requireFunctionUnbound.getInitializedOnMainThread(this); } JSObject* requireResolveFunctionUnbound() const { return m_requireResolveFunctionUnbound.getInitializedOnMainThread(this); } @@ -597,6 +598,7 @@ class GlobalObject : public Bun::GlobalScope { V(private, LazyPropertyOfGlobalObject, m_utilInspectStylizeColorFunction) \ V(private, LazyPropertyOfGlobalObject, m_utilInspectStylizeNoColorFunction) \ V(private, LazyPropertyOfGlobalObject, m_wasmStreamingConsumeStreamFunction) \ + V(private, LazyPropertyOfGlobalObject, m_traceDynamicImportFunction) \ V(private, LazyPropertyOfGlobalObject, m_streamsRuntime) \ V(private, LazyPropertyOfGlobalObject, m_requireMap) \ V(private, LazyPropertyOfGlobalObject, m_JSArrayBufferControllerPrototype) \ @@ -768,6 +770,8 @@ class GlobalObject : public Bun::GlobalScope { bool hasOverriddenModuleWrapper = false; // De-optimization once `require("module").runMain` is written to bool hasOverriddenModuleRunMain = false; + // De-optimization once a diagnostics_channel "tracing:module.*" subscriber is added + bool hasModuleTracingSubscribers = false; // WeakGCMap — JS-level dedup of SecureContext by // config digest. WeakGCMap self-registers with the heap, so no diff --git a/test/js/node/diagnostics_channel/diagnostics_channel.test.ts b/test/js/node/diagnostics_channel/diagnostics_channel.test.ts index 37dfd54d7a8f..c411fd25106f 100644 --- a/test/js/node/diagnostics_channel/diagnostics_channel.test.ts +++ b/test/js/node/diagnostics_channel/diagnostics_channel.test.ts @@ -1,7 +1,8 @@ import { gc } from "bun"; import { beforeEach, describe, expect, mock, test } from "bun:test"; +import { bunEnv, bunExe, tempDir } from "harness"; import { AsyncLocalStorage } from "node:async_hooks"; -import { channel, Channel, hasSubscribers, subscribe, unsubscribe } from "node:diagnostics_channel"; +import { channel, Channel, hasSubscribers, subscribe, tracingChannel, unsubscribe } from "node:diagnostics_channel"; describe("Channel", () => { // test-diagnostics-channel-has-subscribers.js @@ -343,6 +344,224 @@ describe("TracingChannel", () => { // Port tests from: // https://github.com/search?q=repo%3Anodejs%2Fnode+test-diagnostics-channel+AND+%2Ftracing%2F&type=code test.todo("TODO"); + + test("hasSubscribers reflects sub-channel state", () => { + const tc = tracingChannel("tracing-channel-hasSubscribers-test"); + expect(tc.hasSubscribers).toBeFalse(); + + const fn = () => {}; + tc.asyncEnd.subscribe(fn); + expect(tc.hasSubscribers).toBeTrue(); + tc.asyncEnd.unsubscribe(fn); + expect(tc.hasSubscribers).toBeFalse(); + + tc.error.subscribe(fn); + expect(tc.hasSubscribers).toBeTrue(); + tc.error.unsubscribe(fn); + expect(tc.hasSubscribers).toBeFalse(); + }); +}); + +describe.concurrent("module tracing channels", () => { + const moduleTracingFixture = ` + import dc from "node:diagnostics_channel"; + import { createRequire } from "node:module"; + import path from "node:path"; + + const NAMES = [ + "tracing:module.require:start", "tracing:module.require:end", "tracing:module.require:error", + "tracing:module.import:start", "tracing:module.import:end", + "tracing:module.import:asyncStart", "tracing:module.import:asyncEnd", "tracing:module.import:error", + ]; + const events = []; + for (const name of NAMES) { + dc.subscribe(name, (ctx) => { + events.push({ + name, + id: ctx.id, + parentFilename: ctx.parentFilename ? path.basename(ctx.parentFilename) : ctx.parentFilename, + url: ctx.url ? path.basename(ctx.url) : ctx.url, + parentURL: ctx.parentURL ? path.basename(new URL(ctx.parentURL).pathname) : ctx.parentURL, + hasResult: "result" in ctx, + hasError: "error" in ctx, + }); + }); + } + + const req = createRequire(import.meta.url); + req("./a.cjs"); + try { req("./missing.cjs"); } catch {} + await import("./b.mjs"); + try { await import("./missing.mjs"); } catch {} + + process.stdout.write(JSON.stringify(events)); + `; + + test("tracing:module.require publishes on every require()", async () => { + using dir = tempDir("dc-module-require", { + "entry.mjs": moduleTracingFixture, + "a.cjs": "module.exports = 1;\n", + "b.mjs": "export default 2;\n", + }); + await using proc = Bun.spawn({ + cmd: [bunExe(), "entry.mjs"], + env: bunEnv, + cwd: String(dir), + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + const events = JSON.parse(stdout).filter((e: any) => e.name.startsWith("tracing:module.require:")); + expect(events).toEqual([ + { + name: "tracing:module.require:start", + id: "./a.cjs", + parentFilename: "entry.mjs", + hasResult: false, + hasError: false, + }, + { + name: "tracing:module.require:end", + id: "./a.cjs", + parentFilename: "entry.mjs", + hasResult: true, + hasError: false, + }, + { + name: "tracing:module.require:start", + id: "./missing.cjs", + parentFilename: "entry.mjs", + hasResult: false, + hasError: false, + }, + { + name: "tracing:module.require:error", + id: "./missing.cjs", + parentFilename: "entry.mjs", + hasResult: false, + hasError: true, + }, + { + name: "tracing:module.require:end", + id: "./missing.cjs", + parentFilename: "entry.mjs", + hasResult: false, + hasError: true, + }, + ]); + expect(exitCode).toBe(0); + }); + + test("tracing:module.import publishes on every dynamic import()", async () => { + using dir = tempDir("dc-module-import", { + "entry.mjs": moduleTracingFixture, + "a.cjs": "module.exports = 1;\n", + "b.mjs": "export default 2;\n", + }); + await using proc = Bun.spawn({ + cmd: [bunExe(), "entry.mjs"], + env: bunEnv, + cwd: String(dir), + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + const events = JSON.parse(stdout).filter((e: any) => e.name.startsWith("tracing:module.import:")); + expect(events).toEqual([ + { name: "tracing:module.import:start", url: "b.mjs", parentURL: "entry.mjs", hasResult: false, hasError: false }, + { name: "tracing:module.import:end", url: "b.mjs", parentURL: "entry.mjs", hasResult: false, hasError: false }, + { + name: "tracing:module.import:asyncStart", + url: "b.mjs", + parentURL: "entry.mjs", + hasResult: true, + hasError: false, + }, + { + name: "tracing:module.import:asyncEnd", + url: "b.mjs", + parentURL: "entry.mjs", + hasResult: true, + hasError: false, + }, + { + name: "tracing:module.import:start", + url: "missing.mjs", + parentURL: "entry.mjs", + hasResult: false, + hasError: false, + }, + { + name: "tracing:module.import:end", + url: "missing.mjs", + parentURL: "entry.mjs", + hasResult: false, + hasError: false, + }, + { + name: "tracing:module.import:error", + url: "missing.mjs", + parentURL: "entry.mjs", + hasResult: false, + hasError: true, + }, + { + name: "tracing:module.import:asyncStart", + url: "missing.mjs", + parentURL: "entry.mjs", + hasResult: false, + hasError: true, + }, + { + name: "tracing:module.import:asyncEnd", + url: "missing.mjs", + parentURL: "entry.mjs", + hasResult: false, + hasError: true, + }, + ]); + expect(exitCode).toBe(0); + }); + + test("tracing:module.require result matches require() return value", async () => { + using dir = tempDir("dc-module-require-result", { + "entry.cjs": ` + const dc = require("node:diagnostics_channel"); + let captured; + dc.subscribe("tracing:module.require:end", (ctx) => { captured = ctx; }); + const result = require("./a.cjs"); + process.stdout.write(JSON.stringify({ same: captured.result === result, result })); + `, + "a.cjs": "module.exports = { marker: 'hello' };\n", + }); + await using proc = Bun.spawn({ + cmd: [bunExe(), "entry.cjs"], + env: bunEnv, + cwd: String(dir), + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + expect(JSON.parse(stdout)).toEqual({ same: true, result: { marker: "hello" } }); + expect(exitCode).toBe(0); + }); + + test("require() still works when nothing is subscribed", async () => { + using dir = tempDir("dc-module-no-sub", { + "entry.cjs": `process.stdout.write(String(require("./a.cjs")));`, + "a.cjs": "module.exports = 42;\n", + }); + await using proc = Bun.spawn({ + cmd: [bunExe(), "entry.cjs"], + env: bunEnv, + cwd: String(dir), + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + expect(stdout).toBe("42"); + expect(exitCode).toBe(0); + }); }); const mocks = new Map(); diff --git a/test/napi/node-napi-tests/test/js-native-api/test_function/test.js b/test/napi/node-napi-tests/test/js-native-api/test_function/test.js index a976540f5d62..eba665c1285f 100644 --- a/test/napi/node-napi-tests/test/js-native-api/test_function/test.js +++ b/test/napi/node-napi-tests/test/js-native-api/test_function/test.js @@ -31,10 +31,15 @@ assert.strictEqual(test_function.TestCall(func4, 1), 2); assert.strictEqual(test_function.TestName.name, 'Name'); assert.strictEqual(test_function.TestNameShort.name, 'Name_'); -let tracked_function = test_function.MakeTrackedFunction(common.mustCall()); -assert(!!tracked_function); -tracked_function = null; -global.gc(); +// We use IIFE for the tracked_function scope instead of a block to be +// compatible with non-V8 JS engines whose conservative stack scan may keep +// the object alive while the creating frame is still on the stack. +(() => { + let tracked_function = test_function.MakeTrackedFunction(common.mustCall()); + assert(!!tracked_function); + tracked_function = null; +})(); +for (let i = 0; i < 10; ++i) global.gc(); assert.deepStrictEqual(test_function.TestCreateFunctionParameters(), { envIsNull: 'Invalid argument', diff --git a/test/napi/node-napi-tests/test/js-native-api/test_instance_data/test.js b/test/napi/node-napi-tests/test/js-native-api/test_instance_data/test.js index 630776088344..ad533d85466a 100644 --- a/test/napi/node-napi-tests/test/js-native-api/test_instance_data/test.js +++ b/test/napi/node-napi-tests/test/js-native-api/test_instance_data/test.js @@ -17,8 +17,13 @@ if (module !== require.main) { assert.strictEqual(test_instance_data.increment(), 42); // Test that the instance data can be accessed from a finalizer. - test_instance_data.objectWithFinalizer(common.mustCall()); - global.gc(); + // We use IIFE for the object's scope to be compatible with non-V8 JS + // engines whose conservative stack scan may keep the object alive while + // the creating frame is still on the stack. + (() => { + test_instance_data.objectWithFinalizer(common.mustCall()); + })(); + for (let i = 0; i < 10; ++i) global.gc(); } else { // When launched as a script, run tests in either a child process or in a // worker thread.