Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

src,lib: add performance.uvMetricsInfo #54413

Merged
merged 9 commits into from
Aug 30, 2024
34 changes: 34 additions & 0 deletions doc/api/perf_hooks.md
Original file line number Diff line number Diff line change
Expand Up @@ -884,6 +884,40 @@ added: v8.5.0
The high resolution millisecond timestamp at which the Node.js process was
initialized.

### `performanceNodeTiming.uvMetricsInfo`

<!-- YAML
added: REPLACEME
-->

* Returns: {Object}
* `loopCount` {number} Number of event loop iterations.
* `events` {number} Number of events that have been processed by the event handler.
* `eventsWaiting` {number} Number of events that were waiting to be processed when the event provider was called.

This is a wrapper to the `uv_metrics_info` function.
It returns the current set of event loop metrics.

It is recommended to use this property inside a function whose execution was
scheduled using `setImmediate` to avoid collecting metrics before finishing all
operations scheduled during the current loop iteration.

```cjs
const { performance } = require('node:perf_hooks');

setImmediate(() => {
console.log(performance.nodeTiming.uvMetricsInfo);
});
```

```mjs
import { performance } from 'node:perf_hooks';

setImmediate(() => {
console.log(performance.nodeTiming.uvMetricsInfo);
});
```

### `performanceNodeTiming.v8Start`

<!-- YAML
Expand Down
8 changes: 8 additions & 0 deletions lib/internal/perf/nodetiming.js
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ const {
NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
},
loopIdleTime,
uvMetricsInfo,
} = internalBinding('performance');

class PerformanceNodeTiming {
Expand Down Expand Up @@ -122,6 +123,13 @@ class PerformanceNodeTiming {
configurable: true,
get: loopIdleTime,
},

uvMetricsInfo: {
__proto__: null,
enumerable: true,
configurable: true,
get: uvMetricsInfo,
},
});
}

Expand Down
3 changes: 3 additions & 0 deletions src/env_properties.h
Original file line number Diff line number Diff line change
Expand Up @@ -143,6 +143,8 @@
V(env_var_settings_string, "envVarSettings") \
V(errno_string, "errno") \
V(error_string, "error") \
V(events, "events") \
V(events_waiting, "eventsWaiting") \
V(exchange_string, "exchange") \
V(expire_string, "expire") \
V(exponent_string, "exponent") \
Expand Down Expand Up @@ -212,6 +214,7 @@
V(kind_string, "kind") \
V(length_string, "length") \
V(library_string, "library") \
V(loop_count, "loopCount") \
V(mac_string, "mac") \
V(max_buffer_string, "maxBuffer") \
V(max_concurrent_streams_string, "maxConcurrentStreams") \
Expand Down
26 changes: 26 additions & 0 deletions src/node_perf.cc
Original file line number Diff line number Diff line change
Expand Up @@ -261,6 +261,30 @@ void LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
args.GetReturnValue().Set(1.0 * idle_time / NANOS_PER_MILLIS);
}

void UvMetricsInfo(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
uv_metrics_t metrics;

// uv_metrics_info always return 0
CHECK_EQ(uv_metrics_info(env->event_loop(), &metrics), 0);

Local<Object> obj = Object::New(env->isolate());
obj->Set(env->context(),
env->loop_count(),
Integer::NewFromUnsigned(env->isolate(), metrics.loop_count))
.Check();
obj->Set(env->context(),
env->events(),
Integer::NewFromUnsigned(env->isolate(), metrics.events))
.Check();
obj->Set(env->context(),
env->events_waiting(),
Integer::NewFromUnsigned(env->isolate(), metrics.events_waiting))
.Check();
Comment on lines +271 to +283
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a note for the future optimization: maybe we should use a buffer to store these values to avoid creating and returning js objects from c++.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I have plans to return a typed array and build the object in JS land. I'll do it in a follow up PR.


args.GetReturnValue().Set(obj);
}

void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
int64_t interval = args[0].As<Integer>()->Value();
Expand Down Expand Up @@ -324,6 +348,7 @@ static void CreatePerIsolateProperties(IsolateData* isolate_data,
SetMethod(isolate, target, "loopIdleTime", LoopIdleTime);
SetMethod(isolate, target, "createELDHistogram", CreateELDHistogram);
SetMethod(isolate, target, "markBootstrapComplete", MarkBootstrapComplete);
SetMethod(isolate, target, "uvMetricsInfo", UvMetricsInfo);
SetFastMethodNoSideEffect(
isolate, target, "now", SlowPerformanceNow, &fast_performance_now);
}
Expand Down Expand Up @@ -390,6 +415,7 @@ void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
registry->Register(LoopIdleTime);
registry->Register(CreateELDHistogram);
registry->Register(MarkBootstrapComplete);
registry->Register(UvMetricsInfo);
registry->Register(SlowPerformanceNow);
registry->Register(FastPerformanceNow);
registry->Register(fast_performance_now.GetTypeInfo());
Expand Down
46 changes: 46 additions & 0 deletions test/fixtures/test-nodetiming-uvmetricsinfo.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
// Enforcing strict checks on the order or number of events across different
// platforms can be tricky and unreliable due to various factors.
// As a result, this test relies on the `uv_metrics_info` call instead.
const { performance } = require('node:perf_hooks');
const assert = require('node:assert');
const fs = require('node:fs');
const { nodeTiming } = performance;

function safeMetricsInfo(cb) {
setImmediate(() => {
const info = nodeTiming.uvMetricsInfo;
cb(info);
});
}

{
const info = nodeTiming.uvMetricsInfo;
assert.strictEqual(info.loopCount, 0);
assert.strictEqual(info.events, 0);
// This is the only part of the test that we test events waiting
// Adding checks for this property will make the test flaky
// as it can be highly influenced by race conditions.
assert.strictEqual(info.eventsWaiting, 0);
}

{
// The synchronous call should obviously not affect the uv metrics
const fd = fs.openSync(__filename, 'r');
fs.readFileSync(fd);
const info = nodeTiming.uvMetricsInfo;
assert.strictEqual(info.loopCount, 0);
assert.strictEqual(info.events, 0);
assert.strictEqual(info.eventsWaiting, 0);
}

{
function openFile(info) {
assert.strictEqual(info.loopCount, 1);

fs.open(__filename, 'r', (err) => {
assert.ifError(err);
});
}

safeMetricsInfo(openFile);
}
20 changes: 20 additions & 0 deletions test/parallel/test-performance-nodetiming-uvmetricsinfo.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
'use strict';

const common = require('../common');
common.skipIfWorker();

const { spawnSync } = require('node:child_process');
const assert = require('node:assert');
const fixtures = require('../common/fixtures');

const file = fixtures.path('test-nodetiming-uvmetricsinfo.js');

{
const { status, stderr } = spawnSync(
process.execPath,
[
file,
],
);
assert.strictEqual(status, 0, stderr.toString());
}
Loading