diff --git a/packages/bun-usockets/src/eventing/epoll_kqueue.c b/packages/bun-usockets/src/eventing/epoll_kqueue.c index e8e36dc9d05b..7b4e7da36dcc 100644 --- a/packages/bun-usockets/src/eventing/epoll_kqueue.c +++ b/packages/bun-usockets/src/eventing/epoll_kqueue.c @@ -408,6 +408,13 @@ void us_loop_run_bun_tick(struct us_loop_t *loop, const struct timespec* timeout } } + /* Only ticks that really park are timed, so a busy loop pays nothing and a + * parked one pays two vDSO reads against a syscall it was making anyway. + * Publish the entry so a cross-thread reader can add the in-progress park. */ + const uint64_t idle_start_ns = will_idle_inside_event_loop ? us_internal_monotonic_ns() : 0; + if (will_idle_inside_event_loop) + __atomic_store_n(&loop->data.idle_entry_ns, idle_start_ns, __ATOMIC_RELEASE); + /* Fetch ready polls */ #ifdef LIBUS_USE_EPOLL /* A zero timespec already has a fast path in ep_poll (fs/eventpoll.c): @@ -428,6 +435,12 @@ void us_loop_run_bun_tick(struct us_loop_t *loop, const struct timespec* timeout } while (IS_EINTR(loop->num_ready_polls)); #endif + if (will_idle_inside_event_loop) { + __atomic_add_fetch(&loop->data.idle_ns, us_internal_monotonic_ns() - idle_start_ns, + __ATOMIC_RELAXED); + __atomic_store_n(&loop->data.idle_entry_ns, 0, __ATOMIC_RELEASE); + } + /* Before anything can allocate again. */ if (handed_off) mi_on_thread_idle_end(); diff --git a/packages/bun-usockets/src/eventing/libuv.c b/packages/bun-usockets/src/eventing/libuv.c index 01c3a1932372..f06cd654b34f 100644 --- a/packages/bun-usockets/src/eventing/libuv.c +++ b/packages/bun-usockets/src/eventing/libuv.c @@ -269,6 +269,10 @@ struct us_loop_t *us_create_loop(void *hint, loop->uv_loop = hint ? hint : uv_loop_new(); loop->is_default = hint != 0; + /* Without this libuv never accumulates provider_idle_time, so + * uv_metrics_idle_time() — and performance.eventLoopUtilization() — read 0. + * node enables it unconditionally too (node.cc, node_worker.cc). */ + uv_loop_configure(loop->uv_loop, UV_METRICS_IDLE_TIME); loop->uv_pre = us_malloc(sizeof(uv_prepare_t)); uv_prepare_init(loop->uv_loop, loop->uv_pre); diff --git a/packages/bun-usockets/src/internal/internal.h b/packages/bun-usockets/src/internal/internal.h index 27148b318f55..f8d350495bc0 100644 --- a/packages/bun-usockets/src/internal/internal.h +++ b/packages/bun-usockets/src/internal/internal.h @@ -156,6 +156,9 @@ uint64_t us_internal_monotonic_ns(void); long long us_internal_sweep_timeout_ns(struct us_loop_t *loop); void us_internal_sweep_if_due(struct us_loop_t *loop); #endif +/* Nanoseconds this loop has spent parked, including a park in progress. Safe + * from another thread. Both platforms: Rust calls it uncgated. */ +uint64_t us_loop_idle_ns(struct us_loop_t *loop); void us_internal_free_closed_sockets(us_loop_r loop); void us_internal_loop_link_group(struct us_loop_t *loop, struct us_socket_group_t *group); void us_internal_loop_unlink_group(struct us_loop_t *loop, struct us_socket_group_t *group); diff --git a/packages/bun-usockets/src/internal/loop_data.h b/packages/bun-usockets/src/internal/loop_data.h index 071ceaadcd56..4cf58e2f8cf4 100644 --- a/packages/bun-usockets/src/internal/loop_data.h +++ b/packages/bun-usockets/src/internal/loop_data.h @@ -70,6 +70,15 @@ struct us_internal_loop_data_t { * for lsquic's time-driven state. POSIX folds the deadline into the * epoll_pwait2 timeout via getTimeout() instead. */ struct us_timer_t *quic_timer; +#endif +#ifndef LIBUS_USE_LIBUV + /* Nanoseconds parked, for eventLoopUtilization(). Read cross-thread — + * __atomic_* only. MIRRORED in src/uws_sys/InternalLoopData.rs: this struct + * is us_loop_t's first member, so a field here shifts num_polls. */ + unsigned long long idle_ns; + /* Monotonic ns the current park began, 0 when not parked: a mid-park reader + * must add (now - entry) or it sees a stale total. So does libuv. */ + unsigned long long idle_entry_ns; #endif struct us_socket_group_t *iterator; char *recv_buf; diff --git a/packages/bun-usockets/src/loop.c b/packages/bun-usockets/src/loop.c index 987120f6bda6..ac16c2a9814c 100644 --- a/packages/bun-usockets/src/loop.c +++ b/packages/bun-usockets/src/loop.c @@ -119,6 +119,26 @@ void us_internal_sweep_if_due(struct us_loop_t *loop) { #endif +/* Nanoseconds this loop has spent parked, for performance.eventLoopUtilization(). + * Safe to call from another thread. */ +uint64_t us_loop_idle_ns(struct us_loop_t *loop) { +#ifdef LIBUS_USE_LIBUV + return uv_metrics_idle_time(loop->uv_loop); +#else + uint64_t idle = __atomic_load_n(&loop->data.idle_ns, __ATOMIC_RELAXED); + /* Parked right now? The total is only folded in when the park ends, so add + * the in-progress interval — otherwise a mid-park reader sees a stale idle + * and over-reports active. Same as libuv's uv_metrics_idle_time. */ + uint64_t entry = __atomic_load_n(&loop->data.idle_entry_ns, __ATOMIC_ACQUIRE); + if (entry > 0) { + uint64_t now = us_internal_monotonic_ns(); + if (now > entry) + idle += now - entry; + } + return idle; +#endif +} + void us_internal_loop_data_init(struct us_loop_t *loop, void (*wakeup_cb)(struct us_loop_t *loop), void (*pre_cb)(struct us_loop_t *loop), void (*post_cb)(struct us_loop_t *loop)) { // We allocate with calloc, so we only need to initialize the specific fields in use. diff --git a/src/js/internal/perf/event_loop_utilization.ts b/src/js/internal/perf/event_loop_utilization.ts new file mode 100644 index 000000000000..07fb6eedbffb --- /dev/null +++ b/src/js/internal/perf/event_loop_utilization.ts @@ -0,0 +1,35 @@ +// Shared by perf_hooks and worker_threads, as node shares +// lib/internal/perf/event_loop_utilization.js between the two. +// +// `elu` is [elapsedSinceLoopStartMs, idleMs] from native, or null when the loop +// has not turned yet — node's equivalent of its `loopStart <= 0` branch, and it +// is checked first there too, so elu(u, u) before the loop turns is {0,0,0} +// rather than NaN. +// +// The divisions are deliberately unguarded: node returns NaN for a zero total +// (verified on v26.3.0 — eventLoopUtilization(u, u) after the loop has turned +// yields NaN), so collapsing that to 0 would diverge. +function internalEventLoopUtilization(elu, util1, util2) { + if (elu === null) { + return { idle: 0, active: 0, utilization: 0 }; + } + + if (util2) { + const idle = util1.idle - util2.idle; + const active = util1.active - util2.active; + return { idle, active, utilization: active / (idle + active) }; + } + + const idle = elu[1]; + const active = elu[0] - idle; + + if (!util1) { + return { idle, active, utilization: active / (idle + active) }; + } + + const idleDelta = idle - util1.idle; + const activeDelta = active - util1.active; + return { idle: idleDelta, active: activeDelta, utilization: activeDelta / (idleDelta + activeDelta) }; +} + +export default { internalEventLoopUtilization }; diff --git a/src/js/node/perf_hooks.ts b/src/js/node/perf_hooks.ts index 16206fe4a3b2..2aabd36192a9 100644 --- a/src/js/node/perf_hooks.ts +++ b/src/js/node/perf_hooks.ts @@ -114,12 +114,13 @@ function createPerformanceNodeTiming() { return object; } -function eventLoopUtilization(_utilization1, _utilization2) { - return { - idle: 0, - active: 0, - utilization: 0, - }; +// [elapsedSinceLoopStartMs, idleMs] for this thread's loop, or null before it +// has turned. +const getLoopELU = $newRustFunction("bun.rs", "getLoopELU", 0); +const { internalEventLoopUtilization } = require("internal/perf/event_loop_utilization"); + +function eventLoopUtilization(utilization1, utilization2) { + return internalEventLoopUtilization(getLoopELU(), utilization1, utilization2); } // PerformanceEntry is not a valid constructor, so we have to fake it. diff --git a/src/js/node/worker_threads.ts b/src/js/node/worker_threads.ts index 6e63f675cd3d..d00c6db41449 100644 --- a/src/js/node/worker_threads.ts +++ b/src/js/node/worker_threads.ts @@ -6,6 +6,7 @@ type WebWorker = InstanceType; const EventEmitter = require("node:events"); const { SafeMap } = require("internal/primordials"); const Readable = require("internal/streams/readable"); +const { internalEventLoopUtilization } = require("internal/perf/event_loop_utilization"); const Writable = require("internal/streams/writable"); const { throwNotImplemented, warnNotImplementedOnce } = require("internal/shared"); const { @@ -135,7 +136,9 @@ function injectFakeEmitter(Class) { function wrapped(run, listener) { return function (event) { - return listener(run(event)); + // node invokes emitter listeners with the emitter as `this`; an + // addEventListener handler's `this` is already the target, so forward it. + return listener.$call(this, run(event)); }; } @@ -1187,17 +1190,16 @@ class Worker extends EventEmitter { get performance() { return (this.#performance ??= { - eventLoopUtilization() { - warnNotImplementedOnce("worker_threads.Worker.performance"); - return { - idle: 0, - active: 0, - utilization: 0, - }; - }, + eventLoopUtilization: this.#eventLoopUtilization.bind(this), }); } + #eventLoopUtilization(utilization1, utilization2) { + // null covers both "thread gone" and "loop has not turned" — node reports + // all-zero for each. + return internalEventLoopUtilization(this.#worker.eventLoopUtilizationInternal(), utilization1, utilization2); + } + terminate(callback: unknown) { if (typeof callback === "function") { process.emitWarning( diff --git a/src/jsc/VirtualMachine.rs b/src/jsc/VirtualMachine.rs index 7e11f2cdc079..d1cab79c2214 100644 --- a/src/jsc/VirtualMachine.rs +++ b/src/jsc/VirtualMachine.rs @@ -279,6 +279,10 @@ pub struct VirtualMachine { pub argv: Vec>, pub origin_timer: std::time::Instant, + /// When THIS thread's loop started, for performance.eventLoopUtilization(). + /// Not `origin_timer`, which is the process origin shared by every thread — + /// a worker's active time is measured from its own start. + pub loop_start: std::time::Instant, pub origin_timestamp: u64, /// For fake timers: override performance.now() with a specific value (in nanoseconds). pub overridden_performance_now: Option, @@ -2106,6 +2110,7 @@ impl VirtualMachine { addr_of_mut!((*vm).pending_internal_promise_reported_at).write(u32::MAX); addr_of_mut!((*vm).on_unhandled_rejection) .write(VirtualMachine::default_on_unhandled_rejection); + addr_of_mut!((*vm).loop_start).write(std::time::Instant::now()); let (origin_timer, origin_timestamp) = process_origin(); addr_of_mut!((*vm).origin_timer).write(origin_timer); addr_of_mut!((*vm).origin_timestamp).write(origin_timestamp); diff --git a/src/jsc/bindings/webcore/JSWorker.cpp b/src/jsc/bindings/webcore/JSWorker.cpp index 0e94c9adb507..3ef854b72537 100644 --- a/src/jsc/bindings/webcore/JSWorker.cpp +++ b/src/jsc/bindings/webcore/JSWorker.cpp @@ -86,6 +86,7 @@ static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_ref); static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_getHeapSnapshot); static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_getHeapStatistics); static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_startCpuProfileInternal); +static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_eventLoopUtilizationInternal); static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_stopCpuProfileInternal); static JSC_DECLARE_HOST_FUNCTION(jsWorkerPrototypeFunction_cpuUsageInternal); @@ -447,6 +448,7 @@ static const HashTableValue JSWorkerPrototypeTableValues[] = { { "startCpuProfileInternal"_s, static_cast(JSC::PropertyAttribute::Function | JSC::PropertyAttribute::DontEnum), NoIntrinsic, { HashTableValue::NativeFunctionType, jsWorkerPrototypeFunction_startCpuProfileInternal, 0 } }, { "stopCpuProfileInternal"_s, static_cast(JSC::PropertyAttribute::Function | JSC::PropertyAttribute::DontEnum), NoIntrinsic, { HashTableValue::NativeFunctionType, jsWorkerPrototypeFunction_stopCpuProfileInternal, 0 } }, { "cpuUsageInternal"_s, static_cast(JSC::PropertyAttribute::Function | JSC::PropertyAttribute::DontEnum), NoIntrinsic, { HashTableValue::NativeFunctionType, jsWorkerPrototypeFunction_cpuUsageInternal, 0 } }, + { "eventLoopUtilizationInternal"_s, static_cast(JSC::PropertyAttribute::Function | JSC::PropertyAttribute::DontEnum), NoIntrinsic, { HashTableValue::NativeFunctionType, jsWorkerPrototypeFunction_eventLoopUtilizationInternal, 0 } }, }; const ClassInfo JSWorkerPrototype::s_info = { "Worker"_s, &Base::s_info, nullptr, nullptr, CREATE_METHOD_TABLE(JSWorkerPrototype) }; @@ -857,6 +859,33 @@ static inline JSC::EncodedJSValue jsWorkerPrototypeFunction_stopCpuProfileIntern return JSValue::encode(promise); } +// Synchronous by contract: node's worker.performance.eventLoopUtilization() +// returns a value, it does not await the worker. Safe to read cross-thread — +// the counter is atomic and the loop start is immutable after publish. +static inline JSC::EncodedJSValue jsWorkerPrototypeFunction_eventLoopUtilizationInternalBody(JSC::JSGlobalObject* lexicalGlobalObject, JSC::CallFrame* callFrame, typename IDLOperation::ClassParameter castedThis) +{ + auto* globalObject = defaultGlobalObject(lexicalGlobalObject); + auto& vm = JSC::getVM(globalObject); + auto throwScope = DECLARE_THROW_SCOPE(vm); + UNUSED_PARAM(callFrame); + double elapsedMs = 0; + double idleMs = 0; + if (!castedThis->wrapped().eventLoopUtilization(elapsedMs, idleMs)) + RELEASE_AND_RETURN(throwScope, JSValue::encode(JSC::jsNull())); + JSC::JSArray* result = JSC::constructEmptyArray(globalObject, nullptr, 2); + RETURN_IF_EXCEPTION(throwScope, {}); + result->putDirectIndex(globalObject, 0, JSC::jsNumber(elapsedMs)); + RETURN_IF_EXCEPTION(throwScope, {}); + result->putDirectIndex(globalObject, 1, JSC::jsNumber(idleMs)); + RETURN_IF_EXCEPTION(throwScope, {}); + RELEASE_AND_RETURN(throwScope, JSValue::encode(result)); +} + +JSC_DEFINE_HOST_FUNCTION(jsWorkerPrototypeFunction_eventLoopUtilizationInternal, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) +{ + return IDLOperation::call(*lexicalGlobalObject, *callFrame, "eventLoopUtilizationInternal"); +} + static inline JSC::EncodedJSValue jsWorkerPrototypeFunction_cpuUsageInternalBody(JSC::JSGlobalObject* lexicalGlobalObject, JSC::CallFrame* callFrame, typename IDLOperation::ClassParameter castedThis) { auto* globalObject = defaultGlobalObject(lexicalGlobalObject); diff --git a/src/jsc/bindings/webcore/Worker.cpp b/src/jsc/bindings/webcore/Worker.cpp index 6682985171ce..e245c1e5718f 100644 --- a/src/jsc/bindings/webcore/Worker.cpp +++ b/src/jsc/bindings/webcore/Worker.cpp @@ -98,6 +98,10 @@ void WebWorker__releaseParentPollRef(void* worker); // Free the native WebWorker struct. Called from ~Worker. void WebWorker__destroy(void* worker); +// Read this worker's loop counters from the parent thread. False if the worker +// VM is gone. See src/jsc/web_worker.rs. +bool WebWorker__getELU(void* worker, double* outElapsedMs, double* outIdleMs); + } // extern "C" // ------------------------------------------------------------------------------------------------- @@ -375,6 +379,13 @@ void Worker::terminate() WebWorker__notifyNeedTermination(impl_); } +bool Worker::eventLoopUtilization(double& elapsedMs, double& idleMs) +{ + if (!impl_) + return false; + return WebWorker__getELU(impl_, &elapsedMs, &idleMs); +} + void Worker::setKeepAlive(bool keepAlive) { // Once terminate() has been called or the close task has started, the diff --git a/src/jsc/bindings/webcore/Worker.h b/src/jsc/bindings/webcore/Worker.h index 38a1382b5aae..03221175e8b2 100644 --- a/src/jsc/bindings/webcore/Worker.h +++ b/src/jsc/bindings/webcore/Worker.h @@ -134,6 +134,9 @@ class Worker final : public ThreadSafeRefCounted, public EventTargetWith void dispatchOnline(Zig::GlobalObject* workerGlobalObject); void fireEarlyMessages(Zig::GlobalObject* workerGlobalObject); void dispatchErrorWithMessage(WTF::String message, WTF::String code); + /// `[elapsedSinceLoopStartMs, idleMs]` for this worker's loop, read live from + /// the parent. False once the thread is gone (node reports all-zero then). + bool eventLoopUtilization(double& elapsedMs, double& idleMs); static WTF::String errorCodeOf(JSC::JSGlobalObject*, JSC::JSValue); bool dispatchErrorWithValue(Zig::GlobalObject* workerGlobalObject, JSValue value); bool dispatchExit(int32_t exitCode); diff --git a/src/jsc/web_worker.rs b/src/jsc/web_worker.rs index a0f83e3c5e90..bbddeb358a5e 100644 --- a/src/jsc/web_worker.rs +++ b/src/jsc/web_worker.rs @@ -399,6 +399,49 @@ pub fn terminate_all_and_wait(timeout_ms: u64) { } } +/// The PARENT reading a live worker's loop counters. False once the worker VM is +/// gone, which node reports as all-zero. `vm_lock` only closes the TOCTOU on +/// `vm`: `idle_ns` is atomic and `loop_start` is fixed before publish. +/// +/// # Safety +/// `worker` is a live `WebWorker*` owned by the calling C++ `Worker`; the out +/// params are non-null and writable. +#[unsafe(no_mangle)] +pub(crate) unsafe extern "C" fn WebWorker__getELU( + worker: *mut WebWorker, + out_elapsed_ms: *mut f64, + out_idle_ms: *mut f64, +) -> bool { + // SAFETY: per fn contract — a live WebWorker for the duration of the call. + let w = unsafe { &*worker }; + w.vm_lock.lock(); + let vm_ptr = w.vm_ptr(); + let live = !vm_ptr.is_null(); + if live { + // No `&VirtualMachine` binding: the worker thread may hold a live mutable + // view. Raw-pointer access keeps any autoref scoped to the access, as the + // terminate path above does. + // SAFETY: event_loop() is the live self-pointer; the reads below are an + // atomic load and a Copy field written before the VM was published. + let loop_ = unsafe { (*(*vm_ptr).event_loop()).usockets_loop().as_ref() }; + let Some(loop_) = loop_ else { + w.vm_lock.unlock(); + return false; + }; + // Idle BEFORE elapsed, matching node's order — reversed, idle is dated + // after now and active = now - idle comes out short. + let idle_ms = loop_.idle_ns() as f64 / 1_000_000.0; + let elapsed_ms = unsafe { (*vm_ptr).loop_start }.elapsed().as_secs_f64() * 1000.0; + // SAFETY: per fn contract — out params are writable. + unsafe { + *out_elapsed_ms = elapsed_ms; + *out_idle_ms = idle_ms; + } + } + w.vm_lock.unlock(); + live +} + #[unsafe(no_mangle)] pub(crate) extern "C" fn WebWorker__getParentWorker(vm: &VirtualMachine) -> *mut c_void { vm.worker_ref() diff --git a/src/runtime/dispatch_js2native.rs b/src/runtime/dispatch_js2native.rs index 87a6033c6b5e..4ce01ff610b7 100644 --- a/src/runtime/dispatch_js2native.rs +++ b/src/runtime/dispatch_js2native.rs @@ -72,10 +72,33 @@ pub(crate) fn bun_get_use_system_ca( _global: &JSGlobalObject, _frame: &CallFrame, ) -> JsResult { - Ok(match bun_jsc::virtual_machine::VirtualMachine::get().use_system_ca { - Some(v) => JSValue::js_boolean(v), - None => JSValue::UNDEFINED, - }) + Ok( + match bun_jsc::virtual_machine::VirtualMachine::get().use_system_ca { + Some(v) => JSValue::js_boolean(v), + None => JSValue::UNDEFINED, + }, + ) +} + +/// `[elapsedSinceLoopStartMs, idleMs]` for THIS thread's loop — the two numbers +/// performance.eventLoopUtilization() is defined in terms of (node derives +/// active as now - loopStart - idle). +pub(crate) fn bun_get_loop_elu(global: &JSGlobalObject, _frame: &CallFrame) -> JsResult { + let vm = bun_jsc::virtual_machine::VirtualMachine::get(); + // SAFETY: the VM owns this loop and this runs on its thread. + let loop_ = unsafe { (*vm.event_loop).usockets_loop().as_ref() }; + let Some(loop_) = loop_ else { + return Ok(JSValue::NULL); + }; + // Idle BEFORE elapsed, matching node's order (it passes loopIdleTime() in + // and reads process.hrtime() after). Reversed, idle is dated after now and + // active = now - idle comes out short. + let idle_ms = loop_.idle_ns() as f64 / 1_000_000.0; + let elapsed_ms = vm.loop_start.elapsed().as_secs_f64() * 1000.0; + let arr = JSValue::create_empty_array(global, 2)?; + arr.put_index(global, 0, JSValue::js_number(elapsed_ms))?; + arr.put_index(global, 1, JSValue::js_number(idle_ms))?; + Ok(arr) } mod css { diff --git a/src/uws_sys/InternalLoopData.rs b/src/uws_sys/InternalLoopData.rs index 5a38af507434..58d34d102ad5 100644 --- a/src/uws_sys/InternalLoopData.rs +++ b/src/uws_sys/InternalLoopData.rs @@ -35,6 +35,15 @@ pub struct InternalLoopData { pub quic_next_tick_us: i64, #[cfg(windows)] pub quic_timer: *mut Timer, + /// Nanoseconds this loop has spent parked, for eventLoopUtilization(). + /// Mirrors the `#ifndef LIBUS_USE_LIBUV` field in loop_data.h — libuv tracks + /// the same itself via uv_metrics_idle_time. + #[cfg(not(windows))] + pub idle_ns: u64, + /// Monotonic ns the current park began, 0 when not parked. Mirrors + /// loop_data.h — see the layout warning on `idle_ns`. + #[cfg(not(windows))] + pub idle_entry_ns: u64, pub iterator: *mut SocketGroup, pub recv_buf: *mut u8, pub send_buf: *mut u8, diff --git a/src/uws_sys/Loop.rs b/src/uws_sys/Loop.rs index 144d86379b31..4d83ace8879e 100644 --- a/src/uws_sys/Loop.rs +++ b/src/uws_sys/Loop.rs @@ -243,6 +243,14 @@ impl PosixLoop { unsafe { c::us_wakeup_loop(self) }; } + /// Nanoseconds this loop has spent parked, for eventLoopUtilization(). + /// `&self`: a parent thread reads this while the worker holds its own + /// `&mut` — the body is one atomic load, so it must not alias mutably. + pub fn idle_ns(&self) -> u64 { + // SAFETY: self is a valid loop pointer; the counter is read atomically. + unsafe { c::us_loop_idle_ns(self as *const Loop as *mut Loop) } + } + #[inline] pub fn wake(&mut self) { self.wakeup(); @@ -472,6 +480,14 @@ impl WindowsLoop { unsafe { c::us_wakeup_loop(self) }; } + /// Nanoseconds this loop has spent parked, for eventLoopUtilization(). + /// `&self`: a parent thread reads this while the worker holds its own + /// `&mut` — the body is one atomic load, so it must not alias mutably. + pub fn idle_ns(&self) -> u64 { + // SAFETY: self is a valid loop pointer; the counter is read atomically. + unsafe { c::us_loop_idle_ns(self as *const Loop as *mut Loop) } + } + #[inline] pub fn wake(&mut self) { self.wakeup(); @@ -649,6 +665,7 @@ mod c { #[cfg(windows)] pub(super) fn us_loop_pump(loop_: *mut Loop); pub fn us_wakeup_loop(loop_: *mut Loop); + pub(super) fn us_loop_idle_ns(loop_: *mut Loop) -> u64; pub(super) fn uws_loop_addPostHandler(loop_: *mut Loop, ctx: *mut c_void, cb: LoopCtxCb); pub(super) fn uws_loop_removePostHandler(loop_: *mut Loop, ctx: *mut c_void, cb: LoopCtxCb); pub(super) fn uws_loop_addPreHandler(loop_: *mut Loop, ctx: *mut c_void, cb: LoopCtxCb); diff --git a/test/js/node/test/sequential/test-worker-eventlooputil.js b/test/js/node/test/sequential/test-worker-eventlooputil.js new file mode 100644 index 000000000000..39c6d723ff79 --- /dev/null +++ b/test/js/node/test/sequential/test-worker-eventlooputil.js @@ -0,0 +1,115 @@ +'use strict'; + +const { mustCall, mustCallAtLeast } = require('../common'); + +const assert = require('assert'); +const { + Worker, + MessageChannel, + MessagePort, + parentPort, +} = require('worker_threads'); +const { performance } = require('perf_hooks'); +const { eventLoopUtilization } = require('perf_hooks'); + +// Use argv to detect whether we're running as a Worker called by this test vs. +// this test also being called as a Worker. +if (process.argv[2] === 'iamalive') { + const iaElu = idleActive(eventLoopUtilization()); + // Checks that the worker bootstrap is running after the event loop started. + assert.ok(iaElu > 0, `${iaElu} <= 0`); + parentPort.once('message', mustCall((msg) => { + assert.ok(msg.metricsCh instanceof MessagePort); + msg.metricsCh.on('message', mustCallAtLeast(workerOnMetricsMsg, 1)); + })); + return; +} + +function workerOnMetricsMsg(msg) { + if (msg.cmd === 'close') { + return this.close(); + } + + if (msg.cmd === 'elu') { + return this.postMessage(eventLoopUtilization()); + } + + if (msg.cmd === 'spin') { + const elu = eventLoopUtilization(); + const t = performance.now(); + while (performance.now() - t < msg.dur); + return this.postMessage(eventLoopUtilization(elu)); + } +} + +let worker; +let metricsCh; +let mainElu; +let workerELU; + +(function r() { + // Force some idle time to accumulate before proceeding with test. + if (eventLoopUtilization().idle <= 0) + return setTimeout(mustCall(r), 5); + + mainElu = eventLoopUtilization(); + + worker = new Worker(__filename, { argv: [ 'iamalive' ] }); + metricsCh = new MessageChannel(); + worker.postMessage({ metricsCh: metricsCh.port1 }, [ metricsCh.port1 ]); + + workerELU = worker.performance.eventLoopUtilization; + metricsCh.port2.once('message', mustCall(checkWorkerIdle)); + metricsCh.port2.postMessage({ cmd: 'elu' }); + // Make sure it's still safe to call eventLoopUtilization() after the worker + // has been closed. + worker.on('exit', mustCall(() => { + assert.deepStrictEqual(worker.performance.eventLoopUtilization(), + { idle: 0, active: 0, utilization: 0 }); + })); +})(); + +function checkWorkerIdle(wElu) { + const perfWorkerElu = workerELU(); + const tmpMainElu = eventLoopUtilization(mainElu); + + assert.ok(idleActive(wElu) > 0, `${idleActive(wElu)} <= 0`); + assert.ok(idleActive(workerELU(wElu)) > 0, + `${idleActive(workerELU(wElu))} <= 0`); + assert.ok(idleActive(perfWorkerElu) > idleActive(wElu), + `${idleActive(perfWorkerElu)} <= ${idleActive(wElu)}`); + assert.ok(idleActive(tmpMainElu) > idleActive(perfWorkerElu), + `${idleActive(tmpMainElu)} <= ${idleActive(perfWorkerElu)}`); + + wElu = workerELU(); + setTimeout(mustCall(() => { + wElu = workerELU(wElu); + // Some clocks fire early. Removing a few milliseconds to cover that. + assert.ok(idleActive(wElu) >= 45, `${idleActive(wElu)} < 45`); + // Cutting the idle time in half since it's possible that the call took a + // lot of resources to process? + assert.ok(wElu.idle >= 25, `${wElu.idle} < 25`); + + checkWorkerActive(); + }), 50); +} + +function checkWorkerActive() { + const w = workerELU(); + + metricsCh.port2.postMessage({ cmd: 'spin', dur: 50 }); + metricsCh.port2.once('message', mustCall((wElu) => { + const w2 = workerELU(w); + + assert.ok(w2.active >= 50, `${w2.active} < 50`); + assert.ok(wElu.active >= 50, `${wElu.active} < 50`); + assert.ok(idleActive(wElu) < idleActive(w2), + `${idleActive(wElu)} >= ${idleActive(w2)}`); + + metricsCh.port2.postMessage({ cmd: 'close' }); + })); +} + +function idleActive(elu) { + return elu.idle + elu.active; +}