From 0ab69a1e8675a724fd2abe26a9bdeb499e2cd16d Mon Sep 17 00:00:00 2001 From: Garrett Spong Date: Thu, 5 May 2022 15:06:10 -0600 Subject: [PATCH 1/3] Fixes documents being out of order when providing status filters and overflow exists --- .../rule_execution_log/event_log/event_log_reader.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts index 20cc2f0e78c77..1094160785ee3 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts +++ b/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts @@ -81,6 +81,7 @@ export const createEventLogReader = (eventLog: IEventLogClient): IEventLogReader filteredExecutionUUIDs: { terms: { field: EXECUTION_UUID_FIELD, + order: { '@timestamp': 'desc' }, size: MAX_EXECUTION_EVENTS_DISPLAYED, }, }, @@ -113,7 +114,7 @@ export const createEventLogReader = (eventLog: IEventLogClient): IEventLogReader maxExecutions: MAX_EXECUTION_EVENTS_DISPLAYED, page, perPage, - sort: [{ [sortField]: { order: sortOrder } }] as estypes.Sort, + sort: [{ [sortField]: { order: sortOrder } }], }), }); From 2908958bba00626d6c6d52d487be5523bb4e409f Mon Sep 17 00:00:00 2001 From: Garrett Spong Date: Thu, 5 May 2022 20:52:39 -0600 Subject: [PATCH 2/3] Sort on timestamp from sub-agg --- .../rule_execution_log/event_log/event_log_reader.ts | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts b/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts index 1094160785ee3..811f7c88e12fc 100644 --- a/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts +++ b/x-pack/plugins/security_solution/server/lib/detection_engine/rule_execution_log/event_log/event_log_reader.ts @@ -81,9 +81,16 @@ export const createEventLogReader = (eventLog: IEventLogClient): IEventLogReader filteredExecutionUUIDs: { terms: { field: EXECUTION_UUID_FIELD, - order: { '@timestamp': 'desc' }, + order: { executeStartTime: 'desc' }, size: MAX_EXECUTION_EVENTS_DISPLAYED, }, + aggs: { + executeStartTime: { + min: { + field: '@timestamp', + }, + }, + }, }, }, }); From 7a657ac59cc211de8a7f42dae6efebfc5b2cb5d8 Mon Sep 17 00:00:00 2001 From: Garrett Spong Date: Fri, 8 Jul 2022 17:36:29 -0600 Subject: [PATCH 3/3] Adds api integration test --- .../group1/get_rule_execution_events.ts | 72 ++++++++++++++++++- 1 file changed, 71 insertions(+), 1 deletion(-) diff --git a/x-pack/test/detection_engine_api_integration/security_and_spaces/group1/get_rule_execution_events.ts b/x-pack/test/detection_engine_api_integration/security_and_spaces/group1/get_rule_execution_events.ts index 9fadbd39f7704..b5743935a3688 100644 --- a/x-pack/test/detection_engine_api_integration/security_and_spaces/group1/get_rule_execution_events.ts +++ b/x-pack/test/detection_engine_api_integration/security_and_spaces/group1/get_rule_execution_events.ts @@ -5,6 +5,7 @@ * 2.0. */ +import { cloneDeep } from 'lodash'; import dateMath from '@kbn/datemath'; import expect from '@kbn/expect'; import moment from 'moment'; @@ -25,7 +26,11 @@ import { waitForEventLogExecuteComplete, waitForRuleSuccessOrStatus, } from '../../utils'; -import { failedGapExecution } from './template_data/execution_events'; +import { + failedGapExecution, + failedRanAfterDisabled, + successfulExecution, +} from './template_data/execution_events'; // eslint-disable-next-line import/no-default-export export default ({ getService }: FtrProviderContext) => { @@ -164,5 +169,70 @@ export default ({ getService }: FtrProviderContext) => { ) ).to.eql(true); }); + + // For details, see: https://github.com/elastic/kibana/issues/131382 + it('should return execution events ordered by @timestamp desc when a status filter is active and there are more than 1000 executions', async () => { + const rule = getRuleForSignalTesting(['auditbeat-*'], uuid.v4(), false); + const { id } = await createRule(supertest, log, rule); + + // Daterange for which we'll generate execution events between + const start = dateMath.parse('now')?.utc().toISOString(); + const end = dateMath.parse('now+24d', { roundUp: true })?.utc().toISOString(); + + // 1002 total executions total, one minute apart + const dateTimes = [...Array(1002).keys()].map((i) => + moment(start) + .add(i + 1, 'm') + .toDate() + .toISOString() + ); + + // Create 1000 successful executions + const events = dateTimes.slice(0, 1000).flatMap((dateTime) => { + const executionId = uuid.v4(); + return cloneDeep(successfulExecution).map((e, i) => { + set(e, '@timestamp', dateTime); + set(e, 'event.start', dateTime); + set(e, 'event.end', dateTime); + set(e, 'rule.id', id); + set(e, 'kibana.saved_objects[0].id', id); + set(e, 'kibana.alert.rule.execution.uuid', executionId); + return e; + }); + }); + + await indexEventLogExecutionEvents(es, log, events); + + // Create 2 failed executions + const failedEvents = dateTimes.slice(1000).flatMap((dateTime) => { + const executionId = uuid.v4(); + return cloneDeep(failedRanAfterDisabled).map((e, i) => { + set(e, '@timestamp', dateTime); + set(e, 'event.start', dateTime); + set(e, 'event.end', dateTime); + set(e, 'rule.id', id); + set(e, 'kibana.saved_objects[0].id', id); + set(e, 'kibana.alert.rule.execution.uuid', executionId); + return e; + }); + }); + + await indexEventLogExecutionEvents(es, log, failedEvents); + await waitForEventLogExecuteComplete(es, log, id, 1002); + + // Be sure to provide between 1-2 filters so that the server must prefetch events + const response = await supertest + .get(detectionEngineRuleExecutionEventsUrl(id)) + .set('kbn-xsrf', 'true') + .query({ start, end, status_filters: 'failed,succeeded' }); + + // Verify the most recent execution was one of the failedRanAfterDisabled executions, which have a duration of 3ms and are made up of 2 docs per execution, + // and not one of the successfulExecution executions, which have a duration of 3183ms and are made up of 5 docs per execution + // The bug was because the prefetch of events was sorted by doc count by default, not `@timestamp`, which would result in the successful events pushing the 2 more recent + // failed events out of the 1000 query size of the prefetch query, which would result in only the successful executions being returned even though there were more recent + // failed executions + expect(response.body.total).to.eql(1002); + expect(response.body.events[0].duration_ms).to.eql(3); + }); }); };