github-mirrors/kibana
1
0
Fork 0
mirror of https://github.com/elastic/kibana.git synced 2025-04-23 09:19:04 -04:00
Code Issues Projects Releases Packages Wiki Activity

[Response Ops] Refactor alerting task runner - AlertingEventLog class (#131670)

Browse source 
* Created AlertingEventLogger class to handle event log transactions

* Updating all the tests

* Fixing functional test

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
This commit is contained in:
Ying Mao 2022-05-10 12:07:52 -04:00 • committed by GitHub
parent 56376b397f
commit 95e524da82
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
14 changed files with 2399 additions and 1937 deletions
Download patch file Download diff file Expand all files Collapse all files

30
x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.mock.ts Normal file
View file

@ -0,0 +1,30 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0; you may not use this file except in compliance with the Elastic License
* 2.0.
*/
import { PublicMethodsOf } from '@kbn/utility-types';
import { AlertingEventLogger } from './alerting_event_logger';
const createAlertingEventLoggerMock = () => {
const mock: jest.Mocked<PublicMethodsOf<AlertingEventLogger>> = {
initialize: jest.fn(),
start: jest.fn(),
getEvent: jest.fn(),
getStartAndDuration: jest.fn(),
setRuleName: jest.fn(),
setExecutionSucceeded: jest.fn(),
setExecutionFailed: jest.fn(),
logTimeout: jest.fn(),
logAlert: jest.fn(),
logAction: jest.fn(),
done: jest.fn(),
};
return mock;
};
export const alertingEventLoggerMock = {
create: createAlertingEventLoggerMock,
};

1115
x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.test.ts Normal file
View file

File diff suppressed because it is too large Load diff

389
x-pack/plugins/alerting/server/lib/alerting_event_logger/alerting_event_logger.ts Normal file
View file

@ -0,0 +1,389 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0; you may not use this file except in compliance with the Elastic License
* 2.0.
*/
import { IEvent, IEventLogger, SAVED_OBJECT_REL_PRIMARY } from '@kbn/event-log-plugin/server';
import { EVENT_LOG_ACTIONS } from '../../plugin';
import { UntypedNormalizedRuleType } from '../../rule_type_registry';
import { AlertInstanceState, RuleExecutionStatus } from '../../types';
import { createAlertEventLogRecordObject } from '../create_alert_event_log_record_object';
import { RuleRunMetrics } from '../rule_run_metrics_store';
// 1,000,000 nanoseconds in 1 millisecond
const Millis2Nanos = 1000 * 1000;
export interface RuleContextOpts {
ruleId: string;
ruleType: UntypedNormalizedRuleType;
consumer: string;
namespace?: string;
spaceId: string;
executionId: string;
taskScheduledAt: Date;
ruleName?: string;
}
type RuleContext = RuleContextOpts & {
taskScheduleDelay: number;
};
interface DoneOpts {
status?: RuleExecutionStatus;
metrics?: RuleRunMetrics | null;
}
interface AlertOpts {
action: string;
id: string;
message: string;
group?: string;
subgroup?: string;
state?: AlertInstanceState;
}
interface ActionOpts {
id: string;
typeId: string;
alertId: string;
alertGroup?: string;
alertSubgroup?: string;
}
export class AlertingEventLogger {
private eventLogger: IEventLogger;
private isInitialized = false;
private startTime?: Date;
private ruleContext?: RuleContextOpts;
// this is the "execute" event that will be updated over the lifecycle of this class
private event: IEvent;
constructor(eventLogger: IEventLogger) {
this.eventLogger = eventLogger;
}
// For testing purposes
public getEvent(): IEvent {
return this.event;
}
public initialize(context: RuleContextOpts) {
if (this.isInitialized) {
throw new Error('AlertingEventLogger already initialized');
}
this.isInitialized = true;
this.ruleContext = context;
}
public start() {
if (!this.isInitialized || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.startTime = new Date();
const context = {
...this.ruleContext,
taskScheduleDelay: this.startTime.getTime() - this.ruleContext.taskScheduledAt.getTime(),
};
// Initialize the "execute" event
this.event = initializeExecuteRecord(context);
this.eventLogger.startTiming(this.event, this.startTime);
// Create and log "execute-start" event
const executeStartEvent = createExecuteStartRecord(context, this.startTime);
this.eventLogger.logEvent(executeStartEvent);
}
public getStartAndDuration(): { start?: Date; duration?: string | number } {
return { start: this.startTime, duration: this.event?.event?.duration };
}
public setRuleName(ruleName: string) {
if (!this.isInitialized || !this.event || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.ruleContext.ruleName = ruleName;
updateEvent(this.event, { ruleName });
}
public setExecutionSucceeded(message: string) {
if (!this.isInitialized || !this.event) {
throw new Error('AlertingEventLogger not initialized');
}
updateEvent(this.event, { message, outcome: 'success' });
}
public setExecutionFailed(message: string, errorMessage: string) {
if (!this.isInitialized || !this.event) {
throw new Error('AlertingEventLogger not initialized');
}
updateEvent(this.event, { message, outcome: 'failure', error: errorMessage });
}
public logTimeout() {
if (!this.isInitialized || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.eventLogger.logEvent(createExecuteTimeoutRecord(this.ruleContext));
}
public logAlert(alert: AlertOpts) {
if (!this.isInitialized || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.eventLogger.logEvent(createAlertRecord(this.ruleContext, alert));
}
public logAction(action: ActionOpts) {
if (!this.isInitialized || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.eventLogger.logEvent(createActionExecuteRecord(this.ruleContext, action));
}
public done({ status, metrics }: DoneOpts) {
if (!this.isInitialized || !this.event || !this.ruleContext) {
throw new Error('AlertingEventLogger not initialized');
}
this.eventLogger.stopTiming(this.event);
if (status) {
updateEvent(this.event, { status: status.status });
if (status.error) {
updateEvent(this.event, {
outcome: 'failure',
reason: status.error?.reason || 'unknown',
error: this.event?.error?.message || status.error.message,
...(this.event.message
? {}
: {
message: `${this.ruleContext.ruleType.id}:${this.ruleContext.ruleId}: execution failed`,
}),
});
} else {
if (status.warning) {
updateEvent(this.event, {
reason: status.warning?.reason || 'unknown',
message: status.warning?.message || this.event?.message,
});
}
}
}
if (metrics) {
updateEvent(this.event, { metrics });
}
this.eventLogger.logEvent(this.event);
}
}
export function createExecuteStartRecord(context: RuleContext, startTime?: Date) {
const event = initializeExecuteRecord(context);
return {
...event,
event: {
...event.event,
action: EVENT_LOG_ACTIONS.executeStart,
...(startTime ? { start: startTime.toISOString() } : {}),
},
message: `rule execution start: "${context.ruleId}"`,
};
}
export function createAlertRecord(context: RuleContextOpts, alert: AlertOpts) {
return createAlertEventLogRecordObject({
ruleId: context.ruleId,
ruleType: context.ruleType,
consumer: context.consumer,
namespace: context.namespace,
spaceId: context.spaceId,
executionId: context.executionId,
action: alert.action,
state: alert.state,
instanceId: alert.id,
group: alert.group,
subgroup: alert.subgroup,
message: alert.message,
savedObjects: [
{
id: context.ruleId,
type: 'alert',
typeId: context.ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
],
ruleName: context.ruleName,
});
}
export function createActionExecuteRecord(context: RuleContextOpts, action: ActionOpts) {
return createAlertEventLogRecordObject({
ruleId: context.ruleId,
ruleType: context.ruleType,
consumer: context.consumer,
namespace: context.namespace,
spaceId: context.spaceId,
executionId: context.executionId,
action: EVENT_LOG_ACTIONS.executeAction,
instanceId: action.alertId,
group: action.alertGroup,
subgroup: action.alertSubgroup,
message: `alert: ${context.ruleType.id}:${context.ruleId}: '${context.ruleName}' instanceId: '${
action.alertId
}' scheduled ${
action.alertSubgroup
? `actionGroup(subgroup): '${action.alertGroup}(${action.alertSubgroup})'`
: `actionGroup: '${action.alertGroup}'`
} action: ${action.typeId}:${action.id}`,
savedObjects: [
{
id: context.ruleId,
type: 'alert',
typeId: context.ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
{
type: 'action',
id: action.id,
typeId: action.typeId,
},
],
ruleName: context.ruleName,
});
}
export function createExecuteTimeoutRecord(context: RuleContextOpts) {
return createAlertEventLogRecordObject({
ruleId: context.ruleId,
ruleType: context.ruleType,
consumer: context.consumer,
namespace: context.namespace,
spaceId: context.spaceId,
executionId: context.executionId,
action: EVENT_LOG_ACTIONS.executeTimeout,
message: `rule: ${context.ruleType.id}:${context.ruleId}: '${
context.ruleName ?? ''
}' execution cancelled due to timeout - exceeded rule type timeout of ${
context.ruleType.ruleTaskTimeout
}`,
savedObjects: [
{
id: context.ruleId,
type: 'alert',
typeId: context.ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
],
ruleName: context.ruleName,
});
}
export function initializeExecuteRecord(context: RuleContext) {
return createAlertEventLogRecordObject({
ruleId: context.ruleId,
ruleType: context.ruleType,
consumer: context.consumer,
namespace: context.namespace,
spaceId: context.spaceId,
executionId: context.executionId,
action: EVENT_LOG_ACTIONS.execute,
task: {
scheduled: context.taskScheduledAt.toISOString(),
scheduleDelay: Millis2Nanos * context.taskScheduleDelay,
},
savedObjects: [
{
id: context.ruleId,
type: 'alert',
typeId: context.ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
],
});
}
interface UpdateEventOpts {
message?: string;
outcome?: string;
error?: string;
ruleName?: string;
status?: string;
reason?: string;
metrics?: RuleRunMetrics;
}
export function updateEvent(event: IEvent, opts: UpdateEventOpts) {
const { message, outcome, error, ruleName, status, reason, metrics } = opts;
if (!event) {
throw new Error('Cannot update event because it is not initialized.');
}
if (message) {
event.message = message;
}
if (outcome) {
event.event = event.event || {};
event.event.outcome = outcome;
}
if (error) {
event.error = event.error || {};
event.error.message = error;
}
if (ruleName) {
event.rule = {
...event.rule,
name: ruleName,
};
}
if (status) {
event.kibana = event.kibana || {};
event.kibana.alerting = event.kibana.alerting || {};
event.kibana.alerting.status = status;
}
if (reason) {
event.event = event.event || {};
event.event.reason = reason;
}
if (metrics) {
event.kibana = event.kibana || {};
event.kibana.alert = event.kibana.alert || {};
event.kibana.alert.rule = event.kibana.alert.rule || {};
event.kibana.alert.rule.execution = event.kibana.alert.rule.execution || {};
event.kibana.alert.rule.execution.metrics = {
number_of_triggered_actions: metrics.numberOfTriggeredActions
? metrics.numberOfTriggeredActions
: 0,
number_of_generated_actions: metrics.numberOfGeneratedActions
? metrics.numberOfGeneratedActions
: 0,
number_of_active_alerts: metrics.numberOfActiveAlerts ? metrics.numberOfActiveAlerts : 0,
number_of_new_alerts: metrics.numberOfNewAlerts ? metrics.numberOfNewAlerts : 0,
number_of_recovered_alerts: metrics.numberOfRecoveredAlerts
? metrics.numberOfRecoveredAlerts
: 0,
total_number_of_alerts:
(metrics.numberOfActiveAlerts ?? 0) + (metrics.numberOfRecoveredAlerts ?? 0),
number_of_searches: metrics.numSearches ? metrics.numSearches : 0,
es_search_duration_ms: metrics.esSearchDurationMs ? metrics.esSearchDurationMs : 0,
total_search_duration_ms: metrics.totalSearchDurationMs ? metrics.totalSearchDurationMs : 0,
};
}
}

71
x-pack/plugins/alerting/server/task_runner/create_execution_handler.test.ts
View file

@ -13,7 +13,6 @@ import {
actionsMock,
renderActionParameterTemplatesDefault,
} from '@kbn/actions-plugin/server/mocks';
import { eventLoggerMock } from '@kbn/event-log-plugin/server/event_logger.mock';
import { KibanaRequest } from '@kbn/core/server';
import { asSavedObjectExecutionSource } from '@kbn/actions-plugin/server';
import { InjectActionParamsOpts } from './inject_action_params';
@ -26,11 +25,14 @@ import {
RuleTypeState,
} from '../types';
import { RuleRunMetricsStore } from '../lib/rule_run_metrics_store';
import { alertingEventLoggerMock } from '../lib/alerting_event_logger/alerting_event_logger.mock';
jest.mock('./inject_action_params', () => ({
injectActionParams: jest.fn(),
}));
const alertingEventLogger = alertingEventLoggerMock.create();
const ruleType: NormalizedRuleType<
RuleTypeParams,
RuleTypeParams,
@ -60,7 +62,6 @@ const ruleType: NormalizedRuleType<
const actionsClient = actionsClientMock.create();
const mockActionsPlugin = actionsMock.createStart();
const mockEventLogger = eventLoggerMock.create();
const createExecutionHandlerParams: jest.Mocked<
CreateExecutionHandlerOptions<
RuleTypeParams,
@ -83,7 +84,7 @@ const createExecutionHandlerParams: jest.Mocked<
kibanaBaseUrl: 'http://localhost:5601',
ruleType,
logger: loggingSystemMock.create().get(),
eventLogger: mockEventLogger,
alertingEventLogger,
actions: [
{
id: '1',
@ -178,63 +179,13 @@ describe('Create Execution Handler', () => {
]
`);
expect(mockEventLogger.logEvent).toHaveBeenCalledTimes(1);
expect(mockEventLogger.logEvent.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
Object {
"event": Object {
"action": "execute-action",
"category": Array [
"alerts",
],
"kind": "alert",
},
"kibana": Object {
"alert": Object {
"rule": Object {
"consumer": "rule-consumer",
"execution": Object {
"uuid": "5f6aa57d-3e22-484e-bae8-cbed868f4d28",
},
"rule_type_id": "test",
},
},
"alerting": Object {
"action_group_id": "default",
"instance_id": "2",
},
"saved_objects": Array [
Object {
"id": "1",
"namespace": "test1",
"rel": "primary",
"type": "alert",
"type_id": "test",
},
Object {
"id": "1",
"namespace": "test1",
"type": "action",
"type_id": "test",
},
],
"space_ids": Array [
"test1",
],
},
"message": "alert: test:1: 'name-of-alert' instanceId: '2' scheduled actionGroup: 'default' action: test:1",
"rule": Object {
"category": "test",
"id": "1",
"license": "basic",
"name": "name-of-alert",
"ruleset": "alerts",
},
},
],
]
`);
expect(alertingEventLogger.logAction).toHaveBeenCalledTimes(1);
expect(alertingEventLogger.logAction).toHaveBeenNthCalledWith(1, {
id: '1',
typeId: 'test',
alertId: '2',
alertGroup: 'default',
});
expect(jest.requireMock('./inject_action_params').injectActionParams).toHaveBeenCalledWith({
ruleId: '1',

49
x-pack/plugins/alerting/server/task_runner/create_execution_handler.ts
View file

@ -5,10 +5,8 @@
* 2.0.
*/
import { asSavedObjectExecutionSource } from '@kbn/actions-plugin/server';
import { SAVED_OBJECT_REL_PRIMARY } from '@kbn/event-log-plugin/server';
import { isEphemeralTaskRejectedDueToCapacityError } from '@kbn/task-manager-plugin/server';
import { transformActionParams } from './transform_action_params';
import { EVENT_LOG_ACTIONS } from '../plugin';
import { injectActionParams } from './inject_action_params';
import {
ActionsCompletion,
@ -17,9 +15,6 @@ import {
RuleTypeParams,
RuleTypeState,
} from '../types';
import { UntypedNormalizedRuleType } from '../rule_type_registry';
import { createAlertEventLogRecordObject } from '../lib/create_alert_event_log_record_object';
import { CreateExecutionHandlerOptions, ExecutionHandlerOptions } from './types';
export type ExecutionHandler<ActionGroupIds extends string> = (
@ -47,7 +42,7 @@ export function createExecutionHandler<
apiKey,
ruleType,
kibanaBaseUrl,
eventLogger,
alertingEventLogger,
request,
ruleParams,
supportsEphemeralTasks,
@ -117,8 +112,6 @@ export function createExecutionHandler<
ruleRunMetricsStore.incrementNumberOfGeneratedActions(actions.length);
const ruleLabel = `${ruleType.id}:${ruleId}: '${ruleName}'`;
const actionsClient = await actionsPlugin.getActionsClientWithRequest(request);
let ephemeralActionsToSchedule = maxEphemeralActionsPerRule;
@ -189,8 +182,6 @@ export function createExecutionHandler<
],
};
// TODO would be nice to add the action name here, but it's not available
const actionLabel = `${actionTypeId}:${action.id}`;
if (supportsEphemeralTasks && ephemeralActionsToSchedule > 0) {
ephemeralActionsToSchedule--;
try {
@ -204,39 +195,13 @@ export function createExecutionHandler<
await actionsClient.enqueueExecution(enqueueOptions);
}
const event = createAlertEventLogRecordObject({
ruleId,
ruleType: ruleType as UntypedNormalizedRuleType,
consumer: ruleConsumer,
action: EVENT_LOG_ACTIONS.executeAction,
executionId,
spaceId,
instanceId: alertId,
group: actionGroup,
subgroup: actionSubgroup,
ruleName,
savedObjects: [
{
type: 'alert',
id: ruleId,
typeId: ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
{
type: 'action',
id: action.id,
typeId: actionTypeId,
},
],
...namespace,
message: `alert: ${ruleLabel} instanceId: '${alertId}' scheduled ${
actionSubgroup
? `actionGroup(subgroup): '${actionGroup}(${actionSubgroup})'`
: `actionGroup: '${actionGroup}'`
} action: ${actionLabel}`,
alertingEventLogger.logAction({
id: action.id,
typeId: actionTypeId,
alertId,
alertGroup: actionGroup,
alertSubgroup: actionSubgroup,
});
eventLogger.logEvent(event);
}
};
}

214
x-pack/plugins/alerting/server/task_runner/fixtures.ts
View file

@ -5,14 +5,8 @@
* 2.0.
*/
import { isNil } from 'lodash';
import { TaskStatus } from '@kbn/task-manager-plugin/server';
import {
Rule,
RuleExecutionStatusWarningReasons,
RuleTypeParams,
RecoveredActionGroup,
} from '../../common';
import { Rule, RuleTypeParams, RecoveredActionGroup } from '../../common';
import { getDefaultRuleMonitoring } from './task_runner';
import { UntypedNormalizedRuleType } from '../rule_type_registry';
import { EVENT_LOG_ACTIONS } from '../plugin';
@ -108,6 +102,8 @@ export const ruleType: jest.Mocked<UntypedNormalizedRuleType> = {
recoveryActionGroup: RecoveredActionGroup,
executor: jest.fn(),
producer: 'alerts',
cancelAlertsOnRuleTimeout: true,
ruleTaskTimeout: '5m',
};
export const mockRunNowResponse = {
@ -182,178 +178,45 @@ export const mockTaskInstance = () => ({
ownerId: null,
});
export const generateAlertSO = (id: string) => ({
id,
rel: 'primary',
type: 'alert',
type_id: RULE_TYPE_ID,
});
export const generateAlertOpts = ({ action, group, subgroup, state, id }: GeneratorParams = {}) => {
id = id ?? '1';
let message: string = '';
switch (action) {
case EVENT_LOG_ACTIONS.newInstance:
message = `test:1: 'rule-name' created new alert: '${id}'`;
break;
case EVENT_LOG_ACTIONS.activeInstance:
message = subgroup
? `test:1: 'rule-name' active alert: '${id}' in actionGroup(subgroup): 'default(${subgroup})'`
: `test:1: 'rule-name' active alert: '${id}' in actionGroup: 'default'`;
break;
case EVENT_LOG_ACTIONS.recoveredInstance:
message = `test:1: 'rule-name' alert '${id}' has recovered`;
break;
}
return {
action,
id,
message,
state,
...(group ? { group } : {}),
...(subgroup ? { subgroup } : {}),
};
};
export const generateActionSO = (id: string) => ({
export const generateActionOpts = ({
subgroup,
id,
namespace: undefined,
type: 'action',
type_id: 'action',
});
export const generateEventLog = ({
action,
task,
duration,
consumer,
start,
end,
outcome,
reason,
instanceId,
actionSubgroup,
actionGroupId,
actionId,
status,
numberOfTriggeredActions,
numberOfGeneratedActions,
numberOfActiveAlerts,
numberOfRecoveredAlerts,
numberOfNewAlerts,
savedObjects = [generateAlertSO('1')],
alertGroup,
alertId,
}: GeneratorParams = {}) => ({
...(status === 'error' && {
error: {
message: generateErrorMessage(String(reason)),
},
}),
event: {
action,
...(!isNil(duration) && { duration }),
...(start && { start }),
...(end && { end }),
...(outcome && { outcome }),
...(reason && { reason }),
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
...(consumer && { consumer }),
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
...((!isNil(numberOfTriggeredActions) || !isNil(numberOfGeneratedActions)) && {
metrics: {
number_of_triggered_actions: numberOfTriggeredActions,
number_of_generated_actions: numberOfGeneratedActions,
number_of_active_alerts: numberOfActiveAlerts ?? 0,
number_of_new_alerts: numberOfNewAlerts ?? 0,
number_of_recovered_alerts: numberOfRecoveredAlerts ?? 0,
total_number_of_alerts:
((numberOfActiveAlerts ?? 0) as number) +
((numberOfRecoveredAlerts ?? 0) as number),
number_of_searches: 3,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
}),
},
rule_type_id: 'test',
},
},
...((actionSubgroup || actionGroupId || instanceId || status) && {
alerting: {
...(actionSubgroup && { action_subgroup: actionSubgroup }),
...(actionGroupId && { action_group_id: actionGroupId }),
...(instanceId && { instance_id: instanceId }),
...(status && { status }),
},
}),
saved_objects: savedObjects,
space_ids: ['default'],
...(task && {
task: {
schedule_delay: 0,
scheduled: DATE_1970,
},
}),
},
message: generateMessage({
action,
instanceId,
actionGroupId,
actionSubgroup,
reason,
status,
actionId,
}),
rule: {
category: 'test',
id: '1',
license: 'basic',
...(hasRuleName({ action, status }) && { name: RULE_NAME }),
ruleset: 'alerts',
},
id: id ?? '1',
typeId: 'action',
alertId: alertId ?? '1',
alertGroup: alertGroup ?? 'default',
...(subgroup ? { alertSubgroup: subgroup } : {}),
});
const generateMessage = ({
action,
instanceId,
actionGroupId,
actionSubgroup,
actionId,
reason,
status,
}: GeneratorParams) => {
if (action === EVENT_LOG_ACTIONS.executeStart) {
return `rule execution start: "${mockTaskInstance().params.alertId}"`;
}
if (action === EVENT_LOG_ACTIONS.newInstance) {
return `${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' created new alert: '${instanceId}'`;
}
if (action === EVENT_LOG_ACTIONS.activeInstance) {
if (actionSubgroup) {
return `${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' active alert: '${instanceId}' in actionGroup(subgroup): 'default(${actionSubgroup})'`;
}
return `${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' active alert: '${instanceId}' in actionGroup: '${actionGroupId}'`;
}
if (action === EVENT_LOG_ACTIONS.recoveredInstance) {
return `${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' alert '${instanceId}' has recovered`;
}
if (action === EVENT_LOG_ACTIONS.executeAction) {
if (actionSubgroup) {
return `alert: ${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' instanceId: '${instanceId}' scheduled actionGroup(subgroup): 'default(${actionSubgroup})' action: action:${actionId}`;
}
return `alert: ${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}' instanceId: '${instanceId}' scheduled actionGroup: '${actionGroupId}' action: action:${actionId}`;
}
if (action === EVENT_LOG_ACTIONS.execute) {
if (status === 'error' && reason === 'execute') {
return `rule execution failure: ${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}'`;
}
if (status === 'error') {
return `${RULE_TYPE_ID}:${RULE_ID}: execution failed`;
}
if (actionGroupId === 'recovered') {
return `rule-name' instanceId: '${instanceId}' scheduled actionGroup: '${actionGroupId}' action: action:${actionId}`;
}
if (
status === 'warning' &&
reason === RuleExecutionStatusWarningReasons.MAX_EXECUTABLE_ACTIONS
) {
return `The maximum number of actions for this rule type was reached; excess actions were not triggered.`;
}
return `rule executed: ${RULE_TYPE_ID}:${RULE_ID}: '${RULE_NAME}'`;
}
};
const generateErrorMessage = (reason: string) => {
if (reason === 'disabled') {
return 'Rule failed to execute because rule ran after it was disabled.';
}
return GENERIC_ERROR_MESSAGE;
};
export const generateRunnerResult = ({
successRatio = 1,
history = Array(false),
@ -424,6 +287,3 @@ export const generateAlertInstance = ({ id, duration, start }: GeneratorParams =
},
},
});
const hasRuleName = ({ action, status }: GeneratorParams) => {
return action !== 'execute-start' && status !== 'error';
};

1317
x-pack/plugins/alerting/server/task_runner/task_runner.test.ts
View file

File diff suppressed because it is too large Load diff

320
x-pack/plugins/alerting/server/task_runner/task_runner.ts
View file

@ -5,19 +5,14 @@
* 2.0.
*/
import apm from 'elastic-apm-node';
import { cloneDeep, mapValues, omit, pickBy, set, without } from 'lodash';
import { cloneDeep, mapValues, omit, pickBy, without } from 'lodash';
import type { Request } from '@hapi/hapi';
import { UsageCounter } from '@kbn/usage-collection-plugin/server';
import uuid from 'uuid';
import { addSpaceIdToPath } from '@kbn/spaces-plugin/server';
import { KibanaRequest, Logger } from '@kbn/core/server';
import { ConcreteTaskInstance, throwUnrecoverableError } from '@kbn/task-manager-plugin/server';
import {
IEvent,
SAVED_OBJECT_REL_PRIMARY,
millisToNanos,
nanosToMillis,
} from '@kbn/event-log-plugin/server';
import { millisToNanos, nanosToMillis } from '@kbn/event-log-plugin/server';
import { TaskRunnerContext } from './task_runner_factory';
import { createExecutionHandler, ExecutionHandler } from './create_execution_handler';
import { Alert, createAlertFactory } from '../alert';
@ -62,10 +57,6 @@ import {
} from '../../common';
import { NormalizedRuleType, UntypedNormalizedRuleType } from '../rule_type_registry';
import { getEsErrorMessage } from '../lib/errors';
import {
createAlertEventLogRecordObject,
Event,
} from '../lib/create_alert_event_log_record_object';
import { InMemoryMetrics, IN_MEMORY_METRICS } from '../monitoring';
import {
GenerateNewAndRecoveredAlertEventsParams,
@ -79,13 +70,11 @@ import {
} from './types';
import { IExecutionStatusAndMetrics } from '../lib/rule_execution_status';
import { RuleRunMetricsStore } from '../lib/rule_run_metrics_store';
import { AlertingEventLogger } from '../lib/alerting_event_logger/alerting_event_logger';
const FALLBACK_RETRY_INTERVAL = '5m';
const CONNECTIVITY_RETRY_INTERVAL = '5m';
// 1,000,000 nanoseconds in 1 millisecond
const Millis2Nanos = 1000 * 1000;
export const getDefaultRuleMonitoring = (): RuleMonitoring => ({
execution: {
history: [],
@ -107,7 +96,6 @@ export class TaskRunner<
private context: TaskRunnerContext;
private logger: Logger;
private taskInstance: RuleTaskInstance;
private ruleName: string | null;
private ruleConsumer: string | null;
private ruleType: NormalizedRuleType<
Params,
@ -121,6 +109,7 @@ export class TaskRunner<
private readonly executionId: string;
private readonly ruleTypeRegistry: RuleTypeRegistry;
private readonly inMemoryMetrics: InMemoryMetrics;
private alertingEventLogger: AlertingEventLogger;
private usageCounter?: UsageCounter;
private searchAbortController: AbortController;
private cancelled: boolean;
@ -143,7 +132,6 @@ export class TaskRunner<
this.logger = context.logger;
this.usageCounter = context.usageCounter;
this.ruleType = ruleType;
this.ruleName = null;
this.ruleConsumer = null;
this.taskInstance = taskInstanceToAlertTaskInstance(taskInstance);
this.ruleTypeRegistry = context.ruleTypeRegistry;
@ -151,6 +139,7 @@ export class TaskRunner<
this.cancelled = false;
this.executionId = uuid.v4();
this.inMemoryMetrics = inMemoryMetrics;
this.alertingEventLogger = new AlertingEventLogger(this.context.eventLogger);
}
private async getDecryptedAttributes(
@ -231,7 +220,7 @@ export class TaskRunner<
spaceId,
ruleType: this.ruleType,
kibanaBaseUrl,
eventLogger: this.context.eventLogger,
alertingEventLogger: this.alertingEventLogger,
request,
ruleParams,
supportsEphemeralTasks: this.context.supportsEphemeralTasks,
@ -321,8 +310,7 @@ export class TaskRunner<
rule: SanitizedRule<Params>,
params: Params,
executionHandler: ExecutionHandler<ActionGroupIds | RecoveryActionGroupId>,
spaceId: string,
event: Event
spaceId: string
): Promise<RuleTaskStateAndMetrics> {
const {
alertTypeId,
@ -358,7 +346,6 @@ export class TaskRunner<
const originalAlerts = cloneDeep(alerts);
const originalAlertIds = new Set(Object.keys(originalAlerts));
const eventLogger = this.context.eventLogger;
const ruleLabel = `${this.ruleType.id}:${ruleId}: '${name}'`;
const scopedClusterClient = this.context.elasticsearch.client.asScoped(fakeRequest);
@ -440,22 +427,15 @@ export class TaskRunner<
})
);
} catch (err) {
event.message = `rule execution failure: ${ruleLabel}`;
event.error = event.error || {};
event.error.message = err.message;
event.event = event.event || {};
event.event.outcome = 'failure';
this.alertingEventLogger.setExecutionFailed(
`rule execution failure: ${ruleLabel}`,
err.message
);
throw new ErrorWithReason(RuleExecutionStatusErrorReasons.Execute, err);
}
event.message = `rule executed: ${ruleLabel}`;
event.event = event.event || {};
event.event.outcome = 'success';
event.rule = {
...event.rule,
name: rule.name,
};
this.alertingEventLogger.setExecutionSucceeded(`rule executed: ${ruleLabel}`);
const ruleRunMetricsStore = new RuleRunMetricsStore();
@ -488,17 +468,11 @@ export class TaskRunner<
if (this.shouldLogAndScheduleActionsForAlerts()) {
generateNewAndRecoveredAlertEvents({
eventLogger,
executionId: this.executionId,
alertingEventLogger: this.alertingEventLogger,
originalAlerts,
currentAlerts: alertsWithScheduledActions,
recoveredAlerts,
ruleId,
ruleLabel,
namespace,
ruleType,
rule,
spaceId,
ruleRunMetricsStore,
});
}
@ -584,8 +558,7 @@ export class TaskRunner<
private async validateAndExecuteRule(
fakeRequest: KibanaRequest,
apiKey: RawRule['apiKey'],
rule: SanitizedRule<Params>,
event: Event
rule: SanitizedRule<Params>
) {
const {
params: { alertId: ruleId, spaceId },
@ -604,10 +577,10 @@ export class TaskRunner<
rule.params,
fakeRequest
);
return this.executeRule(fakeRequest, rule, validatedParams, executionHandler, spaceId, event);
return this.executeRule(fakeRequest, rule, validatedParams, executionHandler, spaceId);
}
private async loadRuleAttributesAndRun(event: Event): Promise<Resultable<RuleRunResult, Error>> {
private async loadRuleAttributesAndRun(): Promise<Resultable<RuleRunResult, Error>> {
const {
params: { alertId: ruleId, spaceId },
} = this.taskInstance;
@ -657,7 +630,7 @@ export class TaskRunner<
throw new ErrorWithReason(RuleExecutionStatusErrorReasons.Read, err);
}
this.ruleName = rule.name;
this.alertingEventLogger.setRuleName(rule.name);
try {
this.ruleTypeRegistry.ensureRuleTypeEnabled(rule.alertTypeId);
@ -674,7 +647,7 @@ export class TaskRunner<
return {
monitoring: asOk(rule.monitoring),
stateWithMetrics: await promiseResult<RuleTaskStateAndMetrics, Error>(
this.validateAndExecuteRule(fakeRequest, apiKey, rule, event)
this.validateAndExecuteRule(fakeRequest, apiKey, rule)
),
schedule: asOk(
// fetch the rule again to ensure we return the correct schedule as it may have
@ -716,46 +689,21 @@ export class TaskRunner<
this.logger.debug(`executing rule ${this.ruleType.id}:${ruleId} at ${runDateString}`);
const namespace = this.context.spaceIdToNamespace(spaceId);
const eventLogger = this.context.eventLogger;
const scheduleDelay = runDate.getTime() - this.taskInstance.scheduledAt.getTime();
const event = createAlertEventLogRecordObject({
this.alertingEventLogger.initialize({
ruleId,
ruleType: this.ruleType as UntypedNormalizedRuleType,
consumer: this.ruleConsumer!,
action: EVENT_LOG_ACTIONS.execute,
namespace,
spaceId,
executionId: this.executionId,
task: {
scheduled: this.taskInstance.scheduledAt.toISOString(),
scheduleDelay: Millis2Nanos * scheduleDelay,
},
savedObjects: [
{
id: ruleId,
type: 'alert',
typeId: this.ruleType.id,
relation: SAVED_OBJECT_REL_PRIMARY,
},
],
taskScheduledAt: this.taskInstance.scheduledAt,
...(namespace ? { namespace } : {}),
});
eventLogger.startTiming(event);
const startEvent = cloneDeep({
...event,
event: {
...event.event,
action: EVENT_LOG_ACTIONS.executeStart,
},
message: `rule execution start: "${ruleId}"`,
});
eventLogger.logEvent(startEvent);
this.alertingEventLogger.start();
const { stateWithMetrics, schedule, monitoring } = await errorAsRuleTaskRunResult(
this.loadRuleAttributesAndRun(event)
this.loadRuleAttributesAndRun()
);
const ruleMonitoring =
@ -772,10 +720,6 @@ export class TaskRunner<
(ruleRunStateWithMetrics) => executionStatusFromState(ruleRunStateWithMetrics, runDate),
(err: ElasticsearchError) => executionStatusFromError(err, runDate)
);
// set the executionStatus date to same as event, if it's set
if (event.event?.start) {
executionStatus.lastExecutionDate = new Date(event.event.start);
}
if (apm.currentTransaction) {
if (executionStatus.status === 'ok' || executionStatus.status === 'active') {
@ -794,91 +738,27 @@ export class TaskRunner<
);
}
eventLogger.stopTiming(event);
set(event, 'kibana.alerting.status', executionStatus.status);
if (this.ruleConsumer) {
set(event, 'kibana.alert.rule.consumer', this.ruleConsumer);
}
this.alertingEventLogger.done({ status: executionStatus, metrics: executionMetrics });
const monitoringHistory: RuleMonitoringHistory = {
success: true,
timestamp: +new Date(),
};
// Copy duration into execution status if available
if (null != event.event?.duration) {
executionStatus.lastDuration = nanosToMillis(event.event?.duration);
// set start and duration based on event log
const { start, duration } = this.alertingEventLogger.getStartAndDuration();
if (null != start) {
executionStatus.lastExecutionDate = start;
}
if (null != duration) {
executionStatus.lastDuration = nanosToMillis(duration);
monitoringHistory.duration = executionStatus.lastDuration;
}
// if executionStatus indicates an error, fill in fields in
// event from it
if (executionStatus.error) {
set(event, 'event.reason', executionStatus.error?.reason || 'unknown');
set(event, 'event.outcome', 'failure');
set(event, 'error.message', event?.error?.message || executionStatus.error.message);
if (!event.message) {
event.message = `${this.ruleType.id}:${ruleId}: execution failed`;
}
monitoringHistory.success = false;
} else {
if (executionStatus.warning) {
set(event, 'event.reason', executionStatus.warning?.reason || 'unknown');
set(event, 'message', executionStatus.warning?.message || event?.message);
}
if (executionMetrics) {
set(
event,
'kibana.alert.rule.execution.metrics.number_of_triggered_actions',
executionMetrics.numberOfTriggeredActions
);
set(
event,
'kibana.alert.rule.execution.metrics.number_of_generated_actions',
executionMetrics.numberOfGeneratedActions
);
set(
event,
'kibana.alert.rule.execution.metrics.number_of_active_alerts',
executionMetrics.numberOfActiveAlerts
);
set(
event,
'kibana.alert.rule.execution.metrics.number_of_new_alerts',
executionMetrics.numberOfNewAlerts
);
set(
event,
'kibana.alert.rule.execution.metrics.total_number_of_alerts',
(executionMetrics.numberOfActiveAlerts ?? 0) +
(executionMetrics.numberOfRecoveredAlerts ?? 0)
);
set(
event,
'kibana.alert.rule.execution.metrics.number_of_recovered_alerts',
executionMetrics.numberOfRecoveredAlerts
);
}
}
// Copy search stats into event log
if (executionMetrics) {
set(
event,
'kibana.alert.rule.execution.metrics.number_of_searches',
executionMetrics.numSearches ?? 0
);
set(
event,
'kibana.alert.rule.execution.metrics.es_search_duration_ms',
executionMetrics.esSearchDurationMs ?? 0
);
set(
event,
'kibana.alert.rule.execution.metrics.total_search_duration_ms',
executionMetrics.totalSearchDurationMs ?? 0
);
}
ruleMonitoring.execution.history.push(monitoringHistory);
@ -887,8 +767,6 @@ export class TaskRunner<
...getExecutionDurationPercentiles(ruleMonitoring),
};
eventLogger.logEvent(event);
if (!this.cancelled) {
this.inMemoryMetrics.increment(IN_MEMORY_METRICS.RULE_EXECUTIONS);
if (executionStatus.error) {
@ -982,48 +860,7 @@ export class TaskRunner<
);
this.searchAbortController.abort();
const eventLogger = this.context.eventLogger;
const event: IEvent = {
event: {
action: EVENT_LOG_ACTIONS.executeTimeout,
kind: 'alert',
category: [this.ruleType.producer],
},
message: `rule: ${this.ruleType.id}:${ruleId}: '${
this.ruleName ?? ''
}' execution cancelled due to timeout - exceeded rule type timeout of ${
this.ruleType.ruleTaskTimeout
}`,
kibana: {
alert: {
rule: {
...(this.ruleConsumer ? { consumer: this.ruleConsumer } : {}),
execution: {
uuid: this.executionId,
},
rule_type_id: this.ruleType.id,
},
},
saved_objects: [
{
rel: SAVED_OBJECT_REL_PRIMARY,
type: 'alert',
id: ruleId,
type_id: this.ruleType.id,
namespace,
},
],
space_ids: [spaceId],
},
rule: {
id: ruleId,
license: this.ruleType.minimumLicenseRequired,
category: this.ruleType.id,
ruleset: this.ruleType.producer,
...(this.ruleName ? { name: this.ruleName } : {}),
},
};
eventLogger.logEvent(event);
this.alertingEventLogger.logTimeout();
this.inMemoryMetrics.increment(IN_MEMORY_METRICS.RULE_TIMEOUTS);
@ -1096,16 +933,10 @@ function generateNewAndRecoveredAlertEvents<
InstanceContext extends AlertInstanceContext
>(params: GenerateNewAndRecoveredAlertEventsParams<InstanceState, InstanceContext>) {
const {
eventLogger,
executionId,
ruleId,
namespace,
alertingEventLogger,
currentAlerts,
originalAlerts,
recoveredAlerts,
rule,
ruleType,
spaceId,
ruleRunMetricsStore,
} = params;
const originalAlertIds = Object.keys(originalAlerts);
@ -1128,14 +959,15 @@ function generateNewAndRecoveredAlertEvents<
recoveredAlerts[id].getLastScheduledActions() ?? {};
const state = recoveredAlerts[id].getState();
const message = `${params.ruleLabel} alert '${id}' has recovered`;
logAlertEvent(
alertingEventLogger.logAlert({
action: EVENT_LOG_ACTIONS.recoveredInstance,
id,
EVENT_LOG_ACTIONS.recoveredInstance,
group: actionGroup,
subgroup: actionSubgroup,
message,
state,
actionGroup,
actionSubgroup
);
});
}
for (const id of newIds) {
@ -1143,7 +975,14 @@ function generateNewAndRecoveredAlertEvents<
currentAlerts[id].getScheduledActionOptions() ?? {};
const state = currentAlerts[id].getState();
const message = `${params.ruleLabel} created new alert: '${id}'`;
logAlertEvent(id, EVENT_LOG_ACTIONS.newInstance, message, state, actionGroup, actionSubgroup);
alertingEventLogger.logAlert({
action: EVENT_LOG_ACTIONS.newInstance,
id,
group: actionGroup,
subgroup: actionSubgroup,
message,
state,
});
}
for (const id of currentAlertIds) {
@ -1155,69 +994,14 @@ function generateNewAndRecoveredAlertEvents<
? `actionGroup(subgroup): '${actionGroup}(${actionSubgroup})'`
: `actionGroup: '${actionGroup}'`
}`;
logAlertEvent(
alertingEventLogger.logAlert({
action: EVENT_LOG_ACTIONS.activeInstance,
id,
EVENT_LOG_ACTIONS.activeInstance,
group: actionGroup,
subgroup: actionSubgroup,
message,
state,
actionGroup,
actionSubgroup
);
}
function logAlertEvent(
alertId: string,
action: string,
message: string,
state: InstanceState,
group?: string,
subgroup?: string
) {
const event: IEvent = {
event: {
action,
kind: 'alert',
category: [ruleType.producer],
...(state?.start ? { start: state.start as string } : {}),
...(state?.end ? { end: state.end as string } : {}),
...(state?.duration !== undefined ? { duration: state.duration as string } : {}),
},
kibana: {
alert: {
rule: {
consumer: rule.consumer,
execution: {
uuid: executionId,
},
rule_type_id: ruleType.id,
},
},
alerting: {
instance_id: alertId,
...(group ? { action_group_id: group } : {}),
...(subgroup ? { action_subgroup: subgroup } : {}),
},
saved_objects: [
{
rel: SAVED_OBJECT_REL_PRIMARY,
type: 'alert',
id: ruleId,
type_id: ruleType.id,
namespace,
},
],
space_ids: [spaceId],
},
message,
rule: {
id: rule.id,
license: ruleType.minimumLicenseRequired,
category: ruleType.id,
ruleset: ruleType.producer,
name: rule.name,
},
};
eventLogger.logEvent(event);
});
}
}

788
x-pack/plugins/alerting/server/task_runner/task_runner_cancel.test.ts
View file

@ -14,7 +14,7 @@ import {
AlertInstanceState,
AlertInstanceContext,
} from '../types';
import { ConcreteTaskInstance, TaskStatus } from '@kbn/task-manager-plugin/server';
import { ConcreteTaskInstance } from '@kbn/task-manager-plugin/server';
import { TaskRunnerContext } from './task_runner_factory';
import { TaskRunner } from './task_runner';
import { encryptedSavedObjectsMock } from '@kbn/encrypted-saved-objects-plugin/server/mocks';
@ -32,11 +32,23 @@ import { actionsMock, actionsClientMock } from '@kbn/actions-plugin/server/mocks
import { alertsMock, rulesClientMock } from '../mocks';
import { eventLoggerMock } from '@kbn/event-log-plugin/server/event_logger.mock';
import { IEventLogger } from '@kbn/event-log-plugin/server';
import { Rule, RecoveredActionGroup } from '../../common';
import { UntypedNormalizedRuleType } from '../rule_type_registry';
import { ruleTypeRegistryMock } from '../rule_type_registry.mock';
import { dataPluginMock } from '@kbn/data-plugin/server/mocks';
import { inMemoryMetricsMock } from '../monitoring/in_memory_metrics.mock';
import {
AlertingEventLogger,
RuleContextOpts,
} from '../lib/alerting_event_logger/alerting_event_logger';
import { alertingEventLoggerMock } from '../lib/alerting_event_logger/alerting_event_logger.mock';
import {
mockTaskInstance,
ruleType,
mockedRuleTypeSavedObject,
generateAlertOpts,
DATE_1970,
generateActionOpts,
} from './fixtures';
import { EVENT_LOG_ACTIONS } from '../plugin';
jest.mock('uuid', () => ({
v4: () => '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
@ -45,48 +57,29 @@ jest.mock('../lib/wrap_scoped_cluster_client', () => ({
createWrappedScopedClusterClientFactory: jest.fn(),
}));
const ruleType: jest.Mocked<UntypedNormalizedRuleType> = {
id: 'test',
name: 'My test rule',
actionGroups: [{ id: 'default', name: 'Default' }, RecoveredActionGroup],
defaultActionGroupId: 'default',
minimumLicenseRequired: 'basic',
isExportable: true,
recoveryActionGroup: RecoveredActionGroup,
executor: jest.fn(),
producer: 'alerts',
cancelAlertsOnRuleTimeout: true,
ruleTaskTimeout: '5m',
};
jest.mock('../lib/alerting_event_logger/alerting_event_logger');
let fakeTimer: sinon.SinonFakeTimers;
const mockUsageCountersSetup = usageCountersServiceMock.createSetupContract();
const mockUsageCounter = mockUsageCountersSetup.createUsageCounter('test');
const alertingEventLogger = alertingEventLoggerMock.create();
describe('Task Runner Cancel', () => {
let mockedTaskInstance: ConcreteTaskInstance;
let alertingEventLoggerInitializer: RuleContextOpts;
beforeAll(() => {
fakeTimer = sinon.useFakeTimers();
mockedTaskInstance = {
id: '',
attempts: 0,
status: TaskStatus.Running,
version: '123',
runAt: new Date(),
schedule: { interval: '10s' },
scheduledAt: new Date(),
startedAt: new Date(),
retryAt: new Date(Date.now() + 5 * 60 * 1000),
state: {},
taskType: 'alerting:test',
params: {
alertId: '1',
spaceId: 'default',
consumer: 'bar',
},
ownerId: null,
mockedTaskInstance = mockTaskInstance();
alertingEventLoggerInitializer = {
consumer: mockedTaskInstance.params.consumer,
executionId: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
ruleId: mockedTaskInstance.params.alertId,
ruleType,
spaceId: mockedTaskInstance.params.spaceId,
taskScheduledAt: mockedTaskInstance.scheduledAt,
};
});
@ -136,53 +129,6 @@ describe('Task Runner Cancel', () => {
},
};
const mockDate = new Date('2019-02-12T21:01:22.479Z');
const mockedRuleSavedObject: Rule<RuleTypeParams> = {
id: '1',
consumer: 'bar',
createdAt: mockDate,
updatedAt: mockDate,
throttle: null,
muteAll: false,
notifyWhen: 'onActiveAlert',
enabled: true,
alertTypeId: ruleType.id,
apiKey: '',
apiKeyOwner: 'elastic',
schedule: { interval: '10s' },
name: 'rule-name',
tags: ['rule-', '-tags'],
createdBy: 'rule-creator',
updatedBy: 'rule-updater',
mutedInstanceIds: [],
params: {
bar: true,
},
actions: [
{
group: 'default',
id: '1',
actionTypeId: 'action',
params: {
foo: true,
},
},
{
group: RecoveredActionGroup.id,
id: '2',
actionTypeId: 'action',
params: {
isResolved: true,
},
},
],
executionStatus: {
status: 'unknown',
lastExecutionDate: new Date('2020-08-20T19:23:38Z'),
},
};
beforeEach(() => {
jest.resetAllMocks();
jest
@ -208,7 +154,7 @@ describe('Task Runner Cancel', () => {
taskRunnerFactoryInitializerParams.executionContext.withContext.mockImplementation((ctx, fn) =>
fn()
);
rulesClient.get.mockResolvedValue(mockedRuleSavedObject);
rulesClient.get.mockResolvedValue(mockedRuleTypeSavedObject);
encryptedSavedObjectsClient.getDecryptedAsInternalUser.mockResolvedValueOnce({
id: '1',
type: 'alert',
@ -221,6 +167,8 @@ describe('Task Runner Cancel', () => {
});
taskRunnerFactoryInitializerParams.actionsPlugin.isActionTypeEnabled.mockReturnValue(true);
taskRunnerFactoryInitializerParams.actionsPlugin.isActionExecutable.mockReturnValue(true);
alertingEventLogger.getStartAndDuration.mockImplementation(() => ({ start: new Date() }));
(AlertingEventLogger as jest.Mock).mockImplementation(() => alertingEventLogger);
});
test('updates rule saved object execution status and writes to event log entry when task is cancelled mid-execution', async () => {
@ -230,6 +178,7 @@ describe('Task Runner Cancel', () => {
taskRunnerFactoryInitializerParams,
inMemoryMetrics
);
expect(AlertingEventLogger).toHaveBeenCalledTimes(1);
const promise = taskRunner.run();
await Promise.resolve();
@ -242,136 +191,7 @@ describe('Task Runner Cancel', () => {
`Aborting any in-progress ES searches for rule type test with id 1`
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
// execute-start event, timeout event and then an execute event because rule executors are not cancelling anything yet
expect(eventLogger.logEvent).toHaveBeenCalledTimes(3);
expect(eventLogger.startTiming).toHaveBeenCalledTimes(1);
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(1, {
event: {
action: 'execute-start',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
saved_objects: [
{
id: '1',
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
},
message: 'rule execution start: "1"',
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(2, {
event: {
action: 'execute-timeout',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
saved_objects: [
{
id: '1',
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: `rule: test:1: '' execution cancelled due to timeout - exceeded rule type timeout of 5m`,
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(3, {
event: {
action: 'execute',
category: ['alerts'],
kind: 'alert',
outcome: 'success',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 0,
number_of_generated_actions: 0,
number_of_active_alerts: 0,
number_of_new_alerts: 0,
number_of_recovered_alerts: 0,
total_number_of_alerts: 0,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
status: 'ok',
},
saved_objects: [
{
id: '1',
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
},
message: `rule executed: test:1: 'rule-name'`,
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
ruleset: 'alerts',
},
});
testAlertingEventLogCalls({ status: 'ok' });
expect(
taskRunnerFactoryInitializerParams.internalSavedObjectsRepository.update
@ -426,22 +246,50 @@ describe('Task Runner Cancel', () => {
},
inMemoryMetrics
);
expect(AlertingEventLogger).toHaveBeenCalledTimes(1);
const promise = taskRunner.run();
await Promise.resolve();
await taskRunner.cancel();
await promise;
testActionsExecute();
testLogger();
testAlertingEventLogCalls({
status: 'active',
newAlerts: 1,
activeAlerts: 1,
generatedActions: 1,
triggeredActions: 1,
logAction: 1,
logAlert: 2,
});
expect(alertingEventLogger.logAlert).toHaveBeenNthCalledWith(
1,
generateAlertOpts({
action: EVENT_LOG_ACTIONS.newInstance,
group: 'default',
state: { start: DATE_1970, duration: '0' },
})
);
expect(alertingEventLogger.logAlert).toHaveBeenNthCalledWith(
2,
generateAlertOpts({
action: EVENT_LOG_ACTIONS.activeInstance,
group: 'default',
state: { start: DATE_1970, duration: '0' },
})
);
expect(alertingEventLogger.logAction).toHaveBeenNthCalledWith(1, generateActionOpts({}));
expect(mockUsageCounter.incrementCounter).not.toHaveBeenCalled();
});
test('actionsPlugin.execute is called if rule execution is cancelled but cancelAlertsOnRuleTimeout for ruleType is false', async () => {
ruleTypeRegistry.get.mockReturnValue({
const updatedRuleType = {
...ruleType,
cancelAlertsOnRuleTimeout: false,
});
};
ruleTypeRegistry.get.mockReturnValue(updatedRuleType);
ruleType.executor.mockImplementation(
async ({
services: executorServices,
@ -457,21 +305,47 @@ describe('Task Runner Cancel', () => {
);
// setting cancelAlertsOnRuleTimeout for ruleType to false here
const taskRunner = new TaskRunner(
{
...ruleType,
cancelAlertsOnRuleTimeout: false,
},
updatedRuleType,
mockedTaskInstance,
taskRunnerFactoryInitializerParams,
inMemoryMetrics
);
expect(AlertingEventLogger).toHaveBeenCalledTimes(1);
const promise = taskRunner.run();
await Promise.resolve();
await taskRunner.cancel();
await promise;
testActionsExecute();
testLogger();
testAlertingEventLogCalls({
ruleContext: { ...alertingEventLoggerInitializer, ruleType: updatedRuleType },
status: 'active',
activeAlerts: 1,
generatedActions: 1,
newAlerts: 1,
triggeredActions: 1,
logAlert: 2,
logAction: 1,
});
expect(alertingEventLogger.logAlert).toHaveBeenNthCalledWith(
1,
generateAlertOpts({
action: EVENT_LOG_ACTIONS.newInstance,
group: 'default',
state: { start: DATE_1970, duration: '0' },
})
);
expect(alertingEventLogger.logAlert).toHaveBeenNthCalledWith(
2,
generateAlertOpts({
action: EVENT_LOG_ACTIONS.activeInstance,
group: 'default',
state: { start: DATE_1970, duration: '0' },
})
);
expect(alertingEventLogger.logAction).toHaveBeenNthCalledWith(1, generateActionOpts({}));
expect(mockUsageCounter.incrementCounter).not.toHaveBeenCalled();
});
@ -496,174 +370,15 @@ describe('Task Runner Cancel', () => {
taskRunnerFactoryInitializerParams,
inMemoryMetrics
);
expect(AlertingEventLogger).toHaveBeenCalledTimes(1);
const promise = taskRunner.run();
await Promise.resolve();
await taskRunner.cancel();
await promise;
const logger = taskRunnerFactoryInitializerParams.logger;
expect(logger.debug).toHaveBeenCalledTimes(8);
expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z');
expect(logger.debug).nthCalledWith(
2,
`Cancelling rule type test with id 1 - execution exceeded rule type timeout of 5m`
);
expect(logger.debug).nthCalledWith(
3,
'Aborting any in-progress ES searches for rule type test with id 1'
);
expect(logger.debug).nthCalledWith(
4,
`Updating rule task for test rule with id 1 - execution error due to timeout`
);
expect(logger.debug).nthCalledWith(
5,
`rule test:1: 'rule-name' has 1 active alerts: [{\"instanceId\":\"1\",\"actionGroup\":\"default\"}]`
);
expect(logger.debug).nthCalledWith(
6,
`no scheduling of actions for rule test:1: 'rule-name': rule execution has been cancelled.`
);
expect(logger.debug).nthCalledWith(
7,
'ruleRunStatus for test:1: {"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}'
);
expect(logger.debug).nthCalledWith(
8,
'ruleRunMetrics for test:1: {"numSearches":3,"totalSearchDurationMs":23423,"esSearchDurationMs":33,"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"numberOfActiveAlerts":0,"numberOfRecoveredAlerts":0,"numberOfNewAlerts":0,"triggeredActionsStatus":"complete"}'
);
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
expect(eventLogger.startTiming).toHaveBeenCalledTimes(1);
expect(eventLogger.logEvent).toHaveBeenCalledTimes(3);
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(1, {
event: {
action: 'execute-start',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [
{
id: '1',
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: `rule execution start: \"1\"`,
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(2, {
event: {
action: 'execute-timeout',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: `rule: test:1: '' execution cancelled due to timeout - exceeded rule type timeout of 5m`,
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(3, {
event: {
action: 'execute',
category: ['alerts'],
kind: 'alert',
outcome: 'success',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 0,
number_of_generated_actions: 0,
number_of_active_alerts: 0,
number_of_recovered_alerts: 0,
number_of_new_alerts: 0,
total_number_of_alerts: 0,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
status: 'active',
},
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: "rule executed: test:1: 'rule-name'",
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
ruleset: 'alerts',
},
testAlertingEventLogCalls({
status: 'active',
});
expect(mockUsageCounter.incrementCounter).toHaveBeenCalledTimes(1);
@ -673,7 +388,7 @@ describe('Task Runner Cancel', () => {
});
});
function testActionsExecute() {
function testLogger() {
const logger = taskRunnerFactoryInitializerParams.logger;
expect(logger.debug).toHaveBeenCalledTimes(7);
expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z');
@ -701,256 +416,69 @@ describe('Task Runner Cancel', () => {
7,
'ruleRunMetrics for test:1: {"numSearches":3,"totalSearchDurationMs":23423,"esSearchDurationMs":33,"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"numberOfActiveAlerts":1,"numberOfRecoveredAlerts":0,"numberOfNewAlerts":1,"triggeredActionsStatus":"complete"}'
);
}
const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;
expect(eventLogger.logEvent).toHaveBeenCalledTimes(6);
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(1, {
event: {
action: 'execute-start',
category: ['alerts'],
kind: 'alert',
function testAlertingEventLogCalls({
ruleContext = alertingEventLoggerInitializer,
activeAlerts = 0,
newAlerts = 0,
recoveredAlerts = 0,
triggeredActions = 0,
generatedActions = 0,
status,
logAlert = 0,
logAction = 0,
}: {
status: string;
ruleContext?: RuleContextOpts;
activeAlerts?: number;
newAlerts?: number;
recoveredAlerts?: number;
triggeredActions?: number;
generatedActions?: number;
setRuleName?: boolean;
logAlert?: number;
logAction?: number;
}) {
expect(alertingEventLogger.initialize).toHaveBeenCalledWith(ruleContext);
expect(alertingEventLogger.start).toHaveBeenCalled();
expect(alertingEventLogger.setRuleName).toHaveBeenCalledWith(mockedRuleTypeSavedObject.name);
expect(alertingEventLogger.getStartAndDuration).toHaveBeenCalled();
expect(alertingEventLogger.done).toHaveBeenCalledWith({
metrics: {
esSearchDurationMs: 33,
numSearches: 3,
numberOfActiveAlerts: activeAlerts,
numberOfGeneratedActions: generatedActions,
numberOfNewAlerts: newAlerts,
numberOfRecoveredAlerts: recoveredAlerts,
numberOfTriggeredActions: triggeredActions,
totalSearchDurationMs: 23423,
triggeredActionsStatus: 'complete',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: `rule execution start: "1"`,
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(2, {
event: {
action: 'execute-timeout',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: `rule: test:1: '' execution cancelled due to timeout - exceeded rule type timeout of 5m`,
rule: {
category: 'test',
id: '1',
license: 'basic',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(3, {
event: {
action: 'new-instance',
category: ['alerts'],
kind: 'alert',
duration: '0',
start: '1970-01-01T00:00:00.000Z',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
action_group_id: 'default',
instance_id: '1',
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: "test:1: 'rule-name' created new alert: '1'",
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
namespace: undefined,
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(4, {
event: {
action: 'active-instance',
category: ['alerts'],
duration: '0',
kind: 'alert',
start: '1970-01-01T00:00:00.000Z',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
action_group_id: 'default',
instance_id: '1',
},
saved_objects: [
{ id: '1', namespace: undefined, rel: 'primary', type: 'alert', type_id: 'test' },
],
space_ids: ['default'],
},
message: "test:1: 'rule-name' active alert: '1' in actionGroup: 'default'",
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(5, {
event: {
action: 'execute-action',
category: ['alerts'],
kind: 'alert',
},
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
instance_id: '1',
action_group_id: 'default',
},
saved_objects: [
{
id: '1',
rel: 'primary',
type: 'alert',
type_id: 'test',
},
{
id: '1',
type: 'action',
type_id: 'action',
},
],
space_ids: ['default'],
},
message:
"alert: test:1: 'rule-name' instanceId: '1' scheduled actionGroup: 'default' action: action:1",
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
ruleset: 'alerts',
},
});
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(6, {
event: { action: 'execute', category: ['alerts'], kind: 'alert', outcome: 'success' },
kibana: {
alert: {
rule: {
consumer: 'bar',
execution: {
metrics: {
number_of_searches: 3,
number_of_triggered_actions: 1,
number_of_generated_actions: 1,
number_of_active_alerts: 1,
number_of_new_alerts: 1,
number_of_recovered_alerts: 0,
total_number_of_alerts: 1,
es_search_duration_ms: 33,
total_search_duration_ms: 23423,
},
uuid: '5f6aa57d-3e22-484e-bae8-cbed868f4d28',
},
rule_type_id: 'test',
},
},
alerting: {
status: 'active',
},
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [
{
id: '1',
namespace: undefined,
rel: 'primary',
type: 'alert',
type_id: 'test',
},
],
space_ids: ['default'],
},
message: "rule executed: test:1: 'rule-name'",
rule: {
category: 'test',
id: '1',
license: 'basic',
name: 'rule-name',
ruleset: 'alerts',
status: {
lastExecutionDate: new Date('1970-01-01T00:00:00.000Z'),
status,
},
});
expect(alertingEventLogger.setExecutionSucceeded).toHaveBeenCalledWith(
`rule executed: test:1: 'rule-name'`
);
expect(alertingEventLogger.setExecutionFailed).not.toHaveBeenCalled();
if (logAlert > 0) {
expect(alertingEventLogger.logAlert).toHaveBeenCalledTimes(logAlert);
} else {
expect(alertingEventLogger.logAlert).not.toHaveBeenCalled();
}
if (logAction > 0) {
expect(alertingEventLogger.logAction).toHaveBeenCalledTimes(logAction);
} else {
expect(alertingEventLogger.logAction).not.toHaveBeenCalled();
}
expect(alertingEventLogger.logTimeout).toHaveBeenCalled();
}
});

26
x-pack/plugins/alerting/server/task_runner/types.ts
View file

@ -8,8 +8,8 @@
import { Dictionary } from 'lodash';
import { KibanaRequest, Logger } from '@kbn/core/server';
import { ConcreteTaskInstance } from '@kbn/task-manager-plugin/server';
import { IEventLogger } from '@kbn/event-log-plugin/server';
import { PluginStartContract as ActionsPluginStartContract } from '@kbn/actions-plugin/server';
import { PublicMethodsOf } from '@kbn/utility-types';
import {
ActionGroup,
RuleAction,
@ -20,7 +20,6 @@ import {
IntervalSchedule,
RuleMonitoring,
RuleTaskState,
SanitizedRule,
} from '../../common';
import { Alert } from '../alert';
import { NormalizedRuleType } from '../rule_type_registry';
@ -28,6 +27,7 @@ import { ExecutionHandler } from './create_execution_handler';
import { RawRule } from '../types';
import { ActionsConfigMap } from '../lib/get_actions_config_map';
import { RuleRunMetrics, RuleRunMetricsStore } from '../lib/rule_run_metrics_store';
import { AlertingEventLogger } from '../lib/alerting_event_logger/alerting_event_logger';
export interface RuleTaskRunResult {
state: RuleTaskState;
@ -61,29 +61,11 @@ export interface GenerateNewAndRecoveredAlertEventsParams<
InstanceState extends AlertInstanceState,
InstanceContext extends AlertInstanceContext
> {
eventLogger: IEventLogger;
executionId: string;
alertingEventLogger: AlertingEventLogger;
originalAlerts: Dictionary<Alert<InstanceState, InstanceContext>>;
currentAlerts: Dictionary<Alert<InstanceState, InstanceContext>>;
recoveredAlerts: Dictionary<Alert<InstanceState, InstanceContext>>;
ruleId: string;
ruleLabel: string;
namespace: string | undefined;
ruleType: NormalizedRuleType<
RuleTypeParams,
RuleTypeParams,
RuleTypeState,
{
[x: string]: unknown;
},
{
[x: string]: unknown;
},
string,
string
>;
rule: SanitizedRule<RuleTypeParams>;
spaceId: string;
ruleRunMetricsStore: RuleRunMetricsStore;
}
@ -145,7 +127,7 @@ export interface CreateExecutionHandlerOptions<
RecoveryActionGroupId
>;
logger: Logger;
eventLogger: IEventLogger;
alertingEventLogger: PublicMethodsOf<AlertingEventLogger>;
request: KibanaRequest;
ruleParams: RuleTypeParams;
supportsEphemeralTasks: boolean;

9
x-pack/plugins/event_log/server/event_logger.test.ts
View file

@ -143,6 +143,15 @@ describe('EventLogger', () => {
expect(nanosToMillis(duration)).toBeCloseTo(timeStopValue - timeStartValue);
});
test('can set specific start time in startTiming', () => {
const event: IEvent = {};
eventLogger.startTiming(event, new Date('2020-01-01T02:00:00.000Z'));
const timeStart = event.event!.start!;
expect(timeStart).toBeTruthy();
expect(timeStart).toEqual('2020-01-01T02:00:00.000Z');
});
test('timing method endTiming() method works when startTiming() is not called', async () => {
const event: IEvent = {};
eventLogger.stopTiming(event);

5
x-pack/plugins/event_log/server/event_logger.ts
View file

@ -47,11 +47,12 @@ export class EventLogger implements IEventLogger {
this.systemLogger = ctorParams.systemLogger;
}
startTiming(event: IEvent): void {
startTiming(event: IEvent, startTime?: Date): void {
if (event == null) return;
event.event = event.event || {};
event.event.start = new Date().toISOString();
const start = startTime ?? new Date();
event.event.start = start.toISOString();
}
stopTiming(event: IEvent): void {

2
x-pack/plugins/event_log/server/types.ts
View file

@ -66,7 +66,7 @@ export interface IEventLogClient {
export interface IEventLogger {
logEvent(properties: IEvent): void;
startTiming(event: IEvent): void;
startTiming(event: IEvent, startTime?: Date): void;
stopTiming(event: IEvent): void;
}

1
x-pack/test/alerting_api_integration/spaces_only/tests/alerting/event_log.ts
View file

@ -727,6 +727,7 @@ export default function eventLogTests({ getService }: FtrProviderContext) {
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
name: 'abc',
},
consumer: 'alertsFixture',
numActiveAlerts: 0,