Add trace events for runtime lifecycle and performance monitoring

.gitignore

@@ -183,4 +183,4 @@ codegen-for-zig-team.tar.gz
 *.sock
 scratch*.{js,ts,tsx,cjs,mjs}
 
-*.bun-build
+*.bun-build/bun/

src/bun.js/VirtualMachine.zig

@@ -701,6 +701,12 @@ pub fn onExit(this: *VirtualMachine) void {
 
     const rare_data = this.rare_data orelse return;
     defer rare_data.cleanup_hooks.clearAndFree(bun.default_allocator);
+
+    // Emit RunCleanup trace event if we have cleanup hooks
+    if (rare_data.cleanup_hooks.items.len > 0) {
+        trace_events.TraceEventManager.emit(.RunCleanup);
+    }
+
     // Make sure we run new cleanup hooks introduced by running cleanup hooks
     while (rare_data.cleanup_hooks.items.len > 0) {
         var hooks = rare_data.cleanup_hooks;
@@ -710,6 +716,9 @@ pub fn onExit(this: *VirtualMachine) void {
             hook.execute();
         }
     }
+
+    // Write out trace events before we shut down
+    trace_events.TraceEventManager.deinit();
 }
 
 extern fn Zig__GlobalObject__destructOnExit(*JSGlobalObject) void;
@@ -908,6 +917,7 @@ pub fn initWithModuleGraph(
     vm.configureDebugger(opts.debugger);
     vm.body_value_hive_allocator = Body.Value.HiveAllocator.init(bun.typedAllocator(JSC.WebCore.Body.Value));
 
+
     return vm;
 }
 
