Skip to content

Commit 19706fb

Browse files
TinaHeiligerskibanamachine
TinaHeiligers
and
kibanamachine
authored
Handles ns to ms conversion for event loop delay metrics (#118447)
Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
1 parent ed4feb8 commit 19706fb

10 files changed

Lines changed: 109 additions & 59 deletions

File tree

‎src/core/server/metrics/event_loop_delays/event_loop_delays_monitor.mocks.ts‎

Lines changed: 33 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,15 +9,17 @@ import moment from 'moment';
99
import type { EventLoopDelaysMonitor } from './event_loop_delays_monitor';
1010
import type { IntervalHistogram } from '../types';
1111

12-
function createMockHistogram(overwrites: Partial<IntervalHistogram> = {}): IntervalHistogram {
12+
function createMockRawNsDataHistogram(
13+
overwrites: Partial<IntervalHistogram> = {}
14+
): IntervalHistogram {
1315
const now = Date.now();
1416

15-
return {
17+
const mockedRawCollectedDataInNs = {
1618
min: 9093120,
1719
max: 53247999,
18-
mean: 11993238.600747818,
20+
mean: 11993238,
1921
exceeds: 0,
20-
stddev: 1168191.9357543814,
22+
stddev: 1168191,
2123
fromTimestamp: moment(now).toISOString(),
2224
lastUpdatedAt: moment(now).toISOString(),
2325
percentiles: {
@@ -28,6 +30,31 @@ function createMockHistogram(overwrites: Partial<IntervalHistogram> = {}): Inter
2830
},
2931
...overwrites,
3032
};
33+
return mockedRawCollectedDataInNs;
34+
}
35+
36+
function createMockMonitorDataMsHistogram(
37+
overwrites: Partial<IntervalHistogram> = {}
38+
): IntervalHistogram {
39+
const now = Date.now();
40+
41+
const mockedRawCollectedDataInMs = {
42+
min: 9.09312,
43+
max: 53.247999,
44+
mean: 11.993238,
45+
exceeds: 0,
46+
stddev: 1.168191,
47+
fromTimestamp: moment(now).toISOString(),
48+
lastUpdatedAt: moment(now).toISOString(),
49+
percentiles: {
50+
'50': 12.607487,
51+
'75': 12.615679,
52+
'95': 12.648447,
53+
'99': 12.713983,
54+
},
55+
...overwrites,
56+
};
57+
return mockedRawCollectedDataInMs;
3158
}
3259

3360
function createMockEventLoopDelaysMonitor() {
@@ -40,12 +67,12 @@ function createMockEventLoopDelaysMonitor() {
4067
stop: jest.fn(),
4168
});
4269

43-
mockCollect.mockReturnValue(createMockHistogram());
70+
mockCollect.mockReturnValue(createMockMonitorDataMsHistogram()); // this must mock the return value of the public collect method from this monitor.
4471

4572
return new MockEventLoopDelaysMonitor();
4673
}
4774

4875
export const mocked = {
49-
createHistogram: createMockHistogram,
76+
createHistogram: createMockRawNsDataHistogram, // raw data as received from Node.js perf_hooks.monitorEventLoopDelay([options])
5077
createEventLoopDelaysMonitor: createMockEventLoopDelaysMonitor,
5178
};

‎src/core/server/metrics/event_loop_delays/event_loop_delays_monitor.test.ts‎

Lines changed: 13 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@
99
/* eslint-disable dot-notation */
1010
jest.mock('perf_hooks');
1111
import { monitorEventLoopDelay } from 'perf_hooks';
12-
import { EventLoopDelaysMonitor } from './event_loop_delays_monitor';
12+
import { EventLoopDelaysMonitor, nsToMs } from './event_loop_delays_monitor';
1313
import { mocked } from './event_loop_delays_monitor.mocks';
1414

1515
describe('EventLoopDelaysMonitor', () => {
@@ -39,10 +39,20 @@ describe('EventLoopDelaysMonitor', () => {
3939
expect(eventLoopDelaysMonitor['loopMonitor'].percentile).toHaveBeenNthCalledWith(3, 95);
4040
expect(eventLoopDelaysMonitor['loopMonitor'].percentile).toHaveBeenNthCalledWith(4, 99);
4141

42-
// mocked perf_hook returns `mocked.createHistogram()`.
42+
// mocked perf_hook returns `mocked.createNsHistogram()` that returns data in ns.
43+
// The `collect` function returns the data in ms.
4344
// This ensures that the wiring of the `collect` function is correct.
4445
const mockedHistogram = mocked.createHistogram();
45-
expect(histogramData).toEqual(mockedHistogram);
46+
47+
expect(histogramData.min).toEqual(nsToMs(mockedHistogram.min));
48+
expect(histogramData.max).toEqual(nsToMs(mockedHistogram.max));
49+
expect(histogramData.mean).toEqual(nsToMs(mockedHistogram.mean));
50+
expect(histogramData.stddev).toEqual(nsToMs(mockedHistogram.stddev));
51+
expect(histogramData.exceeds).toEqual(nsToMs(mockedHistogram.exceeds));
52+
expect(histogramData.percentiles['50']).toEqual(nsToMs(mockedHistogram.percentiles['50']));
53+
expect(histogramData.percentiles['75']).toEqual(nsToMs(mockedHistogram.percentiles['75']));
54+
expect(histogramData.percentiles['95']).toEqual(nsToMs(mockedHistogram.percentiles['95']));
55+
expect(histogramData.percentiles['99']).toEqual(nsToMs(mockedHistogram.percentiles['99']));
4656
});
4757

4858
test('#reset resets histogram data', () => {

‎src/core/server/metrics/event_loop_delays/event_loop_delays_monitor.ts‎

Lines changed: 32 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,18 @@ import type { IntervalHistogram as PerfIntervalHistogram } from 'perf_hooks';
1010
import { monitorEventLoopDelay } from 'perf_hooks';
1111
import type { IntervalHistogram } from '../types';
1212

13+
/**
14+
* Nanosecond to milisecond conversion unit
15+
*/
16+
export const ONE_MILLISECOND_AS_NANOSECONDS = 1_000_000;
17+
18+
/**
19+
* Converts time metric from ns to ms
20+
**/
21+
export function nsToMs(metric: number) {
22+
return metric / ONE_MILLISECOND_AS_NANOSECONDS;
23+
}
24+
1325
export class EventLoopDelaysMonitor {
1426
private readonly loopMonitor: PerfIntervalHistogram;
1527
private fromTimestamp: Date;
@@ -28,26 +40,36 @@ export class EventLoopDelaysMonitor {
2840
* Collect gathers event loop delays metrics from nodejs perf_hooks.monitorEventLoopDelay
2941
* the histogram calculations start from the last time `reset` was called or this
3042
* EventLoopDelaysMonitor instance was created.
43+
*
44+
* Returns metrics in milliseconds.
45+
3146
* @returns {IntervalHistogram}
3247
*/
48+
3349
public collect(): IntervalHistogram {
3450
const lastUpdated = new Date();
3551
this.loopMonitor.disable();
36-
const { min, max, mean, exceeds, stddev } = this.loopMonitor;
52+
const {
53+
min: minNs,
54+
max: maxNs,
55+
mean: meanNs,
56+
exceeds: exceedsNs,
57+
stddev: stddevNs,
58+
} = this.loopMonitor;
3759

3860
const collectedData: IntervalHistogram = {
39-
min,
40-
max,
41-
mean,
42-
exceeds,
43-
stddev,
61+
min: nsToMs(minNs),
62+
max: nsToMs(maxNs),
63+
mean: nsToMs(meanNs),
64+
exceeds: nsToMs(exceedsNs),
65+
stddev: nsToMs(stddevNs),
4466
fromTimestamp: this.fromTimestamp.toISOString(),
4567
lastUpdatedAt: lastUpdated.toISOString(),
4668
percentiles: {
47-
50: this.loopMonitor.percentile(50),
48-
75: this.loopMonitor.percentile(75),
49-
95: this.loopMonitor.percentile(95),
50-
99: this.loopMonitor.percentile(99),
69+
50: nsToMs(this.loopMonitor.percentile(50)),
70+
75: nsToMs(this.loopMonitor.percentile(75)),
71+
95: nsToMs(this.loopMonitor.percentile(95)),
72+
99: nsToMs(this.loopMonitor.percentile(99)),
5173
},
5274
};
5375

‎src/core/server/metrics/types.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -70,7 +70,7 @@ export interface OpsMetrics {
7070

7171
/**
7272
* an IntervalHistogram object that samples and reports the event loop delay over time.
73-
* The delays will be reported in nanoseconds.
73+
* The delays will be reported in milliseconds.
7474
*
7575
* @public
7676
*/

‎src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/constants.ts‎

Lines changed: 1 addition & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ export const MONITOR_EVENT_LOOP_DELAYS_RESET = 24 * 60 * 60 * 1000;
3232
export const MONITOR_EVENT_LOOP_DELAYS_START = 1 * 60 * 1000;
3333

3434
/**
35-
* Mean event loop delay threshold for logging a warning.
35+
* Mean event loop delay threshold in ms for logging a warning.
3636
*/
3737
export const MONITOR_EVENT_LOOP_WARN_THRESHOLD = 350;
3838

@@ -45,8 +45,3 @@ export const MONITOR_EVENT_LOOP_THRESHOLD_START = 1 * 60 * 1000;
4545
* Check the event loop utilization every 30 seconds
4646
*/
4747
export const MONITOR_EVENT_LOOP_THRESHOLD_INTERVAL = 30 * 1000;
48-
49-
/**
50-
* Nanosecond to milisecond conversion unit
51-
*/
52-
export const ONE_MILLISECOND_AS_NANOSECONDS = 1000000;

‎src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/schema.ts‎

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -59,19 +59,19 @@ export const eventLoopDelaysUsageSchema: MakeSchemaFrom<EventLoopDelaysUsageRepo
5959
min: {
6060
type: 'long',
6161
_meta: {
62-
description: 'The minimum recorded event loop delay.',
62+
description: 'The minimum recorded event loop delay in ms.',
6363
},
6464
},
6565
max: {
6666
type: 'long',
6767
_meta: {
68-
description: 'The maximum recorded event loop delay.',
68+
description: 'The maximum recorded event loop delay in ms.',
6969
},
7070
},
7171
mean: {
7272
type: 'long',
7373
_meta: {
74-
description: 'The mean of the recorded event loop delays.',
74+
description: 'The mean of the recorded event loop delays in ms.',
7575
},
7676
},
7777
exceeds: {
@@ -84,32 +84,32 @@ export const eventLoopDelaysUsageSchema: MakeSchemaFrom<EventLoopDelaysUsageRepo
8484
stddev: {
8585
type: 'long',
8686
_meta: {
87-
description: 'The standard deviation of the recorded event loop delays.',
87+
description: 'The standard deviation of the recorded event loop delays in ms.',
8888
},
8989
},
9090
percentiles: {
9191
'50': {
9292
type: 'long',
9393
_meta: {
94-
description: 'The 50th accumulated percentile distribution',
94+
description: 'The 50th accumulated percentile distribution in ms',
9595
},
9696
},
9797
'75': {
9898
type: 'long',
9999
_meta: {
100-
description: 'The 75th accumulated percentile distribution',
100+
description: 'The 75th accumulated percentile distribution in ms',
101101
},
102102
},
103103
'95': {
104104
type: 'long',
105105
_meta: {
106-
description: 'The 95th accumulated percentile distribution',
106+
description: 'The 95th accumulated percentile distribution in ms',
107107
},
108108
},
109109
'99': {
110110
type: 'long',
111111
_meta: {
112-
description: 'The 99th accumulated percentile distribution',
112+
description: 'The 99th accumulated percentile distribution in ms',
113113
},
114114
},
115115
},

‎src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/track_delays.ts‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import { storeHistogram } from './saved_objects';
2121
* The monitoring of the event loop starts immediately.
2222
* The first collection of the histogram happens after 1 minute.
2323
* The daily histogram data is updated every 1 hour.
24+
* The histogram metrics are in milliseconds.
2425
*/
2526
export function startTrackingEventLoopDelaysUsage(
2627
internalRepository: ISavedObjectsRepository,

‎src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/track_threshold.ts‎

Lines changed: 3 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -9,13 +9,11 @@
99
import { takeUntil, finalize } from 'rxjs/operators';
1010
import { Observable, timer } from 'rxjs';
1111
import type { Logger } from 'kibana/server';
12-
import moment from 'moment';
1312
import type { UsageCounter } from '../../../../usage_collection/server';
1413
import {
1514
MONITOR_EVENT_LOOP_THRESHOLD_START,
1615
MONITOR_EVENT_LOOP_THRESHOLD_INTERVAL,
1716
MONITOR_EVENT_LOOP_WARN_THRESHOLD,
18-
ONE_MILLISECOND_AS_NANOSECONDS,
1917
} from './constants';
2018
import type { EventLoopDelaysMonitor } from '../../../../../core/server';
2119

@@ -48,14 +46,11 @@ export function startTrackingEventLoopDelaysThreshold(
4846
finalize(() => eventLoopDelaysMonitor.stop())
4947
)
5048
.subscribe(async () => {
51-
const { mean } = eventLoopDelaysMonitor.collect();
52-
const meanDurationMs = moment
53-
.duration(mean / ONE_MILLISECOND_AS_NANOSECONDS)
54-
.asMilliseconds();
49+
const { mean: meanMS } = eventLoopDelaysMonitor.collect();
5550

56-
if (meanDurationMs > warnThreshold) {
51+
if (meanMS > warnThreshold) {
5752
logger.warn(
58-
`Average event loop delay threshold exceeded ${warnThreshold}ms. Received ${meanDurationMs}ms. ` +
53+
`Average event loop delay threshold exceeded ${warnThreshold}ms. Received ${meanMS}ms. ` +
5954
`See https://ela.st/kibana-scaling-considerations for more information about scaling Kibana.`
6055
);
6156

‎src/plugins/telemetry/schema/oss_plugins.json‎

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -7075,19 +7075,19 @@
70757075
"min": {
70767076
"type": "long",
70777077
"_meta": {
7078-
"description": "The minimum recorded event loop delay."
7078+
"description": "The minimum recorded event loop delay in ms."
70797079
}
70807080
},
70817081
"max": {
70827082
"type": "long",
70837083
"_meta": {
7084-
"description": "The maximum recorded event loop delay."
7084+
"description": "The maximum recorded event loop delay in ms."
70857085
}
70867086
},
70877087
"mean": {
70887088
"type": "long",
70897089
"_meta": {
7090-
"description": "The mean of the recorded event loop delays."
7090+
"description": "The mean of the recorded event loop delays in ms."
70917091
}
70927092
},
70937093
"exceeds": {
@@ -7099,33 +7099,33 @@
70997099
"stddev": {
71007100
"type": "long",
71017101
"_meta": {
7102-
"description": "The standard deviation of the recorded event loop delays."
7102+
"description": "The standard deviation of the recorded event loop delays in ms."
71037103
}
71047104
},
71057105
"percentiles": {
71067106
"properties": {
71077107
"50": {
71087108
"type": "long",
71097109
"_meta": {
7110-
"description": "The 50th accumulated percentile distribution"
7110+
"description": "The 50th accumulated percentile distribution in ms"
71117111
}
71127112
},
71137113
"75": {
71147114
"type": "long",
71157115
"_meta": {
7116-
"description": "The 75th accumulated percentile distribution"
7116+
"description": "The 75th accumulated percentile distribution in ms"
71177117
}
71187118
},
71197119
"95": {
71207120
"type": "long",
71217121
"_meta": {
7122-
"description": "The 95th accumulated percentile distribution"
7122+
"description": "The 95th accumulated percentile distribution in ms"
71237123
}
71247124
},
71257125
"99": {
71267126
"type": "long",
71277127
"_meta": {
7128-
"description": "The 99th accumulated percentile distribution"
7128+
"description": "The 99th accumulated percentile distribution in ms"
71297129
}
71307130
}
71317131
}
@@ -9301,4 +9301,4 @@
93019301
}
93029302
}
93039303
}
9304-
}
9304+
}

0 commit comments

Comments
 (0)