[Security Solution] [Detections] Log message enhancements (#78429)

* adds missing buildRuleMessage to debug logs to display rule id, name, etc. in logs

* add buildRuleMessage fn to params

Co-authored-by: Elastic Machine <[email protected]>

Author: dhurley14

x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_ml_signals.ts

@@ -14,6 +14,7 @@ import { RuleAlertAction } from '../../../../common/detection_engine/types';
 import { RuleTypeParams, RefreshTypes } from '../types';
 import { singleBulkCreate, SingleBulkCreateResponse } from './single_bulk_create';
 import { AnomalyResults, Anomaly } from '../../machine_learning';
+import { BuildRuleMessage } from './rule_messages';
 
 interface BulkCreateMlSignalsParams {
   actions: RuleAlertAction[];
@@ -33,6 +34,7 @@ interface BulkCreateMlSignalsParams {
   refresh: RefreshTypes;
   tags: string[];
   throttle: string;
+  buildRuleMessage: BuildRuleMessage;
 }
 
 interface EcsAnomaly extends Anomaly {
@@ -85,6 +87,6 @@ export const bulkCreateMlSignals = async (
 ): Promise<SingleBulkCreateResponse> => {
   const anomalyResults = params.someResult;
   const ecsResults = transformAnomalyResultsToEcs(anomalyResults);
-
-  return singleBulkCreate({ ...params, filteredEvents: ecsResults });
+  const buildRuleMessage = params.buildRuleMessage;
+  return singleBulkCreate({ ...params, filteredEvents: ecsResults, buildRuleMessage });
 };

x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_threshold_signals.ts

@@ -15,6 +15,7 @@ import { RuleAlertAction } from '../../../../common/detection_engine/types';
 import { RuleTypeParams, RefreshTypes } from '../types';
 import { singleBulkCreate, SingleBulkCreateResponse } from './single_bulk_create';
 import { SignalSearchResponse } from './types';
+import { BuildRuleMessage } from './rule_messages';
 
 // used to generate constant Threshold Signals ID when run with the same params
 const NAMESPACE_ID = '0684ec03-7201-4ee0-8ee0-3a3f6b2479b2';
@@ -40,6 +41,7 @@ interface BulkCreateThresholdSignalsParams {
   tags: string[];
   throttle: string;
   startedAt: Date;
+  buildRuleMessage: BuildRuleMessage;
 }
 
 interface FilterObject {
@@ -195,6 +197,7 @@ export const bulkCreateThresholdSignals = async (
     params.ruleParams.threshold!,
     params.ruleParams.ruleId
   );
+  const buildRuleMessage = params.buildRuleMessage;
 
-  return singleBulkCreate({ ...params, filteredEvents: ecsResults });
+  return singleBulkCreate({ ...params, filteredEvents: ecsResults, buildRuleMessage });
 };

x-pack/plugins/security_solution/server/lib/detection_engine/signals/find_threshold_signals.ts

@@ -12,6 +12,7 @@ import { singleSearchAfter } from './single_search_after';
 import { AlertServices } from '../../../../../alerts/server';
 import { Logger } from '../../../../../../../src/core/server';
 import { SignalSearchResponse } from './types';
+import { BuildRuleMessage } from './rule_messages';
 
 interface FindThresholdSignalsParams {
   from: string;
@@ -21,6 +22,7 @@ interface FindThresholdSignalsParams {
   logger: Logger;
   filter: unknown;
   threshold: Threshold;
+  buildRuleMessage: BuildRuleMessage;
 }
 
 export const findThresholdSignals = async ({
@@ -31,6 +33,7 @@ export const findThresholdSignals = async ({
   logger,
   filter,
   threshold,
+  buildRuleMessage,
 }: FindThresholdSignalsParams): Promise<{
   searchResult: SignalSearchResponse;
   searchDuration: string;
@@ -59,5 +62,6 @@ export const findThresholdSignals = async ({
     logger,
     filter,
     pageSize: 0,
+    buildRuleMessage,
   });
 };

x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.ts

@@ -80,6 +80,7 @@ export const searchAfterAndBulkCreate = async ({
 
         // perform search_after with optionally undefined sortId
         const { searchResult, searchDuration, searchErrors } = await singleSearchAfter({
+          buildRuleMessage,
           searchAfterSortId: sortId,
           index: inputIndexPattern,
           from: tuple.from.toISOString(),
@@ -153,6 +154,7 @@ export const searchAfterAndBulkCreate = async ({
             success: bulkSuccess,
             errors: bulkErrors,
           } = await singleBulkCreate({
+            buildRuleMessage,
             filteredEvents,
             ruleParams,
             services,

x-pack/plugins/security_solution/server/lib/detection_engine/signals/signal_rule_alert_type.ts

@@ -257,6 +257,7 @@ export const signalRulesAlertType = ({
             enabled,
             refresh,
             tags,
+            buildRuleMessage,
           });
           // The legacy ES client does not define failures when it can be present on the structure, hence why I have the & { failures: [] }
           const shardFailures =
@@ -295,6 +296,7 @@ export const signalRulesAlertType = ({
             logger,
             filter: esFilter,
             threshold,
+            buildRuleMessage,
           });
 
           const {
@@ -323,6 +325,7 @@ export const signalRulesAlertType = ({
             enabled,
             refresh,
             tags,
+            buildRuleMessage,
           });
           result = mergeReturns([
             result,

x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.test.ts

@@ -19,7 +19,14 @@ import {
 import { DEFAULT_SIGNALS_INDEX } from '../../../../common/constants';
 import { singleBulkCreate, filterDuplicateRules } from './single_bulk_create';
 import { alertsMock, AlertServicesMock } from '../../../../../alerts/server/mocks';
+import { buildRuleMessageFactory } from './rule_messages';
 
+const buildRuleMessage = buildRuleMessageFactory({
+  id: 'fake id',
+  ruleId: 'fake rule id',
+  index: 'fakeindex',
+  name: 'fake name',
+});
 describe('singleBulkCreate', () => {
   const mockService: AlertServicesMock = alertsMock.createAlertServices();
 
@@ -158,6 +165,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
     expect(success).toEqual(true);
     expect(createdItemsCount).toEqual(0);
@@ -192,6 +200,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
     expect(success).toEqual(true);
     expect(createdItemsCount).toEqual(0);
@@ -218,6 +227,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
     expect(success).toEqual(true);
     expect(createdItemsCount).toEqual(0);
@@ -245,6 +255,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
 
     expect(mockLogger.error).not.toHaveBeenCalled();
@@ -274,6 +285,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
     expect(mockLogger.error).toHaveBeenCalled();
     expect(errors).toEqual(['[4]: internal server error']);
@@ -339,6 +351,7 @@ describe('singleBulkCreate', () => {
       refresh: false,
       tags: ['some fake tag 1', 'some fake tag 2'],
       throttle: 'no_actions',
+      buildRuleMessage,
     });
     expect(success).toEqual(true);
     expect(createdItemsCount).toEqual(1);

x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.ts

@@ -12,6 +12,7 @@ import { RuleAlertAction } from '../../../../common/detection_engine/types';
 import { RuleTypeParams, RefreshTypes } from '../types';
 import { generateId, makeFloatString, errorAggregator } from './utils';
 import { buildBulkBody } from './build_bulk_body';
+import { BuildRuleMessage } from './rule_messages';
 import { Logger } from '../../../../../../../src/core/server';
 
 interface SingleBulkCreateParams {
@@ -32,6 +33,7 @@ interface SingleBulkCreateParams {
   tags: string[];
   throttle: string;
   refresh: RefreshTypes;
+  buildRuleMessage: BuildRuleMessage;
 }
 
 /**
@@ -85,6 +87,7 @@ export interface BulkInsertSignalsResponse {
 
 // Bulk Index documents.
 export const singleBulkCreate = async ({
+  buildRuleMessage,
   filteredEvents,
   ruleParams,
   services,
@@ -104,9 +107,9 @@ export const singleBulkCreate = async ({
   throttle,
 }: SingleBulkCreateParams): Promise<SingleBulkCreateResponse> => {
   filteredEvents.hits.hits = filterDuplicateRules(id, filteredEvents);
-  logger.debug(`about to bulk create ${filteredEvents.hits.hits.length} events`);
+  logger.debug(buildRuleMessage(`about to bulk create ${filteredEvents.hits.hits.length} events`));
   if (filteredEvents.hits.hits.length === 0) {
-    logger.debug(`all events were duplicates`);
+    logger.debug(buildRuleMessage(`all events were duplicates`));
     return { success: true, createdItemsCount: 0, errors: [] };
   }
   // index documents after creating an ID based on the
@@ -153,21 +156,27 @@ export const singleBulkCreate = async ({
     body: bulkBody,
   });
   const end = performance.now();
-  logger.debug(`individual bulk process time took: ${makeFloatString(end - start)} milliseconds`);
-  logger.debug(`took property says bulk took: ${response.took} milliseconds`);
+  logger.debug(
+    buildRuleMessage(
+      `individual bulk process time took: ${makeFloatString(end - start)} milliseconds`
+    )
+  );
+  logger.debug(buildRuleMessage(`took property says bulk took: ${response.took} milliseconds`));
 
   const createdItemsCount = countBy(response.items, 'create.status')['201'] ?? 0;
   const duplicateSignalsCount = countBy(response.items, 'create.status')['409'];
   const errorCountByMessage = errorAggregator(response, [409]);
 
-  logger.debug(`bulk created ${createdItemsCount} signals`);
+  logger.debug(buildRuleMessage(`bulk created ${createdItemsCount} signals`));
   if (duplicateSignalsCount > 0) {
-    logger.debug(`ignored ${duplicateSignalsCount} duplicate signals`);
+    logger.debug(buildRuleMessage(`ignored ${duplicateSignalsCount} duplicate signals`));
   }
 
   if (!isEmpty(errorCountByMessage)) {
     logger.error(
-      `[-] bulkResponse had errors with responses of: ${JSON.stringify(errorCountByMessage)}`
+      buildRuleMessage(
+        `[-] bulkResponse had errors with responses of: ${JSON.stringify(errorCountByMessage)}`
+      )
     );
     return {
       errors: Object.keys(errorCountByMessage),

x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.test.ts

@@ -12,7 +12,14 @@ import {
 import { singleSearchAfter } from './single_search_after';
 import { alertsMock, AlertServicesMock } from '../../../../../alerts/server/mocks';
 import { ShardError } from '../../types';
+import { buildRuleMessageFactory } from './rule_messages';
 
+const buildRuleMessage = buildRuleMessageFactory({
+  id: 'fake id',
+  ruleId: 'fake rule id',
+  index: 'fakeindex',
+  name: 'fake name',
+});
 describe('singleSearchAfter', () => {
   const mockService: AlertServicesMock = alertsMock.createAlertServices();
 
@@ -32,6 +39,7 @@ describe('singleSearchAfter', () => {
       pageSize: 1,
       filter: undefined,
       timestampOverride: undefined,
+      buildRuleMessage,
     });
     expect(searchResult).toEqual(sampleDocSearchResultsNoSortId());
   });
@@ -47,6 +55,7 @@ describe('singleSearchAfter', () => {
       pageSize: 1,
       filter: undefined,
       timestampOverride: undefined,
+      buildRuleMessage,
     });
     expect(searchErrors).toEqual([]);
   });
@@ -94,6 +103,7 @@ describe('singleSearchAfter', () => {
       pageSize: 1,
       filter: undefined,
       timestampOverride: undefined,
+      buildRuleMessage,
     });
     expect(searchErrors).toEqual(['reason: some reason, type: some type, caused by: some reason']);
   });
@@ -110,6 +120,7 @@ describe('singleSearchAfter', () => {
       pageSize: 1,
       filter: undefined,
       timestampOverride: undefined,
+      buildRuleMessage,
     });
     expect(searchResult).toEqual(sampleDocSearchResultsWithSortId());
   });
@@ -129,6 +140,7 @@ describe('singleSearchAfter', () => {
         pageSize: 1,
         filter: undefined,
         timestampOverride: undefined,
+        buildRuleMessage,
       })
     ).rejects.toThrow('Fake Error');
   });

x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.ts

@@ -8,6 +8,7 @@ import { performance } from 'perf_hooks';
 import { AlertServices } from '../../../../../alerts/server';
 import { Logger } from '../../../../../../../src/core/server';
 import { SignalSearchResponse } from './types';
+import { BuildRuleMessage } from './rule_messages';
 import { buildEventsSearchQuery } from './build_events_query';
 import { createErrorsFromShard, makeFloatString } from './utils';
 import { TimestampOverrideOrUndefined } from '../../../../common/detection_engine/schemas/common/schemas';
@@ -23,6 +24,7 @@ interface SingleSearchAfterParams {
   pageSize: number;
   filter: unknown;
   timestampOverride: TimestampOverrideOrUndefined;
+  buildRuleMessage: BuildRuleMessage;
 }
 
 // utilize search_after for paging results into bulk.
@@ -37,6 +39,7 @@ export const singleSearchAfter = async ({
   logger,
   pageSize,
   timestampOverride,
+  buildRuleMessage,
 }: SingleSearchAfterParams): Promise<{
   searchResult: SignalSearchResponse;
   searchDuration: string;
@@ -69,7 +72,7 @@ export const singleSearchAfter = async ({
       searchErrors,
     };
   } catch (exc) {
-    logger.error(`[-] nextSearchAfter threw an error ${exc}`);
+    logger.error(buildRuleMessage(`[-] nextSearchAfter threw an error ${exc}`));
     throw exc;
   }
 };