Skip to content

Commit f4d1802

Browse files
committed
perf_hooks: add reqwrap latency monitor
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)
1 parent 76e67e9 commit f4d1802

File tree

14 files changed

+709
-212
lines changed

14 files changed

+709
-212
lines changed

doc/api/perf_hooks.md

Lines changed: 151 additions & 93 deletions
Original file line numberDiff line numberDiff line change
@@ -4,10 +4,11 @@
44

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

1213
```js
1314
const { PerformanceObserver, performance } = require('perf_hooks');
@@ -25,6 +26,113 @@ doSomeLongRunningProcess(() => {
2526
});
2627
```
2728

29+
## Class: Histogram
30+
<!-- YAML
31+
added: v11.10.0
32+
-->
33+
The `Histogram` class is returned by several `perf_hooks` APIs including
34+
`perf_hooks.monitorEventLoopDelay()` and `perf_hooks.monitorRequestWrapLatency()`.
35+
36+
### histogram.count
37+
<!-- YAML
38+
added: REPLACEME
39+
-->
40+
41+
* {number}
42+
43+
The total number of sample values recorded.
44+
45+
### histogram.disable()
46+
<!-- YAML
47+
added: v11.10.0
48+
-->
49+
50+
* Returns: {boolean}
51+
52+
Disables the histogram tracking. Returns `true` if the tracking was
53+
disabled, `false` if it was already disabled.
54+
55+
### histogram.enable()
56+
<!-- YAML
57+
added: v11.10.0
58+
-->
59+
60+
* Returns: {boolean}
61+
62+
Enables the histogram tracking. Returns `true` if the tracking was
63+
enabled, `false` if it was already enabled.
64+
65+
### histogram.exceeds
66+
<!-- YAML
67+
added: v11.10.0
68+
-->
69+
70+
* {number}
71+
72+
The number of times the sample value exceeded the maximum.
73+
74+
### histogram.max
75+
<!-- YAML
76+
added: v11.10.0
77+
-->
78+
79+
* {number}
80+
81+
The maximum recorded sample value.
82+
83+
### histogram.mean
84+
<!-- YAML
85+
added: v11.10.0
86+
-->
87+
88+
* {number}
89+
90+
The mean of the recorded sample value.
91+
92+
### histogram.min
93+
<!-- YAML
94+
added: v11.10.0
95+
-->
96+
97+
* {number}
98+
99+
The minimum recorded sample value.
100+
101+
### histogram.percentile(percentile)
102+
<!-- YAML
103+
added: v11.10.0
104+
-->
105+
106+
* `percentile` {number} A percentile value between 1 and 100.
107+
* Returns: {number}
108+
109+
Returns the value at the given percentile.
110+
111+
### histogram.percentiles
112+
<!-- YAML
113+
added: v11.10.0
114+
-->
115+
116+
* {Map}
117+
118+
Returns a `Map` object detailing the accumulated percentile distribution.
119+
120+
### histogram.reset()
121+
<!-- YAML
122+
added: v11.10.0
123+
-->
124+
125+
Resets the collected histogram data.
126+
127+
### histogram.stddev
128+
<!-- YAML
129+
added: v11.10.0
130+
-->
131+
132+
* {number}
133+
134+
The standard deviation of the recorded sample values.
135+
28136
## Class: Performance
29137
<!-- YAML
30138
added: v8.5.0
@@ -432,103 +540,52 @@ console.log(h.percentile(50));
432540
console.log(h.percentile(99));
433541
```
434542

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

441-
#### histogram.disable()
547+
## perf_hooks.monitorRequestWrapLatency([options])
442548
<!-- YAML
443-
added: v11.10.0
444-
-->
445-
446-
* Returns: {boolean}
447-
448-
Disables the event loop delay sample timer. Returns `true` if the timer was
449-
stopped, `false` if it was already stopped.
450-
451-
#### histogram.enable()
452-
<!-- YAML
453-
added: v11.10.0
549+
added: REPLACEME
454550
-->
455551

456-
* Returns: {boolean}
457-
458-
Enables the event loop delay sample timer. Returns `true` if the timer was
459-
started, `false` if it was already started.
460-
461-
#### histogram.exceeds
462-
<!-- YAML
463-
added: v11.10.0
464-
-->
465-
466-
* {number}
467-
468-
The number of times the event loop delay exceeded the maximum 1 hour event
469-
loop delay threshold.
470-
471-
#### histogram.max
472-
<!-- YAML
473-
added: v11.10.0
474-
-->
475-
476-
* {number}
477-
478-
The maximum recorded event loop delay.
479-
480-
#### histogram.mean
481-
<!-- YAML
482-
added: v11.10.0
483-
-->
484-
485-
* {number}
486-
487-
The mean of the recorded event loop delays.
488-
489-
#### histogram.min
490-
<!-- YAML
491-
added: v11.10.0
492-
-->
493-
494-
* {number}
495-
496-
The minimum recorded event loop delay.
497-
498-
#### histogram.percentile(percentile)
499-
<!-- YAML
500-
added: v11.10.0
501-
-->
502-
503-
* `percentile` {number} A percentile value between 1 and 100.
504-
* Returns: {number}
505-
506-
Returns the value at the given percentile.
507-
508-
#### histogram.percentiles
509-
<!-- YAML
510-
added: v11.10.0
511-
-->
512-
513-
* {Map}
514-
515-
Returns a `Map` object detailing the accumulated percentile distribution.
516-
517-
#### histogram.reset()
518-
<!-- YAML
519-
added: v11.10.0
520-
-->
552+
* `options` {Object}
553+
* `types` {string[]} A list of [async_hook types][] to include in the
554+
histogram samples. If not specified, the histogram will record
555+
values for all ReqWrap types.
556+
* Returns: {Histogram}
521557

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

524-
#### histogram.stddev
525-
<!-- YAML
526-
added: v11.10.0
527-
-->
566+
The histogram effectively measures how long the event loop is
567+
taking to perform and resolve individual asynchronous operations,
568+
without differentiating between the types of operations
569+
measured.
528570

529-
* {number}
571+
```js
572+
const { monitorRequestWrapLatency } = require('perf_hooks');
573+
const h = monitorRequestWrapLatency();
574+
h.enable();
575+
// Do something.
576+
h.disable();
577+
console.log(h.min);
578+
console.log(h.max);
579+
console.log(h.mean);
580+
console.log(h.stddev);
581+
console.log(h.percentiles);
582+
console.log(h.percentile(50));
583+
console.log(h.percentile(99));
584+
```
530585

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

533590
## Examples
534591

@@ -612,3 +669,4 @@ require('some-module');
612669
[`timeOrigin`]: https://w3c.github.io/hr-time/#dom-performance-timeorigin
613670
[Async Hooks]: async_hooks.html
614671
[W3C Performance Timeline]: https://w3c.github.io/performance-timeline/
672+
[async_hook types]: async_hooks.html#async_hooks_type

doc/api/tracing.md

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -23,18 +23,20 @@ The available categories are:
2323
* `node.environment` - Enables capture of Node.js Environment milestones.
2424
* `node.fs.sync` - Enables capture of trace data for file system sync methods.
2525
* `node.perf` - Enables capture of [Performance API] measurements.
26-
* `node.perf.usertiming` - Enables capture of only Performance API User Timing
27-
measures and marks.
26+
* `node.perf.event_loop` - Enables capture of event loop delay information
27+
when the `perf_hooks.monitorEventLoopDelay()` API is used.
28+
* `node.perf.reqwrap` - Enables capture of ReqWrap Latency information when
29+
the `perf_hooks.monitorRequestWrapLatency()` API is used.
2830
* `node.perf.timerify` - Enables capture of only Performance API timerify
2931
measurements.
32+
* `node.perf.usertiming` - Enables capture of only Performance API User Timing
33+
measures and marks.
3034
* `node.promises.rejections` - Enables capture of trace data tracking the number
3135
of unhandled Promise rejections and handled-after-rejections.
3236
* `node.vm.script` - Enables capture of trace data for the `vm` module's
3337
`runInNewContext()`, `runInContext()`, and `runInThisContext()` methods.
3438
* `v8` - The [V8] events are GC, compiling, and execution related.
3539

36-
By default the `node`, `node.async_hooks`, and `v8` categories are enabled.
37-
3840
```txt
3941
node --trace-event-categories v8,node,node.async_hooks server.js
4042
```

lib/perf_hooks.js

Lines changed: 22 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,8 @@
11
'use strict';
22

33
const {
4-
ELDHistogram: _ELDHistogram,
4+
ELDHistogram,
5+
RWLHistogram,
56
PerformanceEntry,
67
mark: _mark,
78
clearMark: _clearMark,
@@ -548,7 +549,7 @@ function sortedInsert(list, entry) {
548549
list.splice(location, 0, entry);
549550
}
550551

551-
class ELDHistogram {
552+
class Histogram {
552553
constructor(handle) {
553554
this[kHandle] = handle;
554555
this[kMap] = new Map();
@@ -558,6 +559,7 @@ class ELDHistogram {
558559
enable() { return this[kHandle].enable(); }
559560
disable() { return this[kHandle].disable(); }
560561

562+
get count() { return this[kHandle].count(); }
561563
get exceeds() { return this[kHandle].exceeds(); }
562564
get min() { return this[kHandle].min(); }
563565
get max() { return this[kHandle].max(); }
@@ -588,7 +590,8 @@ class ELDHistogram {
588590
mean: this.mean,
589591
stddev: this.stddev,
590592
percentiles: this.percentiles,
591-
exceeds: this.exceeds
593+
exceeds: this.exceeds,
594+
count: this.count
592595
};
593596
}
594597
}
@@ -608,13 +611,27 @@ function monitorEventLoopDelay(options = {}) {
608611
const errors = lazyErrors();
609612
throw new errors.ERR_INVALID_OPT_VALUE.RangeError('resolution', resolution);
610613
}
611-
return new ELDHistogram(new _ELDHistogram(resolution));
614+
return new Histogram(new ELDHistogram(resolution));
615+
}
616+
617+
function monitorRequestWrapLatency(options = {}) {
618+
if (typeof options !== 'object' || options === null) {
619+
const errors = lazyErrors();
620+
throw new errors.ERR_INVALID_ARG_TYPE('options', 'Object', options);
621+
}
622+
const { types } = options;
623+
if (types === null || (types && !Array.isArray(types))) {
624+
const errors = lazyErrors();
625+
throw new errors.ERR_INVALID_ARG_TYPE('options.types', 'string[]', types);
626+
}
627+
return new Histogram(new RWLHistogram(types));
612628
}
613629

614630
module.exports = {
615631
performance,
616632
PerformanceObserver,
617-
monitorEventLoopDelay
633+
monitorEventLoopDelay,
634+
monitorRequestWrapLatency,
618635
};
619636

620637
Object.defineProperty(module.exports, 'constants', {

src/env-inl.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@
3333
#include "node_perf_common.h"
3434
#include "node_context_data.h"
3535
#include "node_worker.h"
36+
#include "histogram-inl.h"
3637

3738
#include <cstddef>
3839
#include <cstdint>

0 commit comments

Comments
 (0)