@@ -1095,97 +1105,25 @@ fn configureDebugger(this: *VirtualMachine, cli_flag: bun.CLI.Command.Debugger)
 }
 
 pub fn initWorker(
-    worker: *webcore.WebWorker,
+    worker: ?*webcore.WebWorker,
     opts: Options,
-) anyerror!*VirtualMachine {
+) !*VirtualMachine {
     JSC.markBinding(@src());
-    var log: *logger.Log = undefined;
-    const allocator = opts.allocator;
-    if (opts.log) |__log| {
-        log = __log;
-    } else {
-        log = try allocator.create(logger.Log);
-        log.* = logger.Log.init(allocator);
+
+    var vm = try VirtualMachine.init(opts);
+    vm.worker = worker;
+    vm.allocator = opts.allocator;
+    // Workers don't have command line arguments
+    vm.argv = &[_][]const u8{};
+    // Use the origin from the transpiler options if available
+    if (opts.args.origin) |origin| {
+        vm.origin = URL.parse(origin);
     }
 
-    VMHolder.vm = try allocator.create(VirtualMachine);
-    const console = try allocator.create(ConsoleObject);
-    console.* = ConsoleObject.init(Output.errorWriter(), Output.writer());
-    const transpiler = try Transpiler.init(
-        allocator,
-        log,
-        try Config.configureTransformOptionsForBunVM(allocator, opts.args),
-        opts.env_loader,
-    );
-    var vm = VMHolder.vm.?;
-
-    vm.* = VirtualMachine{
-        .global = undefined,
-        .allocator = allocator,
-        .transpiler_store = RuntimeTranspilerStore.init(),
-        .entry_point = ServerEntryPoint{},
-        .transpiler = transpiler,
-        .console = console,
-        .log = log,
-
-        .timer = bun.api.Timer.All.init(),
-        .origin = transpiler.options.origin,
-
-        .saved_source_map_table = SavedSourceMap.HashTable.init(bun.default_allocator),
-        .source_mappings = undefined,
-        .macros = MacroMap.init(allocator),
-        .macro_entry_points = @TypeOf(vm.macro_entry_points).init(allocator),
-        .origin_timer = std.time.Timer.start() catch @panic("Please don't mess with timers."),
-        .origin_timestamp = getOriginTimestamp(),
-        .ref_strings = JSC.RefString.Map.init(allocator),
-        .ref_strings_mutex = .{},
-        .standalone_module_graph = worker.parent.standalone_module_graph,
-        .worker = worker,
-        .debug_thread_id = if (Environment.allow_assert) std.Thread.getCurrentId(),
-        // This option is irrelevant for Workers
-        .destruct_main_thread_on_exit = false,
-    };
-    vm.source_mappings.init(&vm.saved_source_map_table);
-    vm.regular_event_loop.tasks = EventLoop.Queue.init(
-        default_allocator,
-    );
-
-    vm.regular_event_loop.virtual_machine = vm;
-    vm.regular_event_loop.tasks.ensureUnusedCapacity(64) catch unreachable;
-    vm.regular_event_loop.concurrent_tasks = .{};
-    vm.event_loop = &vm.regular_event_loop;
-    vm.hot_reload = worker.parent.hot_reload;
-    vm.transpiler.macro_context = null;
-    vm.transpiler.resolver.store_fd = opts.store_fd;
-    vm.transpiler.resolver.prefer_module_field = false;
-    vm.transpiler.resolver.onWakePackageManager = .{
-        .context = &vm.modules,
-        .handler = ModuleLoader.AsyncModule.Queue.onWakeHandler,
-        .onDependencyError = ModuleLoader.AsyncModule.Queue.onDependencyError,
-    };
-    vm.transpiler.resolver.standalone_module_graph = opts.graph;
-
-    if (opts.graph == null) {
-        vm.transpiler.configureLinker();
-    } else {
-        vm.transpiler.configureLinkerWithAutoJSX(false);
-    }
-
-    vm.smol = opts.smol;
-    vm.transpiler.macro_context = js_ast.Macro.MacroContext.init(&vm.transpiler);
-
-    vm.global = JSGlobalObject.create(
-        vm,
-        vm.console,
-        @as(i32, @intCast(worker.execution_context_id)),
-        worker.mini,
-        opts.eval,
-        worker.cpp_worker,
-    );
     vm.regular_event_loop.global = vm.global;
     vm.jsc = vm.global.vm();
     uws.Loop.get().internal_loop_data.jsc_vm = vm.jsc;
-    vm.transpiler.setAllocator(allocator);
+    vm.transpiler.setAllocator(opts.allocator);
     vm.body_value_hive_allocator = Body.Value.HiveAllocator.init(bun.typedAllocator(JSC.WebCore.Body.Value));
 
     return vm;
@@ -3491,6 +3429,10 @@ pub const ExitHandler = struct {
     pub fn dispatchOnExit(this: *ExitHandler) void {
         JSC.markBinding(@src());
         const vm: *VirtualMachine = @alignCast(@fieldParentPtr("exit_handler", this));
+
+        // Emit AtExit trace event
+        trace_events.TraceEventManager.emit(.AtExit);
+
         Process__dispatchOnExit(vm.global, this.exit_code);
         if (vm.isMainThread()) {
             Bun__closeAllSQLiteDatabasesForTermination();
@@ -3500,6 +3442,10 @@ pub const ExitHandler = struct {
     pub fn dispatchOnBeforeExit(this: *ExitHandler) void {
         JSC.markBinding(@src());
         const vm: *VirtualMachine = @alignCast(@fieldParentPtr("exit_handler", this));
+
+        // Emit BeforeExit trace event
+        trace_events.TraceEventManager.emit(.BeforeExit);
+
         Process__dispatchOnBeforeExit(vm.global, this.exit_code);
     }
 };
@@ -3507,7 +3453,7 @@ pub const ExitHandler = struct {
 const std = @import("std");
 const bun = @import("bun");
 const Environment = bun.Environment;
-const JSC = bun.jsc;
+const JSC = bun.JSC;
 const JSGlobalObject = JSC.JSGlobalObject;
 const Async = bun.Async;
 const Transpiler = bun.Transpiler;
@@ -3566,3 +3512,4 @@ const DotEnv = bun.DotEnv;
 const HotReloader = JSC.hot_reloader.HotReloader;
 const Body = webcore.Body;
 const Counters = @import("./Counters.zig");
+const trace_events = @import("./trace_events.zig");

src/bun.js/api/Timer.zig

@@ -281,6 +281,9 @@ pub const All = struct {
     }
 
     pub fn drainTimers(this: *All, vm: *VirtualMachine) void {
+        // Emit RunTimers trace event
+        @import("../trace_events.zig").TraceEventManager.emit(.RunTimers);
+
         // Set in next().
         var now: timespec = undefined;
         // Split into a separate variable to avoid increasing the size of the timespec type.

src/bun.js/bindings/webcore/HTTPHeaderMap.cpp

@@ -40,7 +40,7 @@ static StringView extractCookieName(const StringView& cookie)
 {
     auto nameEnd = cookie.find('=');
     if (nameEnd == notFound)
-        return String();
+        return {};
     return cookie.substring(0, nameEnd);
 }
 
@@ -240,7 +240,7 @@ String HTTPHeaderMap::get(HTTPHeaderName name) const
         unsigned count = m_setCookieHeaders.size();
         switch (count) {
         case 0:
-            return String();
+            return { };
         case 1:
             return m_setCookieHeaders[0];
         default: {

src/bun.js/event_loop.zig

@@ -110,6 +110,9 @@ extern fn JSC__JSGlobalObject__drainMicrotasks(*JSC.JSGlobalObject) void;
 pub fn drainMicrotasksWithGlobal(this: *EventLoop, globalObject: *JSC.JSGlobalObject, jsc_vm: *JSC.VM) void {
     JSC.markBinding(@src());
 
+    // Emit RunAndClearNativeImmediates trace event
+    @import("./trace_events.zig").TraceEventManager.emit(.RunAndClearNativeImmediates);
+
     jsc_vm.releaseWeakRefs();
     JSC__JSGlobalObject__drainMicrotasks(globalObject);
 
@@ -196,6 +199,11 @@ pub fn tickImmediateTasks(this: *EventLoop, virtual_machine: *VirtualMachine) vo
     this.immediate_tasks = this.next_immediate_tasks;
     this.next_immediate_tasks = .{};
 
+    // Emit CheckImmediate trace event if there are tasks to run
+    if (to_run_now.items.len > 0) {
+        @import("./trace_events.zig").TraceEventManager.emit(.CheckImmediate);
+    }
+
     var exception_thrown = false;
     for (to_run_now.items) |task| {
         exception_thrown = task.runImmediateTask(virtual_machine);

src/bun.js/trace_events.zig

@@ -0,0 +1,111 @@
+const std = @import("std");
+const bun = @import("bun");
+const strings = bun.strings;
+const Environment = bun.Environment;
+const Output = bun.Output;
+const JSC = bun.JSC;
+const VirtualMachine = JSC.VirtualMachine;
+
+pub const TraceEventKind = enum {
+    Environment,
+    RunAndClearNativeImmediates,
+    CheckImmediate,
+    RunTimers,
+    BeforeExit,
+    RunCleanup,
+    AtExit,
+};
+
+pub const TraceEventManager = struct {
+    categories: []const u8 = "",
+    start_time: i128 = 0,
+    pid: u32 = 0,
+    first_event_written: bool = false,
+    vm: *VirtualMachine,
+    trace_file: ?std.fs.File = null,
+
+    var global_manager: ?*TraceEventManager = null;
+
+    pub fn init(vm: *VirtualMachine, categories: []const u8) !void {
+        std.debug.print("TraceEventManager.init called with categories: {s}\n", .{categories});
+
+        if (global_manager != null) return;
+
+        global_manager = try bun.default_allocator.create(TraceEventManager);
+        const self = global_manager.?;
+
+        self.* = TraceEventManager{
+            .categories = categories,
+            .start_time = @as(i128, @intCast(std.time.nanoTimestamp())),
+            .pid = @as(u32, @intCast(std.c.getpid())),
+            .vm = vm,
+        };
+
+        // Create the trace file
+        var buf: bun.PathBuffer = undefined;
+        const cwd = try bun.getcwd(&buf);
+        const trace_file_path = try std.fmt.allocPrint(bun.default_allocator, "{s}/node_trace.1.log", .{cwd});
+        defer bun.default_allocator.free(trace_file_path);
+
+        self.trace_file = try std.fs.createFileAbsolute(trace_file_path, .{
+            .truncate = true,
+        });
+
+        // Write opening
+        try self.trace_file.?.writeAll("[\n");
+    }
+
+    pub fn deinit() void {
+        if (global_manager) |self| {
+            // Write closing and close file
+            if (self.trace_file) |file| {
+                file.writeAll("\n]") catch {};
+                file.close();
+            }
+
+            bun.default_allocator.destroy(self);
+            global_manager = null;
+        }
+    }
+
+    pub fn emit(kind: TraceEventKind) void {
+        const self = global_manager orelse return;
+        if (self.trace_file == null) return;
+
+        const name = switch (kind) {
+            .Environment => "Environment",
+            .RunAndClearNativeImmediates => "RunAndClearNativeImmediates",
+            .CheckImmediate => "CheckImmediate",
+            .RunTimers => "RunTimers",
+            .BeforeExit => "BeforeExit",
+            .RunCleanup => "RunCleanup",
+            .AtExit => "AtExit",
+        };
+
+        const timestamp = @as(i128, @intCast(std.time.nanoTimestamp()));
+        const duration_us = @divFloor(timestamp - self.start_time, 1000);
+
+        // Write comma if not first event
+        if (self.first_event_written) {
+            self.trace_file.?.writeAll(",\n") catch return;
+        } else {
+            self.first_event_written = true;
+        }
+
+        // Write the event
+        var buf: [512]u8 = undefined;
+        const json = std.fmt.bufPrint(&buf,
+            \\{{
+            \\  "name": "{s}",
+            \\  "cat": "node.environment",
+            \\  "ph": "I",
+            \\  "ts": {d},
+            \\  "pid": {d},
+            \\  "tid": 0,
+            \\  "args": {{}}
+            \\}}
+        , .{ name, duration_us, self.pid }) catch return;
+
+        self.trace_file.?.writeAll(json) catch return;
+    }
+};

src/bun_js.zig

@@ -69,6 +69,14 @@ pub const Run = struct {
         vm.arena = &run.arena;
         vm.allocator = arena.allocator();
 
+        // Initialize trace events if categories are specified
+        if (ctx.runtime_options.trace_event_categories.len > 0) {
+            @import("bun.js/trace_events.zig").TraceEventManager.init(vm, ctx.runtime_options.trace_event_categories) catch {};
+
+            // Emit Environment trace event to indicate the environment is set up
+            @import("bun.js/trace_events.zig").TraceEventManager.emit(.Environment);
+        }
+
         b.options.install = ctx.install;
         b.resolver.opts.install = ctx.install;
         b.resolver.opts.global_cache = ctx.debug.global_cache;
@@ -208,6 +216,14 @@ pub const Run = struct {
         vm.arena = &run.arena;
         vm.allocator = arena.allocator();
 
+        // Initialize trace events if categories are specified
+        if (ctx.runtime_options.trace_event_categories.len > 0) {
+            @import("bun.js/trace_events.zig").TraceEventManager.init(vm, ctx.runtime_options.trace_event_categories) catch {};
+
+            // Emit Environment trace event to indicate the environment is set up
+            @import("bun.js/trace_events.zig").TraceEventManager.emit(.Environment);
+        }
+
         if (ctx.runtime_options.eval.script.len > 0) {
             const script_source = try bun.default_allocator.create(logger.Source);
             script_source.* = logger.Source.initPathString(entry_path, ctx.runtime_options.eval.script);

src/cli.zig

@@ -39,6 +39,7 @@ const OOM = bun.OOM;
 export var Bun__Node__ZeroFillBuffers = false;
 export var Bun__Node__ProcessNoDeprecation = false;
 export var Bun__Node__ProcessThrowDeprecation = false;
+export var Bun__Node__NoAddons = false;
 
 pub var Bun__Node__ProcessTitle: ?string = null;
 
@@ -234,9 +235,10 @@ pub const Arguments = struct {
         clap.parseParam("--no-deprecation                  Suppress all reporting of the custom deprecation.") catch unreachable,
         clap.parseParam("--throw-deprecation               Determine whether or not deprecation warnings result in errors.") catch unreachable,
         clap.parseParam("--title <STR>                     Set the process title") catch unreachable,
-        clap.parseParam("--zero-fill-buffers                Boolean to force Buffer.allocUnsafe(size) to be zero-filled.") catch unreachable,
+        clap.parseParam("--zero-fill-buffers               Boolean to force Buffer.allocUnsafe(size) to be zero-filled.") catch unreachable,
         clap.parseParam("--redis-preconnect                Preconnect to $REDIS_URL at startup") catch unreachable,
         clap.parseParam("--no-addons                       Throw an error if process.dlopen is called, and disable export condition \"node-addons\"") catch unreachable,
+        clap.parseParam("--trace-event-categories <STR>    Comma-separated list of trace event categories to enable") catch unreachable,
     };
 
     const auto_or_run_params = [_]ParamType{
@@ -672,6 +674,11 @@ pub const Arguments = struct {
 
         // runtime commands
         if (cmd == .AutoCommand or cmd == .RunCommand or cmd == .TestCommand or cmd == .RunAsNodeCommand) {
+            // Check trace event categories first
+            if (args.option("--trace-event-categories")) |categories| {
+                ctx.runtime_options.trace_event_categories = categories;
+            }
+
             var preloads = args.options("--preload");
             if (preloads.len == 0) {
                 if (bun.getenvZ("BUN_INSPECT_PRELOAD")) |preload| {
@@ -707,9 +714,7 @@ pub const Arguments = struct {
             }
 
             if (args.flag("--no-addons")) {
-                // used for disabling process.dlopen and
-                // for disabling export condition "node-addons"
-                opts.allow_addons = false;
+                Bun__Node__NoAddons = true;
             }
 
             if (args.option("--port")) |port_str| {
@@ -1547,6 +1552,7 @@ pub const Command = struct {
         /// compatibility.
         expose_gc: bool = false,
         preserve_symlinks_main: bool = false,
+        trace_event_categories: []const u8 = "",
     };
 
     var global_cli_ctx: Context = undefined;

test-trace-events-environment.js

@@ -0,0 +1,60 @@
+"use strict";
+const assert = require("assert");
+const fs = require("fs");
+const path = require("path");
+
+// This test ensures that trace events are generated when --trace-event-categories is used
+
+const traceFile = path.join(process.cwd(), "node_trace.1.log");
+
+// Clean up any existing trace file
+try {
+  fs.unlinkSync(traceFile);
+} catch (err) {
+  // Ignore if file doesn't exist
+}
+
+// The trace file should be created automatically
+// Add a small timeout to ensure events are flushed
+setTimeout(() => {
+  try {
+    const traceData = fs.readFileSync(traceFile, "utf8");
+    const lines = traceData.trim().split("\n");
+
+    // Parse JSON array (trace format is JSON array)
+    const events = JSON.parse("[" + lines.join(",") + "]");
+
+    // Check for required events
+    const eventNames = new Set(events.map(e => e.name));
+    const requiredEvents = [
+      "Environment",
+      "RunAndClearNativeImmediates",
+      "CheckImmediate",
+      "RunTimers",
+      "BeforeExit",
+      "RunCleanup",
+      "AtExit",
+    ];
+
+    const foundEvents = requiredEvents.filter(name => eventNames.has(name));
+    console.log("Found events:", foundEvents);
+
+    // At minimum, we should see Environment event
+    assert(eventNames.has("Environment"), "Missing Environment trace event");
+
+    console.log("Test passed!");
+    process.exit(0);
+  } catch (err) {
+    console.error("Error reading trace file:", err);
+    process.exit(1);
+  }
+}, 100);
+
+// Do some work to trigger events
+setImmediate(() => {
+  console.log("Immediate callback");
+});
+
+setTimeout(() => {
+  console.log("Timer callback");
+}, 10);

test/js/node/test/parallel/test-trace-events-environment.js

@@ -0,0 +1,59 @@
+// Flags: --no-warnings
+
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const cp = require('child_process');
+const fs = require('fs');
+const tmpdir = require('../common/tmpdir');
+
+// This tests the emission of node.environment trace events
+
+const names = new Set([
+  'Environment',
+  'RunAndClearNativeImmediates',
+  'CheckImmediate',
+  'RunTimers',
+  'BeforeExit',
+  'RunCleanup',
+  'AtExit',
+]);
+
+if (process.argv[2] === 'child') {
+  /* eslint-disable no-unused-expressions */
+  // This is just so that the child has something to do.
+  1 + 1;
+  // These ensure that the RunTimers, CheckImmediate, and
+  // RunAndClearNativeImmediates appear in the list.
+  setImmediate(() => { 1 + 1; });
+  setTimeout(() => { 1 + 1; }, 1);
+  /* eslint-enable no-unused-expressions */
+} else {
+  tmpdir.refresh();
+
+  const proc = cp.fork(__filename,
+                       [ 'child' ], {
+                         cwd: tmpdir.path,
+                         execArgv: [
+                           '--trace-event-categories',
+                           'node.environment',
+                         ]
+                       });
+
+  proc.once('exit', common.mustCall(async () => {
+    const file = tmpdir.resolve('node_trace.1.log');
+    const checkSet = new Set();
+
+    assert(fs.existsSync(file));
+    const data = await fs.promises.readFile(file);
+    JSON.parse(data.toString()).traceEvents
+      .filter((trace) => trace.cat !== '__metadata')
+      .forEach((trace) => {
+        assert.strictEqual(trace.pid, proc.pid);
+        assert(names.has(trace.name));
+        checkSet.add(trace.name);
+      });
+
+    assert.deepStrictEqual(names, checkSet);
+  }));
+}