Skip to content

Commit

Permalink
perf_hooks: add reqwrap latency monitor
Browse files Browse the repository at this point in the history
Adds a histogram that tracks ReqWrap latency (defined as the
length of time it takes from when the reqwrap is dispatched
to when the callback is invoked)
  • Loading branch information
jasnell committed Mar 13, 2019
1 parent 76e67e9 commit f4d1802
Show file tree
Hide file tree
Showing 14 changed files with 709 additions and 212 deletions.
244 changes: 151 additions & 93 deletions doc/api/perf_hooks.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,11 @@

> Stability: 1 - Experimental
The Performance Timing API provides an implementation of the
[W3C Performance Timeline][] specification. The purpose of the API
is to support collection of high resolution performance metrics.
This is the same Performance API as implemented in modern Web browsers.
The `perf_hooks` module provides an implementation of the Performance
Timing API based on the [W3C Performance Timeline][] specification, as
well as several other performance and timing diagnostic functions. The
purpose of the API is to support collection of high resolution performance
metrics.

```js
const { PerformanceObserver, performance } = require('perf_hooks');
Expand All @@ -25,6 +26,113 @@ doSomeLongRunningProcess(() => {
});
```

## Class: Histogram
<!-- YAML
added: v11.10.0
-->
The `Histogram` class is returned by several `perf_hooks` APIs including
`perf_hooks.monitorEventLoopDelay()` and `perf_hooks.monitorRequestWrapLatency()`.

### histogram.count
<!-- YAML
added: REPLACEME
-->

* {number}

The total number of sample values recorded.

### histogram.disable()
<!-- YAML
added: v11.10.0
-->

* Returns: {boolean}

Disables the histogram tracking. Returns `true` if the tracking was
disabled, `false` if it was already disabled.

### histogram.enable()
<!-- YAML
added: v11.10.0
-->

* Returns: {boolean}

Enables the histogram tracking. Returns `true` if the tracking was
enabled, `false` if it was already enabled.

### histogram.exceeds
<!-- YAML
added: v11.10.0
-->

* {number}

The number of times the sample value exceeded the maximum.

### histogram.max
<!-- YAML
added: v11.10.0
-->

* {number}

The maximum recorded sample value.

### histogram.mean
<!-- YAML
added: v11.10.0
-->

* {number}

The mean of the recorded sample value.

### histogram.min
<!-- YAML
added: v11.10.0
-->

* {number}

The minimum recorded sample value.

### histogram.percentile(percentile)
<!-- YAML
added: v11.10.0
-->

* `percentile` {number} A percentile value between 1 and 100.
* Returns: {number}

Returns the value at the given percentile.

### histogram.percentiles
<!-- YAML
added: v11.10.0
-->

* {Map}

Returns a `Map` object detailing the accumulated percentile distribution.

### histogram.reset()
<!-- YAML
added: v11.10.0
-->

Resets the collected histogram data.

### histogram.stddev
<!-- YAML
added: v11.10.0
-->

* {number}

The standard deviation of the recorded sample values.

