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

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

/ node Public

Commit 221e283

Browse files
trevnorris
authored and
targos
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>
1 parent b6b7a3b commit 221e283

9 files changed

Lines changed: 370 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

@@ -766,6 +769,7 @@ require('some-module');
766769
[Performance Timeline]: https://w3c.github.io/performance-timeline/
767770
[User Timing]: https://www.w3.org/TR/user-timing/
768771
[Web Performance APIs]: https://w3c.github.io/perf-timing-primer/
772+
[Worker threads]: worker_threads.md#worker_threads_worker_threads
769773
[`'exit'`]: process.md#process_event_exit
770774
[`child_process.spawnSync()`]: child_process.md#child_process_child_process_spawnsync_command_args_options
771775
[`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
@@ -799,6 +799,65 @@ If the Worker thread is no longer running, which may occur before the
799799
[`'exit'` event][] is emitted, the returned `Promise` will be rejected
800800
immediately with an [`ERR_WORKER_NOT_RUNNING`][] error.
801801

802+
### `worker.performance`
803+
<!-- YAML
804+
added: REPLACEME
805+
-->
806+
807+
An object that can be used to query performance information from a worker
808+
instance. Similar to [`perf_hooks.performance`][].
809+
810+
#### `performance.eventLoopUtilization([utilization1[, utilization2]])`
811+
<!-- YAML
812+
added: REPLACEME
813+
-->
814+
815+
* `utilization1` {Object} The result of a previous call to
816+
`eventLoopUtilization()`.
817+
* `utilization2` {Object} The result of a previous call to
818+
`eventLoopUtilization()` prior to `utilization1`.
819+
* Returns {Object}
820+
* `idle` {number}
821+
* `active` {number}
822+
* `utilization` {number}
823+
824+
The same call as [`perf_hooks` `eventLoopUtilization()`][], except the values
825+
of the worker instance are returned.
826+
827+
One difference is that, unlike the main thread, bootstrapping within a worker
828+
is done within the event loop. So the event loop utilization will be
829+
immediately available once the worker's script begins execution.
830+
831+
An `idle` time that does not increase does not indicate that the worker is
832+
stuck in bootstrap. The following examples shows how the worker's entire
833+
lifetime will never accumulate any `idle` time, but is still be able to process
834+
messages.
835+
836+
```js
837+
const { Worker, isMainThread, parentPort } = require('worker_threads');
838+
839+
if (isMainThread) {
840+
const worker = new Worker(__filename);
841+
setInterval(() => {
842+
worker.postMessage('hi');
843+
console.log(worker.performance.eventLoopUtilization());
844+
}, 100).unref();
845+
return;
846+
}
847+
848+
parentPort.on('message', () => console.log('msg')).unref();
849+
(function r(n) {
850+
if (--n < 0) return;
851+
const t = Date.now();
852+
while (Date.now() - t < 300);
853+
setImmediate(r, n);
854+
})(10);
855+
```
856+
857+
The event loop utilization of a worker is available only after the [`'online'`
858+
event][] emitted, and if called before this, or after the [`'exit'`
859+
event][], then all properties have the value of `0`.
860+
802861
### `worker.postMessage(value[, transferList])`
803862
<!-- YAML
804863
added: v10.5.0
@@ -920,6 +979,7 @@ active handle in the event system. If the worker is already `unref()`ed calling
920979
[Web Workers]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API
921980
[`'close'` event]: #worker_threads_event_close
922981
[`'exit'` event]: #worker_threads_event_exit
982+
[`'online'` event]: #worker_threads_event_online
923983
[`ArrayBuffer`]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/ArrayBuffer
924984
[`AsyncResource`]: async_hooks.md#async_hooks_class_asyncresource
925985
[`Buffer.allocUnsafe()`]: buffer.md#buffer_static_method_buffer_allocunsafe_size
@@ -940,6 +1000,8 @@ active handle in the event system. If the worker is already `unref()`ed calling
9401000
[`fs.close()`]: fs.md#fs_fs_close_fd_callback
9411001
[`fs.open()`]: fs.md#fs_fs_open_path_flags_mode_callback
9421002
[`markAsUntransferable()`]: #worker_threads_worker_markasuntransferable_object
1003+
[`perf_hooks.performance`]: #perf_hooks.md#perf_hooks_perf_hooks_performance
1004+
[`perf_hooks` `eventLoopUtilization()`]: perf_hooks.md#perf_hooks_performance_eventlooputilization_utilization1_utilization2
9431005
[`port.on('message')`]: #worker_threads_event_message
9441006
[`port.onmessage()`]: https://developer.mozilla.org/en-US/docs/Web/API/MessagePort/onmessage
9451007
[`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: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -746,6 +746,39 @@ void Worker::TakeHeapSnapshot(const FunctionCallbackInfo<Value>& args) {
746746
args.GetReturnValue().Set(scheduled ? taker->object() : Local<Object>());
747747
}
748748

749+
void Worker::LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
750+
Worker* w;
751+
ASSIGN_OR_RETURN_UNWRAP(&w, args.This());
752+
753+
Mutex::ScopedLock lock(w->mutex_);
754+
// Using w->is_stopped() here leads to a deadlock, and checking is_stopped()
755+
// before locking the mutex is a race condition. So manually do the same
756+
// check.
757+
if (w->stopped_ || w->env_ == nullptr)
758+
return args.GetReturnValue().Set(-1);
759+
760+
uint64_t idle_time = uv_metrics_idle_time(w->env_->event_loop());
761+
args.GetReturnValue().Set(1.0 * idle_time / 1e6);
762+
}
763+
764+
void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
765+
Worker* w;
766+
ASSIGN_OR_RETURN_UNWRAP(&w, args.This());
767+
768+
Mutex::ScopedLock lock(w->mutex_);
769+
// Using w->is_stopped() here leads to a deadlock, and checking is_stopped()
770+
// before locking the mutex is a race condition. So manually do the same
771+
// check.
772+
if (w->stopped_ || w->env_ == nullptr)
773+
return args.GetReturnValue().Set(-1);
774+
775+
double loop_start_time = w->env_->performance_state()->milestones[
776+
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
777+
CHECK_GE(loop_start_time, 0);
778+
args.GetReturnValue().Set(
779+
(loop_start_time - node::performance::timeOrigin) / 1e6);
780+
}
781+
749782
namespace {
750783

751784
// Return the MessagePort that is global for this Environment and communicates
@@ -779,6 +812,8 @@ void InitWorker(Local<Object> target,
779812
env->SetProtoMethod(w, "unref", Worker::Unref);
780813
env->SetProtoMethod(w, "getResourceLimits", Worker::GetResourceLimits);
781814
env->SetProtoMethod(w, "takeHeapSnapshot", Worker::TakeHeapSnapshot);
815+
env->SetProtoMethod(w, "loopIdleTime", Worker::LoopIdleTime);
816+
env->SetProtoMethod(w, "loopStartTime", Worker::LoopStartTime);
782817

783818
Local<String> workerString =
784819
FIXED_ONE_BYTE_STRING(env->isolate(), "Worker");
@@ -845,6 +880,8 @@ void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
845880
registry->Register(Worker::Unref);
846881
registry->Register(Worker::GetResourceLimits);
847882
registry->Register(Worker::TakeHeapSnapshot);
883+
registry->Register(Worker::LoopIdleTime);
884+
registry->Register(Worker::LoopStartTime);
848885
}
849886

850887
} // anonymous namespace

‎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);

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

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,7 @@ const expectedModules = new Set([
108108
if (!common.isMainThread) {
109109
[
110110
'Internal Binding messaging',
111+
'Internal Binding performance',
111112
'Internal Binding symbols',
112113
'Internal Binding worker',
113114
'NativeModule internal/streams/duplex',

0 commit comments

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