From c83605289ad302cf6358fe4e15348dfaf65f648e Mon Sep 17 00:00:00 2001 From: pabloerhard Date: Fri, 24 Apr 2026 14:28:07 -0400 Subject: [PATCH] initial work to add event loop based metrics --- doc/api/perf_hooks.md | 14 +++-- lib/internal/perf/event_loop_delay.js | 3 +- src/histogram.cc | 80 ++++++++++++++++++++------- src/histogram.h | 19 ++++--- src/node_perf.cc | 16 +----- 5 files changed, 83 insertions(+), 49 deletions(-) diff --git a/doc/api/perf_hooks.md b/doc/api/perf_hooks.md index bd38befcffbedc..a98660fae6d957 100644 --- a/doc/api/perf_hooks.md +++ b/doc/api/perf_hooks.md @@ -1708,7 +1708,10 @@ added: v11.10.0 --> * `options` {Object} - * `resolution` {number} The sampling rate in milliseconds. Must be greater + * `resolution` {number} Deprecated. Previously the sampling rate in + milliseconds; sampling is now driven directly by the libuv event loop via + `uv_prepare_t`/`uv_check_t` hooks, so this value is ignored. It is still + validated to preserve backward compatible error behavior. Must be greater than zero. **Default:** `10`. * Returns: {IntervalHistogram} @@ -1717,11 +1720,10 @@ _This property is an extension by Node.js. It is not available in Web browsers._ Creates an `IntervalHistogram` object that samples and reports the event loop delay over time. The delays will be reported in nanoseconds. -Using a timer to detect approximate event loop delay works because the -execution of timers is tied specifically to the lifecycle of the libuv -event loop. That is, a delay in the loop will cause a delay in the execution -of the timer, and those delays are specifically what this API is intended to -detect. +Samples are taken directly from the event loop using `uv_prepare_t` and +`uv_check_t` hooks, which only fire while the loop is iterating. As a result, +the histogram does not keep the loop alive or force additional iterations when +the application is idle. ```mjs import { monitorEventLoopDelay } from 'node:perf_hooks'; diff --git a/lib/internal/perf/event_loop_delay.js b/lib/internal/perf/event_loop_delay.js index 17581b1310c5c0..5b189ad94423b4 100644 --- a/lib/internal/perf/event_loop_delay.js +++ b/lib/internal/perf/event_loop_delay.js @@ -79,6 +79,7 @@ class ELDHistogram extends Histogram { * @returns {ELDHistogram} */ function monitorEventLoopDelay(options = kEmptyObject) { + // TODO: remove this once backward compatibility is removed validateObject(options, 'options'); const { resolution = 10 } = options; @@ -88,7 +89,7 @@ function monitorEventLoopDelay(options = kEmptyObject) { function() { markTransferMode(this, true, false); this[kEnabled] = false; - this[kHandle] = createELDHistogram(resolution); + this[kHandle] = createELDHistogram(); this[kMap] = new SafeMap(); }, [], ELDHistogram); } diff --git a/src/histogram.cc b/src/histogram.cc index 8752a419ec4030..6d64d58e88a03c 100644 --- a/src/histogram.cc +++ b/src/histogram.cc @@ -350,29 +350,27 @@ IntervalHistogram::IntervalHistogram( Environment* env, Local wrap, AsyncWrap::ProviderType type, - int32_t interval, - std::function on_interval, const Histogram::Options& options) : HandleWrap( env, wrap, - reinterpret_cast(&timer_), + reinterpret_cast(&check_handle_), type), - HistogramImpl(options), - interval_(interval), - on_interval_(std::move(on_interval)) { + HistogramImpl(options) { MakeWeak(); wrap->SetAlignedPointerInInternalField( HistogramImpl::InternalFields::kImplField, static_cast(this), EmbedderDataTag::kDefault); - uv_timer_init(env->event_loop(), &timer_); + uv_check_init(env->event_loop(), &check_handle_); + uv_prepare_init(env->event_loop(), &prepare_handle_); + uv_unref(reinterpret_cast(&check_handle_)); + uv_unref(reinterpret_cast(&prepare_handle_)); + prepare_handle_.data = this; } BaseObjectPtr IntervalHistogram::Create( Environment* env, - int32_t interval, - std::function on_interval, const Histogram::Options& options) { Local obj; if (!GetConstructorTemplate(env) @@ -385,18 +383,34 @@ BaseObjectPtr IntervalHistogram::Create( env, obj, AsyncWrap::PROVIDER_ELDHISTOGRAM, - interval, - std::move(on_interval), options); } -void IntervalHistogram::TimerCB(uv_timer_t* handle) { - IntervalHistogram* histogram = - ContainerOf(&IntervalHistogram::timer_, handle); +void IntervalHistogram::PrepareCB(uv_prepare_t* handle) { + IntervalHistogram* self = static_cast(handle->data); + if (!self->enabled_) return; + self->prepare_time_ = uv_hrtime(); + self->timeout_ = uv_backend_timeout(handle->loop); +} + +void IntervalHistogram::CheckCB(uv_check_t* handle) { + IntervalHistogram* self = + ContainerOf(&IntervalHistogram::check_handle_, handle); + if (!self->enabled_) return; - Histogram* h = histogram->histogram().get(); + uint64_t check_time = uv_hrtime(); + uint64_t poll_time = check_time - self->prepare_time_; + uint64_t latency = self->prepare_time_ - self->check_time_; - histogram->on_interval_(*h); + if (self->timeout_ >= 0) { + uint64_t timeout_ns = static_cast(self->timeout_) * 1000 * 1000; + if (poll_time > timeout_ns) { + latency += poll_time - timeout_ns; + } + } + + self->histogram()->Record(latency == 0 ? 1 : latency); + self->check_time_ = check_time; } void IntervalHistogram::MemoryInfo(MemoryTracker* tracker) const { @@ -408,14 +422,42 @@ void IntervalHistogram::OnStart(StartFlags flags) { enabled_ = true; if (flags == StartFlags::RESET) histogram()->Reset(); - uv_timer_start(&timer_, TimerCB, interval_, interval_); - uv_unref(reinterpret_cast(&timer_)); + check_time_ = uv_hrtime(); + prepare_time_ = check_time_; + timeout_ = 0; + uv_check_start(&check_handle_, CheckCB); + uv_prepare_start(&prepare_handle_, PrepareCB); + uv_unref(reinterpret_cast(&check_handle_)); + uv_unref(reinterpret_cast(&prepare_handle_)); } void IntervalHistogram::OnStop() { if (!enabled_ || IsHandleClosing()) return; enabled_ = false; - uv_timer_stop(&timer_); + uv_check_stop(&check_handle_); + uv_prepare_stop(&prepare_handle_); +} + +void IntervalHistogram::PrepareCloseCB(uv_handle_t* handle) { + IntervalHistogram* self = static_cast(handle->data); + uv_close(reinterpret_cast(&self->check_handle_), + HandleWrap::OnClose); +} + +void IntervalHistogram::Close(Local close_callback) { + if (IsHandleClosing()) return; + OnStop(); + state_ = kClosing; + + if (!close_callback.IsEmpty() && close_callback->IsFunction() && + !persistent().IsEmpty()) { + object()->Set(env()->context(), + env()->handle_onclose_symbol(), + close_callback).Check(); + } + + uv_close(reinterpret_cast(&prepare_handle_), + PrepareCloseCB); } void IntervalHistogram::Start(const FunctionCallbackInfo& args) { diff --git a/src/histogram.h b/src/histogram.h index 31c6564b9b1f12..b043edc3036c7c 100644 --- a/src/histogram.h +++ b/src/histogram.h @@ -225,16 +225,12 @@ class IntervalHistogram final : public HandleWrap, public HistogramImpl { static BaseObjectPtr Create( Environment* env, - int32_t interval, - std::function on_interval, const Histogram::Options& options); IntervalHistogram( Environment* env, v8::Local wrap, AsyncWrap::ProviderType type, - int32_t interval, - std::function on_interval, const Histogram::Options& options = Histogram::Options {}); static void Start(const v8::FunctionCallbackInfo& args); @@ -248,19 +244,26 @@ class IntervalHistogram final : public HandleWrap, public HistogramImpl { } std::unique_ptr CloneForMessaging() const override; + void Close(v8::Local close_callback = + v8::Local()) override; + void MemoryInfo(MemoryTracker* tracker) const override; SET_MEMORY_INFO_NAME(IntervalHistogram) SET_SELF_SIZE(IntervalHistogram) private: - static void TimerCB(uv_timer_t* handle); + static void PrepareCB(uv_prepare_t* handle); + static void CheckCB(uv_check_t* handle); + static void PrepareCloseCB(uv_handle_t* handle); void OnStart(StartFlags flags = StartFlags::RESET); void OnStop(); bool enabled_ = false; - int32_t interval_ = 0; - std::function on_interval_; - uv_timer_t timer_; + uv_prepare_t prepare_handle_; + uv_check_t check_handle_; + uint64_t prepare_time_ = 0; + uint64_t check_time_ = 0; + int64_t timeout_ = 0; static v8::CFunction fast_start_; static v8::CFunction fast_stop_; diff --git a/src/node_perf.cc b/src/node_perf.cc index e984fd4c3bf003..01467500a5761e 100644 --- a/src/node_perf.cc +++ b/src/node_perf.cc @@ -280,22 +280,8 @@ void UvMetricsInfo(const FunctionCallbackInfo& args) { void CreateELDHistogram(const FunctionCallbackInfo& args) { Environment* env = Environment::GetCurrent(args); - int64_t interval = args[0].As()->Value(); - CHECK_GT(interval, 0); BaseObjectPtr histogram = - IntervalHistogram::Create(env, interval, [](Histogram& histogram) { - uint64_t delta = histogram.RecordDelta(); - TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop), - "delay", delta); - TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop), - "min", histogram.Min()); - TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop), - "max", histogram.Max()); - TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop), - "mean", histogram.Mean()); - TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop), - "stddev", histogram.Stddev()); - }, Histogram::Options { 1000 }); + IntervalHistogram::Create(env, Histogram::Options { 1 }); args.GetReturnValue().Set(histogram->object()); }