Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Appearance settings

Commit eec7542

Browse filesBrowse files
trevnorrisrichardlau
trevnorris
authored and
richardlau
committed
worker: add eventLoopUtilization()
Allow calling eventLoopUtilization() directly on a worker thread: const worker = new Worker('./foo.js'); const elu = worker.performance.eventLoopUtilization(); setTimeout(() => { worker.performance.eventLoopUtilization(elu); }, 10); Add a new performance object on the Worker instance that will hopefully one day hold all the other performance metrics, such as nodeTiming. Include benchmarks and tests. PR-URL: #35664 Reviewed-By: Juan José Arboleda <soyjuanarbol@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de> Reviewed-By: James M Snell <jasnell@gmail.com> Backport-PR-URL: #37165
1 parent 0f6d445 commit eec7542
Copy full SHA for eec7542

8 files changed

+424-22Lines changed: 424 additions & 22 deletions

File tree

Expand file treeCollapse file tree
Open diff view settings
Filter options
Expand file treeCollapse file tree
Open diff view settings
Collapse file

‎benchmark/worker/bench-eventlooputil.js‎

Copy file name to clipboard
+61Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
'use strict';
2+
3+
const common = require('../common.js');
4+
const { Worker, parentPort } = require('worker_threads');
5+
6+
if (process.argv[2] === 'idle cats') {
7+
return parentPort.once('message', () => {});
8+
}
9+
10+
const bench = common.createBenchmark(main, {
11+
n: [1e6],
12+
method: [
13+
'ELU_simple',
14+
'ELU_passed',
15+
],
16+
});
17+
18+
function main({ method, n }) {
19+
switch (method) {
20+
case 'ELU_simple':
21+
benchELUSimple(n);
22+
break;
23+
case 'ELU_passed':
24+
benchELUPassed(n);
25+
break;
26+
default:
27+
throw new Error(`Unsupported method ${method}`);
28+
}
29+
}
30+
31+
function benchELUSimple(n) {
32+
const worker = new Worker(__filename, { argv: ['idle cats'] });
33+
34+
spinUntilIdle(worker, () => {
35+
bench.start();
36+
for (let i = 0; i < n; i++)
37+
worker.performance.eventLoopUtilization();
38+
bench.end(n);
39+
worker.postMessage('bye');
40+
});
41+
}
42+
43+
function benchELUPassed(n) {
44+
const worker = new Worker(__filename, { argv: ['idle cats'] });
45+
46+
spinUntilIdle(worker, () => {
47+
let elu = worker.performance.eventLoopUtilization();
48+
bench.start();
49+
for (let i = 0; i < n; i++)
50+
elu = worker.performance.eventLoopUtilization(elu);
51+
bench.end(n);
52+
worker.postMessage('bye');
53+
});
54+
}
55+
56+
function spinUntilIdle(w, cb) {
57+
const t = w.performance.eventLoopUtilization();
58+
if (t.idle + t.active > 0)
59+
return process.nextTick(cb);
60+
setTimeout(() => spinUntilIdle(w, cb), 1);
61+
}
Collapse file

‎doc/api/perf_hooks.md‎

Copy file name to clipboardExpand all lines: doc/api/perf_hooks.md
+63Lines changed: 63 additions & 0 deletions
  • Display the source diff
  • Display the rich diff
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,68 @@ added: v8.5.0
5353
If `name` is not provided, removes all `PerformanceMark` objects from the
5454
Performance Timeline. If `name` is provided, removes only the named mark.
5555

