From b9413cf3c816d65c53d5b7fb5f2d0e1300729f3c Mon Sep 17 00:00:00 2001 From: "Devin W. Hurley" Date: Mon, 20 Jul 2020 15:55:26 -0400 Subject: [PATCH] [SIEM] [Detections] Fixes faulty circuit breaker (#71999) * removes useSortIds which was leftover from a previous attempt at implementing gap detection mitigation code. This only showed up because I modified the count variable used to determine when we hit maxSignals from utilizing the searchResult hits length to using the count of bulk created items (signals indexed) in this commit 56de45d156be23069815fec17440cf978710451f * removes logs and fixes if statement ordering * adds tests, increases code coverage for search after and bulk create function, updates log statements * update tests after rebase onto master * clean up if statements * fix test data * merge conflicts are hard --- .../signals/__mocks__/es_results.ts | 42 +++- .../signals/build_bulk_body.test.ts | 7 +- .../signals/search_after_bulk_create.test.ts | 207 ++++++++++++++++++ .../signals/search_after_bulk_create.ts | 171 +++++++++------ 4 files changed, 351 insertions(+), 76 deletions(-) diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/__mocks__/es_results.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/__mocks__/es_results.ts index 17e05109b9a87..19fcf65ec0c5e 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/__mocks__/es_results.ts +++ b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/__mocks__/es_results.ts @@ -56,11 +56,10 @@ export const sampleRuleAlertParams = ( exceptionsList: getListArrayMock(), }); -export const sampleDocNoSortId = (someUuid: string = sampleIdGuid): SignalSourceHit => ({ +export const sampleDocNoSortIdNoVersion = (someUuid: string = sampleIdGuid): SignalSourceHit => ({ _index: 'myFakeSignalIndex', _type: 'doc', _score: 100, - _version: 1, _id: someUuid, _source: { someKey: 'someValue', @@ -68,18 +67,26 @@ export const sampleDocNoSortId = (someUuid: string = sampleIdGuid): SignalSource }, }); -export const sampleDocNoSortIdNoVersion = (someUuid: string = sampleIdGuid): SignalSourceHit => ({ +export const sampleDocWithSortId = ( + someUuid: string = sampleIdGuid, + ip?: string +): SignalSourceHit => ({ _index: 'myFakeSignalIndex', _type: 'doc', _score: 100, + _version: 1, _id: someUuid, _source: { someKey: 'someValue', '@timestamp': '2020-04-20T21:27:45+0000', + source: { + ip: ip ?? '127.0.0.1', + }, }, + sort: ['1234567891111'], }); -export const sampleDocWithSortId = ( +export const sampleDocNoSortId = ( someUuid: string = sampleIdGuid, ip?: string ): SignalSourceHit => ({ @@ -95,7 +102,7 @@ export const sampleDocWithSortId = ( ip: ip ?? '127.0.0.1', }, }, - sort: ['1234567891111'], + sort: [], }); export const sampleEmptyDocSearchResults = (): SignalSearchResponse => ({ @@ -116,6 +123,8 @@ export const sampleEmptyDocSearchResults = (): SignalSearchResponse => ({ export const sampleDocWithAncestors = (): SignalSearchResponse => { const sampleDoc = sampleDocNoSortId(); + delete sampleDoc.sort; + delete sampleDoc._source.source; sampleDoc._source.signal = { parent: { rule: '04128c15-0d1b-4716-a4c5-46997ac7f3bd', @@ -317,6 +326,29 @@ export const repeatedSearchResultsWithSortId = ( }, }); +export const repeatedSearchResultsWithNoSortId = ( + total: number, + pageSize: number, + guids: string[], + ips?: string[] +) => ({ + took: 10, + timed_out: false, + _shards: { + total: 10, + successful: 10, + failed: 0, + skipped: 0, + }, + hits: { + total, + max_score: 100, + hits: Array.from({ length: pageSize }).map((x, index) => ({ + ...sampleDocNoSortId(guids[index], ips ? ips[index] : '127.0.0.1'), + })), + }, +}); + export const sampleDocSearchResultsWithSortId = ( someUuid: string = sampleIdGuid ): SignalSearchResponse => ({ diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/build_bulk_body.test.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/build_bulk_body.test.ts index e840ae96cf3c1..fe2e0f2d96fd8 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/build_bulk_body.test.ts +++ b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/build_bulk_body.test.ts @@ -21,8 +21,10 @@ describe('buildBulkBody', () => { test('bulk body builds well-defined body', () => { const sampleParams = sampleRuleAlertParams(); + const doc = sampleDocNoSortId(); + delete doc._source.source; const fakeSignalSourceHit = buildBulkBody({ - doc: sampleDocNoSortId(), + doc, ruleParams: sampleParams, id: sampleRuleGuid, name: 'rule-name', @@ -107,6 +109,7 @@ describe('buildBulkBody', () => { test('bulk body builds original_event if it exists on the event to begin with', () => { const sampleParams = sampleRuleAlertParams(); const doc = sampleDocNoSortId(); + delete doc._source.source; doc._source.event = { action: 'socket_opened', module: 'system', @@ -208,6 +211,7 @@ describe('buildBulkBody', () => { test('bulk body builds original_event if it exists on the event to begin with but no kind information', () => { const sampleParams = sampleRuleAlertParams(); const doc = sampleDocNoSortId(); + delete doc._source.source; doc._source.event = { action: 'socket_opened', module: 'system', @@ -307,6 +311,7 @@ describe('buildBulkBody', () => { test('bulk body builds original_event if it exists on the event to begin with with only kind information', () => { const sampleParams = sampleRuleAlertParams(); const doc = sampleDocNoSortId(); + delete doc._source.source; doc._source.event = { kind: 'event', }; diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.test.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.test.ts index 17935f64d5e14..3312191c3b41b 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.test.ts +++ b/x-pack/plugins/security_solution/server/lib/detection_engine/signals/search_after_bulk_create.test.ts @@ -11,6 +11,7 @@ import { sampleRuleGuid, mockLogger, repeatedSearchResultsWithSortId, + repeatedSearchResultsWithNoSortId, sampleDocSearchResultsNoSortIdNoHits, } from './__mocks__/es_results'; import { searchAfterAndBulkCreate } from './search_after_bulk_create'; @@ -356,6 +357,212 @@ describe('searchAfterAndBulkCreate', () => { expect(lastLookBackDate).toEqual(new Date('2020-04-20T21:27:45+0000')); }); + test('should return success when all search results are in the allowlist and with sortId present', async () => { + listClient.getListItemByValues = jest + .fn() + .mockResolvedValue([{ value: '1.1.1.1' }, { value: '2.2.2.2' }, { value: '3.3.3.3' }]); + const sampleParams = sampleRuleAlertParams(30); + mockService.callCluster + .mockResolvedValueOnce( + repeatedSearchResultsWithSortId(4, 4, someGuids.slice(0, 3), [ + '1.1.1.1', + '2.2.2.2', + '2.2.2.2', + '2.2.2.2', + ]) + ) + .mockResolvedValueOnce(sampleDocSearchResultsNoSortIdNoHits()); + + const exceptionItem = getExceptionListItemSchemaMock(); + exceptionItem.entries = [ + { + field: 'source.ip', + operator: 'included', + type: 'list', + list: { + id: 'ci-badguys.txt', + type: 'ip', + }, + }, + ]; + const { success, createdSignalsCount, lastLookBackDate } = await searchAfterAndBulkCreate({ + ruleParams: sampleParams, + gap: null, + previousStartedAt: new Date(), + listClient, + exceptionsList: [exceptionItem], + services: mockService, + logger: mockLogger, + id: sampleRuleGuid, + inputIndexPattern, + signalsIndex: DEFAULT_SIGNALS_INDEX, + name: 'rule-name', + actions: [], + createdAt: '2020-01-28T15:58:34.810Z', + updatedAt: '2020-01-28T15:59:14.004Z', + createdBy: 'elastic', + updatedBy: 'elastic', + interval: '5m', + enabled: true, + pageSize: 1, + filter: undefined, + refresh: false, + tags: ['some fake tag 1', 'some fake tag 2'], + throttle: 'no_actions', + buildRuleMessage, + }); + expect(success).toEqual(true); + expect(mockService.callCluster).toHaveBeenCalledTimes(2); + expect(createdSignalsCount).toEqual(0); // should not create any signals because all events were in the allowlist + expect(lastLookBackDate).toEqual(new Date('2020-04-20T21:27:45+0000')); + }); + + test('should return success when all search results are in the allowlist and no sortId present', async () => { + listClient.getListItemByValues = jest + .fn() + .mockResolvedValue([{ value: '1.1.1.1' }, { value: '2.2.2.2' }, { value: '3.3.3.3' }]); + const sampleParams = sampleRuleAlertParams(30); + mockService.callCluster.mockResolvedValueOnce( + repeatedSearchResultsWithNoSortId(4, 4, someGuids.slice(0, 3), [ + '1.1.1.1', + '2.2.2.2', + '2.2.2.2', + '2.2.2.2', + ]) + ); + + const exceptionItem = getExceptionListItemSchemaMock(); + exceptionItem.entries = [ + { + field: 'source.ip', + operator: 'included', + type: 'list', + list: { + id: 'ci-badguys.txt', + type: 'ip', + }, + }, + ]; + const { success, createdSignalsCount, lastLookBackDate } = await searchAfterAndBulkCreate({ + ruleParams: sampleParams, + gap: null, + previousStartedAt: new Date(), + listClient, + exceptionsList: [exceptionItem], + services: mockService, + logger: mockLogger, + id: sampleRuleGuid, + inputIndexPattern, + signalsIndex: DEFAULT_SIGNALS_INDEX, + name: 'rule-name', + actions: [], + createdAt: '2020-01-28T15:58:34.810Z', + updatedAt: '2020-01-28T15:59:14.004Z', + createdBy: 'elastic', + updatedBy: 'elastic', + interval: '5m', + enabled: true, + pageSize: 1, + filter: undefined, + refresh: false, + tags: ['some fake tag 1', 'some fake tag 2'], + throttle: 'no_actions', + buildRuleMessage, + }); + expect(success).toEqual(true); + expect(mockService.callCluster).toHaveBeenCalledTimes(1); + expect(createdSignalsCount).toEqual(0); // should not create any signals because all events were in the allowlist + expect(lastLookBackDate).toEqual(new Date('2020-04-20T21:27:45+0000')); + // I don't like testing log statements since logs change but this is the best + // way I can think of to ensure this section is getting hit with this test case. + expect(((mockLogger.debug as unknown) as jest.Mock).mock.calls[7][0]).toContain( + 'sortIds was empty on searchResult' + ); + }); + + test('should return success when no sortId present but search results are in the allowlist', async () => { + const sampleParams = sampleRuleAlertParams(30); + mockService.callCluster + .mockResolvedValueOnce(repeatedSearchResultsWithNoSortId(4, 4, someGuids.slice(0, 3))) + .mockResolvedValueOnce({ + took: 100, + errors: false, + items: [ + { + fakeItemValue: 'fakeItemKey', + }, + { + create: { + status: 201, + }, + }, + { + create: { + status: 201, + }, + }, + { + create: { + status: 201, + }, + }, + { + create: { + status: 201, + }, + }, + ], + }); + + const exceptionItem = getExceptionListItemSchemaMock(); + exceptionItem.entries = [ + { + field: 'source.ip', + operator: 'included', + type: 'list', + list: { + id: 'ci-badguys.txt', + type: 'ip', + }, + }, + ]; + const { success, createdSignalsCount, lastLookBackDate } = await searchAfterAndBulkCreate({ + ruleParams: sampleParams, + gap: null, + previousStartedAt: new Date(), + listClient, + exceptionsList: [exceptionItem], + services: mockService, + logger: mockLogger, + id: sampleRuleGuid, + inputIndexPattern, + signalsIndex: DEFAULT_SIGNALS_INDEX, + name: 'rule-name', + actions: [], + createdAt: '2020-01-28T15:58:34.810Z', + updatedAt: '2020-01-28T15:59:14.004Z', + createdBy: 'elastic', + updatedBy: 'elastic', + interval: '5m', + enabled: true, + pageSize: 1, + filter: undefined, + refresh: false, + tags: ['some fake tag 1', 'some fake tag 2'], + throttle: 'no_actions', + buildRuleMessage, + }); + expect(success).toEqual(true); + expect(mockService.callCluster).toHaveBeenCalledTimes(2); + expect(createdSignalsCount).toEqual(4); // should not create any signals because all events were in the allowlist + expect(lastLookBackDate).toEqual(new Date('2020-04-20T21:27:45+0000')); + // I don't like testing log statements since logs change but this is the best + // way I can think of to ensure this section is getting hit with this test case. + expect(((mockLogger.debug as unknown) as jest.Mock).mock.calls[12][0]).toContain( + 'sortIds was empty on filteredEvents' + ); + }); + test('should return success when no exceptions list provided', async () => { const sampleParams = sampleRuleAlertParams(30); mockService.callCluster 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 2a0e39cbbf237..e90e5996877f8 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 @@ -90,23 +90,12 @@ export const searchAfterAndBulkCreate = async ({ createdSignalsCount: 0, }; - let sortId; // tells us where to start our next search_after query - let searchResultSize = 0; + // sortId tells us where to start our next consecutive search_after query + let sortId; - /* - The purpose of `maxResults` is to ensure we do not perform - extra search_after's. This will be reset on each - iteration, although it really only matters for the first - iteration of the loop. - e.g. if maxSignals = 100 but our search result only yields - 27 documents, there is no point in performing another search - since we know there are no more events that match our rule, - and thus, no more signals we could possibly generate. - However, if maxSignals = 500 and our search yields a total - of 3050 results we don't want to make 3050 signals, - we only want 500. So maxResults will help us control how - many times we perform a search_after - */ + // signalsCreatedCount keeps track of how many signals we have created, + // to ensure we don't exceed maxSignals + let signalsCreatedCount = 0; const totalToFromTuples = getSignalTimeTuples({ logger, @@ -118,7 +107,6 @@ export const searchAfterAndBulkCreate = async ({ interval, buildRuleMessage, }); - const useSortIds = totalToFromTuples.length <= 1; logger.debug(buildRuleMessage(`totalToFromTuples: ${totalToFromTuples.length}`)); while (totalToFromTuples.length > 0) { const tuple = totalToFromTuples.pop(); @@ -127,16 +115,18 @@ export const searchAfterAndBulkCreate = async ({ toReturn.success = false; return toReturn; } - searchResultSize = 0; - while (searchResultSize < tuple.maxSignals) { + signalsCreatedCount = 0; + while (signalsCreatedCount < tuple.maxSignals) { try { logger.debug(buildRuleMessage(`sortIds: ${sortId}`)); + + // perform search_after with optionally undefined sortId const { searchResult, searchDuration, }: { searchResult: SignalSearchResponse; searchDuration: string } = await singleSearchAfter( { - searchAfterSortId: useSortIds ? sortId : undefined, + searchAfterSortId: sortId, index: inputIndexPattern, from: tuple.from.toISOString(), to: tuple.to.toISOString(), @@ -149,6 +139,7 @@ export const searchAfterAndBulkCreate = async ({ ); toReturn.searchAfterTimes.push(searchDuration); + // determine if there are any candidate signals to be processed const totalHits = typeof searchResult.hits.total === 'number' ? searchResult.hits.total @@ -157,7 +148,23 @@ export const searchAfterAndBulkCreate = async ({ logger.debug( buildRuleMessage(`searchResult.hit.hits.length: ${searchResult.hits.hits.length}`) ); - if (totalHits === 0) { + + // search results yielded zero hits so exit + // with search_after, these two values can be different when + // searching with the last sortId of a consecutive search_after + // yields zero hits, but there were hits using the previous + // sortIds. + // e.g. totalHits was 156, index 50 of 100 results, do another search-after + // this time with a new sortId, index 22 of the remainding 56, get another sortId + // search with that sortId, total is still 156 but the hits.hits array is empty. + if (totalHits === 0 || searchResult.hits.hits.length === 0) { + logger.debug( + buildRuleMessage( + `${ + totalHits === 0 ? 'totalHits' : 'searchResult.hits.hits.length' + } was 0, exiting and moving on to next tuple` + ) + ); toReturn.success = true; break; } @@ -167,10 +174,10 @@ export const searchAfterAndBulkCreate = async ({ searchResult.hits.hits[searchResult.hits.hits.length - 1]?._source['@timestamp'] ) : null; - searchResultSize += searchResult.hits.hits.length; // filter out the search results that match with the values found in the list. - // the resulting set are valid signals that are not on the allowlist. + // the resulting set are signals to be indexed, given they are not duplicates + // of signals already present in the signals index. const filteredEvents: SignalSearchResponse = listClient != null ? await filterEventsAgainstList({ @@ -181,55 +188,79 @@ export const searchAfterAndBulkCreate = async ({ buildRuleMessage, }) : searchResult; - if (filteredEvents.hits.total === 0 || filteredEvents.hits.hits.length === 0) { - // everything in the events were allowed, so no need to generate signals - toReturn.success = true; - break; - } - const { - bulkCreateDuration: bulkDuration, - createdItemsCount: createdCount, - } = await singleBulkCreate({ - filteredEvents, - ruleParams, - services, - logger, - id, - signalsIndex, - actions, - name, - createdAt, - createdBy, - updatedAt, - updatedBy, - interval, - enabled, - refresh, - tags, - throttle, - }); - logger.debug(buildRuleMessage(`created ${createdCount} signals`)); - toReturn.createdSignalsCount += createdCount; - if (bulkDuration) { - toReturn.bulkCreateTimes.push(bulkDuration); - } + // only bulk create if there are filteredEvents leftover + // if there isn't anything after going through the value list filter + // skip the call to bulk create and proceed to the next search_after, + // if there is a sort id to continue the search_after with. + if (filteredEvents.hits.hits.length !== 0) { + // make sure we are not going to create more signals than maxSignals allows + if (signalsCreatedCount + filteredEvents.hits.hits.length > tuple.maxSignals) { + filteredEvents.hits.hits = filteredEvents.hits.hits.slice( + 0, + tuple.maxSignals - signalsCreatedCount + ); + } + const { + bulkCreateDuration: bulkDuration, + createdItemsCount: createdCount, + } = await singleBulkCreate({ + filteredEvents, + ruleParams, + services, + logger, + id, + signalsIndex, + actions, + name, + createdAt, + createdBy, + updatedAt, + updatedBy, + interval, + enabled, + refresh, + tags, + throttle, + }); + logger.debug(buildRuleMessage(`created ${createdCount} signals`)); + toReturn.createdSignalsCount += createdCount; + signalsCreatedCount += createdCount; + logger.debug(buildRuleMessage(`signalsCreatedCount: ${signalsCreatedCount}`)); + if (bulkDuration) { + toReturn.bulkCreateTimes.push(bulkDuration); + } - logger.debug( - buildRuleMessage(`filteredEvents.hits.hits: ${filteredEvents.hits.hits.length}`) - ); - if (useSortIds && filteredEvents.hits.hits[0].sort == null) { - logger.debug(buildRuleMessage('sortIds was empty on search')); - toReturn.success = true; - break; - } else if ( - useSortIds && - filteredEvents.hits.hits !== null && - filteredEvents.hits.hits[0].sort !== null - ) { - sortId = filteredEvents.hits.hits[0].sort - ? filteredEvents.hits.hits[0].sort[0] - : undefined; + logger.debug( + buildRuleMessage(`filteredEvents.hits.hits: ${filteredEvents.hits.hits.length}`) + ); + + if ( + filteredEvents.hits.hits[0].sort != null && + filteredEvents.hits.hits[0].sort.length !== 0 + ) { + sortId = filteredEvents.hits.hits[0].sort + ? filteredEvents.hits.hits[0].sort[0] + : undefined; + } else { + logger.debug(buildRuleMessage('sortIds was empty on filteredEvents')); + toReturn.success = true; + break; + } + } else { + // we are guaranteed to have searchResult hits at this point + // because we check before if the totalHits or + // searchResult.hits.hits.length is 0 + if ( + searchResult.hits.hits[0].sort != null && + searchResult.hits.hits[0].sort.length !== 0 + ) { + sortId = searchResult.hits.hits[0].sort ? searchResult.hits.hits[0].sort[0] : undefined; + } else { + logger.debug(buildRuleMessage('sortIds was empty on searchResult')); + toReturn.success = true; + break; + } } } catch (exc) { logger.error(buildRuleMessage(`[-] search_after and bulk threw an error ${exc}`));