diff --git a/CHANGELOG.md b/CHANGELOG.md index c0037886..e16bb8b6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -28,6 +28,7 @@ project adheres to [Semantic Versioning](http://semver.org/). ### Added - feat: implement GC metrics collection without native(C++) modules. +- faet: implement advanced event loop monitoring ## [11.5.3] - 2019-06-27 diff --git a/README.md b/README.md index eeba8f87..b017d1e4 100644 --- a/README.md +++ b/README.md @@ -51,11 +51,14 @@ In addition, some Node-specific metrics are included, such as event loop lag, active handles, GC and Node.js version. See what metrics there are in [lib/metrics](lib/metrics). -`collectDefaultMetrics` takes 1 options object with up to 4 entries, a timeout for how -often the probe should be fired, an optional prefix for metric names, -a registry to which metrics should be registered and -`gcDurationBuckets` with custom buckets for GC duration histogram. -Default buckets of GC duration histogram are `[0.001, 0.01, 0.1, 1, 2, 5]` (in seconds). +`collectDefaultMetrics` takes 1 options object with following entries: + +- `timeout` for how often the probe should be fired. Default: 10 seconds. +- `prefix` an optional prefix for metric names. +- `registry` to which metrics should be registered. +- `gcDurationBuckets` with custom buckets for GC duration histogram. Default buckets of GC duration histogram are `[0.001, 0.01, 0.1, 1, 2, 5]` (in seconds). +- `eventLoopMonitoringPrecision` with sampling rate in milliseconds. Must be greater than zero. Default: 10. + By default probes are launched every 10 seconds, but this can be modified like this: ```js diff --git a/index.d.ts b/index.d.ts index e66b1d11..57f650cd 100644 --- a/index.d.ts +++ b/index.d.ts @@ -651,6 +651,7 @@ export interface DefaultMetricsCollectorConfiguration { register?: Registry; prefix?: string; gcDurationBuckets?: number[]; + eventLoopMonitoringPrecision?: number; } /** diff --git a/lib/defaultMetrics.js b/lib/defaultMetrics.js index 553ed24c..6deb90b1 100644 --- a/lib/defaultMetrics.js +++ b/lib/defaultMetrics.js @@ -47,6 +47,7 @@ module.exports = function startDefaultMetrics(config) { normalizedConfig = Object.assign( { timestamps: true, + eventLoopMonitoringPrecision: 10, timeout: 10000 }, normalizedConfig diff --git a/lib/metrics/eventLoopLag.js b/lib/metrics/eventLoopLag.js index 56aff27a..07f73e0f 100644 --- a/lib/metrics/eventLoopLag.js +++ b/lib/metrics/eventLoopLag.js @@ -1,31 +1,110 @@ 'use strict'; - const Gauge = require('../gauge'); +// Check if perf_hooks module is available +let perf_hooks; +try { + /* eslint-disable node/no-unsupported-features/node-builtins */ + perf_hooks = require('perf_hooks'); +} catch (e) { + // node version is too old +} + const NODEJS_EVENTLOOP_LAG = 'nodejs_eventloop_lag_seconds'; +const NODEJS_EVENTLOOP_LAG_MIN = 'nodejs_eventloop_lag_min_seconds'; +const NODEJS_EVENTLOOP_LAG_MAX = 'nodejs_eventloop_lag_max_seconds'; +const NODEJS_EVENTLOOP_LAG_MEAN = 'nodejs_eventloop_lag_mean_seconds'; +const NODEJS_EVENTLOOP_LAG_STDDEV = 'nodejs_eventloop_lag_stddev_seconds'; +const NODEJS_EVENTLOOP_LAG_P50 = 'nodejs_eventloop_lag_p50_seconds'; +const NODEJS_EVENTLOOP_LAG_P90 = 'nodejs_eventloop_lag_p90_seconds'; +const NODEJS_EVENTLOOP_LAG_P99 = 'nodejs_eventloop_lag_p99_seconds'; function reportEventloopLag(start, gauge) { const delta = process.hrtime(start); const nanosec = delta[0] * 1e9 + delta[1]; const seconds = nanosec / 1e9; - gauge.set(seconds, Date.now()); + gauge.set(seconds); } module.exports = (registry, config = {}) => { const namePrefix = config.prefix ? config.prefix : ''; - const gauge = new Gauge({ + const lag = new Gauge({ name: namePrefix + NODEJS_EVENTLOOP_LAG, help: 'Lag of event loop in seconds.', registers: registry ? [registry] : undefined, aggregator: 'average' }); + const lagMin = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_MIN, + help: 'The minimum recorded event loop delay.', + registers: registry ? [registry] : undefined + }); + const lagMax = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_MAX, + help: 'The maximum recorded event loop delay.', + registers: registry ? [registry] : undefined + }); + const lagMean = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_MEAN, + help: 'The mean of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagStddev = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_STDDEV, + help: 'The standard deviation of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagP50 = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_P50, + help: 'The 50th percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagP90 = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_P90, + help: 'The 90th percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagP99 = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_P99, + help: 'The 99th percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + + if (!perf_hooks || !perf_hooks.monitorEventLoopDelay) { + return () => { + const start = process.hrtime(); + setImmediate(reportEventloopLag, start, lag); + }; + } + + const histogram = perf_hooks.monitorEventLoopDelay({ + resolution: config.eventLoopMonitoringPrecision + }); + histogram.enable(); return () => { const start = process.hrtime(); - setImmediate(reportEventloopLag, start, gauge); + setImmediate(reportEventloopLag, start, lag); + + lagMin.set(histogram.min / 1e9); + lagMax.set(histogram.max / 1e9); + lagMean.set(histogram.mean / 1e9); + lagStddev.set(histogram.stddev / 1e9); + lagP50.set(histogram.percentile(50) / 1e9); + lagP90.set(histogram.percentile(90) / 1e9); + lagP99.set(histogram.percentile(99) / 1e9); }; }; -module.exports.metricNames = [NODEJS_EVENTLOOP_LAG]; +module.exports.metricNames = [ + NODEJS_EVENTLOOP_LAG, + NODEJS_EVENTLOOP_LAG_MIN, + NODEJS_EVENTLOOP_LAG_MAX, + NODEJS_EVENTLOOP_LAG_MEAN, + NODEJS_EVENTLOOP_LAG_STDDEV, + NODEJS_EVENTLOOP_LAG_P50, + NODEJS_EVENTLOOP_LAG_P90, + NODEJS_EVENTLOOP_LAG_P99 +]; diff --git a/test/metrics/eventLoopLagTest.js b/test/metrics/eventLoopLagTest.js index d9bfd6e9..0dd6dcc3 100644 --- a/test/metrics/eventLoopLagTest.js +++ b/test/metrics/eventLoopLagTest.js @@ -18,12 +18,50 @@ describe('eventLoopLag', () => { setTimeout(() => { const metrics = register.getMetricsAsJSON(); - expect(metrics).toHaveLength(1); + expect(metrics).toHaveLength(8); expect(metrics[0].help).toEqual('Lag of event loop in seconds.'); expect(metrics[0].type).toEqual('gauge'); expect(metrics[0].name).toEqual('nodejs_eventloop_lag_seconds'); + expect(metrics[1].help).toEqual('The minimum recorded event loop delay.'); + expect(metrics[1].type).toEqual('gauge'); + expect(metrics[1].name).toEqual('nodejs_eventloop_lag_min_seconds'); + + expect(metrics[2].help).toEqual('The maximum recorded event loop delay.'); + expect(metrics[2].type).toEqual('gauge'); + expect(metrics[2].name).toEqual('nodejs_eventloop_lag_max_seconds'); + + expect(metrics[3].help).toEqual( + 'The mean of the recorded event loop delays.' + ); + expect(metrics[3].type).toEqual('gauge'); + expect(metrics[3].name).toEqual('nodejs_eventloop_lag_mean_seconds'); + + expect(metrics[4].help).toEqual( + 'The standard deviation of the recorded event loop delays.' + ); + expect(metrics[4].type).toEqual('gauge'); + expect(metrics[4].name).toEqual('nodejs_eventloop_lag_stddev_seconds'); + + expect(metrics[5].help).toEqual( + 'The 50th percentile of the recorded event loop delays.' + ); + expect(metrics[5].type).toEqual('gauge'); + expect(metrics[5].name).toEqual('nodejs_eventloop_lag_p50_seconds'); + + expect(metrics[6].help).toEqual( + 'The 90th percentile of the recorded event loop delays.' + ); + expect(metrics[6].type).toEqual('gauge'); + expect(metrics[6].name).toEqual('nodejs_eventloop_lag_p90_seconds'); + + expect(metrics[7].help).toEqual( + 'The 99th percentile of the recorded event loop delays.' + ); + expect(metrics[7].type).toEqual('gauge'); + expect(metrics[7].name).toEqual('nodejs_eventloop_lag_p99_seconds'); + done(); }, 5); });