Add trace events support for Bun runtime

cmake/sources/CxxSources.txt

@@ -160,6 +160,7 @@ src/bun.js/bindings/NodeFSStatFSBinding.cpp
 src/bun.js/bindings/NodeHTTP.cpp
 src/bun.js/bindings/NodeTimerObject.cpp
 src/bun.js/bindings/NodeTLS.cpp
+src/bun.js/bindings/NodeTraceEvents.cpp
 src/bun.js/bindings/NodeURL.cpp
 src/bun.js/bindings/NodeValidator.cpp
 src/bun.js/bindings/NodeVM.cpp
@@ -330,46 +331,6 @@ src/bun.js/bindings/webcore/JSPerformanceObserverEntryList.cpp
 src/bun.js/bindings/webcore/JSPerformanceResourceTiming.cpp
 src/bun.js/bindings/webcore/JSPerformanceServerTiming.cpp
 src/bun.js/bindings/webcore/JSPerformanceTiming.cpp
-src/bun.js/bindings/webcore/JSReadableByteStreamController.cpp
-src/bun.js/bindings/webcore/JSReadableStream.cpp
-src/bun.js/bindings/webcore/JSReadableStreamBYOBReader.cpp
-src/bun.js/bindings/webcore/JSReadableStreamBYOBRequest.cpp
-src/bun.js/bindings/webcore/JSReadableStreamDefaultController.cpp
-src/bun.js/bindings/webcore/JSReadableStreamDefaultReader.cpp
-src/bun.js/bindings/webcore/JSReadableStreamSink.cpp
-src/bun.js/bindings/webcore/JSReadableStreamSource.cpp
-src/bun.js/bindings/webcore/JSReadableStreamSourceCustom.cpp
-src/bun.js/bindings/webcore/JSStructuredSerializeOptions.cpp
-src/bun.js/bindings/webcore/JSTextDecoderStream.cpp
-src/bun.js/bindings/webcore/JSTextEncoder.cpp
-src/bun.js/bindings/webcore/JSTextEncoderStream.cpp
-src/bun.js/bindings/webcore/JSTransformStream.cpp
-src/bun.js/bindings/webcore/JSTransformStreamDefaultController.cpp
-src/bun.js/bindings/webcore/JSURLSearchParams.cpp
-src/bun.js/bindings/webcore/JSWebSocket.cpp
-src/bun.js/bindings/webcore/JSWorker.cpp
-src/bun.js/bindings/webcore/JSWorkerOptions.cpp
-src/bun.js/bindings/webcore/JSWritableStream.cpp
-src/bun.js/bindings/webcore/JSWritableStreamDefaultController.cpp
-src/bun.js/bindings/webcore/JSWritableStreamDefaultWriter.cpp
-src/bun.js/bindings/webcore/JSWritableStreamSink.cpp
-src/bun.js/bindings/webcore/MessageChannel.cpp
-src/bun.js/bindings/webcore/MessageEvent.cpp
-src/bun.js/bindings/webcore/MessagePort.cpp
-src/bun.js/bindings/webcore/MessagePortChannel.cpp
-src/bun.js/bindings/webcore/MessagePortChannelProvider.cpp
-src/bun.js/bindings/webcore/MessagePortChannelProviderImpl.cpp
-src/bun.js/bindings/webcore/MessagePortChannelRegistry.cpp
-src/bun.js/bindings/webcore/NetworkLoadMetrics.cpp
-src/bun.js/bindings/webcore/Performance.cpp
-src/bun.js/bindings/webcore/PerformanceEntry.cpp
-src/bun.js/bindings/webcore/PerformanceMark.cpp
-src/bun.js/bindings/webcore/PerformanceMeasure.cpp
-src/bun.js/bindings/webcore/PerformanceObserver.cpp
-src/bun.js/bindings/webcore/PerformanceObserverEntryList.cpp
-src/bun.js/bindings/webcore/PerformanceResourceTiming.cpp
-src/bun.js/bindings/webcore/PerformanceServerTiming.cpp
-src/bun.js/bindings/webcore/PerformanceTiming.cpp
 src/bun.js/bindings/webcore/PerformanceUserTiming.cpp
 src/bun.js/bindings/webcore/ReadableStream.cpp
 src/bun.js/bindings/webcore/ReadableStreamDefaultController.cpp

