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

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

/ node Public

Commit 9460f2c

Browse files
trevnorris
authored and
MylesBorins
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 Backport-PR-URL: #37163 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>
1 parent 89046d7 commit 9460f2c

9 files changed

Lines changed: 368 additions & 24 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: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -72,8 +72,11 @@ added:
7272
The `eventLoopUtilization()` method returns an object that contains the
7373
cumulative duration of time the event loop has been both idle and active as a
7474
high resolution milliseconds timer. The `utilization` value is the calculated
75-
Event Loop Utilization (ELU). If bootstrapping has not yet finished, the
76-
properties have the value of `0`.
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.
7780

7881
Both `utilization1` and `utilization2` are optional parameters.
7982

@@ -762,6 +765,7 @@ require('some-module');
762765
[Performance Timeline]: https://w3c.github.io/performance-timeline/
763766
[User Timing]: https://www.w3.org/TR/user-timing/
764767
[Web Performance APIs]: https://w3c.github.io/perf-timing-primer/
768+
[Worker threads]: worker_threads.md#worker_threads_worker_threads
765769
[`'exit'`]: process.md#process_event_exit
766770
[`child_process.spawnSync()`]: child_process.md#child_process_child_process_spawnsync_command_args_options
767771
[`process.hrtime()`]: process.md#process_process_hrtime_time

‎doc/api/worker_threads.md‎

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -787,6 +787,65 @@ If the Worker thread is no longer running, which may occur before the
787787
[`'exit'` event][] is emitted, the returned `Promise` will be rejected
788788
immediately with an [`ERR_WORKER_NOT_RUNNING`][] error.
789789

