[Alerting] Keep the number_of_scheduled_actions in event log (#128438)

* numberOfScheduledActions in event log
This commit is contained in:
Ersin Erdal 2022-03-28 20:15:31 +02:00 committed by GitHub
parent a50e87cfa5
commit 8885b9fb57
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
15 changed files with 89 additions and 66 deletions

View file

@ -49,6 +49,7 @@ export enum AlertExecutionStatusWarningReasons {
export interface AlertExecutionStatus {
status: AlertExecutionStatuses;
numberOfTriggeredActions?: number;
numberOfScheduledActions?: number;
metrics?: RuleExecutionMetrics;
lastExecutionDate: Date;
lastDuration?: number;

View file

@ -24,6 +24,7 @@ const ruleExecutionMetricsSchema = t.partial({
const alertExecutionStore = t.partial({
numberOfTriggeredActions: t.number,
numberOfScheduledActions: t.number,
triggeredActionsStatus: t.string,
});

View file

@ -34,11 +34,13 @@ describe('RuleExecutionStatus', () => {
const status = executionStatusFromState({
alertExecutionStore: {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
},
} as RuleExecutionState);
checkDateIsNearNow(status.lastExecutionDate);
expect(status.numberOfTriggeredActions).toBe(0);
expect(status.numberOfScheduledActions).toBe(0);
expect(status.status).toBe('ok');
expect(status.error).toBe(undefined);
expect(status.warning).toBe(undefined);
@ -49,12 +51,14 @@ describe('RuleExecutionStatus', () => {
alertInstances: {},
alertExecutionStore: {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
},
metrics,
});
checkDateIsNearNow(status.lastExecutionDate);
expect(status.numberOfTriggeredActions).toBe(0);
expect(status.numberOfScheduledActions).toBe(0);
expect(status.status).toBe('ok');
expect(status.error).toBe(undefined);
expect(status.warning).toBe(undefined);
@ -66,12 +70,14 @@ describe('RuleExecutionStatus', () => {
alertInstances: { a: {} },
alertExecutionStore: {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
},
metrics,
});
checkDateIsNearNow(status.lastExecutionDate);
expect(status.numberOfTriggeredActions).toBe(0);
expect(status.numberOfScheduledActions).toBe(0);
expect(status.status).toBe('active');
expect(status.error).toBe(undefined);
expect(status.warning).toBe(undefined);
@ -82,6 +88,7 @@ describe('RuleExecutionStatus', () => {
const status = executionStatusFromState({
alertExecutionStore: {
numberOfTriggeredActions: 1,
numberOfScheduledActions: 2,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
},
alertInstances: { a: {} },
@ -89,6 +96,7 @@ describe('RuleExecutionStatus', () => {
});
checkDateIsNearNow(status.lastExecutionDate);
expect(status.numberOfTriggeredActions).toBe(1);
expect(status.numberOfScheduledActions).toBe(2);
expect(status.status).toBe('active');
expect(status.error).toBe(undefined);
expect(status.warning).toBe(undefined);
@ -313,28 +321,6 @@ describe('RuleExecutionStatus', () => {
}
`);
});
test('valid status, date, error, duration and triggeredActions', () => {
const result = ruleExecutionStatusFromRaw(MockLogger, 'rule-id', {
status,
lastExecutionDate: date,
numberOfTriggeredActions: 5,
error,
lastDuration: 1234,
});
expect(result).toMatchInlineSnapshot(`
Object {
"error": Object {
"message": "wops",
"reason": "execute",
},
"lastDuration": 1234,
"lastExecutionDate": 2020-09-03T16:26:58.000Z,
"numberOfTriggeredActions": 5,
"status": "active",
}
`);
});
});
});

View file

@ -35,6 +35,7 @@ export function executionStatusFromState(state: RuleExecutionState): AlertExecut
return {
metrics: state.metrics,
numberOfTriggeredActions: state.alertExecutionStore.numberOfTriggeredActions,
numberOfScheduledActions: state.alertExecutionStore.numberOfScheduledActions,
lastExecutionDate: new Date(),
status,
...(hasIncompleteAlertExecution && {
@ -84,7 +85,6 @@ export function ruleExecutionStatusFromRaw(
const {
lastExecutionDate,
lastDuration,
numberOfTriggeredActions,
status = 'unknown',
error,
warning,
@ -107,10 +107,6 @@ export function ruleExecutionStatusFromRaw(
executionStatus.lastDuration = lastDuration;
}
if (null != numberOfTriggeredActions) {
executionStatus.numberOfTriggeredActions = numberOfTriggeredActions;
}
if (error) {
executionStatus.error = error;
}

View file

@ -127,6 +127,7 @@ describe('Create Execution Handler', () => {
);
alertExecutionStore = {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
};
});
@ -512,6 +513,7 @@ describe('Create Execution Handler', () => {
alertExecutionStore = {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
};
@ -524,6 +526,7 @@ describe('Create Execution Handler', () => {
});
expect(alertExecutionStore.numberOfTriggeredActions).toBe(2);
expect(alertExecutionStore.numberOfScheduledActions).toBe(3);
expect(alertExecutionStore.triggeredActionsStatus).toBe(ActionsCompletion.PARTIAL);
expect(actionsClient.enqueueExecution).toHaveBeenCalledTimes(2);
});

View file

@ -112,6 +112,8 @@ export function createExecutionHandler<
}),
}));
alertExecutionStore.numberOfScheduledActions += actions.length;
const ruleLabel = `${ruleType.id}:${ruleId}: '${ruleName}'`;
const actionsClient = await actionsPlugin.getActionsClientWithRequest(request);

View file

@ -211,6 +211,7 @@ export const generateEventLog = ({
actionId,
status,
numberOfTriggeredActions,
numberOfScheduledActions,
savedObjects = [generateAlertSO('1')],
}: GeneratorParams = {}) => ({
...(status === 'error' && {
@ -234,9 +235,10 @@ export const generateEventLog = ({
...(consumer && { consumer }),
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
...(!isNil(numberOfTriggeredActions) && {
...((!isNil(numberOfTriggeredActions) || !isNil(numberOfScheduledActions)) && {
metrics: {
number_of_triggered_actions: numberOfTriggeredActions,
number_of_scheduled_actions: numberOfScheduledActions,
number_of_searches: 3,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,

View file

@ -232,7 +232,7 @@ describe('Task Runner', () => {
expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z');
expect(logger.debug).nthCalledWith(
2,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfScheduledActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
@ -312,7 +312,7 @@ describe('Task Runner', () => {
);
expect(logger.debug).nthCalledWith(
3,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfScheduledActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger;
@ -368,6 +368,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 1,
numberOfScheduledActions: 1,
task: true,
consumer: 'bar',
})
@ -419,7 +420,7 @@ describe('Task Runner', () => {
);
expect(logger.debug).nthCalledWith(
4,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfScheduledActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
@ -462,6 +463,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
consumer: 'bar',
})
@ -583,7 +585,7 @@ describe('Task Runner', () => {
);
expect(logger.debug).nthCalledWith(
4,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfScheduledActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
expect(mockUsageCounter.incrementCounter).not.toHaveBeenCalled();
}
@ -772,6 +774,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
consumer: 'bar',
})
@ -836,6 +839,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 1,
numberOfScheduledActions: 1,
task: true,
consumer: 'bar',
})
@ -909,6 +913,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 1,
numberOfScheduledActions: 1,
task: true,
consumer: 'bar',
})
@ -1026,6 +1031,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 1,
numberOfScheduledActions: 1,
task: true,
consumer: 'bar',
})
@ -1107,7 +1113,7 @@ describe('Task Runner', () => {
);
expect(logger.debug).nthCalledWith(
4,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"numberOfScheduledActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger;
@ -1174,6 +1180,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 2,
numberOfScheduledActions: 2,
task: true,
consumer: 'bar',
})
@ -1247,7 +1254,7 @@ describe('Task Runner', () => {
);
expect(logger.debug).nthCalledWith(
4,
`ruleExecutionStatus for test:${alertId}: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}`
`ruleExecutionStatus for test:${alertId}: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"numberOfScheduledActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}`
);
const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger;
@ -1435,6 +1442,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 2,
task: true,
consumer: 'bar',
})
@ -2040,6 +2048,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
consumer: 'bar',
})
@ -2142,6 +2151,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'active',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
consumer: 'bar',
})
@ -2233,6 +2243,7 @@ describe('Task Runner', () => {
status: 'active',
consumer: 'bar',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
})
);
@ -2322,6 +2333,7 @@ describe('Task Runner', () => {
status: 'ok',
consumer: 'bar',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
})
);
@ -2407,6 +2419,7 @@ describe('Task Runner', () => {
status: 'ok',
consumer: 'bar',
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
task: true,
})
);
@ -2468,7 +2481,7 @@ describe('Task Runner', () => {
expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z');
expect(logger.debug).nthCalledWith(
2,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfScheduledActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
@ -2657,35 +2670,37 @@ describe('Task Runner', () => {
}
);
const mockActions = [
{
group: 'default',
id: '1',
actionTypeId: 'action',
},
{
group: 'default',
id: '2',
actionTypeId: 'action',
},
{
group: 'default',
id: '3',
actionTypeId: 'action',
},
{
group: 'default',
id: '4',
actionTypeId: 'action',
},
{
group: 'default',
id: '5',
actionTypeId: 'action',
},
];
rulesClient.get.mockResolvedValue({
...mockedRuleTypeSavedObject,
actions: [
{
group: 'default',
id: '1',
actionTypeId: 'action',
},
{
group: 'default',
id: '2',
actionTypeId: 'action',
},
{
group: 'default',
id: '3',
actionTypeId: 'action',
},
{
group: 'default',
id: '4',
actionTypeId: 'action',
},
{
group: 'default',
id: '5',
actionTypeId: 'action',
},
],
actions: mockActions,
} as jest.ResolvedValue<unknown>);
ruleTypeRegistry.get.mockReturnValue(ruleTypeWithConfig);
encryptedSavedObjectsClient.getDecryptedAsInternalUser.mockResolvedValueOnce(SAVED_OBJECT);
@ -2801,6 +2816,7 @@ describe('Task Runner', () => {
outcome: 'success',
status: 'warning',
numberOfTriggeredActions: ruleTypeWithConfig.config.execution.actions.max,
numberOfScheduledActions: mockActions.length,
reason: AlertExecutionStatusWarningReasons.MAX_EXECUTABLE_ACTIONS,
task: true,
consumer: 'bar',

View file

@ -492,6 +492,7 @@ export class TaskRunner<
const alertExecutionStore: AlertExecutionStore = {
numberOfTriggeredActions: 0,
numberOfScheduledActions: 0,
triggeredActionsStatus: ActionsCompletion.COMPLETE,
};
@ -816,7 +817,12 @@ export class TaskRunner<
set(
event,
'kibana.alert.rule.execution.metrics.number_of_triggered_actions',
executionStatus.numberOfTriggeredActions ?? 0
executionStatus.numberOfTriggeredActions
);
set(
event,
'kibana.alert.rule.execution.metrics.number_of_scheduled_actions',
executionStatus.numberOfScheduledActions
);
}

View file

@ -330,6 +330,7 @@ describe('Task Runner Cancel', () => {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 0,
number_of_scheduled_actions: 0,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
@ -519,7 +520,7 @@ describe('Task Runner Cancel', () => {
);
expect(logger.debug).nthCalledWith(
7,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfScheduledActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
@ -613,6 +614,7 @@ describe('Task Runner Cancel', () => {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 0,
number_of_scheduled_actions: 0,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
@ -678,7 +680,7 @@ describe('Task Runner Cancel', () => {
);
expect(logger.debug).nthCalledWith(
6,
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfScheduledActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
@ -891,6 +893,7 @@ describe('Task Runner Cancel', () => {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 1,
number_of_scheduled_actions: 1,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},

View file

@ -163,5 +163,6 @@ export enum ActionsCompletion {
export interface AlertExecutionStore {
numberOfTriggeredActions: number;
numberOfScheduledActions: number;
triggeredActionsStatus: ActionsCompletion;
}

View file

@ -195,7 +195,6 @@ export interface AlertMeta extends SavedObjectAttributes {
// delete any previous error if the current status has no error
export interface RawRuleExecutionStatus extends SavedObjectAttributes {
status: AlertExecutionStatuses;
numberOfTriggeredActions?: number;
lastExecutionDate: string;
lastDuration?: number;
error: null | {

View file

@ -296,6 +296,9 @@
"number_of_triggered_actions": {
"type": "long"
},
"number_of_scheduled_actions": {
"type": "long"
},
"number_of_searches": {
"type": "long"
},

View file

@ -130,6 +130,7 @@ export const EventSchema = schema.maybe(
metrics: schema.maybe(
schema.object({
number_of_triggered_actions: ecsNumber(),
number_of_scheduled_actions: ecsNumber(),
number_of_searches: ecsNumber(),
total_indexing_duration_ms: ecsNumber(),
es_search_duration_ms: ecsNumber(),

View file

@ -78,6 +78,9 @@ exports.EcsCustomPropertyMappings = {
number_of_triggered_actions: {
type: 'long',
},
number_of_scheduled_actions: {
type: 'long',
},
number_of_searches: {
type: 'long',
},