src/bun.js/VirtualMachine.zig

@@ -638,6 +638,11 @@ pub fn enterUWSLoop(this: *VirtualMachine) void {
 }
 
 pub fn onBeforeExit(this: *VirtualMachine) void {
+    // Emit trace event
+    if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+        @import("./trace_events.zig").TraceEvents.emitEnvironmentEvent("BeforeExit");
+    }
+
     this.exit_handler.dispatchOnBeforeExit();
     var dispatch = false;
     while (true) {
@@ -696,6 +701,11 @@ pub fn setEntryPointEvalResultCJS(this: *VirtualMachine, value: JSValue) callcon
 }
 
 pub fn onExit(this: *VirtualMachine) void {
+    // Emit trace event
+    if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+        @import("./trace_events.zig").TraceEvents.emitEnvironmentEvent("RunCleanup");
+    }
+
     this.exit_handler.dispatchOnExit();
     this.is_shutting_down = true;
 
@@ -710,11 +720,21 @@ pub fn onExit(this: *VirtualMachine) void {
             hook.execute();
         }
     }
+
+    // Emit AtExit trace event after cleanup
+    if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+        @import("./trace_events.zig").TraceEvents.emitEnvironmentEvent("AtExit");
+    }
 }
 
 extern fn Zig__GlobalObject__destructOnExit(*JSGlobalObject) void;
 
 pub fn globalExit(this: *VirtualMachine) noreturn {
+    // Shutdown trace events if enabled
+    if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+        @import("./trace_events.zig").TraceEvents.shutdown();
+    }
+
     if (this.destruct_main_thread_on_exit and this.is_main_thread) {
         Zig__GlobalObject__destructOnExit(this.global);
         this.deinit();

src/bun.js/api/Timer.zig

@@ -281,6 +281,11 @@ pub const All = struct {
     }
 
     pub fn drainTimers(this: *All, vm: *VirtualMachine) void {
+        // Emit trace event if tracing is enabled
+        if (@import("../trace_events.zig").TraceEvents.isEnabled()) {
+            @import("../trace_events.zig").TraceEvents.emitEnvironmentEvent("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/NodeTraceEvents.cpp

@@ -0,0 +1,190 @@
+#include "NodeTraceEvents.h"
+#include "ZigGlobalObject.h"
+#include <JavaScriptCore/JSObject.h>
+#include <JavaScriptCore/ObjectConstructor.h>
+#include <JavaScriptCore/JSCInlines.h>
+#include <wtf/JSONValues.h>
+#include <wtf/FileSystem.h>
+#include <wtf/text/StringBuilder.h>
+#include <wtf/text/StringView.h>
+#include <chrono>
+#include <mutex>
+#include <unistd.h>
+#include <pthread.h>
+#include <stdio.h>
+
+namespace Bun {
+
+static std::atomic<uint32_t> s_rotation{1};
+static bool s_tracingEnabled = false;
+static WTF::String s_categories;
+static WTF::String s_filePattern;
+static Vector<Ref<JSON::Object>> s_traceEvents;
+static std::mutex s_traceEventsMutex;
+static uint32_t s_processId = 0;
+static uint64_t s_startTime = 0;
+
+void NodeTraceEvents::initialize(const WTF::String& categories, const WTF::String& filePattern)
+{
+    s_tracingEnabled = true;
+    s_categories = categories;
+    s_filePattern = filePattern.isEmpty() ? "node_trace.${rotation}.log"_s : filePattern;
+    s_processId = static_cast<uint32_t>(getpid());
+    s_startTime = std::chrono::duration_cast<std::chrono::microseconds>(
+        std::chrono::high_resolution_clock::now().time_since_epoch()
+    ).count();
+}
+
+bool NodeTraceEvents::isEnabled()
+{
+    return s_tracingEnabled;
+}
+
+bool NodeTraceEvents::isEnabled(const WTF::String& category)
+{
+    if (!s_tracingEnabled) {
+        return false;
+    }
+    
+    // Check if category is in the list
+    Vector<String> categories = s_categories.split(',');
+    for (const auto& cat : categories) {
+        auto trimmed = StringView(cat).trim([](UChar ch) { return isASCIIWhitespace(ch); });
+        if (trimmed == category) {
+            return true;
+        }
+    }
+    return false;
+}
+
+void NodeTraceEvents::emit(const WTF::String& name, const WTF::String& category, JSON::Object* args, uint64_t timestamp)
+{
+    if (!s_tracingEnabled || !isEnabled(category)) {
+        return;
+    }
+
+    if (timestamp == 0) {
+        timestamp = std::chrono::duration_cast<std::chrono::microseconds>(
+            std::chrono::high_resolution_clock::now().time_since_epoch()
+        ).count() - s_startTime;
+    }
+
+    auto event = JSON::Object::create();
+    event->setString("name"_s, name);
+    event->setString("cat"_s, category);
+    event->setString("ph"_s, "X"_s); // Complete event
+    event->setDouble("ts"_s, static_cast<double>(timestamp));
+    event->setDouble("dur"_s, 0.0);
+    event->setInteger("pid"_s, s_processId);
+    event->setInteger("tid"_s, static_cast<int>(pthread_self()));
+    
+    if (args) {
+        // Create a Ref from the raw pointer
+        event->setObject("args"_s, Ref { *args });
+    }
+
+    {
+        std::lock_guard<std::mutex> lock(s_traceEventsMutex);
+        s_traceEvents.append(WTFMove(event));
+    }
+}
+
+void NodeTraceEvents::emitEnvironmentEvent(const WTF::String& name)
+{
+    emit(name, "node.environment"_s);
+}
+
+void NodeTraceEvents::shutdown()
+{
+    if (!s_tracingEnabled) {
+        return;
+    }
+    
+    // Emit final events
+    emitEnvironmentEvent("RunCleanup"_s);
+    emitEnvironmentEvent("AtExit"_s);
+    
+    writeTraceFile();
+    
+    s_tracingEnabled = false;
+}
+
+void NodeTraceEvents::writeTraceFile()
+{
+    std::lock_guard<std::mutex> lock(s_traceEventsMutex);
+    
+    // Generate filename
+    uint32_t rotation = s_rotation.fetch_add(1);
+    WTF::String filename = s_filePattern;
+    
+    // Simple string replacement - since WTF::String doesn't have replace, we'll build it manually
+    StringBuilder builder;
+    unsigned start = 0;
+    
+    // Replace ${rotation}
+    auto rotationPos = filename.find("${rotation}"_s);
+    if (rotationPos != notFound) {
+        builder.append(filename.substring(0, rotationPos));
+        builder.append(String::number(rotation));
+        start = rotationPos + 11; // length of "${rotation}"
+    }
+    
+    // Replace ${pid}
+    auto pidPos = filename.find("${pid}"_s, start);
+    if (pidPos != notFound) {
+        builder.append(filename.substring(start, pidPos - start));
+        builder.append(String::number(s_processId));
+        builder.append(filename.substring(pidPos + 6)); // length of "${pid}"
+    } else {
+        builder.append(filename.substring(start));
+    }
+    
+    filename = builder.toString();
+    
+    // Create root object
+    auto root = JSON::Object::create();
+    auto traceEventsArray = JSON::Array::create();
+    
+    for (const auto& event : s_traceEvents) {
+        traceEventsArray->pushObject(event.copyRef());
+    }
+    
+    root->setArray("traceEvents"_s, WTFMove(traceEventsArray));
+    
+    // Write to file
+    String jsonString = root->toJSONString();
+    CString utf8 = jsonString.utf8();
+    
+    // Use standard C++ file operations
+    CString filenameCString = filename.utf8();
+    FILE* file = fopen(filenameCString.data(), "w");
+    if (file) {
+        fwrite(utf8.data(), 1, utf8.length(), file);
+        fclose(file);
+    }
+}
+
+} // namespace Bun
+
+extern "C" void Bun__NodeTraceEvents__initialize(const char* categories, const char* filePattern)
+{
+    Bun::NodeTraceEvents::initialize(
+        WTF::String::fromUTF8(categories),
+        filePattern && filePattern[0] ? WTF::String::fromUTF8(filePattern) : ""_s
+    );
+}
+
+extern "C" bool Bun__NodeTraceEvents__isEnabled()
+{
+    return Bun::NodeTraceEvents::isEnabled();
+}
+
+extern "C" void Bun__NodeTraceEvents__emitEnvironmentEvent(const char* name)
+{
+    Bun::NodeTraceEvents::emitEnvironmentEvent(WTF::String::fromUTF8(name));
+}
+
+extern "C" void Bun__NodeTraceEvents__shutdown()
+{
+    Bun::NodeTraceEvents::shutdown();
+}

src/bun.js/bindings/NodeTraceEvents.h

@@ -0,0 +1,28 @@
+#pragma once
+
+#include <wtf/text/WTFString.h>
+#include <wtf/JSONValues.h>
+
+namespace Bun {
+
+class NodeTraceEvents {
+public:
+    static void initialize(const WTF::String& categories, const WTF::String& filePattern = ""_s);
+    static bool isEnabled();
+    static bool isEnabled(const WTF::String& category);
+    static void emit(const WTF::String& name, const WTF::String& category, JSON::Object* args = nullptr, uint64_t timestamp = 0);
+    static void emitEnvironmentEvent(const WTF::String& name);
+    static void shutdown();
+    
+private:
+    static void writeTraceFile();
+};
+
+} // namespace Bun
+
+extern "C" {
+    void Bun__NodeTraceEvents__initialize(const char* categories, const char* filePattern);
+    bool Bun__NodeTraceEvents__isEnabled();
+    void Bun__NodeTraceEvents__emitEnvironmentEvent(const char* name);
+    void Bun__NodeTraceEvents__shutdown();
+}

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 StringView();
     return cookie.substring(0, nameEnd);
 }
 

src/bun.js/event_loop.zig

@@ -191,6 +191,11 @@ fn tickWithCount(this: *EventLoop, virtual_machine: *VirtualMachine) u32 {
 }
 
 pub fn tickImmediateTasks(this: *EventLoop, virtual_machine: *VirtualMachine) void {
+    // Emit trace event for RunAndClearNativeImmediates
+    if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+        @import("./trace_events.zig").TraceEvents.emitEnvironmentEvent("RunAndClearNativeImmediates");
+    }
+
     var to_run_now = this.immediate_tasks;
 
     this.immediate_tasks = this.next_immediate_tasks;
@@ -198,6 +203,10 @@ pub fn tickImmediateTasks(this: *EventLoop, virtual_machine: *VirtualMachine) vo
 
     var exception_thrown = false;
     for (to_run_now.items) |task| {
+        // Emit trace event for CheckImmediate before each task
+        if (@import("./trace_events.zig").TraceEvents.isEnabled()) {
+            @import("./trace_events.zig").TraceEvents.emitEnvironmentEvent("CheckImmediate");
+        }
         exception_thrown = task.runImmediateTask(virtual_machine);
     }
 

src/bun.js/trace_events.zig

@@ -0,0 +1,39 @@
+const std = @import("std");
+const bun = @import("bun");
+
+extern fn Bun__NodeTraceEvents__initialize(categories: [*:0]const u8, filePattern: ?[*:0]const u8) void;
+extern fn Bun__NodeTraceEvents__isEnabled() bool;
+extern fn Bun__NodeTraceEvents__emitEnvironmentEvent(name: [*:0]const u8) void;
+extern fn Bun__NodeTraceEvents__shutdown() void;
+
+pub const TraceEvents = struct {
+    pub fn initialize(categories: ?[]const u8, file_pattern: ?[]const u8) void {
+        if (categories) |cats| {
+            const cat_str = bun.default_allocator.dupeZ(u8, cats) catch return;
+            defer bun.default_allocator.free(cat_str);
+
+            if (file_pattern) |pattern| {
+                const pattern_str = bun.default_allocator.dupeZ(u8, pattern) catch return;
+                defer bun.default_allocator.free(pattern_str);
+                Bun__NodeTraceEvents__initialize(cat_str, pattern_str);
+            } else {
+                Bun__NodeTraceEvents__initialize(cat_str, null);
+            }
+        }
+    }
+
+    pub fn isEnabled() bool {
+        return Bun__NodeTraceEvents__isEnabled();
+    }
+
+    pub fn emitEnvironmentEvent(name: []const u8) void {
+        if (!isEnabled()) return;
+        const name_str = bun.default_allocator.dupeZ(u8, name) catch return;
+        defer bun.default_allocator.free(name_str);
+        Bun__NodeTraceEvents__emitEnvironmentEvent(name_str);
+    }
+
+    pub fn shutdown() void {
+        Bun__NodeTraceEvents__shutdown();
+    }
+};

src/bun_js.zig

@@ -112,6 +112,15 @@ pub const Run = struct {
         vm.is_main_thread = true;
         JSC.VirtualMachine.is_main_thread_vm = true;
 
+        // Initialize trace events if requested
+        if (ctx.runtime_options.trace_event_categories) |categories| {
+            const TraceEvents = @import("./bun.js/trace_events.zig").TraceEvents;
+            TraceEvents.initialize(categories, ctx.runtime_options.trace_event_file_pattern);
+
+            // Emit initial environment events
+            TraceEvents.emitEnvironmentEvent("Environment");
+        }
+
         doPreconnect(ctx.runtime_options.preconnect);
 
         const callback = OpaqueWrap(Run, Run.start);
@@ -257,6 +266,15 @@ pub const Run = struct {
         vm.is_main_thread = true;
         JSC.VirtualMachine.is_main_thread_vm = true;
 
+        // Initialize trace events if requested
+        if (ctx.runtime_options.trace_event_categories) |categories| {
+            const TraceEvents = @import("./bun.js/trace_events.zig").TraceEvents;
+            TraceEvents.initialize(categories, ctx.runtime_options.trace_event_file_pattern);
+
+            // Emit initial environment events
+            TraceEvents.emitEnvironmentEvent("Environment");
+        }
+
         // Allow setting a custom timezone
         if (vm.transpiler.env.get("TZ")) |tz| {
             if (tz.len > 0) {

src/cli.zig

@@ -237,6 +237,8 @@ pub const Arguments = struct {
         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>    Enable trace events for specified categories (comma-separated)") catch unreachable,
+        clap.parseParam("--trace-event-file-pattern <STR>  Template for trace file names (e.g. 'trace-${rotation}.log')") catch unreachable,
     };
 
     const auto_or_run_params = [_]ParamType{
@@ -851,6 +853,14 @@ pub const Arguments = struct {
             if (args.flag("--zero-fill-buffers")) {
                 Bun__Node__ZeroFillBuffers = true;
             }
+
+            // Handle trace events
+            if (args.option("--trace-event-categories")) |categories| {
+                ctx.runtime_options.trace_event_categories = categories;
+            }
+            if (args.option("--trace-event-file-pattern")) |pattern| {
+                ctx.runtime_options.trace_event_file_pattern = pattern;
+            }
         }
 
         if (opts.port != null and opts.origin == null) {
@@ -1547,6 +1557,8 @@ pub const Command = struct {
         /// compatibility.
         expose_gc: bool = false,
         preserve_symlinks_main: bool = false,
+        trace_event_categories: ?[]const u8 = null,
+        trace_event_file_pattern: ?[]const u8 = null,
     };
 
     var global_cli_ctx: Context = undefined;

src/deps/zig-clap/clap.zig

@@ -539,7 +539,7 @@ pub fn simpleHelpBunTopLevel(
                 const total_len = flags_len + value_len;
                 const num_spaces_after = max_spacing - total_len;
 
-                Output.pretty(space_buf[0..num_spaces_after] ++ desc_text, .{});
+                Output.pretty("{s}{s}", .{ space_buf[0..num_spaces_after], desc_text });
             }
         }
     }

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);
+  }));
+}