Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
98 changes: 61 additions & 37 deletions src/js/node/perf_hooks.ts
Original file line number Diff line number Diff line change
Expand Up @@ -59,31 +59,64 @@ var constants = {
NODE_PERFORMANCE_MILESTONE_V8_START: 4,
};

// PerformanceEntry is not a valid constructor, so we have to fake it.
class PerformanceNodeTiming {
bootstrapComplete: number = 0;
environment: number = 0;
idleTime: number = 0;
loopExit: number = 0;
loopStart: number = 0;
nodeStart: number = 0;
v8Start: number = 0;

// we have to fake the properties since it's not real
get name() {
return "node";
}

get entryType() {
return "node";
}
// Milliseconds since timeOrigin, or -1 until the milestone is reached. Same
// table performance.measure() resolves these names against.
const getNodeTimingMilestone = $newCppFunction("JSPerformance.cpp", "jsPerformance_getNodeTimingMilestone", 1) as (
name: string,
) => number;

get startTime() {
return this.nodeStart;
}
function milestoneDescriptor(name: string): PropertyDescriptor {
return {
__proto__: null,
enumerable: true,
configurable: true,
get() {
return getNodeTimingMilestone(name);
},
};
}

get duration() {
return performance.now();
// Ported from node's lib/internal/perf/nodetiming.js: every property is an own
// enumerable slot (so `{ ...performance.nodeTiming }` copies them), and the
// milestones are getters because loopStart/loopExit are stamped after this
// module has loaded. PerformanceEntry is not constructible, so the prototype
// chain is linked below instead of with `extends`.
class PerformanceNodeTiming {
declare readonly name: string;
declare readonly entryType: string;
declare readonly startTime: number;
declare readonly duration: number;
declare readonly nodeStart: number;
declare readonly v8Start: number;
declare readonly environment: number;
declare readonly loopStart: number;
declare readonly loopExit: number;
declare readonly bootstrapComplete: number;
declare readonly idleTime: number;

constructor() {
Object.defineProperties(this, {
name: { __proto__: null, enumerable: true, configurable: true, value: "node" },
entryType: { __proto__: null, enumerable: true, configurable: true, value: "node" },
startTime: { __proto__: null, enumerable: true, configurable: true, value: 0 },
duration: {
__proto__: null,
enumerable: true,
configurable: true,
get() {
return performance.now();
},
},
nodeStart: milestoneDescriptor("nodeStart"),
v8Start: milestoneDescriptor("v8Start"),
environment: milestoneDescriptor("environment"),
loopStart: milestoneDescriptor("loopStart"),
loopExit: milestoneDescriptor("loopExit"),
bootstrapComplete: milestoneDescriptor("bootstrapComplete"),
// Bun does not track time parked in the poll, matching the zeros
// eventLoopUtilization() reports.
idleTime: { __proto__: null, enumerable: true, configurable: true, value: 0 },
});
}

toJSON() {
Expand All @@ -92,13 +125,13 @@ class PerformanceNodeTiming {
entryType: this.entryType,
startTime: this.startTime,
duration: this.duration,
nodeStart: this.nodeStart,
v8Start: this.v8Start,
bootstrapComplete: this.bootstrapComplete,
environment: this.environment,
idleTime: this.idleTime,
loopExit: this.loopExit,
loopStart: this.loopStart,
nodeStart: this.nodeStart,
v8Start: this.v8Start,
loopExit: this.loopExit,
idleTime: this.idleTime,
};
}
}
Expand All @@ -107,15 +140,6 @@ if (PerformanceEntry) {
Object.setPrototypeOf(PerformanceNodeTiming, PerformanceEntry);
}

function createPerformanceNodeTiming() {
const object = Object.create(PerformanceNodeTiming.prototype);

object.bootstrapComplete = object.environment = object.nodeStart = object.v8Start = performance.timeOrigin;
object.loopStart = object.idleTime = 1;
object.loopExit = -1;
return object;
}

function eventLoopUtilization(_utilization1, _utilization2) {
return {
idle: 0,
Expand Down Expand Up @@ -320,7 +344,7 @@ function processTimerifyComplete(name, start, args, histogram) {
}
}

const nodeTiming = createPerformanceNodeTiming();
const nodeTiming = new PerformanceNodeTiming();

// Node augments the real `performance` object (not a forwarding shim), so
// timerify/eventLoopUtilization/nodeTiming go on Performance.prototype,
Expand Down
2 changes: 2 additions & 0 deletions src/jsc/JSErrorCode.rs
Original file line number Diff line number Diff line change
Expand Up @@ -68,4 +68,6 @@ pub enum DOMExceptionCode {
InvalidThisError,
InvalidURLError,
CryptoOperationFailedError,
EventRecursion,
InvalidArgValueError,
}
79 changes: 79 additions & 0 deletions src/jsc/VirtualMachine.rs
Original file line number Diff line number Diff line change
Expand Up @@ -133,6 +133,32 @@ impl Default for InitOptions {
}
}

/// The `performance.nodeTiming` milestones, stamped at Bun's equivalent of each
/// Node startup phase. The discriminants index
/// [`VirtualMachine::node_timing_milestones`] and are shared with the name
/// table in `src/jsc/bindings/webcore/PerformanceUserTiming.cpp`.
#[derive(Clone, Copy)]
#[repr(u32)]
pub(crate) enum NodeTimingMilestone {
/// The runtime started building this VM (a hair after `timeOrigin`).
NodeStart = 0,
/// Bun's own per-VM state exists; the JavaScriptCore VM is about to be created.
V8Start = 1,
/// The JSC VM and global object exist (`init` is done).
Environment = 2,
/// Pre-execution bootstrap is done; preloads and the entry point are about to run.
BootstrapComplete = 3,
/// The event loop polled for the first time, i.e. the entry point's
/// synchronous evaluation (and its microtasks) finished.
LoopStart = 4,
/// The event loop drained and 'exit' is about to be emitted.
LoopExit = 5,
}

impl NodeTimingMilestone {
pub(crate) const COUNT: usize = 6;
}

pub struct VirtualMachine {
pub global: *mut JSGlobalObject,
// allocator dropped per §Allocators (global mimalloc)
Expand Down Expand Up @@ -281,6 +307,9 @@ pub struct VirtualMachine {

pub origin_timer: std::time::Instant,
pub(crate) origin_timestamp: u64,
/// Nanoseconds since `origin_timer` at which each [`NodeTimingMilestone`]
/// was reached; `-1` until it is. Read by `Bun__getNodeTimingMilestone`.
pub(crate) node_timing_milestones: [i64; NodeTimingMilestone::COUNT],
/// For fake timers: override performance.now() with a specific value (in nanoseconds).
pub overridden_performance_now: Option<u64>,
pub(crate) macro_event_loop: EventLoop,
Expand Down Expand Up @@ -1590,6 +1619,9 @@ impl VirtualMachine {
self.exit_on_uncaught_exception = true;
return;
}
// A script with no async work never polled the loop; Node still
// reports it as having started (and, below, exited) around now.
self.record_node_timing_milestone(NodeTimingMilestone::LoopStart);
ExitHandler::dispatch_on_before_exit(self);
let mut dispatch = false;
loop {
Expand All @@ -1613,6 +1645,11 @@ impl VirtualMachine {

break;
}
// Only a cleanly drained loop stamps this: `process.exit()` and a
// fatal exception leave it at -1 for the 'exit' listeners, as in Node.
if self.unhandled_error_counter == 0 {
self.record_node_timing_milestone(NodeTimingMilestone::LoopExit);
}
}

pub fn on_exit(&mut self) {
Expand Down Expand Up @@ -2443,6 +2480,8 @@ impl VirtualMachine {
.write(VirtualMachine::default_on_unhandled_rejection);
addr_of_mut!((*vm).origin_timer).write(std::time::Instant::now());
addr_of_mut!((*vm).origin_timestamp).write(get_origin_timestamp());
addr_of_mut!((*vm).node_timing_milestones).write([-1; NodeTimingMilestone::COUNT]);
Self::record_node_timing_milestone_raw(vm, NodeTimingMilestone::NodeStart);
addr_of_mut!((*vm).smol).write(opts.smol);
// `Option<{CPU,Heap}ProfilerConfig>` are NOT zero-valid: each
// payload contains a `bool`, and rustc picks that field's invalid
Expand Down Expand Up @@ -2523,6 +2562,10 @@ impl VirtualMachine {
unsafe { (*vm).runtime_state = (hooks.init_runtime_state)(vm, &mut opts)? };
}

// SAFETY: `origin_timer` and `node_timing_milestones` were written in
// the block above.
unsafe { Self::record_node_timing_milestone_raw(vm, NodeTimingMilestone::V8Start) };

// JSGlobalObject creation. `ensure_waker()` must run before the FFI.
// SAFETY: `vm` is the unique live VM on this thread; raw-ptr deref so
// no `&mut` is held across the FFI re-entry (`Bun__getVM()` —
Expand Down Expand Up @@ -2579,6 +2622,9 @@ impl VirtualMachine {
IS_SMOL_MODE.store(true, core::sync::atomic::Ordering::Relaxed);
}

// SAFETY: see the `V8Start` stamp above.
unsafe { Self::record_node_timing_milestone_raw(vm, NodeTimingMilestone::Environment) };

Ok(vm)
}

Expand Down Expand Up @@ -2610,10 +2656,40 @@ impl VirtualMachine {
self.event_loop_mut().wait_for_promise(promise)
}

/// First write wins: `LoopStart` is recorded on every tick and
/// `BootstrapComplete` on every hot reload, and both mean the first time.
///
/// # Safety
/// `(*vm).origin_timer` and `(*vm).node_timing_milestones` must be
/// initialized. Nothing else is touched and no `&mut VirtualMachine` is
/// formed, which lets [`init`](Self::init) stamp a partially built VM (see
/// the validity note there).
unsafe fn record_node_timing_milestone_raw(
vm: *mut VirtualMachine,
milestone: NodeTimingMilestone,
) {
// SAFETY: per the contract above; only the two fields are projected.
unsafe {
let slots = core::ptr::addr_of_mut!((*vm).node_timing_milestones);
if (*slots)[milestone as usize] >= 0 {
return;
}
let elapsed = (*core::ptr::addr_of!((*vm).origin_timer)).elapsed();
(*slots)[milestone as usize] = elapsed.as_nanos() as i64;
}
}

#[inline]
pub(crate) fn record_node_timing_milestone(&mut self, milestone: NodeTimingMilestone) {
// SAFETY: a `&mut self` is a fully initialized VM.
unsafe { Self::record_node_timing_milestone_raw(self, milestone) }
}

/// `eventLoop().autoTick()` — dispatched through the runtime hook
/// (needs `Timer::All` for the poll timeout).
#[inline]
pub fn auto_tick(&mut self) {
self.record_node_timing_milestone(NodeTimingMilestone::LoopStart);
if let Some(hooks) = runtime_hooks() {
// SAFETY: hook contract — `self` is the live per-thread VM.
unsafe { (hooks.auto_tick)(self) };
Expand All @@ -2631,6 +2707,7 @@ impl VirtualMachine {
/// `on_before_exit` / `bun_main` still make forward progress.
#[inline]
pub fn auto_tick_active(&mut self) {
self.record_node_timing_milestone(NodeTimingMilestone::LoopStart);
if let Some(hooks) = runtime_hooks() {
// SAFETY: `self` is the live per-thread VM (hook contract).
unsafe { (hooks.auto_tick_active)(self) };
Expand Down Expand Up @@ -2692,6 +2769,7 @@ impl VirtualMachine {
// evaluating `internal/process/pre_execution`.
crate::cpp::Bun__preExecutionBootstrap(self.global());
}
self.record_node_timing_milestone(NodeTimingMilestone::BootstrapComplete);

if !self.main_is_html_entrypoint {
if let Some(hooks) = hooks {
Expand Down Expand Up @@ -4821,6 +4899,7 @@ impl VirtualMachine {
self.event_loop_mut().ensure_waker();

let _ = self.ensure_debugger(true);
self.record_node_timing_milestone(NodeTimingMilestone::BootstrapComplete);

if !self.transpiler.options.disable_transpilation {
if let Some(hooks) = runtime_hooks() {
Expand Down
2 changes: 2 additions & 0 deletions src/jsc/bindings/ExceptionCode.h
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,8 @@ enum ExceptionCode : uint8_t {
InvalidURLError,
CryptoOperationFailedError,
EVENT_RECURSION,
// ERR_INVALID_ARG_VALUE with the message supplied by the thrower.
InvalidArgValueError,
};

} // namespace WebCore
Expand Down
3 changes: 3 additions & 0 deletions src/jsc/bindings/JSDOMExceptionHandling.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -175,6 +175,9 @@ JSValue createDOMException(JSGlobalObject* lexicalGlobalObject, ExceptionCode ec
case ExceptionCode::EVENT_RECURSION:
return Bun::createError(lexicalGlobalObject, Bun::ErrorCode::ERR_EVENT_RECURSION, message);

case ExceptionCode::InvalidArgValueError:
return Bun::createError(lexicalGlobalObject, Bun::ErrorCode::ERR_INVALID_ARG_VALUE, message);

default: {
// FIXME: All callers to createDOMException need to pass in the correct global object.
// For now, we're going to assume the lexicalGlobalObject. Which is wrong in cases like this:
Expand Down
13 changes: 13 additions & 0 deletions src/jsc/bindings/webcore/JSPerformance.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,7 @@
#include "JSPerformanceMeasureOptions.h"
// #include "JSPerformanceNavigation.h"
#include "JSPerformanceTiming.h"
#include "PerformanceUserTiming.h"

#include "ScriptExecutionContext.h"
#include "WebCoreJSClientData.h"
Expand Down Expand Up @@ -140,6 +141,18 @@ JSC_DEFINE_HOST_FUNCTION(jsPerformancePrototypeFunction_markResourceTiming, (JSG
return JSValue::encode(jsUndefined());
}

JSC_DEFINE_HOST_FUNCTION(jsPerformance_getNodeTimingMilestone, (JSGlobalObject * globalObject, JSC::CallFrame* callFrame))
{
auto& vm = JSC::getVM(globalObject);
auto scope = DECLARE_THROW_SCOPE(vm);
auto name = callFrame->argument(0).toWTFString(globalObject);
RETURN_IF_EXCEPTION(scope, {});
auto milestone = PerformanceUserTiming::nodeTimingMilestone(vm, name);
if (!milestone)
return JSValue::encode(jsUndefined());
return JSValue::encode(jsNumber(*milestone));
}

// -- end copied --

class JSPerformancePrototype final : public JSC::JSNonFinalObject {
Expand Down
3 changes: 3 additions & 0 deletions src/jsc/bindings/webcore/JSPerformance.h
Original file line number Diff line number Diff line change
Expand Up @@ -100,4 +100,7 @@ template<> struct JSDOMWrapperConverterTraits<Performance> {
using ToWrappedReturnType = Performance*;
};

// (milestoneName) => the value performance.nodeTiming reports for it; backs node/perf_hooks.ts.
JSC_DECLARE_HOST_FUNCTION(jsPerformance_getNodeTimingMilestone);

} // namespace WebCore
4 changes: 2 additions & 2 deletions src/jsc/bindings/webcore/Performance.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -221,11 +221,11 @@ ExceptionOr<Ref<PerformanceMark>> Performance::mark(JSC::JSGlobalObject& globalO
return mark.releaseReturnValue();
}

void Performance::clearMarks(const String& markName)
ExceptionOr<void> Performance::clearMarks(const String& markName)
{
if (!m_userTiming)
m_userTiming = makeUnique<PerformanceUserTiming>(*this);
m_userTiming->clearMarks(markName);
return m_userTiming->clearMarks(markName);
}

ExceptionOr<Ref<PerformanceMeasure>> Performance::measure(JSC::JSGlobalObject& globalObject, const String& measureName, std::optional<StartOrMeasureOptions>&& startOrMeasureOptions, const String& endMark)
Expand Down
2 changes: 1 addition & 1 deletion src/jsc/bindings/webcore/Performance.h
Original file line number Diff line number Diff line change
Expand Up @@ -95,7 +95,7 @@ class Performance final : public RefCounted<Performance>, public ContextDestruct
void setResourceTimingBufferSize(unsigned);

ExceptionOr<Ref<PerformanceMark>> mark(JSC::JSGlobalObject&, const String& markName, std::optional<PerformanceMarkOptions>&&);
void clearMarks(const String& markName);
ExceptionOr<void> clearMarks(const String& markName);

using StartOrMeasureOptions = std::variant<String, PerformanceMeasureOptions>;
ExceptionOr<Ref<PerformanceMeasure>> measure(JSC::JSGlobalObject&, const String& measureName, std::optional<StartOrMeasureOptions>&&, const String& endMark);
Expand Down
3 changes: 3 additions & 0 deletions src/jsc/bindings/webcore/PerformanceMark.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,9 @@ static double performanceNow(ScriptExecutionContext& scriptExecutionContext)

ExceptionOr<Ref<PerformanceMark>> PerformanceMark::create(JSC::JSGlobalObject& globalObject, ScriptExecutionContext& scriptExecutionContext, const String& name, std::optional<PerformanceMarkOptions>&& markOptions)
{
if (PerformanceUserTiming::isRestrictedMarkName(name))
return PerformanceUserTiming::restrictedMarkNameException(name);

double startTime;
JSC::JSValue detail;
if (markOptions) {
Expand Down
Loading