790+
### `worker.performance`
791+
<!-- YAML
792+
added: REPLACEME
793+
-->
794+
795+
An object that can be used to query performance information from a worker
796+
instance. Similar to [`perf_hooks.performance`][].
797+
798+
#### `performance.eventLoopUtilization([utilization1[, utilization2]])`
799+
<!-- YAML
800+
added: REPLACEME
801+
-->
802+
803+
* `utilization1` {Object} The result of a previous call to
804+
`eventLoopUtilization()`.
805+
* `utilization2` {Object} The result of a previous call to
806+
`eventLoopUtilization()` prior to `utilization1`.
807+
* Returns {Object}
808+
* `idle` {number}
809+
* `active` {number}
810+
* `utilization` {number}
811+
812+
The same call as [`perf_hooks` `eventLoopUtilization()`][], except the values
813+
of the worker instance are returned.
814+
815+
One difference is that, unlike the main thread, bootstrapping within a worker
816+
is done within the event loop. So the event loop utilization will be
817+
immediately available once the worker's script begins execution.
818+
819+
An `idle` time that does not increase does not indicate that the worker is
820+
stuck in bootstrap. The following examples shows how the worker's entire
821+
lifetime will never accumulate any `idle` time, but is still be able to process
822+
messages.
823+
824+
```js
825+
const { Worker, isMainThread, parentPort } = require('worker_threads');
826+
827+
if (isMainThread) {
828+
const worker = new Worker(__filename);
829+
setInterval(() => {
830+
worker.postMessage('hi');
831+
console.log(worker.performance.eventLoopUtilization());
832+
}, 100).unref();
833+
return;
834+
}
835+
836+
parentPort.on('message', () => console.log('msg')).unref();
837+
(function r(n) {
838+
if (--n < 0) return;
839+
const t = Date.now();
840+
while (Date.now() - t < 300);
841+
setImmediate(r, n);
842+
})(10);
843+
```
844+
845+
The event loop utilization of a worker is available only after the [`'online'`
846+
event][] emitted, and if called before this, or after the [`'exit'`
847+
event][], then all properties have the value of `0`.
848+
790849
### `worker.postMessage(value[, transferList])`
791850
<!-- YAML
792851
added: v10.5.0
@@ -908,6 +967,7 @@ active handle in the event system. If the worker is already `unref()`ed calling
908967
[Web Workers]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API
909968
[`'close'` event]: #worker_threads_event_close
910969
[`'exit'` event]: #worker_threads_event_exit
970+
[`'online'` event]: #worker_threads_event_online
911971
[`ArrayBuffer`]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/ArrayBuffer
912972
[`AsyncResource`]: async_hooks.md#async_hooks_class_asyncresource
913973
[`Buffer.allocUnsafe()`]: buffer.md#buffer_static_method_buffer_allocunsafe_size
@@ -927,6 +987,8 @@ active handle in the event system. If the worker is already `unref()`ed calling
927987
[`fs.close()`]: fs.md#fs_fs_close_fd_callback
928988
[`fs.open()`]: fs.md#fs_fs_open_path_flags_mode_callback
929989
[`markAsUntransferable()`]: #worker_threads_worker_markasuntransferable_object
990+
[`perf_hooks.performance`]: #perf_hooks.md#perf_hooks_perf_hooks_performance
991+
[`perf_hooks` `eventLoopUtilization()`]: perf_hooks.md#perf_hooks_performance_eventlooputilization_utilization1_utilization2
930992
[`port.on('message')`]: #worker_threads_event_message
931993
[`port.onmessage()`]: https://developer.mozilla.org/en-US/docs/Web/API/MessagePort/onmessage
932994
[`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
@@ -20,6 +20,7 @@ const {
2020
const EventEmitter = require('events');
2121
const assert = require('internal/assert');
2222
const path = require('path');
23+
const { timeOrigin } = internalBinding('performance');
2324

2425
const errorCodes = require('internal/errors').codes;
2526
const {
@@ -70,6 +71,8 @@ const kOnMessage = Symbol('kOnMessage');
7071
const kOnCouldNotSerializeErr = Symbol('kOnCouldNotSerializeErr');
7172
const kOnErrorMessage = Symbol('kOnErrorMessage');
7273
const kParentSideStdio = Symbol('kParentSideStdio');
74+
const kLoopStartTime = Symbol('kLoopStartTime');
75+
const kIsOnline = Symbol('kIsOnline');
7376

7477
const SHARE_ENV = SymbolFor('nodejs.worker_threads.SHARE_ENV');
7578
let debug = require('internal/util/debuglog').debuglog('worker', (fn) => {
@@ -223,6 +226,12 @@ class Worker extends EventEmitter {
223226
null,
224227
hasStdin: !!options.stdin
225228
}, transferList);
229+
// Use this to cache the Worker's loopStart value once available.
230+
this[kLoopStartTime] = -1;
231+
this[kIsOnline] = false;
232+
this.performance = {
233+
eventLoopUtilization: eventLoopUtilization.bind(this),
234+
};
226235
// Actually start the new thread now that everything is in place.
227236
this[kHandle].startThread();
228237
}
@@ -254,6 +263,7 @@ class Worker extends EventEmitter {
254263
[kOnMessage](message) {
255264
switch (message.type) {
256265
case messageTypes.UP_AND_RUNNING:
266+
this[kIsOnline] = true;
257267
return this.emit('online');
258268
case messageTypes.COULD_NOT_SERIALIZE_ERROR:
259269
return this[kOnCouldNotSerializeErr]();
@@ -415,6 +425,52 @@ function makeResourceLimits(float64arr) {
415425
};
416426
}
417427

428+
function eventLoopUtilization(util1, util2) {
429+
// TODO(trevnorris): Works to solve the thread-safe read/write issue of
430+
// loopTime, but has the drawback that it can't be set until the event loop
431+
// has had a chance to turn. So it will be impossible to read the ELU of
432+
// a worker thread immediately after it's been created.
433+
if (!this[kIsOnline] || !this[kHandle]) {
434+
return { idle: 0, active: 0, utilization: 0 };
435+
}
436+
437+
// Cache loopStart, since it's only written to once.
438+
if (this[kLoopStartTime] === -1) {
439+
this[kLoopStartTime] = this[kHandle].loopStartTime();
440+
if (this[kLoopStartTime] === -1)
441+
return { idle: 0, active: 0, utilization: 0 };
442+
}
443+
444+
if (util2) {
445+
const idle = util1.idle - util2.idle;
446+
const active = util1.active - util2.active;
447+
return { idle, active, utilization: active / (idle + active) };
448+
}
449+
450+
const idle = this[kHandle].loopIdleTime();
451+
452+
// Using performance.now() here is fine since it's always the time from
453+
// the beginning of the process, and is why it needs to be offset by the
454+
// loopStart time (which is also calculated from the beginning of the
455+
// process).
456+
const active = now() - this[kLoopStartTime] - idle;
457+
458+
if (!util1) {
459+
return { idle, active, utilization: active / (idle + active) };
460+
}
461+
462+
const idle_delta = idle - util1.idle;
463+
const active_delta = active - util1.active;
464+
const utilization = active_delta / (idle_delta + active_delta);
465+
return { idle: idle_delta, active: active_delta, utilization };
466+
}
467+
468+
// Duplicate code from performance.now() so don't need to require perf_hooks.
469+
function now() {
470+
const hr = process.hrtime();
471+
return (hr[0] * 1000 + hr[1] / 1e6) - timeOrigin;
472+
}
473+
418474
module.exports = {
419475
ownsProcessState,
420476
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
@@ -65,6 +65,8 @@ class Worker : public AsyncWrap {
6565
const v8::FunctionCallbackInfo<v8::Value>& args);
6666
v8::Local<v8::Float64Array> GetResourceLimits(v8::Isolate* isolate) const;
6767
static void TakeHeapSnapshot(const v8::FunctionCallbackInfo<v8::Value>& args);
68+
static void LoopIdleTime(const v8::FunctionCallbackInfo<v8::Value>& args);
69+
static void LoopStartTime(const v8::FunctionCallbackInfo<v8::Value>& args);
6870

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

‎test/parallel/test-bootstrap-modules.js‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,7 @@ const expectedModules = new Set([
9393
if (!common.isMainThread) {
9494
[
9595
'Internal Binding messaging',
96+
'Internal Binding performance',
9697
'Internal Binding symbols',
9798
'Internal Binding worker',
9899
'NativeModule internal/streams/duplex',

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL