[ResponseOps] Include alert creation delay in the event log (#176348)

Resolves #175941 ## Summary Adds a new field, `number_of_delayed_alerts`, to the event log for a rule run. It's a count for all the delayed alerts, I opted to go this route instead of counting the number of times each alert was delayed. Pls let me know if you would like to go another way or would like to add any other metrics :) ### To verify -Go to Dev Tools - Create a rule with the alert delay ``` POST kbn:/api/alerting/rule { "params": { "searchType": "esQuery", "timeWindowSize": 5, "timeWindowUnit": "m", "threshold": [ -1 ], "thresholdComparator": ">", "size": 100, "esQuery": """{ "query":{ "match_all" : {} } }""", "aggType": "count", "groupBy": "all", "termSize": 5, "excludeHitsFromPreviousRun": false, "sourceFields": [], "index": [ ".kibana-event-log*" ], "timeField": "@timestamp" }, "consumer": "stackAlerts", "schedule": { "interval": "1m" }, "tags": [], "name": "test", "rule_type_id": ".es-query", "actions": [ { "group": "query matched", "id": "${ACTION_ID}", "params": { "level": "info", "message": """Elasticsearch query rule '{{rule.name}}' is active: - Value: {{context.value}} - Conditions Met: {{context.conditions}} over {{rule.params.timeWindowSize}}{{rule.params.timeWindowUnit}} - Timestamp: {{context.date}} - Link: {{context.link}}""" }, "frequency": { "notify_when": "onActionGroupChange", "throttle": null, "summary": false } } ], "alert_delay": { "active": 3 } } ``` - Let the rule run and then run the following to look at the event log - Verify that there is a new field `number_of_delayed_alerts` and that the counts what you would would expect for a rule running with the alert_delay
elastic · Feb 12, 2024 · d0dfc33 · d0dfc33
1 parent e17f2f1
commit d0dfc33
Show file tree

Hide file tree

Showing 20 changed files with 152 additions and 67 deletions.
diff --git a/x-pack/plugins/alerting/server/alerts_client/legacy_alerts_client.ts b/x-pack/plugins/alerting/server/alerts_client/legacy_alerts_client.ts
@@ -141,6 +141,7 @@ export class LegacyAlertsClient<
     flappingSettings,
     maintenanceWindowIds,
     alertDelay,
+    ruleRunMetricsStore,
   }: ProcessAlertsOpts) {
     const {
       newAlerts: processedAlertsNew,
@@ -176,6 +177,7 @@ export class LegacyAlertsClient<
       processedAlertsRecoveredCurrent,
       this.startedAtString
     );
+    ruleRunMetricsStore.setNumberOfDelayedAlerts(alerts.delayedAlertsCount);
     alerts.currentRecoveredAlerts = merge(alerts.currentRecoveredAlerts, earlyRecoveredAlerts);
 
     this.processedAlerts.new = alerts.newAlerts;
@@ -213,6 +215,7 @@ export class LegacyAlertsClient<
       flappingSettings,
       maintenanceWindowIds,
       alertDelay,
+      ruleRunMetricsStore,
     });
 
     this.logAlerts({

diff --git a/x-pack/plugins/alerting/server/alerts_client/types.ts b/x-pack/plugins/alerting/server/alerts_client/types.ts
@@ -120,6 +120,7 @@ export interface ProcessAlertsOpts {
   notifyOnActionGroupChange: boolean;
   maintenanceWindowIds: string[];
   alertDelay: number;
+  ruleRunMetricsStore: RuleRunMetricsStore;
 }
 
 export interface LogAlertsOpts {

diff --git a/x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.test.ts b/x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.test.ts
@@ -726,6 +726,7 @@ describe('AlertingEventLogger', () => {
           numberOfNewAlerts: 4,
           numberOfRecoveredAlerts: 5,
           numSearches: 6,
+          numberOfDelayedAlerts: 7,
           esSearchDurationMs: 3300,
           totalSearchDurationMs: 10333,
           hasReachedAlertLimit: false,
@@ -753,6 +754,7 @@ describe('AlertingEventLogger', () => {
                     new: 4,
                     recovered: 5,
                   },
+                  number_of_delayed_alerts: 7,
                   number_of_searches: 6,
                   es_search_duration_ms: 3300,
                   total_search_duration_ms: 10333,
@@ -825,6 +827,7 @@ describe('AlertingEventLogger', () => {
           numberOfNewAlerts: 4,
           numberOfRecoveredAlerts: 5,
           numSearches: 6,
+          numberOfDelayedAlerts: 7,
           esSearchDurationMs: 3300,
           totalSearchDurationMs: 10333,
           hasReachedAlertLimit: false,
@@ -862,6 +865,7 @@ describe('AlertingEventLogger', () => {
                     new: 4,
                     recovered: 5,
                   },
+                  number_of_delayed_alerts: 7,
                   number_of_searches: 6,
                   es_search_duration_ms: 3300,
                   total_search_duration_ms: 10333,
@@ -910,6 +914,7 @@ describe('AlertingEventLogger', () => {
                     new: 0,
                     recovered: 0,
                   },
+                  number_of_delayed_alerts: 0,
                   number_of_searches: 0,
                   es_search_duration_ms: 0,
                   total_search_duration_ms: 0,

diff --git a/x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.ts b/x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.ts
@@ -440,6 +440,7 @@ export function updateEvent(event: IEvent, opts: UpdateEventOpts) {
         new: metrics.numberOfNewAlerts ? metrics.numberOfNewAlerts : 0,
         recovered: metrics.numberOfRecoveredAlerts ? metrics.numberOfRecoveredAlerts : 0,
       },
+      number_of_delayed_alerts: metrics.numberOfDelayedAlerts ? metrics.numberOfDelayedAlerts : 0,
       number_of_searches: metrics.numSearches ? metrics.numSearches : 0,
       es_search_duration_ms: metrics.esSearchDurationMs ? metrics.esSearchDurationMs : 0,
       total_search_duration_ms: metrics.totalSearchDurationMs ? metrics.totalSearchDurationMs : 0,

diff --git a/x-pack/plugins/alerting/server/lib/get_alerts_for_notification.test.ts b/x-pack/plugins/alerting/server/lib/get_alerts_for_notification.test.ts
@@ -23,9 +23,11 @@ describe('getAlertsForNotification', () => {
       'default',
       0,
       {
+        // new alerts
         '1': alert1,
       },
       {
+        // active alerts
         '1': alert1,
         '2': alert2,
       },
@@ -94,11 +96,13 @@ describe('getAlertsForNotification', () => {
       {},
       {},
       {
+        // recovered alerts
         '1': alert1,
         '2': alert2,
         '3': alert3,
       },
       {
+        // current recovered alerts
         '1': alert1,
         '2': alert2,
         '3': alert3,
@@ -228,11 +232,13 @@ describe('getAlertsForNotification', () => {
         {},
         {},
         {
+          // recovered alerts
           '1': alert1,
           '2': alert2,
           '3': alert3,
         },
         {
+          // current recovered alerts
           '1': alert1,
           '2': alert2,
           '3': alert3,
@@ -360,11 +366,13 @@ describe('getAlertsForNotification', () => {
       {},
       {},
       {
+        // recovered alerts
         '1': alert1,
         '2': alert2,
         '3': alert3,
       },
       {
+        // current recovered alerts
         '1': alert1,
         '2': alert2,
         '3': alert3,
@@ -459,21 +467,24 @@ describe('getAlertsForNotification', () => {
     });
     const alert2 = new Alert('2', { meta: { uuid: 'uuid-2' } });
 
-    const { newAlerts, activeAlerts, currentActiveAlerts } = getAlertsForNotification(
-      DEFAULT_FLAPPING_SETTINGS,
-      true,
-      'default',
-      0,
-      {
-        '1': alert1,
-      },
-      {
-        '1': alert1,
-        '2': alert2,
-      },
-      {},
-      {}
-    );
+    const { newAlerts, activeAlerts, currentActiveAlerts, delayedAlertsCount } =
+      getAlertsForNotification(
+        DEFAULT_FLAPPING_SETTINGS,
+        true,
+        'default',
+        0,
+        {
+          // new alerts
+          '1': alert1,
+        },
+        {
+          // active alerts
+          '1': alert1,
+          '2': alert2,
+        },
+        {},
+        {}
+      );
     expect(newAlerts).toMatchInlineSnapshot(`
       Object {
         "1": Object {
@@ -536,28 +547,32 @@ describe('getAlertsForNotification', () => {
         },
       }
     `);
+    expect(delayedAlertsCount).toBe(0);
   });
 
   test('should reset activeCount for all recovered alerts', () => {
     const alert1 = new Alert('1', { meta: { activeCount: 3 } });
     const alert3 = new Alert('3');
 
-    const { recoveredAlerts, currentRecoveredAlerts } = getAlertsForNotification(
-      DEFAULT_FLAPPING_SETTINGS,
-      true,
-      'default',
-      0,
-      {},
-      {},
-      {
-        '1': alert1,
-        '3': alert3,
-      },
-      {
-        '1': alert1,
-        '3': alert3,
-      }
-    );
+    const { recoveredAlerts, currentRecoveredAlerts, delayedAlertsCount } =
+      getAlertsForNotification(
+        DEFAULT_FLAPPING_SETTINGS,
+        true,
+        'default',
+        0,
+        {},
+        {},
+        {
+          // recovered alerts
+          '1': alert1,
+          '3': alert3,
+        },
+        {
+          // current recovered alerts
+          '1': alert1,
+          '3': alert3,
+        }
+      );
 
     expect(alertsWithAnyUUID(recoveredAlerts)).toMatchInlineSnapshot(`
       Object {
@@ -603,6 +618,7 @@ describe('getAlertsForNotification', () => {
         },
       }
     `);
+    expect(delayedAlertsCount).toBe(0);
   });
 
   test('should remove the alert from newAlerts and should not return the alert in currentActiveAlerts if the activeCount is less than the rule alertDelay', () => {
@@ -611,21 +627,24 @@ describe('getAlertsForNotification', () => {
     });
     const alert2 = new Alert('2', { meta: { uuid: 'uuid-2' } });
 
-    const { newAlerts, activeAlerts, currentActiveAlerts } = getAlertsForNotification(
-      DEFAULT_FLAPPING_SETTINGS,
-      true,
-      'default',
-      5,
-      {
-        '1': alert1,
-      },
-      {
-        '1': alert1,
-        '2': alert2,
-      },
-      {},
-      {}
-    );
+    const { newAlerts, activeAlerts, currentActiveAlerts, delayedAlertsCount } =
+      getAlertsForNotification(
+        DEFAULT_FLAPPING_SETTINGS,
+        true,
+        'default',
+        5,
+        {
+          // new alerts
+          '1': alert1,
+        },
+        {
+          // active alerts
+          '1': alert1,
+          '2': alert2,
+        },
+        {},
+        {}
+      );
     expect(newAlerts).toMatchInlineSnapshot(`Object {}`);
     expect(activeAlerts).toMatchInlineSnapshot(`
       Object {
@@ -652,23 +671,26 @@ describe('getAlertsForNotification', () => {
       }
     `);
     expect(currentActiveAlerts).toMatchInlineSnapshot(`Object {}`);
+    expect(delayedAlertsCount).toBe(2);
   });
 
   test('should update active alert to look like a new alert if the activeCount is equal to the rule alertDelay', () => {
     const alert2 = new Alert('2', { meta: { uuid: 'uuid-2' } });
 
-    const { newAlerts, activeAlerts, currentActiveAlerts } = getAlertsForNotification(
-      DEFAULT_FLAPPING_SETTINGS,
-      true,
-      'default',
-      1,
-      {},
-      {
-        '2': alert2,
-      },
-      {},
-      {}
-    );
+    const { newAlerts, activeAlerts, currentActiveAlerts, delayedAlertsCount } =
+      getAlertsForNotification(
+        DEFAULT_FLAPPING_SETTINGS,
+        true,
+        'default',
+        1,
+        {},
+        {
+          // active alerts
+          '2': alert2,
+        },
+        {},
+        {}
+      );
     expect(newAlerts['2'].getState().duration).toBe('0');
     expect(newAlerts['2'].getState().start).toBeTruthy();
 
@@ -677,5 +699,7 @@ describe('getAlertsForNotification', () => {
 
     expect(currentActiveAlerts['2'].getState().duration).toBe('0');
     expect(currentActiveAlerts['2'].getState().start).toBeTruthy();
+
+    expect(delayedAlertsCount).toBe(0);
   });
 });
diff --git a/x-pack/plugins/alerting/server/lib/get_alerts_for_notification.ts b/x-pack/plugins/alerting/server/lib/get_alerts_for_notification.ts
@@ -27,6 +27,7 @@ export function getAlertsForNotification<
   startedAt?: string | null
 ) {
   const currentActiveAlerts: Record<string, Alert<State, Context, ActionGroupIds>> = {};
+  let delayedAlertsCount = 0;
 
   for (const id of keys(activeAlerts)) {
     const alert = activeAlerts[id];
@@ -37,6 +38,7 @@ export function getAlertsForNotification<
     if (alert.getActiveCount() < alertDelay) {
       // remove from new alerts
       delete newAlerts[id];
+      delayedAlertsCount += 1;
     } else {
       currentActiveAlerts[id] = alert;
       // if the active count is equal to the alertDelay it is considered a new alert
@@ -100,5 +102,6 @@ export function getAlertsForNotification<
     currentActiveAlerts,
     recoveredAlerts,
     currentRecoveredAlerts,
+    delayedAlertsCount,
   };
 }
diff --git a/x-pack/plugins/alerting/server/lib/last_run_status.test.ts b/x-pack/plugins/alerting/server/lib/last_run_status.test.ts
@@ -24,6 +24,7 @@ const getMetrics = ({
     numberOfNewAlerts: 12,
     numberOfRecoveredAlerts: 11,
     numberOfTriggeredActions: 5,
+    numberOfDelayedAlerts: 3,
     totalSearchDurationMs: 2,
     hasReachedAlertLimit,
     hasReachedQueuedActionsLimit,

diff --git a/x-pack/plugins/alerting/server/lib/rule_execution_status.test.ts b/x-pack/plugins/alerting/server/lib/rule_execution_status.test.ts
@@ -28,6 +28,7 @@ const executionMetrics = {
   numberOfActiveAlerts: 2,
   numberOfNewAlerts: 3,
   numberOfRecoveredAlerts: 13,
+  numberOfDelayedAlerts: 7,
   hasReachedAlertLimit: false,
   triggeredActionsStatus: ActionsCompletion.COMPLETE,
   hasReachedQueuedActionsLimit: false,

diff --git a/x-pack/plugins/alerting/server/lib/rule_run_metrics_store.mock.ts b/x-pack/plugins/alerting/server/lib/rule_run_metrics_store.mock.ts
@@ -16,6 +16,7 @@ const createRuleRunMetricsStoreMock = () => {
       getNumberOfActiveAlerts: jest.fn(),
       getNumberOfRecoveredAlerts: jest.fn(),
       getNumberOfNewAlerts: jest.fn(),
+      getNumberOfDelayedAlerts: jest.fn(),
       getStatusByConnectorType: jest.fn(),
       getMetrics: jest.fn(),
       getHasReachedAlertLimit: jest.fn(),
@@ -28,6 +29,7 @@ const createRuleRunMetricsStoreMock = () => {
       setNumberOfActiveAlerts: jest.fn(),
       setNumberOfRecoveredAlerts: jest.fn(),
       setNumberOfNewAlerts: jest.fn(),
+      setNumberOfDelayedAlerts: jest.fn(),
       setTriggeredActionsStatusByConnectorType: jest.fn(),
       setHasReachedAlertLimit: jest.fn(),
       hasReachedTheExecutableActionsLimit: jest.fn(),