GeezerVison is showing github.com — worker: add eventLoopUtilization() · nodejs/node@9460f2c
File treeExpand file treeCollapse file tree Open diff view settings Expand file treeCollapse file tree Open diff view settings Collapse file Copy file name to clipboard +61Lines changed: 61 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 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 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 number | Diff line number | Diff line change |
|---|
@@ -72,8 +72,11 @@ added: | 72 | 72 | The `eventLoopUtilization()` method returns an object that contains the | 73 | 73 | cumulative duration of time the event loop has been both idle and active as a | 74 | 74 | 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. | 77 | 80 |
| 78 | 81 | Both `utilization1` and `utilization2` are optional parameters. | 79 | 82 |
| @@ -762,6 +765,7 @@ require('some-module'); | 762 | 765 | [Performance Timeline]: https://w3c.github.io/performance-timeline/ | 763 | 766 | [User Timing]: https://www.w3.org/TR/user-timing/ | 764 | 767 | [Web Performance APIs]: https://w3c.github.io/perf-timing-primer/ | | 768 | +[Worker threads]: worker_threads.md#worker_threads_worker_threads | 765 | 769 | [`'exit'`]: process.md#process_event_exit | 766 | 770 | [`child_process.spawnSync()`]: child_process.md#child_process_child_process_spawnsync_command_args_options | 767 | 771 | [`process.hrtime()`]: process.md#process_process_hrtime_time | |
Collapse file 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 number | Diff line number | Diff line change |
|---|
@@ -787,6 +787,65 @@ If the Worker thread is no longer running, which may occur before the | 787 | 787 | [`'exit'` event][] is emitted, the returned `Promise` will be rejected | 788 | 788 | immediately with an [`ERR_WORKER_NOT_RUNNING`][] error. | 789 | 789 |
| | 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 | + | 790 | 849 | ### `worker.postMessage(value[, transferList])` | 791 | 850 | <!-- YAML | 792 | 851 | added: v10.5.0 | @@ -908,6 +967,7 @@ active handle in the event system. If the worker is already `unref()`ed calling | 908 | 967 | [Web Workers]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API | 909 | 968 | [`'close'` event]: #worker_threads_event_close | 910 | 969 | [`'exit'` event]: #worker_threads_event_exit | | 970 | +[`'online'` event]: #worker_threads_event_online | 911 | 971 | [`ArrayBuffer`]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/ArrayBuffer | 912 | 972 | [`AsyncResource`]: async_hooks.md#async_hooks_class_asyncresource | 913 | 973 | [`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 | 927 | 987 | [`fs.close()`]: fs.md#fs_fs_close_fd_callback | 928 | 988 | [`fs.open()`]: fs.md#fs_fs_open_path_flags_mode_callback | 929 | 989 | [`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 | 930 | 992 | [`port.on('message')`]: #worker_threads_event_message | 931 | 993 | [`port.onmessage()`]: https://developer.mozilla.org/en-US/docs/Web/API/MessagePort/onmessage | 932 | 994 | [`port.postMessage()`]: #worker_threads_port_postmessage_value_transferlist | |
Collapse file Copy file name to clipboardExpand all lines: lib/internal/worker.js +56Lines changed: 56 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -20,6 +20,7 @@ const { | 20 | 20 | const EventEmitter = require('events'); | 21 | 21 | const assert = require('internal/assert'); | 22 | 22 | const path = require('path'); | | 23 | +const { timeOrigin } = internalBinding('performance'); | 23 | 24 |
| 24 | 25 | const errorCodes = require('internal/errors').codes; | 25 | 26 | const { | @@ -70,6 +71,8 @@ const kOnMessage = Symbol('kOnMessage'); | 70 | 71 | const kOnCouldNotSerializeErr = Symbol('kOnCouldNotSerializeErr'); | 71 | 72 | const kOnErrorMessage = Symbol('kOnErrorMessage'); | 72 | 73 | const kParentSideStdio = Symbol('kParentSideStdio'); | | 74 | +const kLoopStartTime = Symbol('kLoopStartTime'); | | 75 | +const kIsOnline = Symbol('kIsOnline'); | 73 | 76 |
| 74 | 77 | const SHARE_ENV = SymbolFor('nodejs.worker_threads.SHARE_ENV'); | 75 | 78 | let debug = require('internal/util/debuglog').debuglog('worker', (fn) => { | @@ -223,6 +226,12 @@ class Worker extends EventEmitter { | 223 | 226 | null, | 224 | 227 | hasStdin: !!options.stdin | 225 | 228 | }, 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 | + }; | 226 | 235 | // Actually start the new thread now that everything is in place. | 227 | 236 | this[kHandle].startThread(); | 228 | 237 | } | @@ -254,6 +263,7 @@ class Worker extends EventEmitter { | 254 | 263 | [kOnMessage](message) { | 255 | 264 | switch (message.type) { | 256 | 265 | case messageTypes.UP_AND_RUNNING: | | 266 | + this[kIsOnline] = true; | 257 | 267 | return this.emit('online'); | 258 | 268 | case messageTypes.COULD_NOT_SERIALIZE_ERROR: | 259 | 269 | return this[kOnCouldNotSerializeErr](); | @@ -415,6 +425,52 @@ function makeResourceLimits(float64arr) { | 415 | 425 | }; | 416 | 426 | } | 417 | 427 |
| | 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 | + | 418 | 474 | module.exports = { | 419 | 475 | ownsProcessState, | 420 | 476 | isMainThread, | |
Collapse file Copy file name to clipboardExpand all lines: src/node_worker.cc +35Lines changed: 35 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -765,6 +765,39 @@ void Worker::TakeHeapSnapshot(const FunctionCallbackInfo<Value>& args) { | 765 | 765 | args.GetReturnValue().Set(scheduled ? taker->object() : Local<Object>()); | 766 | 766 | } | 767 | 767 |
| | 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 | + | 768 | 801 | namespace { | 769 | 802 |
| 770 | 803 | // Return the MessagePort that is global for this Environment and communicates | @@ -798,6 +831,8 @@ void InitWorker(Local<Object> target, | 798 | 831 | env->SetProtoMethod(w, "unref", Worker::Unref); | 799 | 832 | env->SetProtoMethod(w, "getResourceLimits", Worker::GetResourceLimits); | 800 | 833 | env->SetProtoMethod(w, "takeHeapSnapshot", Worker::TakeHeapSnapshot); | | 834 | + env->SetProtoMethod(w, "loopIdleTime", Worker::LoopIdleTime); | | 835 | + env->SetProtoMethod(w, "loopStartTime", Worker::LoopStartTime); | 801 | 836 |
| 802 | 837 | Local<String> workerString = | 803 | 838 | FIXED_ONE_BYTE_STRING(env->isolate(), "Worker"); | |
Collapse file Copy file name to clipboardExpand all lines: src/node_worker.h +2Lines changed: 2 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -65,6 +65,8 @@ class Worker : public AsyncWrap { | 65 | 65 | const v8::FunctionCallbackInfo<v8::Value>& args); | 66 | 66 | v8::Local<v8::Float64Array> GetResourceLimits(v8::Isolate* isolate) const; | 67 | 67 | 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); | 68 | 70 |
| 69 | 71 | private: | 70 | 72 | void CreateEnvMessagePort(Environment* env); | |
Collapse file Copy file name to clipboardExpand all lines: test/parallel/test-bootstrap-modules.js +1Lines changed: 1 addition & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -93,6 +93,7 @@ const expectedModules = new Set([ | 93 | 93 | if (!common.isMainThread) { | 94 | 94 | [ | 95 | 95 | 'Internal Binding messaging', | | 96 | + 'Internal Binding performance', | 96 | 97 | 'Internal Binding symbols', | 97 | 98 | 'Internal Binding worker', | 98 | 99 | 'NativeModule internal/streams/duplex', | |
|