FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

worker: add eventLoopUtilization() · nodejs/node@eec7542 · GitHub

/ node Public

Commit eec7542

Browse files
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

8 files changed

Lines changed: 424 additions & 22 deletions

File tree

‎benchmark/worker/bench-eventlooputil.js‎

Lines 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+
}

‎doc/api/perf_hooks.md‎

Lines changed: 63 additions & 0 deletions
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

‎doc/api/worker_threads.md‎

Lines changed: 62 additions & 0 deletions
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

‎lib/internal/worker.js‎

Lines 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,

‎src/node_worker.cc‎

Lines 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");

‎src/node_worker.h‎

Lines 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)
Back | FazBrowse Home | New Git URL