Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perf_hooks: complete overhaul of the implementation #37136

Closed
wants to merge 1 commit into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 31 additions & 0 deletions benchmark/perf_hooks/usertiming.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,31 @@
'use strict';

const common = require('../common.js');

const {
PerformanceObserver,
performance,
} = require('perf_hooks');

const bench = common.createBenchmark(main, {
n: [1e5]
});

function test() {
performance.mark('a');
setImmediate(() => {
performance.mark('b');
performance.measure('a to b', 'a', 'b');
});
}

function main({ n }) {
const obs = new PerformanceObserver(() => {
bench.end(n);
});
obs.observe({ entryTypes: ['measure'], buffered: true });

bench.start();
for (let i = 0; i < n; i++)
test();
}
16 changes: 16 additions & 0 deletions doc/api/deprecations.md
Original file line number Diff line number Diff line change
Expand Up @@ -2748,6 +2748,22 @@ Previously, `index.js` and extension searching lookups would apply to
With this deprecation, all ES module main entry point resolutions require
an explicit [`"exports"` or `"main"` entry][] with the exact file extension.

### DEP0XXX: Extension PerformanceEntry properties
<!-- YAML
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Runtime deprecation.
-->

Type: Runtime

The `'gc'`, `'http2'`, and `'http'` {PerformanceEntry} object types have
additional properties assigned to them that provide additional information.
These properties are now available within the standard `detail` property
of the `PerformanceEntry` object. The existing accessors have been
deprecated and should no longer be used.

[Legacy URL API]: url.md#url_legacy_url_api
[NIST SP 800-38D]: https://nvlpubs.nist.gov/nistpubs/Legacy/SP/nistspecialpublication800-38d.pdf
[RFC 6066]: https://tools.ietf.org/html/rfc6066#section-3
Expand Down
10 changes: 10 additions & 0 deletions doc/api/errors.md
Original file line number Diff line number Diff line change
Expand Up @@ -1903,6 +1903,16 @@ The `package.json` [`"exports"`][] field does not export the requested subpath.
Because exports are encapsulated, private internal modules that are not exported
cannot be imported through the package resolution, unless using an absolute URL.

<a id="ERR_PERFORMANCE_INVALID_TIMESTAMP"></a>
### `ERR_PERFORMANCE_INVALID_TIMESTAMP`

An invalid timestamp value was provided for a performance mark or measure.

<a id="ERR_PERFORMANCE_MEASURE_INVALID_OPTIONS"></a>
### `ERR_PERFORMANCE_MEASURE_INVALID_OPTIONS`

Invalid options were provided for a performance measure.

<a id="ERR_PROTO_ACCESS"></a>
### `ERR_PROTO_ACCESS`

Expand Down
168 changes: 133 additions & 35 deletions doc/api/perf_hooks.md
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ const obs = new PerformanceObserver((items) => {
console.log(items.getEntries()[0].duration);
performance.clearMarks();
});
obs.observe({ entryTypes: ['measure'] });
obs.observe({ type: 'measure' });
performance.measure('Start to Now');

performance.mark('A');
Expand Down Expand Up @@ -115,23 +115,34 @@ 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.

### `performance.mark([name])`
### `performance.mark([name[, options]])`
<!-- YAML
added: v8.5.0
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Updated to conform to the User Timing Level 3 specification.
-->

* `name` {string}
* `options` {Object}
* `detail` {any} Additional optional detail to include with the mark.
* `startTime` {number} An optional timestamp to be used as the mark time.
**Defaults**: `performance.now()`.
jasnell marked this conversation as resolved.
Show resolved Hide resolved

Creates a new `PerformanceMark` entry in the Performance Timeline. A
`PerformanceMark` is a subclass of `PerformanceEntry` whose
`performanceEntry.entryType` is always `'mark'`, and whose
`performanceEntry.duration` is always `0`. Performance marks are used
to mark specific significant moments in the Performance Timeline.

### `performance.measure(name[, startMark[, endMark]])`
### `performance.measure(name[, startMarkOrOptions[, endMark]])`
<!-- YAML
added: v8.5.0
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Updated to conform to the User Timing Level 3 specification.
- version:
- v13.13.0
- v12.16.3
Expand All @@ -140,8 +151,15 @@ changes:
-->

* `name` {string}
* `startMark` {string} Optional.
* `endMark` {string} Optional.
* `startMarkOrOptions` {string|Object} Optional.
* `detail` {any} Additional optional detail to include with the measure.
* `duration` {number} Duration between start and end times.
* `end` {number|string} Timestamp to be used as the end time, or a string
identifying a previously recorded mark.
* `start` {number|string} Timestamp to be used as the start time, or a string
identifying a previously recorded mark.
* `endMark` {string} Optional. Must be omitted if `startMarkOrOptions` is an
{Object}.

