[Telemetry] Track event loop delays on the server (elastic#101580)

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

@@ -0,0 +1,37 @@
+/*
+ * 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.
+ */
+
+/**
+ * Roll daily indices every 24h
+ */
+export const ROLL_DAILY_INDICES_INTERVAL = 24 * 60 * 60 * 1000;
+
+/**
+ * Start rolling indices after 5 minutes up
+ */
+export const ROLL_INDICES_START = 5 * 60 * 1000;
+
+/**
+ * Reset the event loop delay historgram every 1 hour
+ */
+export const MONITOR_EVENT_LOOP_DELAYS_INTERVAL = 1 * 60 * 60 * 1000;
+
+/**
+ * Reset the event loop delay historgram every 24h
+ */
+export const MONITOR_EVENT_LOOP_DELAYS_RESET = 24 * 60 * 60 * 1000;
+
+/**
+ * Start monitoring the event loop delays after 1 minute
+ */
+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;

src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/event_loop_delays.mocks.ts

@@ -0,0 +1,49 @@
+/*
+ * 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 moment from 'moment';
+import type { IntervalHistogram } from './event_loop_delays';
+
+export const mockMonitorEnable = jest.fn();
+export const mockMonitorPercentile = jest.fn();
+export const mockMonitorReset = jest.fn();
+export const mockMonitorDisable = jest.fn();
+export const monitorEventLoopDelay = jest.fn().mockReturnValue({
+  enable: mockMonitorEnable,
+  percentile: mockMonitorPercentile,
+  disable: mockMonitorDisable,
+  reset: mockMonitorReset,
+});
+
+jest.doMock('perf_hooks', () => ({
+  monitorEventLoopDelay,
+}));
+
+function createMockHistogram(overwrites: Partial<IntervalHistogram> = {}): IntervalHistogram {
+  const now = moment();
+
+  return {
+    min: 9093120,
+    max: 53247999,
+    mean: 11993238.600747818,
+    exceeds: 0,
+    stddev: 1168191.9357543814,
+    fromTimestamp: now.startOf('day').toISOString(),
+    lastUpdatedAt: now.toISOString(),
+    percentiles: {
+      '50': 12607487,
+      '75': 12615679,
+      '95': 12648447,
+      '99': 12713983,
+    },
+    ...overwrites,
+  };
+}
+
+export const mocked = {
+  createHistogram: createMockHistogram,
+};

src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/event_loop_delays.test.ts

@@ -0,0 +1,135 @@
+/*
+ * 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 {
+  mockMonitorEnable,
+  mockMonitorPercentile,
+  monitorEventLoopDelay,
+  mockMonitorReset,
+  mockMonitorDisable,
+} from './event_loop_delays.mocks';
+import { savedObjectsRepositoryMock } from '../../../../../core/server/mocks';
+import { startTrackingEventLoopDelaysUsage, EventLoopDelaysCollector } from './event_loop_delays';
+
+describe('EventLoopDelaysCollector', () => {
+  jest.useFakeTimers('modern');
+  const mockNow = jest.getRealSystemTime();
+  jest.setSystemTime(mockNow);
+
+  beforeEach(() => jest.clearAllMocks());
+  afterAll(() => jest.useRealTimers());
+
+  test('#constructor enables monitoring', () => {
+    new EventLoopDelaysCollector();
+    expect(monitorEventLoopDelay).toBeCalledWith({ resolution: 10 });
+    expect(mockMonitorEnable).toBeCalledTimes(1);
+  });
+
+  test('#collect returns event loop delays histogram', () => {
+    const eventLoopDelaysCollector = new EventLoopDelaysCollector();
+    const histogramData = eventLoopDelaysCollector.collect();
+    expect(mockMonitorPercentile).toHaveBeenNthCalledWith(1, 50);
+    expect(mockMonitorPercentile).toHaveBeenNthCalledWith(2, 75);
+    expect(mockMonitorPercentile).toHaveBeenNthCalledWith(3, 95);
+    expect(mockMonitorPercentile).toHaveBeenNthCalledWith(4, 99);
+
+    expect(Object.keys(histogramData)).toMatchInlineSnapshot(`
+      Array [
+        "min",
+        "max",
+        "mean",
+        "exceeds",
+        "stddev",
+        "fromTimestamp",
+        "lastUpdatedAt",
+        "percentiles",
+      ]
+    `);
+  });
+  test('#reset resets histogram data', () => {
+    const eventLoopDelaysCollector = new EventLoopDelaysCollector();
+    eventLoopDelaysCollector.reset();
+    expect(mockMonitorReset).toBeCalledTimes(1);
+  });
+  test('#stop disables monitoring event loop delays', () => {
+    const eventLoopDelaysCollector = new EventLoopDelaysCollector();
+    eventLoopDelaysCollector.stop();
+    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);
+  });
+});

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

@@ -0,0 +1,109 @@
+/*
+ * 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 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';
+
+export interface IntervalHistogram {
+  fromTimestamp: string;
+  lastUpdatedAt: string;
+  min: number;
+  max: number;
+  mean: number;
+  exceeds: number;
+  stddev: number;
+  percentiles: {
+    50: number;
+    75: number;
+    95: number;
+    99: number;
+  };
+}
+
+export class EventLoopDelaysCollector {
+  private readonly loopMonitor: EventLoopDelayMonitor;
+  private fromTimestamp: Date;
+
+  constructor() {
+    const monitor = monitorEventLoopDelay({
+      resolution: MONITOR_EVENT_LOOP_DELAYS_RESOLUTION,
+    });
+    monitor.enable();
+    this.fromTimestamp = new Date();
+    this.loopMonitor = monitor;
+  }
+
+  public collect(): IntervalHistogram {
+    const { min, max, mean, exceeds, stddev } = this.loopMonitor;
+
+    return {
+      min,
+      max,
+      mean,
+      exceeds,
+      stddev,
+      fromTimestamp: this.fromTimestamp.toISOString(),
+      lastUpdatedAt: new Date().toISOString(),
+      percentiles: {
+        50: this.loopMonitor.percentile(50),
+        75: this.loopMonitor.percentile(75),
+        95: this.loopMonitor.percentile(95),
+        99: this.loopMonitor.percentile(99),
+      },
+    };
+  }
+
+  public reset() {
+    this.loopMonitor.reset();
+    this.fromTimestamp = new Date();
+  }
+
+  public stop() {
+    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);
+    });
+}