## Class: Performance
<!-- YAML
added: v8.5.0
Expand Down Expand Up @@ -432,103 +540,52 @@ console.log(h.percentile(50));
console.log(h.percentile(99));
```

### Class: Histogram
<!-- YAML
added: v11.10.0
-->
Tracks the event loop delay at a given sampling rate.
The maximum event loop delay that can be recorded is one hour. Values above
that limit are dropped. The number of dropped values is reported by the
`histogram.exceeds` property.

#### histogram.disable()
## perf_hooks.monitorRequestWrapLatency([options])
<!-- YAML
added: v11.10.0
-->

* Returns: {boolean}

Disables the event loop delay sample timer. Returns `true` if the timer was
stopped, `false` if it was already stopped.

#### histogram.enable()
<!-- YAML
added: v11.10.0
added: REPLACEME
-->

* Returns: {boolean}

Enables the event loop delay sample timer. Returns `true` if the timer was
started, `false` if it was already started.

#### histogram.exceeds
<!-- YAML
added: v11.10.0
-->

* {number}

The number of times the event loop delay exceeded the maximum 1 hour event
loop delay threshold.

#### histogram.max
<!-- YAML
added: v11.10.0
-->

* {number}

The maximum recorded event loop delay.

#### histogram.mean
<!-- YAML
added: v11.10.0
-->

* {number}

The mean of the recorded event loop delays.

#### histogram.min
<!-- YAML
added: v11.10.0
-->

* {number}

The minimum recorded event loop delay.

#### histogram.percentile(percentile)
<!-- YAML
added: v11.10.0
-->

* `percentile` {number} A percentile value between 1 and 100.
* Returns: {number}

Returns the value at the given percentile.

#### histogram.percentiles
<!-- YAML
added: v11.10.0
-->

* {Map}

Returns a `Map` object detailing the accumulated percentile distribution.

#### histogram.reset()
<!-- YAML
added: v11.10.0
-->
* `options` {Object}
* `types` {string[]} A list of [async_hook types][] to include in the
histogram samples. If not specified, the histogram will record
values for all ReqWrap types.
* Returns: {Histogram}

Resets the collected histogram data.
Returns a `Histogram` object that reports the latency of libuv
request handles. A request handle is an async resource within
Node.js that tracks the state of an individual asynchronous
operation (e.g. a file read, a DNS lookup, etc). The latency
of a request is the length of time from when the request is
passed off to the event loop to when the corresponding callback
is invoked.

#### histogram.stddev
<!-- YAML
added: v11.10.0
-->
The histogram effectively measures how long the event loop is
taking to perform and resolve individual asynchronous operations,
without differentiating between the types of operations
measured.

* {number}
```js
const { monitorRequestWrapLatency } = require('perf_hooks');
const h = monitorRequestWrapLatency();
h.enable();
// Do something.
h.disable();
console.log(h.min);
console.log(h.max);
console.log(h.mean);
console.log(h.stddev);
console.log(h.percentiles);
console.log(h.percentile(50));
console.log(h.percentile(99));
```

The standard deviation of the recorded event loop delays.
The maximum latency that can be recorded is one hour. Values above
that limit are dropped. The number of dropped values is reported by the
`histogram.exceeds` property.

## Examples

Expand Down Expand Up @@ -612,3 +669,4 @@ require('some-module');
[`timeOrigin`]: https://w3c.github.io/hr-time/#dom-performance-timeorigin
[Async Hooks]: async_hooks.html
[W3C Performance Timeline]: https://w3c.github.io/performance-timeline/
[async_hook types]: async_hooks.html#async_hooks_type
10 changes: 6 additions & 4 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
Expand Up @@ -23,18 +23,20 @@ The available categories are:
* `node.environment` - Enables capture of Node.js Environment milestones.
* `node.fs.sync` - Enables capture of trace data for file system sync methods.
* `node.perf` - Enables capture of [Performance API] measurements.
* `node.perf.usertiming` - Enables capture of only Performance API User Timing
measures and marks.
* `node.perf.event_loop` - Enables capture of event loop delay information
when the `perf_hooks.monitorEventLoopDelay()` API is used.
* `node.perf.reqwrap` - Enables capture of ReqWrap Latency information when
the `perf_hooks.monitorRequestWrapLatency()` API is used.
* `node.perf.timerify` - Enables capture of only Performance API timerify
measurements.
* `node.perf.usertiming` - Enables capture of only Performance API User Timing
measures and marks.
* `node.promises.rejections` - Enables capture of trace data tracking the number
of unhandled Promise rejections and handled-after-rejections.
* `node.vm.script` - Enables capture of trace data for the `vm` module's
`runInNewContext()`, `runInContext()`, and `runInThisContext()` methods.
* `v8` - The [V8] events are GC, compiling, and execution related.

By default the `node`, `node.async_hooks`, and `v8` categories are enabled.

```txt
node --trace-event-categories v8,node,node.async_hooks server.js
```
Expand Down
27 changes: 22 additions & 5 deletions lib/perf_hooks.js
Original file line number Diff line number Diff line change
@@ -1,7 +1,8 @@
'use strict';

const {
ELDHistogram: _ELDHistogram,
ELDHistogram,
RWLHistogram,
PerformanceEntry,
mark: _mark,
clearMark: _clearMark,
Expand Down Expand Up @@ -548,7 +549,7 @@ function sortedInsert(list, entry) {
list.splice(location, 0, entry);
}

class ELDHistogram {
class Histogram {
constructor(handle) {
this[kHandle] = handle;
this[kMap] = new Map();
Expand All @@ -558,6 +559,7 @@ class ELDHistogram {
enable() { return this[kHandle].enable(); }
disable() { return this[kHandle].disable(); }

get count() { return this[kHandle].count(); }
get exceeds() { return this[kHandle].exceeds(); }
get min() { return this[kHandle].min(); }
get max() { return this[kHandle].max(); }
Expand Down Expand Up @@ -588,7 +590,8 @@ class ELDHistogram {
mean: this.mean,
stddev: this.stddev,
percentiles: this.percentiles,
exceeds: this.exceeds
exceeds: this.exceeds,
count: this.count
};
}
}
Expand All @@ -608,13 +611,27 @@ function monitorEventLoopDelay(options = {}) {
const errors = lazyErrors();
throw new errors.ERR_INVALID_OPT_VALUE.RangeError('resolution', resolution);
}
return new ELDHistogram(new _ELDHistogram(resolution));
return new Histogram(new ELDHistogram(resolution));
}

function monitorRequestWrapLatency(options = {}) {
if (typeof options !== 'object' || options === null) {
const errors = lazyErrors();
throw new errors.ERR_INVALID_ARG_TYPE('options', 'Object', options);
}
const { types } = options;
if (types === null || (types && !Array.isArray(types))) {
const errors = lazyErrors();
throw new errors.ERR_INVALID_ARG_TYPE('options.types', 'string[]', types);
}
return new Histogram(new RWLHistogram(types));
}

module.exports = {
performance,
PerformanceObserver,
monitorEventLoopDelay
monitorEventLoopDelay,
monitorRequestWrapLatency,
};

Object.defineProperty(module.exports, 'constants', {
Expand Down
1 change: 1 addition & 0 deletions src/env-inl.h
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
#include "node_perf_common.h"
#include "node_context_data.h"
#include "node_worker.h"
#include "histogram-inl.h"

#include <cstddef>
#include <cstdint>
Expand Down
Loading

0 comments on commit f4d1802

Please sign in to comment.