Skip to content

Commit

Permalink
[Telemetry] track and warn event loop delays thresholds (#103615)
Browse files Browse the repository at this point in the history
  • Loading branch information
Bamieh authored Jun 29, 2021
1 parent 7ec04e1 commit de19795
Show file tree
Hide file tree
Showing 11 changed files with 342 additions and 118 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -35,3 +35,23 @@ export const MONITOR_EVENT_LOOP_DELAYS_START = 1 * 60 * 1000;
* Event loop monitoring sampling rate in milliseconds.
*/
export const MONITOR_EVENT_LOOP_DELAYS_RESOLUTION = 10;

/**
* Mean event loop delay threshold for logging a warning.
*/
export const MONITOR_EVENT_LOOP_WARN_THRESHOLD = 350;

/**
* Start monitoring the event loop threshold after 1 minute
*/
export const MONITOR_EVENT_LOOP_THRESHOLD_START = 1 * 60 * 1000;

/**
* Check the event loop utilization every 30 seconds
*/
export const MONITOR_EVENT_LOOP_THRESHOLD_INTERVAL = 30 * 1000;

/**
* Nanosecond to milisecond conversion unit
*/
export const ONE_MILLISECOND_AS_NANOSECONDS = 1000000;
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ export const monitorEventLoopDelay = jest.fn().mockReturnValue({
percentile: mockMonitorPercentile,
disable: mockMonitorDisable,
reset: mockMonitorReset,
...createMockHistogram(),
});

jest.doMock('perf_hooks', () => ({
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,17 +6,14 @@
* Side Public License, v 1.
*/

import { Subject } from 'rxjs';

import {
mockMonitorEnable,
mockMonitorPercentile,
monitorEventLoopDelay,
mockMonitorReset,
mockMonitorDisable,
} from './event_loop_delays.mocks';
import { savedObjectsRepositoryMock } from '../../../../../core/server/mocks';
import { startTrackingEventLoopDelaysUsage, EventLoopDelaysCollector } from './event_loop_delays';
import { EventLoopDelaysCollector } from './event_loop_delays';

describe('EventLoopDelaysCollector', () => {
jest.useFakeTimers('modern');
Expand Down Expand Up @@ -64,72 +61,3 @@ describe('EventLoopDelaysCollector', () => {
expect(mockMonitorDisable).toBeCalledTimes(1);
});
});

describe('startTrackingEventLoopDelaysUsage', () => {
const mockInternalRepository = savedObjectsRepositoryMock.create();
const stopMonitoringEventLoop$ = new Subject<void>();

beforeAll(() => jest.useFakeTimers('modern'));
beforeEach(() => jest.clearAllMocks());
afterEach(() => stopMonitoringEventLoop$.next());

it('initializes EventLoopDelaysCollector and starts timer', () => {
const collectionStartDelay = 1000;
startTrackingEventLoopDelaysUsage(
mockInternalRepository,
stopMonitoringEventLoop$,
collectionStartDelay
);

expect(monitorEventLoopDelay).toBeCalledTimes(1);
expect(mockMonitorPercentile).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionStartDelay);
expect(mockMonitorPercentile).toBeCalled();
});

it('stores event loop delays every collectionInterval duration', () => {
const collectionStartDelay = 100;
const collectionInterval = 1000;
startTrackingEventLoopDelaysUsage(
mockInternalRepository,
stopMonitoringEventLoop$,
collectionStartDelay,
collectionInterval
);

expect(mockInternalRepository.create).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionStartDelay);
expect(mockInternalRepository.create).toBeCalledTimes(1);
jest.advanceTimersByTime(collectionInterval);
expect(mockInternalRepository.create).toBeCalledTimes(2);
jest.advanceTimersByTime(collectionInterval);
expect(mockInternalRepository.create).toBeCalledTimes(3);
});

it('resets histogram every histogramReset duration', () => {
const collectionStartDelay = 0;
const collectionInterval = 1000;
const histogramReset = 5000;
startTrackingEventLoopDelaysUsage(
mockInternalRepository,
stopMonitoringEventLoop$,
collectionStartDelay,
collectionInterval,
histogramReset
);

expect(mockMonitorReset).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionInterval * 5);
expect(mockMonitorReset).toBeCalledTimes(1);
jest.advanceTimersByTime(collectionInterval * 5);
expect(mockMonitorReset).toBeCalledTimes(2);
});

it('stops monitoring event loop delays once stopMonitoringEventLoop$.next is called', () => {
startTrackingEventLoopDelaysUsage(mockInternalRepository, stopMonitoringEventLoop$);

expect(mockMonitorDisable).toBeCalledTimes(0);
stopMonitoringEventLoop$.next();
expect(mockMonitorDisable).toBeCalledTimes(1);
});
});
Original file line number Diff line number Diff line change
Expand Up @@ -8,16 +8,7 @@

import type { EventLoopDelayMonitor } from 'perf_hooks';
import { monitorEventLoopDelay } from 'perf_hooks';
import { takeUntil, finalize, map } from 'rxjs/operators';
import { Observable, timer } from 'rxjs';
import type { ISavedObjectsRepository } from 'kibana/server';
import {
MONITOR_EVENT_LOOP_DELAYS_START,
MONITOR_EVENT_LOOP_DELAYS_INTERVAL,
MONITOR_EVENT_LOOP_DELAYS_RESET,
MONITOR_EVENT_LOOP_DELAYS_RESOLUTION,
} from './constants';
import { storeHistogram } from './saved_objects';
import { MONITOR_EVENT_LOOP_DELAYS_RESOLUTION } from './constants';

export interface IntervalHistogram {
fromTimestamp: string;
Expand Down Expand Up @@ -77,33 +68,3 @@ export class EventLoopDelaysCollector {
this.loopMonitor.disable();
}
}

/**
* The monitoring of the event loop starts immediately.
* The first collection of the histogram happens after 1 minute.
* The daily histogram data is updated every 1 hour.
*/
export function startTrackingEventLoopDelaysUsage(
internalRepository: ISavedObjectsRepository,
stopMonitoringEventLoop$: Observable<void>,
collectionStartDelay = MONITOR_EVENT_LOOP_DELAYS_START,
collectionInterval = MONITOR_EVENT_LOOP_DELAYS_INTERVAL,
histogramReset = MONITOR_EVENT_LOOP_DELAYS_RESET
) {
const eventLoopDelaysCollector = new EventLoopDelaysCollector();

const resetOnCount = Math.ceil(histogramReset / collectionInterval);
timer(collectionStartDelay, collectionInterval)
.pipe(
map((i) => (i + 1) % resetOnCount === 0),
takeUntil(stopMonitoringEventLoop$),
finalize(() => eventLoopDelaysCollector.stop())
)
.subscribe(async (shouldReset) => {
const histogram = eventLoopDelaysCollector.collect();
if (shouldReset) {
eventLoopDelaysCollector.reset();
}
await storeHistogram(histogram, internalRepository);
});
}
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
* Side Public License, v 1.
*/

export { startTrackingEventLoopDelaysUsage } from './event_loop_delays';
export { registerEventLoopDelaysCollector } from './event_loop_delays_usage_collector';
export { startTrackingEventLoopDelaysThreshold } from './track_threshold';
export { startTrackingEventLoopDelaysUsage } from './track_delays';
export { SAVED_OBJECTS_DAILY_TYPE } from './saved_objects';
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0 and the Server Side Public License, v 1; you may not use this file except
* in compliance with, at your election, the Elastic License 2.0 or the Server
* Side Public License, v 1.
*/

import { Subject } from 'rxjs';

import {
mockMonitorPercentile,
monitorEventLoopDelay,
mockMonitorReset,
mockMonitorDisable,
} from './event_loop_delays.mocks';
import { savedObjectsRepositoryMock } from '../../../../../core/server/mocks';
import { startTrackingEventLoopDelaysUsage } from './track_delays';

describe('startTrackingEventLoopDelaysUsage', () => {
const mockInternalRepository = savedObjectsRepositoryMock.create();
const stopMonitoringEventLoop$ = new Subject<void>();

beforeAll(() => jest.useFakeTimers('modern'));
beforeEach(() => jest.clearAllMocks());
afterEach(() => stopMonitoringEventLoop$.next());

it('initializes EventLoopDelaysCollector and starts timer', () => {
const collectionStartDelay = 1000;
startTrackingEventLoopDelaysUsage(mockInternalRepository, stopMonitoringEventLoop$, {
collectionStartDelay,
});

expect(monitorEventLoopDelay).toBeCalledTimes(1);
expect(mockMonitorPercentile).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionStartDelay);
expect(mockMonitorPercentile).toBeCalled();
});

it('stores event loop delays every collectionInterval duration', () => {
const collectionStartDelay = 100;
const collectionInterval = 1000;
startTrackingEventLoopDelaysUsage(mockInternalRepository, stopMonitoringEventLoop$, {
collectionStartDelay,
collectionInterval,
});

expect(mockInternalRepository.create).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionStartDelay);
expect(mockInternalRepository.create).toBeCalledTimes(1);
jest.advanceTimersByTime(collectionInterval);
expect(mockInternalRepository.create).toBeCalledTimes(2);
jest.advanceTimersByTime(collectionInterval);
expect(mockInternalRepository.create).toBeCalledTimes(3);
});

it('resets histogram every histogramReset duration', () => {
const collectionStartDelay = 0;
const collectionInterval = 1000;
const histogramReset = 5000;
startTrackingEventLoopDelaysUsage(mockInternalRepository, stopMonitoringEventLoop$, {
collectionStartDelay,
collectionInterval,
histogramReset,
});

expect(mockMonitorReset).toBeCalledTimes(0);
jest.advanceTimersByTime(collectionInterval * 5);
expect(mockMonitorReset).toBeCalledTimes(1);
jest.advanceTimersByTime(collectionInterval * 5);
expect(mockMonitorReset).toBeCalledTimes(2);
});

it('stops monitoring event loop delays once stopMonitoringEventLoop$.next is called', () => {
startTrackingEventLoopDelaysUsage(mockInternalRepository, stopMonitoringEventLoop$);

expect(mockMonitorDisable).toBeCalledTimes(0);
stopMonitoringEventLoop$.next();
expect(mockMonitorDisable).toBeCalledTimes(1);
});
});
Original file line number Diff line number Diff line change
@@ -0,0 +1,56 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0 and the Server Side Public License, v 1; you may not use this file except
* in compliance with, at your election, the Elastic License 2.0 or the Server
* Side Public License, v 1.
*/

