From 67269fd7f33279699b1ae71225f3d738518c844c Mon Sep 17 00:00:00 2001 From: James M Snell Date: Mon, 7 Aug 2017 15:53:24 -0700 Subject: perf_hooks: implementation of the perf timing API An initial implementation of the Performance Timing API for Node.js. This is the same Performance Timing API implemented by modern browsers with a number of Node.js specific properties. The User Timing mark() and measure() APIs are implemented, garbage collection timing, and node startup milestone timing. ```js const { performance } = require('perf_hooks'); performance.mark('A'); setTimeout(() => { performance.mark('B'); performance.measure('A to B', 'A', 'B'); const entry = performance.getEntriesByName('A to B', 'measure')[0]; console.log(entry.duration); }, 10000); ``` The implementation is at the native layer and makes use of uv_hrtime(). This should enable *eventual* integration with things like Tracing and Inspection. The implementation is extensible and should allow us to add new performance entry types as we go (e.g. for measuring i/o perf, etc). Documentation and a test are provided. PR-URL: https://github.com/nodejs/node/pull/14680 Reviewed-By: Matteo Collina --- doc/api/perf_hooks.md | 656 ++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 656 insertions(+) create mode 100755 doc/api/perf_hooks.md (limited to 'doc/api/perf_hooks.md') diff --git a/doc/api/perf_hooks.md b/doc/api/perf_hooks.md new file mode 100755 index 0000000000..7972e1edb2 --- /dev/null +++ b/doc/api/perf_hooks.md @@ -0,0 +1,656 @@ +# Performance Timing API + + +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. + +```js +const { performance } = require('perf_hooks'); +performance.mark('A'); +doSomeLongRunningProcess(() => { + performance.mark('B'); + performance.measure('A to B', 'A', 'B'); + const measure = performance.getEntriesByName('A to B')[0]; + console.log(measure.duration); + // Prints the number of milliseconds between Mark 'A' and Mark 'B' +}); +``` + +## Class: Performance + + +The `Performance` provides access to performance metric data. A single +instance of this class is provided via the `performance` property. + +### performance.clearFunctions([name]) + + +* `name` {string} + +If `name` is not provided, removes all `PerformanceFunction` objects from the +Performance Timeline. If `name` is provided, removes entries with `name`. + +### performance.clearMarks([name]) + + +* `name` {string} + +If `name` is not provided, removes all `PerformanceMark` objects from the +Performance Timeline. If `name` is provided, removes only the named mark. + +### performance.clearMeasures([name]) + + +* `name` {string} + +If `name` is not provided, removes all `PerformanceMeasure` objects from the +Performance Timeline. If `name` is provided, removes only objects whose +`performanceEntry.name` matches `name`. + +### performance.getEntries() + + +* Returns: {Array} + +Returns a list of all `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime`. + +### performance.getEntriesByName(name[, type]) + + +* `name` {string} +* `type` {string} +* Returns: {Array} + +Returns a list of all `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime` whose `performanceEntry.name` is +equal to `name`, and optionally, whose `performanceEntry.entryType` is equal to +`type`. + +### performance.getEntriesByType(type) + + +* `type` {string} +* Returns: {Array} + +Returns a list of all `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime` whose `performanceEntry.entryType` +is equal to `type`. + +### performance.mark([name]) + + +* `name` {string} + +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) + + +* `name` {string} +* `startMark` {string} +* `endMark` {string} + +Creates a new `PerformanceMeasure` entry in the Performance Timeline. A +`PerformanceMeasure` is a subclass of `PerformanceEntry` whose +`performanceEntry.entryType` is always `'measure'`, and whose +`performanceEntry.duration` measures the number of milliseconds elapsed since +`startMark` and `endMark`. + +The `startMark` argument may identify any *existing* `PerformanceMark` in the +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. + +The `endMark` argument must identify any *existing* `PerformanceMark` in the +the Performance Timeline or any of the timestamp properties provided by the +`PerformanceNodeTiming` class. If the named `endMark` does not exist, an +error will be thrown. + +### performance.nodeFrame + + +* {PerformanceFrame} + +An instance of the `PerformanceFrame` class that provides performance metrics +for the event loop. + +### performance.nodeTiming + + +* {PerformanceNodeTiming} + +An instance of the `PerformanceNodeTiming` class that provides performance +metrics for specific Node.js operational milestones. + +### performance.now() + + +* Returns: {number} + +Returns the current high resolution millisecond timestamp. + +### performance.timeOrigin + + +* {number} + +The [`timeOrigin`][] specifies the high resolution millisecond timestamp from +which all performance metric durations are measured. + +### performance.timerify(fn) + + +* `fn` {Function} + +Wraps a function within a new function that measures the running time of the +wrapped function. A `PerformanceObserver` must be subscribed to the `'function'` +event type in order for the timing details to be accessed. + +```js +const { + performance, + PerformanceObserver +} = require('perf_hooks'); + +function someFunction() { + console.log('hello world'); +} + +const wrapped = performance.timerify(someFunction); + +const obs = new PerformanceObserver((list) => { + console.log(list.getEntries()[0].duration); + obs.disconnect(); + performance.clearFunctions(); +}); +obs.observe({ entryTypes: 'function' }); + +// A performance timeline entry will be created +wrapped(); +``` + +## Class: PerformanceEntry + + +### performanceEntry.duration + + +* {number} + +The total number of milliseconds elapsed for this entry. This value will not +be meaningful for all Performance Entry types. + +### performanceEntry.name + + +* {string} + +The name of the performance entry. + +### performanceEntry.startTime + + +* {number} + +The high resolution millisecond timestamp marking the starting time of the +Performance Entry. + +### performanceEntry.entryType + + +* {string} + +The type of the performance entry. Current it may be one of: `'node'`, `'mark'`, +`'measure'`, `'gc'`, or `'function'`. + +### performanceEntry.kind + + +* {number} + +When `performanceEntry.entryType` is equal to `'gc'`, the `performance.kind` +property identifies the type of garbage collection operation that occurred. +The value may be 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` + +## Class: PerformanceNodeFrame extends PerformanceEntry + + +Provides timing details for the Node.js event loop. + +### performanceNodeFrame.frameCheck + +The high resolution timestamp when `uv_check_t` processing occurred on the +current loop. + +### performanceNodeFrame.frameCount + +The total number of event loop iterations (iterated when `uv_idle_t` +processing occurrs). + +### performanceNodeFrame.frameIdle + +The high resolution timestamp when `uv_idle_t` processing occurred on the +current loop. + +### performanceNodeFrame.framesPerSecond + +The number of event loop iterations per second. + +### performanceNodeFrame.framePrepare + +The high resolution timestamp when `uv_prepare_t` processing occurred on the +current loop. + +## Class: PerformanceNodeTiming extends PerformanceEntry + + +Provides timing details for Node.js itself. + +### performanceNodeTiming.bootstrapComplete + + +* {number} + +The high resolution millisecond timestamp at which the Node.js process +completed bootstrap. + +### performanceNodeTiming.clusterSetupEnd + + +* {number} + +The high resolution millisecond timestamp at which cluster processing ended. + +### performanceNodeTiming.clusterSetupStart + + +* {number} + +The high resolution millisecond timestamp at which cluster processing started. + +### performanceNodeTiming.loopExit + + +* {number} + +The high resolution millisecond timestamp at which the Node.js event loop +exited. + +### performanceNodeTiming.loopStart + + +* {number} + +The high resolution millisecond timestamp at which the Node.js event loop +started. + +### performanceNodeTiming.moduleLoadEnd + + +* {number} + +The high resolution millisecond timestamp at which main module load ended. + +### performanceNodeTiming.moduleLoadStart + + +* {number} + +The high resolution millisecond timestamp at which main module load started. + +### performanceNodeTiming.nodeStart + + +* {number} + +The high resolution millisecond timestamp at which the Node.js process was +initialized. + +### performanceNodeTiming.preloadModuleLoadEnd + + +* {number} + +The high resolution millisecond timestamp at which preload module load ended. + +### performanceNodeTiming.preloadModuleLoadStart + + +* {number} + +The high resolution millisecond timestamp at which preload module load started. + +### performanceNodeTiming.thirdPartyMainEnd + + +* {number} + +The high resolution millisecond timestamp at which third_party_main processing +ended. + +### performanceNodeTiming.thirdPartyMainStart + + +* {number} + +The high resolution millisecond timestamp at which third_party_main processing +started. + +### performanceNodeTiming.v8Start + + +* {number} + +The high resolution millisecond timestamp at which the V8 platform was +initialized. + + +## Class: PerformanceObserver(callback) + + +* `callback` {Function} A `PerformanceObserverCallback` callback function. + +`PerformanceObserver` objects provide notifications when new +`PerformanceEntry` instances have been added to the Performance Timeline. + +```js +const { + performance, + PerformanceObserver +} = require('perf_hooks'); + +const obs = new PerformanceObserver((list, observer) => { + console.log(list.getEntries()); + observer.disconnect(); +}); +obs.observe({ entryTypes: ['mark'], buffered: true }); + +performance.mark('test'); +``` + +Because `PerformanceObserver` instances introduce their own additional +performance overhead, instances should not be left subscribed to notifications +indefinitely. Users should disconnect observers as soon as they are no +longer needed. + +### Callback: PerformanceObserverCallback(list, observer) + + +* `list` {PerformanceObserverEntryList} +* `observer` {PerformanceObserver} + +The `PerformanceObserverCallback` is invoked when a `PerformanceObserver` is +notified about new `PerformanceEntry` instances. The callback receives a +`PerformanceObserverEntryList` instance and a reference to the +`PerformanceObserver`. + +### Class: PerformanceObserverEntryList + + +The `PerformanceObserverEntryList` class is used to provide access to the +`PerformanceEntry` instances passed to a `PerformanceObserver`. + +#### performanceObserverEntryList.getEntries() + + +* Returns: {Array} + +Returns a list of `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime`. + +#### performanceObserverEntryList.getEntriesByName(name[, type]) + + +* `name` {string} +* `type` {string} +* Returns: {Array} + +Returns a list of `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime` whose `performanceEntry.name` is +equal to `name`, and optionally, whose `performanceEntry.entryType` is equal to +`type`. + +#### performanceObserverEntryList.getEntriesByType(type) + + +* `type` {string} +* Returns: {Array} + +Returns a list of `PerformanceEntry` objects in chronological order +with respect to `performanceEntry.startTime` whose `performanceEntry.entryType` +is equal to `type`. + +### performanceObserver.disconnect() + +Disconnects the `PerformanceObserver` instance from all notifications. + +### performanceObserver.observe(options) + +* `options` {Object} + * `entryTypes` {Array} An array of strings identifying the types of + `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. Defaults to `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: + +```js +const { + performance, + PerformanceObserver +} = require('perf_hooks'); + +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 }); + +for (let n = 0; n < 3; n++) + performance.mark(`test${n}`); +``` + +## Examples + +### Measuring the duration of async operations + +The following example uses the [Async Hooks][] and Performance APIs to measure +the actual duration of a Timeout operation (including the amount of time it +to execute the callback). + +```js +'use strict'; +const async_hooks = require('async_hooks'); +const { + performance, + PerformanceObserver +} = require('perf_hooks'); + +const set = new Set(); +const hook = async_hooks.createHook({ + init(id, type) { + if (type === 'Timeout') { + performance.mark(`Timeout-${id}-Init`); + set.add(id); + } + }, + destroy(id) { + if (set.has(id)) { + set.delete(id); + performance.mark(`Timeout-${id}-Destroy`); + performance.measure(`Timeout-${id}`, + `Timeout-${id}-Init`, + `Timeout-${id}-Destroy`); + } + } +}); +hook.enable(); + +const obs = new PerformanceObserver((list, observer) => { + console.log(list.getEntries()[0]); + performance.clearMarks(); + performance.clearMeasures(); + observer.disconnect(); +}); +obs.observe({ entryTypes: ['measure'], buffered: true }); + +setTimeout(() => {}, 1000); +``` + +### Measuring how long it takes to load dependencies + +The following example measures the duration of `require()` operations to load +dependencies: + + +```js +'use strict'; +const { + performance, + PerformanceObserver +} = require('perf_hooks'); +const mod = require('module'); + +// Monkey patch the require function +mod.Module.prototype.require = + performance.timerify(mod.Module.prototype.require); +require = performance.timerify(require); + +// Activate the observer +const obs = new PerformanceObserver((list) => { + const entries = list.getEntries(); + entries.forEach((entry) => { + console.log(`require('${entry[0]}')`, entry.duration); + }); + obs.disconnect(); + // Free memory + performance.clearFunctions(); +}); +obs.observe({ entryTypes: ['function'], buffered: true }); + +require('some-module'); +``` + +[`timeOrigin`]: https://w3c.github.io/hr-time/#dom-performance-timeorigin +[W3C Performance Timeline]: https://w3c.github.io/performance-timeline/ -- cgit v1.2.3