56+
### `performance.eventLoopUtilization([utilization1[, utilization2]])`
57+
<!-- YAML
58+
added:
59+
- v14.10.0
60+
- v12.19.0
61+
-->
62+
63+
* `utilization1` {Object} The result of a previous call to
64+
`eventLoopUtilization()`.
65+
* `utilization2` {Object} The result of a previous call to
66+
`eventLoopUtilization()` prior to `utilization1`.
67+
* Returns {Object}
68+
* `idle` {number}
69+
* `active` {number}
70+
* `utilization` {number}
71+
72+
The `eventLoopUtilization()` method returns an object that contains the
73+
cumulative duration of time the event loop has been both idle and active as a
74+
high resolution milliseconds timer. The `utilization` value is the calculated
75+
Event Loop Utilization (ELU).
76+
77+
If bootstrapping has not yet finished on the main thread the properties have
78+
the value of `0`. The ELU is immediately available on [Worker threads][] since
79+
bootstrap happens within the event loop.
80+
81+
Both `utilization1` and `utilization2` are optional parameters.
82+
83+
If `utilization1` is passed, then the delta between the current call's `active`
84+
and `idle` times, as well as the corresponding `utilization` value are
85+
calculated and returned (similar to [`process.hrtime()`][]).
86+
87+
If `utilization1` and `utilization2` are both passed, then the delta is
88+
calculated between the two arguments. This is a convenience option because,
89+
unlike [`process.hrtime()`][], calculating the ELU is more complex than a
90+
single subtraction.
91+
92+
ELU is similar to CPU utilization, except that it only measures event loop
93+
statistics and not CPU usage. It represents the percentage of time the event
94+
loop has spent outside the event loop's event provider (e.g. `epoll_wait`).
95+
No other CPU idle time is taken into consideration. The following is an example
96+
of how a mostly idle process will have a high ELU.
97+
98+
```js
99+
'use strict';
100+
const { eventLoopUtilization } = require('perf_hooks').performance;
101+
const { spawnSync } = require('child_process');
102+
103+
setImmediate(() => {
104+
const elu = eventLoopUtilization();
105+
spawnSync('sleep', ['5']);
106+
console.log(eventLoopUtilization(elu).utilization);
107+
});
108+
```
109+
110+
Although the CPU is mostly idle while running this script, the value of
111+
`utilization` is `1`. This is because the call to
112+
[`child_process.spawnSync()`][] blocks the event loop from proceeding.
113+
114+
Passing in a user-defined object instead of the result of a previous call to
115+
`eventLoopUtilization()` will lead to undefined behavior. The return values
116+
are not guaranteed to reflect any correct state of the event loop.
117+
56118
### `performance.mark([name])`
57119
<!-- YAML
58120
added: v8.5.0
@@ -760,3 +822,4 @@ require('some-module');
760822
[Performance Timeline]: https://w3c.github.io/performance-timeline/
761823
[Web Performance APIs]: https://w3c.github.io/perf-timing-primer/
762824
[User Timing]: https://www.w3.org/TR/user-timing/
825+
[Worker threads]: worker_threads.md#worker_threads_worker_threads
Collapse file

‎doc/api/worker_threads.md‎

Copy file name to clipboardExpand all lines: doc/api/worker_threads.md
+62Lines changed: 62 additions & 0 deletions
  • Display the source diff
  • Display the rich diff
Original file line numberDiff line numberDiff line change
@@ -767,6 +767,65 @@ If the Worker thread is no longer running, which may occur before the
767767
[`'exit'` event][] is emitted, the returned `Promise` will be rejected
768768
immediately with an [`ERR_WORKER_NOT_RUNNING`][] error.
769769

770+
### `worker.performance`
771+
<!-- YAML
772+
added: REPLACEME
773+
-->
774+
775+
An object that can be used to query performance information from a worker
776+
instance. Similar to [`perf_hooks.performance`][].
777+
778+
#### `performance.eventLoopUtilization([utilization1[, utilization2]])`
779+
<!-- YAML
780+
added: REPLACEME
781+
-->
782+
783+
* `utilization1` {Object} The result of a previous call to
784+
`eventLoopUtilization()`.
785+
* `utilization2` {Object} The result of a previous call to
786+
`eventLoopUtilization()` prior to `utilization1`.
787+
* Returns {Object}
788+
* `idle` {number}
789+
* `active` {number}
790+
* `utilization` {number}
791+
792+
The same call as [`perf_hooks` `eventLoopUtilization()`][], except the values
793+
of the worker instance are returned.
794+
795+
One difference is that, unlike the main thread, bootstrapping within a worker
796+
is done within the event loop. So the event loop utilization will be
797+
immediately available once the worker's script begins execution.
798+
799+
An `idle` time that does not increase does not indicate that the worker is
800+
stuck in bootstrap. The following examples shows how the worker's entire
801+
lifetime will never accumulate any `idle` time, but is still be able to process
802+
messages.
803+
804+
```js
805+
const { Worker, isMainThread, parentPort } = require('worker_threads');
806+
807+
if (isMainThread) {
808+
const worker = new Worker(__filename);
809+
setInterval(() => {
810+
worker.postMessage('hi');
811+
console.log(worker.performance.eventLoopUtilization());
812+
}, 100).unref();
813+
return;
814+
}
815+
816+
parentPort.on('message', () => console.log('msg')).unref();
817+
(function r(n) {
818+
if (--n < 0) return;
819+
const t = Date.now();
820+
while (Date.now() - t < 300);
821+
setImmediate(r, n);
822+
})(10);
823+
```
824+
825+
The event loop utilization of a worker is available only after the [`'online'`
826+
event][] emitted, and if called before this, or after the [`'exit'`
827+
event][], then all properties have the value of `0`.
828+
770829
### `worker.postMessage(value[, transferList])`
771830
<!-- YAML
772831
added: v10.5.0
@@ -880,6 +939,7 @@ active handle in the event system. If the worker is already `unref()`ed calling
880939

