Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Security Solution][Detections] Fixes Rule Execution Log events potentially being out of order when providing status filters and max events are hit #131675

Merged
merged 12 commits into from
Jul 11, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -79,8 +79,16 @@ export const createEventLogReader = (eventLog: IEventLogClient): IEventLogReader
filteredExecutionUUIDs: {
terms: {
field: EXECUTION_UUID_FIELD,
order: { executeStartTime: 'desc' },
size: MAX_EXECUTION_EVENTS_DISPLAYED,
},
aggs: {
executeStartTime: {
min: {
field: '@timestamp',
},
},
},
},
},
});
Expand Down Expand Up @@ -111,7 +119,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 } }],
}),
});

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
* 2.0.
*/

import { cloneDeep } from 'lodash';
import dateMath from '@kbn/datemath';
import expect from '@kbn/expect';
import moment from 'moment';
Expand All @@ -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) => {
Expand Down Expand Up @@ -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);
});
});
};