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 221e283

Browse filesBrowse files
trevnorristargos
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
Copy full SHA for 221e283

File tree

Expand file treeCollapse file tree

9 files changed

+370
-24
lines changed
Open diff view settings
Filter options
Expand file treeCollapse file tree

9 files changed

+370
-24
lines changed
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
+6-2Lines changed: 6 additions & 2 deletions
  • Display the source diff
  • Display the rich diff
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
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
@@ -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
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
@@ -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,
Collapse file

‎src/node_worker.cc‎

Copy file name to clipboardExpand all lines: src/node_worker.cc
+37Lines 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
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);
Collapse file

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

Copy file name to clipboardExpand all lines: test/parallel/test-bootstrap-modules.js
+1Lines 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 (0)
Morty Proxy This is a proxified and sanitized view of the page, visit original site.