881940
[`'close'` event]: #worker_threads_event_close
882941
[`'exit'` event]: #worker_threads_event_exit
942+
[`'online'` event]: #worker_threads_event_online
883943
[`ArrayBuffer`]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/ArrayBuffer
884944
[`AsyncResource`]: async_hooks.html#async_hooks_class_asyncresource
885945
[`Buffer`]: buffer.html
@@ -899,6 +959,8 @@ active handle in the event system. If the worker is already `unref()`ed calling
899959
[`fs.open()`]: fs.html#fs_fs_open_path_flags_mode_callback
900960
[`fs.close()`]: fs.html#fs_fs_close_fd_callback
901961
[`markAsUntransferable()`]: #worker_threads_worker_markasuntransferable_object
962+
[`perf_hooks.performance`]: #perf_hooks.md#perf_hooks_perf_hooks_performance
963+
[`perf_hooks` `eventLoopUtilization()`]: perf_hooks.md#perf_hooks_performance_eventlooputilization_utilization1_utilization2
902964
[`port.on('message')`]: #worker_threads_event_message
903965
[`port.onmessage()`]: https://developer.mozilla.org/en-US/docs/Web/API/MessagePort/onmessage
904966
[`port.postMessage()`]: #worker_threads_port_postmessage_value_transferlist
Collapse file

‎lib/internal/worker.js‎