Creates a new `PerformanceMeasure` entry in the Performance Timeline. A
`PerformanceMeasure` is a subclass of `PerformanceEntry` whose
Expand All @@ -152,7 +170,7 @@ Creates a new `PerformanceMeasure` entry in the Performance Timeline. A
The `startMark` argument may identify any *existing* `PerformanceMark` in the
Performance Timeline, or *may* identify any of the timestamp properties
provided by the `PerformanceNodeTiming` class. If the named `startMark` does
not exist, then `startMark` is set to [`timeOrigin`][] by default.
not exist, an error is thrown.

The optional `endMark` argument must identify any *existing* `PerformanceMark`
in the Performance Timeline or any of the timestamp properties provided by the
Expand Down Expand Up @@ -195,6 +213,11 @@ which the current `node` process began, measured in Unix time.
### `performance.timerify(fn)`
<!-- YAML
added: v8.5.0
changes:
- 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}
Expand Down Expand Up @@ -227,11 +250,24 @@ obs.observe({ entryTypes: ['function'] });
wrapped();
```

If the wrapped function returns a promise, a finally handler will be attached
to the promise and the duration will be reported once the finally handler is
invoked.

## Class: `PerformanceEntry`
<!-- YAML
added: v8.5.0
-->

### `performanceEntry.details`
<!-- YAML
added: REPLACEME
-->

* {any}

Additional detail specific to the `entryType`.

### `performanceEntry.duration`
<!-- YAML
added: v8.5.0
Expand Down Expand Up @@ -264,6 +300,11 @@ The type of the performance entry. It may be one of:
added:
- v13.9.0
- v12.17.0
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Runtime deprecated. Now moved to the detail property
when entryType is 'gc'.
-->

* {number}
Expand Down Expand Up @@ -294,6 +335,11 @@ The name of the performance entry.
### `performanceEntry.kind`
<!-- YAML
added: v8.5.0
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Runtime deprecated. Now moved to the detail property
when entryType is 'gc'.
-->

* {number}
Expand All @@ -319,6 +365,72 @@ added: v8.5.0
The high resolution millisecond timestamp marking the starting time of the
Performance Entry.

### Garbage Collection ('gc') Details

When `performanceEntry.type` is equal to `'gc'`, the `performanceEntry.details`
property will be an {Object} with two properties:

* `kind` {number} One of:
* `perf_hooks.constants.NODE_PERFORMANCE_GC_MAJOR`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_MINOR`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_INCREMENTAL`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_WEAKCB`
* `flags` {number} One of:
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_NO`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_CONSTRUCT_RETAINED`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_FORCED`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_SYNCHRONOUS_PHANTOM_PROCESSING`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_ALL_AVAILABLE_GARBAGE`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_ALL_EXTERNAL_MEMORY`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_SCHEDULE_IDLE`

### HTTP/2 ('http2') Details

When `performanceEntry.type` is equal to `'http2'`, the
`performanceEntry.details` property will be an {Object} containing
additional performance information.

If `performanceEntry.name` is equal to `Http2Stream`, the `details`
will contain the following properties:

* `bytesRead` {number} The number of `DATA` frame bytes received for this
`Http2Stream`.
* `bytesWritten` {number} The number of `DATA` frame bytes sent for this
`Http2Stream`.
* `id` {number} The identifier of the associated `Http2Stream`
* `timeToFirstByte` {number} The number of milliseconds elapsed between the
`PerformanceEntry` `startTime` and the reception of the first `DATA` frame.
* `timeToFirstByteSent` {number} The number of milliseconds elapsed between
the `PerformanceEntry` `startTime` and sending of the first `DATA` frame.
* `timeToFirstHeader` {number} The number of milliseconds elapsed between the
`PerformanceEntry` `startTime` and the reception of the first header.

If `performanceEntry.name` is equal to `Http2Session`, the `details` will
contain the following properties:

* `bytesRead` {number} The number of bytes received for this `Http2Session`.
* `bytesWritten` {number} The number of bytes sent for this `Http2Session`.
* `framesReceived` {number} The number of HTTP/2 frames received by the
`Http2Session`.
* `framesSent` {number} The number of HTTP/2 frames sent by the `Http2Session`.
* `maxConcurrentStreams` {number} The maximum number of streams concurrently
open during the lifetime of the `Http2Session`.
* `pingRTT` {number} The number of milliseconds elapsed since the transmission
of a `PING` frame and the reception of its acknowledgment. Only present if
a `PING` frame has been sent on the `Http2Session`.
* `streamAverageDuration` {number} The average duration (in milliseconds) for
all `Http2Stream` instances.
* `streamCount` {number} The number of `Http2Stream` instances processed by
the `Http2Session`.
* `type` {string} Either `'server'` or `'client'` to identify the type of
`Http2Session`.

### Timerify ('function') Details

When `performanceEntry.type` is equal to `'function'`, the
`performanceEntry.details` property will be an {Array} listing
the input arguments to the timed function.

## Class: `PerformanceNodeTiming`
<!-- YAML
added: v8.5.0
Expand Down Expand Up @@ -457,22 +569,23 @@ Disconnects the `PerformanceObserver` instance from all notifications.
### `performanceObserver.observe(options)`
<!-- YAML
added: v8.5.0
changes:
- version: REPLACEME
pr-url: https://github.com/nodejs/node/pull/37136
description: Updated to conform to User Timing Level 3. The
buffered option has been removed.
-->

* `options` {Object}
* `type` {string} A single {PerformanceEntry} type. Must not be given
if `entryTypes` is already specified.
* `entryTypes` {string[]} An array of strings identifying the types of
`PerformanceEntry` instances the observer is interested in. If not
{PerformanceEntry} instances the observer is interested in. If not
provided an error will be thrown.
* `buffered` {boolean} If true, the notification callback will be
called using `setImmediate()` and multiple `PerformanceEntry` instance
notifications will be buffered internally. If `false`, notifications will
be immediate and synchronous. **Default:** `false`.

Subscribes the `PerformanceObserver` instance to notifications of new
`PerformanceEntry` instances identified by `options.entryTypes`.

When `options.buffered` is `false`, the `callback` will be invoked once for
every `PerformanceEntry` instance:
Subscribes the {PerformanceObserver} instance to notifications of new
{PerformanceEntry} instances identified either by `options.entryTypes`
or `options.type`:

```js
const {
Expand All @@ -483,22 +596,7 @@ const {
const obs = new PerformanceObserver((list, observer) => {
// Called three times synchronously. `list` contains one item.
});
obs.observe({ entryTypes: ['mark'] });

for (let n = 0; n < 3; n++)
performance.mark(`test${n}`);
```

```js
const {
performance,
PerformanceObserver
} = require('perf_hooks');

const obs = new PerformanceObserver((list, observer) => {
// Called once. `list` contains three items.
});
obs.observe({ entryTypes: ['mark'], buffered: true });
obs.observe({ type: 'mark' });

for (let n = 0; n < 3; n++)
performance.mark(`test${n}`);
Expand Down Expand Up @@ -549,7 +647,7 @@ const obs = new PerformanceObserver((perfObserverList, observer) => {
*/
observer.disconnect();
});
obs.observe({ entryTypes: ['mark'], buffered: true });
obs.observe({ type: 'mark' });

performance.mark('test');
performance.mark('meow');
Expand Down Expand Up @@ -603,7 +701,7 @@ const obs = new PerformanceObserver((perfObserverList, observer) => {
console.log(perfObserverList.getEntriesByName('test', 'measure')); // []
observer.disconnect();
});
obs.observe({ entryTypes: ['mark', 'measure'], buffered: true });
obs.observe({ entryTypes: ['mark', 'measure'] });

performance.mark('test');
performance.mark('meow');
Expand Down Expand Up @@ -647,7 +745,7 @@ const obs = new PerformanceObserver((perfObserverList, observer) => {
*/
observer.disconnect();
});
obs.observe({ entryTypes: ['mark'], buffered: true });
obs.observe({ type: 'mark' });

performance.mark('test');
performance.mark('meow');
Expand Down
15 changes: 4 additions & 11 deletions lib/_http_server.js
Original file line number Diff line number Diff line change
Expand Up @@ -89,9 +89,7 @@ const {
DTRACE_HTTP_SERVER_REQUEST,
DTRACE_HTTP_SERVER_RESPONSE
} = require('internal/dtrace');
const { observerCounts, constants } = internalBinding('performance');
const { setTimeout, clearTimeout } = require('timers');
const { NODE_PERFORMANCE_ENTRY_TYPE_HTTP } = constants;

const dc = require('diagnostics_channel');
const onRequestStartChannel = dc.channel('http.server.request.start');
Expand Down Expand Up @@ -193,21 +191,16 @@ function ServerResponse(req) {
this.shouldKeepAlive = false;
}

const httpObserverCount = observerCounts[NODE_PERFORMANCE_ENTRY_TYPE_HTTP];
if (httpObserverCount > 0) {
this[kServerResponseStatistics] = {
startTime: process.hrtime()
};
}
this[kServerResponseStatistics] = {
startTime: process.hrtime()
};
}
ObjectSetPrototypeOf(ServerResponse.prototype, OutgoingMessage.prototype);
ObjectSetPrototypeOf(ServerResponse, OutgoingMessage);

ServerResponse.prototype._finish = function _finish() {
DTRACE_HTTP_SERVER_RESPONSE(this.socket);
if (this[kServerResponseStatistics] !== undefined) {
emitStatistics(this[kServerResponseStatistics]);
}
emitStatistics(this[kServerResponseStatistics]);
FunctionPrototypeCall(OutgoingMessage.prototype._finish, this);
};

Expand Down
Loading