perf_hooks: add idleTime and event loop util

Use uv_metrics_idle_time() to return a high resolution millisecond timer
of the amount of time the event loop has been idle since it was
initialized.

Include performance.eventLoopUtilization() API to handle the math of
calculating the idle and active times. This has been added to prevent
accidental miscalculations of the event loop utilization. Such as not
taking into consideration offsetting nodeTiming.loopStart or timing
differences when being called from a Worker thread.

PR-URL: https://github.com/nodejs/node/pull/34938
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Adrian Estrada <edsadr@gmail.com>
Reviewed-By: Juan José Arboleda <soyjuanarbol@gmail.com>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Stephen Belanger <admin@stephenbelanger.com>
Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>
Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de>

8 files changed, 279 insertions, 2 deletions

diff --git a/benchmark/README.md b/benchmark/README.md
index 6a40d7af3e1..dc02db4abd8 100644
--- a/benchmark/README.md
+++ b/benchmark/README.md
@@ -32,6 +32,7 @@ directory, see [the guide on benchmarks](../doc/guides/writing-and-running-bench
 | module          | Benchmarks for the `module` subsystem.                                                                           |
 | net             | Benchmarks for the `net` subsystem.                                                                              |
 | path            | Benchmarks for the `path` subsystem.                                                                             |
+| perf_hooks      | Benchmarks for the `perf_hooks` subsystem.                                                                       |
 | process         | Benchmarks for the `process` subsystem.                                                                          |
 | querystring     | Benchmarks for the `querystring` subsystem.                                                                      |
 | streams         | Benchmarks for the `streams` subsystem.                                                                          |
diff --git a/benchmark/perf_hooks/bench-eventlooputil.js b/benchmark/perf_hooks/bench-eventlooputil.js
new file mode 100644
index 00000000000..984b2b66aec
--- /dev/null
+++ b/benchmark/perf_hooks/bench-eventlooputil.js
@@ -0,0 +1,64 @@
+'use strict';
+
+const common = require('../common.js');
+const assert = require('assert').ok;
+const { performance } = require('perf_hooks');
+const { nodeTiming, eventLoopUtilization } = performance;
+
+const bench = common.createBenchmark(main, {
+  n: [1e6],
+  method: [
+    'idleTime',
+    'ELU_simple',
+    'ELU_passed',
+  ],
+});
+
+function main({ method, n }) {
+  switch (method) {
+    case 'idleTime':
+      benchIdleTime(n);
+      break;
+    case 'ELU_simple':
+      benchELUSimple(n);
+      break;
+    case 'ELU_passed':
+      benchELUPassed(n);
+      break;
+    default:
+      throw new Error(`Unsupported method ${method}`);
+  }
+}
+
+function benchIdleTime(n) {
+  bench.start();
+  for (let i = 0; i < n; i++)
+    nodeTiming.idleTime;
+  bench.end(n);
+}
+
+function benchELUSimple(n) {
+  // Need to put this in setImmediate or will always return 0.
+  setImmediate(() => {
+    const elu = eventLoopUtilization();
+    assert(elu.active + elu.idle > 0);
+
+    bench.start();
+    for (let i = 0; i < n; i++)
+      eventLoopUtilization();
+    bench.end(n);
+  });
+}
+
+function benchELUPassed(n) {
+  // Need to put this in setImmediate or will always return 0.
+  setImmediate(() => {
+    let elu = eventLoopUtilization();
+    assert(elu.active + elu.idle > 0);
+
+    bench.start();
+    for (let i = 0; i < n; i++)
+      elu = eventLoopUtilization(elu);
+    bench.end(n);
+  });
+}
diff --git a/doc/api/perf_hooks.md b/doc/api/perf_hooks.md
index 392dc2a5245..c8770c25605 100644
--- a/doc/api/perf_hooks.md
+++ b/doc/api/perf_hooks.md
@@ -165,6 +165,62 @@ obs.observe({ entryTypes: ['function'] });
 wrapped();
 ```
 
+### `performance.eventLoopUtilization([util1][,util2])`
+<!-- YAML
+added: REPLACEME
+-->
+
+* `util1` {Object} The result of a previous call to `eventLoopUtilization()`
+* `util2` {Object} The result of a previous call to `eventLoopUtilization()`
+    prior to `util1`
+* Returns {Object}
+  * `idle` {number}
+  * `active` {number}
+  * `utilization` {number}
+
+The `eventLoopUtilization()` method returns an object that contains the
+cumulative duration of time the event loop has been both idle and active as a
+high resolution milliseconds timer. The `utilization` value is the calculated
+Event Loop Utilization (ELU). If bootstrapping has not yet finished, the
+properties have the value of 0.
+
+`util1` and `util2` are optional parameters.
+
+If `util1` is passed then the delta between the current call's `active` and
+`idle` times are calculated and returned (similar to [`process.hrtime()`][]).
+Likewise the adjusted `utilization` value is calculated.
+
+If `util1` and `util2` are both passed then the calculation adjustments are
+done between the two arguments. This is a convenience option because unlike
+[`process.hrtime()`][] additional work is done to calculate the ELU.
+
+ELU is similar to CPU utilization except that it is calculated using high
+precision wall-clock time. It represents the percentage of time the event loop
+has spent outside the event loop's event provider (e.g. `epoll_wait`). No other
+CPU idle time is taken into consideration. The following is an example of how
+a mostly idle process will have a high ELU.
+
+<!-- eslint-skip -->
+```js
+'use strict';
+const { eventLoopUtilization } = require('perf_hooks').performance;
+const { spawnSync } = require('child_process');
+
+setImmediate(() => {
+  const elu = eventLoopUtilization();
+  spawnSync('sleep', ['5']);
+  console.log(eventLoopUtilization(elu).utilization);
+});
+```
+
+While the CPU is mostly idle while running this script the value of
+`utilization` is 1. This is because the call to [`child_process.spawnSync()`][]
+blocks the event loop from proceeding.
+
+Passing in a user-defined object instead of the result of a previous call to
+`eventLoopUtilization()` will lead to undefined behavior. The return values
+are not guaranteed to reflect any correct state of the event loop.
+
 ## Class: `PerformanceEntry`
 <!-- YAML
 added: v8.5.0
@@ -332,6 +388,19 @@ added: v8.5.0
 The high resolution millisecond timestamp at which the V8 platform was
 initialized.
 
+### `performanceNodeTiming.idleTime`
+<!-- YAML
+added: REPLACEME
+-->
+
+* {number}
+
+The high resolution millisecond timestamp of the amount of time the event loop
+has been idle within the event loop's event provider (e.g. `epoll_wait`). This
+does not take CPU usage into consideration. If the event loop has not yet
+started (e.g., in the first tick of the main script), the property has the
+value of 0.
+
 ## Class: `perf_hooks.PerformanceObserver`
 
 ### `new PerformanceObserver(callback)`
@@ -688,6 +757,8 @@ require('some-module');
 ```
 
 [`'exit'`]: process.html#process_event_exit
+[`process.hrtime()`]: process.html#process_process_hrtime_time
+[`child_process.spawnSync()`]: #child_process_child_process_spawnsync_command_args_options
 [`timeOrigin`]: https://w3c.github.io/hr-time/#dom-performance-timeorigin
 [`window.performance`]: https://developer.mozilla.org/en-US/docs/Web/API/Window/performance
 [Async Hooks]: async_hooks.html
diff --git a/lib/perf_hooks.js b/lib/perf_hooks.js
index 2ce0d29464a..683dec3a90a 100644
--- a/lib/perf_hooks.js
+++ b/lib/perf_hooks.js
@@ -25,7 +25,8 @@ const {
   timerify,
   constants,
   installGarbageCollectionTracking,
-  removeGarbageCollectionTracking
+  removeGarbageCollectionTracking,
+  loopIdleTime,
 } = internalBinding('performance');
 
 const {
@@ -205,6 +206,10 @@ class PerformanceNodeTiming extends PerformanceEntry {
     return getMilestoneTimestamp(NODE_PERFORMANCE_MILESTONE_BOOTSTRAP_COMPLETE);
   }
 
+  get idleTime() {
+    return loopIdleTime();
+  }
+
   [kInspect]() {
     return {
       name: 'node',
@@ -448,10 +453,37 @@ class Performance {
     return ret;
   }
 
+  eventLoopUtilization(util1, util2) {
+    const ls = nodeTiming.loopStart;
+
+    if (ls <= 0) {
+      return { idle: 0, active: 0, utilization: 0 };
+    }
+
+    if (util2) {
+      const idle = util1.idle - util2.idle;
+      const active = util1.active - util2.active;
+      return { idle, active, utilization: active / (idle + active) };
+    }
+
+    const idle = nodeTiming.idleTime;
+    const active = performance.now() - ls - idle;
+
+    if (!util1) {
+      return { idle, active, utilization: active / (idle + active) };
+    }
+
+    const idle_delta = idle - util1.idle;
+    const active_delta = active - util1.active;
+    const utilization = active_delta / (idle_delta + active_delta);
+    return { idle: idle_delta, active: active_delta, utilization };
+  }
+
   [kInspect]() {
     return {
       nodeTiming: this.nodeTiming,
-      timeOrigin: this.timeOrigin
+      timeOrigin: this.timeOrigin,
+      idleTime: this.idleTime,
     };
   }
 }
diff --git a/src/node.cc b/src/node.cc
index d68c6d8d148..dd2cd0db75d 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -1079,6 +1079,7 @@ int Start(int argc, char** argv) {
         env_info = NodeMainInstance::GetEnvSerializeInfo();
       }
     }
+    uv_loop_configure(uv_default_loop(), UV_METRICS_IDLE_TIME);
 
     NodeMainInstance main_instance(&params,
                                    uv_default_loop(),
diff --git a/src/node_perf.cc b/src/node_perf.cc
index d71afc2d81c..5fa4eabc993 100644
--- a/src/node_perf.cc
+++ b/src/node_perf.cc
@@ -440,6 +440,13 @@ void Notify(const FunctionCallbackInfo<Value>& args) {
   }
 }
 
+// Return idle time of the event loop
+void LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
+  Environment* env = Environment::GetCurrent(args);
+  uint64_t idle_time = uv_metrics_idle_time(env->event_loop());
+  args.GetReturnValue().Set(1.0 * idle_time / 1e6);
+}
+
 
 // Event Loop Timing Histogram
 namespace {
@@ -629,6 +636,7 @@ void Initialize(Local<Object> target,
                  "removeGarbageCollectionTracking",
                  RemoveGarbageCollectionTracking);
   env->SetMethod(target, "notify", Notify);
+  env->SetMethod(target, "loopIdleTime", LoopIdleTime);
 
   Local<Object> constants = Object::New(isolate);
 
diff --git a/src/node_worker.cc b/src/node_worker.cc
index 2b7cc156db9..b3dd29bf9fb 100644
--- a/src/node_worker.cc
+++ b/src/node_worker.cc
@@ -135,6 +135,7 @@ class WorkerThreadData {
       return;
     }
     loop_init_failed_ = false;
+    uv_loop_configure(&loop_, UV_METRICS_IDLE_TIME);
 
     std::shared_ptr<ArrayBufferAllocator> allocator =
         ArrayBufferAllocator::Create();
diff --git a/test/parallel/test-performance-eventlooputil.js b/test/parallel/test-performance-eventlooputil.js
new file mode 100644
index 00000000000..1a5d86db750
--- /dev/null
+++ b/test/parallel/test-performance-eventlooputil.js
@@ -0,0 +1,99 @@
+'use strict';
+
+require('../common');
+
+const TIMEOUT = 50;
+
+const assert = require('assert');
+const { performance } = require('perf_hooks');
+const { Worker, parentPort } = require('worker_threads');
+
+const { nodeTiming, eventLoopUtilization } = performance;
+const elu = eventLoopUtilization();
+
+// Take into account whether this test was started as a Worker.
+if (nodeTiming.loopStart === -1) {
+  assert.strictEqual(nodeTiming.idleTime, 0);
+  assert.deepStrictEqual(elu, { idle: 0, active: 0, utilization: 0 });
+  assert.deepStrictEqual(eventLoopUtilization(elu),
+                         { idle: 0, active: 0, utilization: 0 });
+  assert.deepStrictEqual(eventLoopUtilization(elu, eventLoopUtilization()),
+                         { idle: 0, active: 0, utilization: 0 });
+}
+
+// Place in setTimeout() to make sure there is some idle time, but not going to
+// assert this since it could make the test flaky.
+setTimeout(() => {
+  const t = Date.now();
+  const elu1 = eventLoopUtilization();
+
+  while (Date.now() - t < 50) { }
+
+  const elu2 = eventLoopUtilization();
+  const elu3 = eventLoopUtilization(elu1);
+  const elu4 = eventLoopUtilization(elu2, elu1);
+
+  assert.strictEqual(elu3.idle, 0);
+  assert.strictEqual(elu4.idle, 0);
+  assert.strictEqual(elu3.utilization, 1);
+  assert.strictEqual(elu4.utilization, 1);
+  assert.strictEqual(elu2.active - elu1.active, elu4.active);
+  assert.ok(elu2.active > elu3.active);
+  assert.ok(elu2.active > elu4.active);
+  assert.ok(elu3.active > elu4.active);
+
+  setTimeout(runIdleTimeTest, TIMEOUT);
+}, 5);
+
+function runIdleTimeTest() {
+  const idleTime = nodeTiming.idleTime;
+  const elu1 = eventLoopUtilization();
+  const sum = elu1.idle + elu1.active;
+
+  assert.ok(sum >= elu1.idle && sum >= elu1.active,
+            `idle: ${elu1.idle}  active: ${elu1.active}  sum: ${sum}`);
+  assert.strictEqual(elu1.idle, idleTime);
+  assert.strictEqual(elu1.utilization, elu1.active / sum);
+
+  setTimeout(runCalcTest, TIMEOUT, elu1);
+}
+
+function runCalcTest(elu1) {
+  const now = performance.now();
+  const elu2 = eventLoopUtilization();
+  const elu3 = eventLoopUtilization(elu2, elu1);
+  const active_delta = elu2.active - elu1.active;
+  const idle_delta = elu2.idle - elu1.idle;
+
+  assert.ok(elu2.idle >= 0);
+  assert.ok(elu2.active >= 0);
+  assert.ok(elu3.idle >= 0);
+  assert.ok(elu3.active >= 0);
+  assert.ok(elu2.idle + elu2.active > elu1.idle + elu2.active);
+  assert.ok(elu2.idle + elu2.active >= now - nodeTiming.loopStart);
+  assert.strictEqual(elu3.active, elu2.active - elu1.active);
+  assert.strictEqual(elu3.idle, elu2.idle - elu1.idle);
+  assert.strictEqual(elu3.utilization,
+                     active_delta / (idle_delta + active_delta));
+
+  setImmediate(runWorkerTest);
+}
+
+function runWorkerTest() {
+  // Use argv to detect whether we're running as a Worker called by this test
+  // vs. this test also being called as a Worker.
+  if (process.argv[2] === 'iamalive') {
+    parentPort.postMessage(JSON.stringify(eventLoopUtilization()));
+    return;
+  }
+
+  const elu1 = eventLoopUtilization();
+  const worker = new Worker(__filename, { argv: [ 'iamalive' ] });
+
+  worker.on('message', (msg) => {
+    const elu2 = eventLoopUtilization(elu1);
+    const data = JSON.parse(msg);
+
+    assert.ok(elu2.active + elu2.idle > data.active + data.idle);
+  });
+}