From 0e447ec9b6714e8337725cc0c6a906b0650b2f9a Mon Sep 17 00:00:00 2001 From: Yuriy Vasiyarov Date: Tue, 25 Jun 2019 16:10:06 +0300 Subject: [PATCH] feat: implement advanced event loop monitoring --- lib/defaultMetrics.js | 1 + lib/metrics/eventLoopLag.js | 109 +++++++++++++++++++++++++++++-- test/metrics/eventLoopLagTest.js | 40 +++++++++++- 3 files changed, 143 insertions(+), 7 deletions(-) diff --git a/lib/defaultMetrics.js b/lib/defaultMetrics.js index 70e2deb9..c96505f6 100644 --- a/lib/defaultMetrics.js +++ b/lib/defaultMetrics.js @@ -49,6 +49,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..b04c92f8 100644 --- a/lib/metrics/eventLoopLag.js +++ b/lib/metrics/eventLoopLag.js @@ -1,31 +1,128 @@ 'use strict'; - const Gauge = require('../gauge'); +// Check if perf_hooks module is available +let perf_hooks; +try { + // eslint-disable-next-line + 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) { +function reportEventloopLag(start, gauge, timestamps) { const delta = process.hrtime(start); const nanosec = delta[0] * 1e9 + delta[1]; const seconds = nanosec / 1e9; - gauge.set(seconds, Date.now()); + if (timestamps) { + gauge.set(seconds, Date.now()); + } else { + 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 50 percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagP90 = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_P90, + help: 'The 90 percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + const lagP99 = new Gauge({ + name: namePrefix + NODEJS_EVENTLOOP_LAG_P99, + help: 'The 99 percentile of the recorded event loop delays.', + registers: registry ? [registry] : undefined + }); + + // eslint-disable-next-line + if (!perf_hooks || !perf_hooks.monitorEventLoopDelay) { + return () => { + const start = process.hrtime(); + setImmediate(reportEventloopLag, start, lag, config.timestamps); + }; + } + + // eslint-disable-next-line + const histogram = perf_hooks.monitorEventLoopDelay({ + resolution: config.eventLoopMonitoringPrecision + }); + histogram.enable(); return () => { const start = process.hrtime(); - setImmediate(reportEventloopLag, start, gauge); + setImmediate(reportEventloopLag, start, lag, config.timestamps); + + if (config.timestamps) { + const now = Date.now(); + + lagMin.set(histogram.min / 1e9, now); + lagMax.set(histogram.max / 1e9, now); + lagMean.set(histogram.mean / 1e9, now); + lagStddev.set(histogram.stddev / 1e9, now); + lagP50.set(histogram.percentile(50) / 1e9, now); + lagP90.set(histogram.percentile(90) / 1e9, now); + lagP99.set(histogram.percentile(99) / 1e9, now); + } else { + 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..dcea0ff3 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 50 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 90 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 99 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); });