Copy file name to clipboardExpand all lines: lib/internal/worker.js
+56Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ const {
1717
const EventEmitter = require('events');
1818
const assert = require('internal/assert');
1919
const path = require('path');
20+
const { timeOrigin } = internalBinding('performance');
2021

2122
const errorCodes = require('internal/errors').codes;
2223
const {
@@ -67,6 +68,8 @@ const kOnMessage = Symbol('kOnMessage');
6768
const kOnCouldNotSerializeErr = Symbol('kOnCouldNotSerializeErr');
6869
const kOnErrorMessage = Symbol('kOnErrorMessage');
6970
const kParentSideStdio = Symbol('kParentSideStdio');
71+
const kLoopStartTime = Symbol('kLoopStartTime');
72+
const kIsOnline = Symbol('kIsOnline');
7073

7174
const SHARE_ENV = SymbolFor('nodejs.worker_threads.SHARE_ENV');
7275
let debug = require('internal/util/debuglog').debuglog('worker', (fn) => {
@@ -214,6 +217,12 @@ class Worker extends EventEmitter {
214217
null,
215218
hasStdin: !!options.stdin
216219
}, transferList);
220+
// Use this to cache the Worker's loopStart value once available.
221+
this[kLoopStartTime] = -1;
222+
this[kIsOnline] = false;
223+
this.performance = {
224+
eventLoopUtilization: eventLoopUtilization.bind(this),
225+
};
217226
// Actually start the new thread now that everything is in place.
218227
this[kHandle].startThread();
219228
}
@@ -245,6 +254,7 @@ class Worker extends EventEmitter {
245254
[kOnMessage](message) {
246255
switch (message.type) {
247256
case messageTypes.UP_AND_RUNNING:
257+
this[kIsOnline] = true;
248258
return this.emit('online');
249259
case messageTypes.COULD_NOT_SERIALIZE_ERROR:
250260
return this[kOnCouldNotSerializeErr]();
@@ -406,6 +416,52 @@ function makeResourceLimits(float64arr) {
406416
};
407417
}
408418

419+
function eventLoopUtilization(util1, util2) {
420+
// TODO(trevnorris): Works to solve the thread-safe read/write issue of
421+
// loopTime, but has the drawback that it can't be set until the event loop
422+
// has had a chance to turn. So it will be impossible to read the ELU of
423+
// a worker thread immediately after it's been created.
424+
if (!this[kIsOnline] || !this[kHandle]) {
425+
return { idle: 0, active: 0, utilization: 0 };
426+
}
427+
428+
// Cache loopStart, since it's only written to once.
429+
if (this[kLoopStartTime] === -1) {
430+
this[kLoopStartTime] = this[kHandle].loopStartTime();
431+
if (this[kLoopStartTime] === -1)
432+
return { idle: 0, active: 0, utilization: 0 };
433+
}
434+
435+
if (util2) {
436+
const idle = util1.idle - util2.idle;
437+
const active = util1.active - util2.active;
438+
return { idle, active, utilization: active / (idle + active) };
439+
}
440+
441+
const idle = this[kHandle].loopIdleTime();
442+
443+
// Using performance.now() here is fine since it's always the time from
444+
// the beginning of the process, and is why it needs to be offset by the
445+
// loopStart time (which is also calculated from the beginning of the
446+
// process).
447+
const active = now() - this[kLoopStartTime] - idle;
448+
449+
if (!util1) {
450+
return { idle, active, utilization: active / (idle + active) };
451+
}
452+
453+
const idle_delta = idle - util1.idle;
454+
const active_delta = active - util1.active;
455+
const utilization = active_delta / (idle_delta + active_delta);
456+
return { idle: idle_delta, active: active_delta, utilization };
457+
}
458+
459+
// Duplicate code from performance.now() so don't need to require perf_hooks.
460+
function now() {
461+
const hr = process.hrtime();
462+
return (hr[0] * 1000 + hr[1] / 1e6) - timeOrigin;
463+
}
464+
409465
module.exports = {
410466
ownsProcessState,
411467
isMainThread,
Collapse file

‎src/node_worker.cc‎

Copy file name to clipboardExpand all lines: src/node_worker.cc
+35Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -765,6 +765,39 @@ void Worker::TakeHeapSnapshot(const FunctionCallbackInfo<Value>& args) {
765765
args.GetReturnValue().Set(scheduled ? taker->object() : Local<Object>());
766766
}
767767

768+
void Worker::LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
769+
Worker* w;
770+
ASSIGN_OR_RETURN_UNWRAP(&w, args.This());
771+
772+
Mutex::ScopedLock lock(w->mutex_);
773+
// Using w->is_stopped() here leads to a deadlock, and checking is_stopped()
774+
// before locking the mutex is a race condition. So manually do the same
775+
// check.
776+
if (w->stopped_ || w->env_ == nullptr)
777+
return args.GetReturnValue().Set(-1);
778+
779+
uint64_t idle_time = uv_metrics_idle_time(w->env_->event_loop());
780+
args.GetReturnValue().Set(1.0 * idle_time / 1e6);
781+
}
782+
783+
void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
784+
Worker* w;
785+
ASSIGN_OR_RETURN_UNWRAP(&w, args.This());
786+
787+
Mutex::ScopedLock lock(w->mutex_);
788+
// Using w->is_stopped() here leads to a deadlock, and checking is_stopped()
789+
// before locking the mutex is a race condition. So manually do the same
790+
// check.
791+
if (w->stopped_ || w->env_ == nullptr)
792+
return args.GetReturnValue().Set(-1);
793+
794+
double loop_start_time = w->env_->performance_state()->milestones[
795+
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
796+
CHECK_GE(loop_start_time, 0);
797+
args.GetReturnValue().Set(
798+
(loop_start_time - node::performance::timeOrigin) / 1e6);
799+
}
800+
768801
namespace {
769802

770803
// Return the MessagePort that is global for this Environment and communicates
@@ -798,6 +831,8 @@ void InitWorker(Local<Object> target,
798831
env->SetProtoMethod(w, "unref", Worker::Unref);
799832
env->SetProtoMethod(w, "getResourceLimits", Worker::GetResourceLimits);
800833
env->SetProtoMethod(w, "takeHeapSnapshot", Worker::TakeHeapSnapshot);
834+
env->SetProtoMethod(w, "loopIdleTime", Worker::LoopIdleTime);
835+
env->SetProtoMethod(w, "loopStartTime", Worker::LoopStartTime);
801836

802837
Local<String> workerString =
803838
FIXED_ONE_BYTE_STRING(env->isolate(), "Worker");
Collapse file

‎src/node_worker.h‎

Copy file name to clipboardExpand all lines: src/node_worker.h
+2Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,8 @@ class Worker : public AsyncWrap {
6666
const v8::FunctionCallbackInfo<v8::Value>& args);
6767
v8::Local<v8::Float64Array> GetResourceLimits(v8::Isolate* isolate) const;
6868
static void TakeHeapSnapshot(const v8::FunctionCallbackInfo<v8::Value>& args);
69+
static void LoopIdleTime(const v8::FunctionCallbackInfo<v8::Value>& args);
70+
static void LoopStartTime(const v8::FunctionCallbackInfo<v8::Value>& args);
6971

7072
private:
7173
void CreateEnvMessagePort(Environment* env);

0 commit comments

Comments
0 (0)
Morty Proxy This is a proxified and sanitized view of the page, visit original site.