import { takeUntil, finalize, map } from 'rxjs/operators';
import { Observable, timer } from 'rxjs';
import type { ISavedObjectsRepository } from 'kibana/server';
import {
MONITOR_EVENT_LOOP_DELAYS_START,
MONITOR_EVENT_LOOP_DELAYS_INTERVAL,
MONITOR_EVENT_LOOP_DELAYS_RESET,
} from './constants';
import { storeHistogram } from './saved_objects';
import { EventLoopDelaysCollector } from './event_loop_delays';

/**
* The monitoring of the event loop starts immediately.
* The first collection of the histogram happens after 1 minute.
* The daily histogram data is updated every 1 hour.
*/
export function startTrackingEventLoopDelaysUsage(
internalRepository: ISavedObjectsRepository,
stopMonitoringEventLoop$: Observable<void>,
configs: {
collectionStartDelay?: number;
collectionInterval?: number;
histogramReset?: number;
} = {}
) {
const {
collectionStartDelay = MONITOR_EVENT_LOOP_DELAYS_START,
collectionInterval = MONITOR_EVENT_LOOP_DELAYS_INTERVAL,
histogramReset = MONITOR_EVENT_LOOP_DELAYS_RESET,
} = configs;

const eventLoopDelaysCollector = new EventLoopDelaysCollector();
const resetOnCount = Math.ceil(histogramReset / collectionInterval);

timer(collectionStartDelay, collectionInterval)
.pipe(
map((i) => (i + 1) % resetOnCount === 0),
takeUntil(stopMonitoringEventLoop$),
finalize(() => eventLoopDelaysCollector.stop())
)
.subscribe(async (shouldReset) => {
const histogram = eventLoopDelaysCollector.collect();
if (shouldReset) {
eventLoopDelaysCollector.reset();
}
await storeHistogram(histogram, internalRepository);
});
}
Loading

0 comments on commit de19795

Please sign in to comment.