From facb3c48fc6d1ffee4530b3bf1061f1db7dc041b Mon Sep 17 00:00:00 2001 From: "Devin W. Hurley" Date: Mon, 28 Sep 2020 18:40:57 -0400 Subject: [PATCH] [7.x] [Security Solution] [Detections] Log message enhancements (#78429) (#78671) * adds missing buildRuleMessage to debug logs to display rule id, name, etc. in logs * add buildRuleMessage fn to params Co-authored-by: Elastic Machine Co-authored-by: Elastic Machine --- .../signals/bulk_create_ml_signals.ts | 6 +++-- .../signals/bulk_create_threshold_signals.ts | 5 +++- .../signals/find_threshold_signals.ts | 4 ++++ .../signals/search_after_bulk_create.ts | 2 ++ .../signals/signal_rule_alert_type.ts | 3 +++ .../signals/single_bulk_create.test.ts | 13 +++++++++++ .../signals/single_bulk_create.ts | 23 +++++++++++++------ .../signals/single_search_after.test.ts | 12 ++++++++++ .../signals/single_search_after.ts | 5 +++- 9 files changed, 62 insertions(+), 11 deletions(-) diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_ml_signals.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_ml_signals.ts index 80839545951d..5c2dfa62e595 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_ml_signals.ts +++ b/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 => { const anomalyResults = params.someResult; const ecsResults = transformAnomalyResultsToEcs(anomalyResults); - - return singleBulkCreate({ ...params, filteredEvents: ecsResults }); + const buildRuleMessage = params.buildRuleMessage; + return singleBulkCreate({ ...params, filteredEvents: ecsResults, buildRuleMessage }); }; diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_threshold_signals.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_threshold_signals.ts index bdcddbf2ed21..9eee04030a90 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/bulk_create_threshold_signals.ts +++ b/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 }); }; diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/find_threshold_signals.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/find_threshold_signals.ts index 604b45217404..282256804996 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/find_threshold_signals.ts +++ b/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, }); }; diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.ts index d369a9133534..2df180582a0a 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.ts +++ b/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, diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/signal_rule_alert_type.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/signal_rule_alert_type.ts index f7b56f42755a..a3b37270e50b 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/signal_rule_alert_type.ts +++ b/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, diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.test.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.test.ts index 374b967d1e77..b7cc13fd13a0 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.test.ts +++ b/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); diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.ts index e3c3c940b322..759890cc9d07 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_bulk_create.ts +++ b/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 => { 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), diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.test.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.test.ts index da81911f07ad..7b7c40f0c435 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.test.ts +++ b/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'); }); diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.ts index f758adb21611..3b89a2d79c0d 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/single_search_after.ts +++ b/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; } };