perf_hooks: add histogram option to timerify

Allows setting a `Histogram` object option on timerify to record function execution times over time. Signed-off-by: James M Snell <[email protected]> PR-URL: #37475 Reviewed-By: Matteo Collina <[email protected]>
nodejs · Mar 5, 2021 · b803bca · b803bca
1 parent 9c1274a
commit b803bca
Show file tree

Hide file tree

Showing 4 changed files with 82 additions and 5 deletions.
diff --git a/doc/api/perf_hooks.md b/doc/api/perf_hooks.md
@@ -210,17 +210,24 @@ added: v8.5.0
 The [`timeOrigin`][] specifies the high resolution millisecond timestamp at
 which the current `node` process began, measured in Unix time.
 
-### `performance.timerify(fn)`
+### `performance.timerify(fn[, options])`
 <!-- YAML
 added: v8.5.0
 changes:
+  - version: REPLACEME
+    pr-url: https://github.com/nodejs/node/pull/37475
+    description: Added the histogram option.
   - version: REPLACEME
     pr-url: https://github.com/nodejs/node/pull/37136
     description: Re-implemented to use pure-JavaScript and the ability
                  to time async functions.
 -->
 
 * `fn` {Function}
+* `options` {Object}
+  * `histogram` {RecordableHistogram} A histogram object created using
+    `perf_hooks.createHistogram()` that will record runtime durations in
+    nanoseconds.
 
 _This property is an extension by Node.js. It is not available in Web browsers._
 

diff --git a/lib/internal/histogram.js b/lib/internal/histogram.js
@@ -42,6 +42,10 @@ const {
   JSTransferable,
 } = require('internal/worker/js_transferable');
 
+function isHistogram(object) {
+  return object?.[kHandle] !== undefined;
+}
+
 class Histogram extends JSTransferable {
   constructor(internal) {
     super();
@@ -193,6 +197,7 @@ module.exports = {
   RecordableHistogram,
   InternalHistogram,
   InternalRecordableHistogram,
+  isHistogram,
   kDestroy,
   kHandle,
   createHistogram,

diff --git a/lib/internal/perf/timerify.js b/lib/internal/perf/timerify.js
@@ -3,6 +3,7 @@
 const {
   FunctionPrototypeBind,
   ObjectDefineProperties,
+  MathCeil,
   ReflectApply,
   ReflectConstruct,
   Symbol,
@@ -13,6 +14,14 @@ const {
   now,
 } = require('internal/perf/perf');
 
+const {
+  validateObject
+} = require('internal/validators');
+
+const {
+  isHistogram
+} = require('internal/histogram');
+
 const {
   isConstructor,
 } = internalBinding('util');
@@ -29,8 +38,10 @@ const {
 
 const kTimerified = Symbol('kTimerified');
 
-function processComplete(name, start, args) {
+function processComplete(name, start, args, histogram) {
   const duration = now() - start;
+  if (histogram !== undefined)
+    histogram.record(MathCeil(duration * 1e6));
   const entry =
     new InternalPerformanceEntry(
       name,
@@ -45,10 +56,23 @@ function processComplete(name, start, args) {
   enqueue(entry);
 }
 
-function timerify(fn) {
+function timerify(fn, options = {}) {
   if (typeof fn !== 'function')
     throw new ERR_INVALID_ARG_TYPE('fn', 'function', fn);
 
+  validateObject(options, 'options');
+  const {
+    histogram
+  } = options;
+
+  if (histogram !== undefined &&
+      (!isHistogram(histogram) || typeof histogram.record !== 'function')) {
+    throw new ERR_INVALID_ARG_TYPE(
+      'options.histogram',
+      'RecordableHistogram',
+      histogram);
+  }
+
   if (fn[kTimerified]) return fn[kTimerified];
 
   const constructor = isConstructor(fn);
@@ -65,9 +89,10 @@ function timerify(fn) {
           result,
           fn.name,
           start,
-          args));
+          args,
+          histogram));
     }
-    processComplete(fn.name, start, args);
+    processComplete(fn.name, start, args, histogram);
     return result;
   }
 

diff --git a/test/parallel/test-performance-function.js b/test/parallel/test-performance-function.js
@@ -4,10 +4,15 @@ const common = require('../common');
 const assert = require('assert');
 
 const {
+  createHistogram,
   performance,
   PerformanceObserver
 } = require('perf_hooks');
 
+const {
+  setTimeout: sleep
+} = require('timers/promises');
+
 {
   // Intentional non-op. Do not wrap in common.mustCall();
   const n = performance.timerify(function noop() {});
@@ -81,3 +86,38 @@ const {
   assert.strictEqual(n.length, m.length);
   assert.strictEqual(n.name, 'timerified m');
 }
+
+(async () => {
+  const histogram = createHistogram();
+  const m = (a, b = 1) => {};
+  const n = performance.timerify(m, { histogram });
+  assert.strictEqual(histogram.max, 0);
+  for (let i = 0; i < 10; i++) {
+    n();
+    await sleep(10);
+  }
+  assert.notStrictEqual(histogram.max, 0);
+  [1, '', {}, [], false].forEach((histogram) => {
+    assert.throws(() => performance.timerify(m, { histogram }), {
+      code: 'ERR_INVALID_ARG_TYPE'
+    });
+  });
+})().then(common.mustCall());
+
+(async () => {
+  const histogram = createHistogram();
+  const m = async (a, b = 1) => {
+    await sleep(10);
+  };
+  const n = performance.timerify(m, { histogram });
+  assert.strictEqual(histogram.max, 0);
+  for (let i = 0; i < 10; i++) {
+    await n();
+  }
+  assert.notStrictEqual(histogram.max, 0);
+  [1, '', {}, [], false].forEach((histogram) => {
+    assert.throws(() => performance.timerify(m, { histogram }), {
+      code: 'ERR_INVALID_ARG_TYPE'
+    });
+  });
+})().then(common.mustCall());