[alerting][actions] add task scheduled date and delay to event log (#102252)

resolves #98634

This adds a new object property to the event log kibana object named
task, with two properties to track the time the task was scheduled to
run, and the delay between when it was supposed to run and when it
actually started. This task property is only added to the appropriate
events.

	task: schema.maybe(
	  schema.object({
	    scheduled: ecsDate(),
	    schedule_delay: ecsNumber(),
	  })
	),
This commit is contained in:
Patrick Mueller 2021-06-22 20:57:26 -04:00 committed by GitHub
parent 450ababee5
commit bb77fa6967
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
17 changed files with 765 additions and 499 deletions

View file

@ -109,6 +109,77 @@ test('successfully executes', async () => {
}); });
expect(loggerMock.debug).toBeCalledWith('executing action test:1: 1'); expect(loggerMock.debug).toBeCalledWith('executing action test:1: 1');
expect(eventLogger.logEvent.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
Object {
"event": Object {
"action": "execute",
"outcome": "success",
},
"kibana": Object {
"saved_objects": Array [
Object {
"id": "1",
"namespace": "some-namespace",
"rel": "primary",
"type": "action",
"type_id": "test",
},
],
},
"message": "action executed: test:1: 1",
},
],
]
`);
});
test('successfully executes as a task', async () => {
const actionType: jest.Mocked<ActionType> = {
id: 'test',
name: 'Test',
minimumLicenseRequired: 'basic',
executor: jest.fn(),
};
const actionSavedObject = {
id: '1',
type: 'action',
attributes: {
actionTypeId: 'test',
config: {
bar: true,
},
secrets: {
baz: true,
},
},
references: [],
};
const actionResult = {
id: actionSavedObject.id,
name: actionSavedObject.id,
...pick(actionSavedObject.attributes, 'actionTypeId', 'config'),
isPreconfigured: false,
};
actionsClient.get.mockResolvedValueOnce(actionResult);
encryptedSavedObjectsClient.getDecryptedAsInternalUser.mockResolvedValueOnce(actionSavedObject);
actionTypeRegistry.get.mockReturnValueOnce(actionType);
const scheduleDelay = 10000; // milliseconds
const scheduled = new Date(Date.now() - scheduleDelay);
await actionExecutor.execute({
...executeParams,
taskInfo: {
scheduled,
},
});
const eventTask = eventLogger.logEvent.mock.calls[0][0]?.kibana?.task;
expect(eventTask).toBeDefined();
expect(eventTask?.scheduled).toBe(scheduled.toISOString());
expect(eventTask?.schedule_delay).toBeGreaterThanOrEqual(scheduleDelay * 1000 * 1000);
expect(eventTask?.schedule_delay).toBeLessThanOrEqual(2 * scheduleDelay * 1000 * 1000);
}); });
test('provides empty config when config and / or secrets is empty', async () => { test('provides empty config when config and / or secrets is empty', async () => {

View file

@ -25,6 +25,9 @@ import { ActionsClient } from '../actions_client';
import { ActionExecutionSource } from './action_execution_source'; import { ActionExecutionSource } from './action_execution_source';
import { RelatedSavedObjects } from './related_saved_objects'; import { RelatedSavedObjects } from './related_saved_objects';
// 1,000,000 nanoseconds in 1 millisecond
const Millis2Nanos = 1000 * 1000;
export interface ActionExecutorContext { export interface ActionExecutorContext {
logger: Logger; logger: Logger;
spaces?: SpacesServiceStart; spaces?: SpacesServiceStart;
@ -39,11 +42,16 @@ export interface ActionExecutorContext {
preconfiguredActions: PreConfiguredAction[]; preconfiguredActions: PreConfiguredAction[];
} }
export interface TaskInfo {
scheduled: Date;
}
export interface ExecuteOptions<Source = unknown> { export interface ExecuteOptions<Source = unknown> {
actionId: string; actionId: string;
request: KibanaRequest; request: KibanaRequest;
params: Record<string, unknown>; params: Record<string, unknown>;
source?: ActionExecutionSource<Source>; source?: ActionExecutionSource<Source>;
taskInfo?: TaskInfo;
relatedSavedObjects?: RelatedSavedObjects; relatedSavedObjects?: RelatedSavedObjects;
} }
@ -71,6 +79,7 @@ export class ActionExecutor {
params, params,
request, request,
source, source,
taskInfo,
relatedSavedObjects, relatedSavedObjects,
}: ExecuteOptions): Promise<ActionTypeExecutorResult<unknown>> { }: ExecuteOptions): Promise<ActionTypeExecutorResult<unknown>> {
if (!this.isInitialized) { if (!this.isInitialized) {
@ -143,9 +152,19 @@ export class ActionExecutor {
const actionLabel = `${actionTypeId}:${actionId}: ${name}`; const actionLabel = `${actionTypeId}:${actionId}: ${name}`;
logger.debug(`executing action ${actionLabel}`); logger.debug(`executing action ${actionLabel}`);
const task = taskInfo
? {
task: {
scheduled: taskInfo.scheduled.toISOString(),
schedule_delay: Millis2Nanos * (Date.now() - taskInfo.scheduled.getTime()),
},
}
: {};
const event: IEvent = { const event: IEvent = {
event: { action: EVENT_LOG_ACTIONS.execute }, event: { action: EVENT_LOG_ACTIONS.execute },
kibana: { kibana: {
...task,
saved_objects: [ saved_objects: [
{ {
rel: SAVED_OBJECT_REL_PRIMARY, rel: SAVED_OBJECT_REL_PRIMARY,

View file

@ -133,6 +133,9 @@ test('executes the task by calling the executor with proper parameters', async (
authorization: 'ApiKey MTIzOmFiYw==', authorization: 'ApiKey MTIzOmFiYw==',
}, },
}), }),
taskInfo: {
scheduled: new Date(),
},
}); });
const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; const [executeParams] = mockedActionExecutor.execute.mock.calls[0];
@ -255,6 +258,9 @@ test('uses API key when provided', async () => {
authorization: 'ApiKey MTIzOmFiYw==', authorization: 'ApiKey MTIzOmFiYw==',
}, },
}), }),
taskInfo: {
scheduled: new Date(),
},
}); });
const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; const [executeParams] = mockedActionExecutor.execute.mock.calls[0];
@ -300,6 +306,9 @@ test('uses relatedSavedObjects when provided', async () => {
authorization: 'ApiKey MTIzOmFiYw==', authorization: 'ApiKey MTIzOmFiYw==',
}, },
}), }),
taskInfo: {
scheduled: new Date(),
},
}); });
}); });
@ -323,7 +332,6 @@ test('sanitizes invalid relatedSavedObjects when provided', async () => {
}); });
await taskRunner.run(); await taskRunner.run();
expect(mockedActionExecutor.execute).toHaveBeenCalledWith({ expect(mockedActionExecutor.execute).toHaveBeenCalledWith({
actionId: '2', actionId: '2',
params: { baz: true }, params: { baz: true },
@ -334,6 +342,9 @@ test('sanitizes invalid relatedSavedObjects when provided', async () => {
authorization: 'ApiKey MTIzOmFiYw==', authorization: 'ApiKey MTIzOmFiYw==',
}, },
}), }),
taskInfo: {
scheduled: new Date(),
},
}); });
}); });
@ -363,6 +374,9 @@ test(`doesn't use API key when not provided`, async () => {
request: expect.objectContaining({ request: expect.objectContaining({
headers: {}, headers: {},
}), }),
taskInfo: {
scheduled: new Date(),
},
}); });
const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; const [executeParams] = mockedActionExecutor.execute.mock.calls[0];

View file

@ -72,6 +72,10 @@ export class TaskRunnerFactory {
getUnsecuredSavedObjectsClient, getUnsecuredSavedObjectsClient,
} = this.taskRunnerContext!; } = this.taskRunnerContext!;
const taskInfo = {
scheduled: taskInstance.runAt,
};
return { return {
async run() { async run() {
const { spaceId, actionTaskParamsId } = taskInstance.params as Record<string, string>; const { spaceId, actionTaskParamsId } = taskInstance.params as Record<string, string>;
@ -118,6 +122,7 @@ export class TaskRunnerFactory {
actionId, actionId,
request: fakeRequest, request: fakeRequest,
...getSourceFromReferences(references), ...getSourceFromReferences(references),
taskInfo,
relatedSavedObjects: validatedRelatedSavedObjects(logger, relatedSavedObjects), relatedSavedObjects: validatedRelatedSavedObjects(logger, relatedSavedObjects),
}); });
} catch (e) { } catch (e) {

View file

@ -195,7 +195,6 @@ test('enqueues execution per selected action', async () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "name-of-alert", "name": "name-of-alert",
"namespace": "test1",
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },

View file

@ -209,7 +209,6 @@ export function createExecutionHandler<
license: alertType.minimumLicenseRequired, license: alertType.minimumLicenseRequired,
category: alertType.id, category: alertType.id,
ruleset: alertType.producer, ruleset: alertType.producer,
...namespace,
name: alertName, name: alertName,
}, },
}; };

View file

@ -282,13 +282,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
} }
@ -394,6 +397,10 @@ describe('Task Runner', () => {
kind: 'alert', kind: 'alert',
}, },
kibana: { kibana: {
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [ saved_objects: [
{ {
id: '1', id: '1',
@ -409,7 +416,6 @@ describe('Task Runner', () => {
category: 'test', category: 'test',
id: '1', id: '1',
license: 'basic', license: 'basic',
namespace: undefined,
ruleset: 'alerts', ruleset: 'alerts',
}, },
}); });
@ -518,6 +524,10 @@ describe('Task Runner', () => {
alerting: { alerting: {
status: 'active', status: 'active',
}, },
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [ saved_objects: [
{ {
id: '1', id: '1',
@ -534,7 +544,6 @@ describe('Task Runner', () => {
id: '1', id: '1',
license: 'basic', license: 'basic',
name: 'alert-name', name: 'alert-name',
namespace: undefined,
ruleset: 'alerts', ruleset: 'alerts',
}, },
}); });
@ -603,6 +612,10 @@ describe('Task Runner', () => {
kind: 'alert', kind: 'alert',
}, },
kibana: { kibana: {
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [ saved_objects: [
{ {
id: '1', id: '1',
@ -618,7 +631,6 @@ describe('Task Runner', () => {
category: 'test', category: 'test',
id: '1', id: '1',
license: 'basic', license: 'basic',
namespace: undefined,
ruleset: 'alerts', ruleset: 'alerts',
}, },
}); });
@ -700,6 +712,10 @@ describe('Task Runner', () => {
alerting: { alerting: {
status: 'active', status: 'active',
}, },
task: {
schedule_delay: 0,
scheduled: '1970-01-01T00:00:00.000Z',
},
saved_objects: [ saved_objects: [
{ {
id: '1', id: '1',
@ -716,7 +732,6 @@ describe('Task Runner', () => {
id: '1', id: '1',
license: 'basic', license: 'basic',
name: 'alert-name', name: 'alert-name',
namespace: undefined,
ruleset: 'alerts', ruleset: 'alerts',
}, },
}); });
@ -854,13 +869,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -897,7 +915,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -926,6 +943,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -933,7 +954,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1151,13 +1171,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1194,7 +1217,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1231,7 +1253,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1273,7 +1294,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1302,6 +1322,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -1309,7 +1333,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1433,13 +1456,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1476,7 +1502,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1513,7 +1538,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1555,7 +1579,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1597,7 +1620,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1626,6 +1648,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -1633,7 +1659,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -1968,13 +1993,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2012,7 +2040,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2049,7 +2076,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2078,6 +2104,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -2085,7 +2115,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2294,13 +2323,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2333,13 +2365,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution failure: test:1: 'alert-name'", "message": "alert execution failure: test:1: 'alert-name'",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2397,13 +2432,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2436,13 +2474,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "test:1: execution failed", "message": "test:1: execution failed",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2508,13 +2549,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2547,13 +2591,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "test:1: execution failed", "message": "test:1: execution failed",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2619,13 +2666,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2658,13 +2708,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "test:1: execution failed", "message": "test:1: execution failed",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2729,13 +2782,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -2768,13 +2824,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "test:1: execution failed", "message": "test:1: execution failed",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3007,13 +3066,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3050,7 +3112,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3087,7 +3148,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3124,7 +3184,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3161,7 +3220,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3190,6 +3248,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -3197,7 +3259,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3291,13 +3352,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3334,7 +3398,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3371,7 +3434,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3400,6 +3462,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -3407,7 +3473,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3493,13 +3558,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3534,7 +3602,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3569,7 +3636,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3598,6 +3664,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -3605,7 +3675,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3686,13 +3755,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3729,7 +3801,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3766,7 +3837,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3795,6 +3865,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -3802,7 +3876,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3885,13 +3958,16 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert execution start: \\"1\\"", "message": "alert execution start: \\"1\\"",
"rule": Object { "rule": Object {
"category": "test", "category": "test",
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3925,7 +4001,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3959,7 +4034,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },
@ -3988,6 +4062,10 @@ describe('Task Runner', () => {
"type_id": "test", "type_id": "test",
}, },
], ],
"task": Object {
"schedule_delay": 0,
"scheduled": "1970-01-01T00:00:00.000Z",
},
}, },
"message": "alert executed: test:1: 'alert-name'", "message": "alert executed: test:1: 'alert-name'",
"rule": Object { "rule": Object {
@ -3995,7 +4073,6 @@ describe('Task Runner', () => {
"id": "1", "id": "1",
"license": "basic", "license": "basic",
"name": "alert-name", "name": "alert-name",
"namespace": undefined,
"ruleset": "alerts", "ruleset": "alerts",
}, },
}, },

View file

@ -54,6 +54,9 @@ import { getEsErrorMessage } from '../lib/errors';
const FALLBACK_RETRY_INTERVAL = '5m'; const FALLBACK_RETRY_INTERVAL = '5m';
// 1,000,000 nanoseconds in 1 millisecond
const Millis2Nanos = 1000 * 1000;
type Event = Exclude<IEvent, undefined>; type Event = Exclude<IEvent, undefined>;
interface AlertTaskRunResult { interface AlertTaskRunResult {
@ -489,15 +492,17 @@ export class TaskRunner<
schedule: taskSchedule, schedule: taskSchedule,
} = this.taskInstance; } = this.taskInstance;
const runDate = new Date().toISOString(); const runDate = new Date();
this.logger.debug(`executing alert ${this.alertType.id}:${alertId} at ${runDate}`); const runDateString = runDate.toISOString();
this.logger.debug(`executing alert ${this.alertType.id}:${alertId} at ${runDateString}`);
const namespace = this.context.spaceIdToNamespace(spaceId); const namespace = this.context.spaceIdToNamespace(spaceId);
const eventLogger = this.context.eventLogger; const eventLogger = this.context.eventLogger;
const scheduleDelay = runDate.getTime() - this.taskInstance.runAt.getTime();
const event: IEvent = { const event: IEvent = {
// explicitly set execute timestamp so it will be before other events // explicitly set execute timestamp so it will be before other events
// generated here (new-instance, schedule-action, etc) // generated here (new-instance, schedule-action, etc)
'@timestamp': runDate, '@timestamp': runDateString,
event: { event: {
action: EVENT_LOG_ACTIONS.execute, action: EVENT_LOG_ACTIONS.execute,
kind: 'alert', kind: 'alert',
@ -513,13 +518,16 @@ export class TaskRunner<
namespace, namespace,
}, },
], ],
task: {
scheduled: this.taskInstance.runAt.toISOString(),
schedule_delay: Millis2Nanos * scheduleDelay,
},
}, },
rule: { rule: {
id: alertId, id: alertId,
license: this.alertType.minimumLicenseRequired, license: this.alertType.minimumLicenseRequired,
category: this.alertType.id, category: this.alertType.id,
ruleset: this.alertType.producer, ruleset: this.alertType.producer,
namespace,
}, },
}; };
@ -814,7 +822,6 @@ function generateNewAndRecoveredInstanceEvents<
license: ruleType.minimumLicenseRequired, license: ruleType.minimumLicenseRequired,
category: ruleType.id, category: ruleType.id,
ruleset: ruleType.producer, ruleset: ruleType.producer,
namespace,
name: rule.name, name: rule.name,
}, },
}; };

View file

@ -127,6 +127,10 @@ Below is a document in the expected structure, with descriptions of the fields:
// Custom fields that are not part of ECS. // Custom fields that are not part of ECS.
kibana: { kibana: {
server_uuid: "UUID of kibana server, for diagnosing multi-Kibana scenarios", server_uuid: "UUID of kibana server, for diagnosing multi-Kibana scenarios",
task: {
scheduled: "ISO date of when the task for this event was supposed to start",
schedule_delay: "delay in nanoseconds between when this task was supposed to start and when it actually started",
},
alerting: { alerting: {
instance_id: "alert instance id, for relevant documents", instance_id: "alert instance id, for relevant documents",
action_group_id: "alert action group, for relevant documents", action_group_id: "alert action group, for relevant documents",

View file

@ -214,10 +214,6 @@
"version": { "version": {
"ignore_above": 1024, "ignore_above": 1024,
"type": "keyword" "type": "keyword"
},
"namespace": {
"ignore_above": 1024,
"type": "keyword"
} }
} }
}, },
@ -241,6 +237,16 @@
"type": "keyword", "type": "keyword",
"ignore_above": 1024 "ignore_above": 1024
}, },
"task": {
"properties": {
"scheduled": {
"type": "date"
},
"schedule_delay": {
"type": "long"
}
}
},
"alerting": { "alerting": {
"properties": { "properties": {
"instance_id": { "instance_id": {

View file

@ -91,7 +91,6 @@ export const EventSchema = schema.maybe(
ruleset: ecsString(), ruleset: ecsString(),
uuid: ecsString(), uuid: ecsString(),
version: ecsString(), version: ecsString(),
namespace: ecsString(),
}) })
), ),
user: schema.maybe( user: schema.maybe(
@ -102,6 +101,12 @@ export const EventSchema = schema.maybe(
kibana: schema.maybe( kibana: schema.maybe(
schema.object({ schema.object({
server_uuid: ecsString(), server_uuid: ecsString(),
task: schema.maybe(
schema.object({
scheduled: ecsDate(),
schedule_delay: ecsNumber(),
})
),
alerting: schema.maybe( alerting: schema.maybe(
schema.object({ schema.object({
instance_id: ecsString(), instance_id: ecsString(),

View file

@ -17,6 +17,17 @@ exports.EcsCustomPropertyMappings = {
type: 'keyword', type: 'keyword',
ignore_above: 1024, ignore_above: 1024,
}, },
// task specific fields
task: {
properties: {
scheduled: {
type: 'date',
},
schedule_delay: {
type: 'long',
},
},
},
// alerting specific fields // alerting specific fields
alerting: { alerting: {
properties: { properties: {

View file

@ -88,7 +88,7 @@ export class EventLogger implements IEventLogger {
try { try {
validatedEvent = validateEvent(this.eventLogService, event); validatedEvent = validateEvent(this.eventLogService, event);
} catch (err) { } catch (err) {
this.systemLogger.warn(`invalid event logged: ${err.message}`); this.systemLogger.warn(`invalid event logged: ${err.message}; ${JSON.stringify(event)})`);
return; return;
} }

View file

@ -1304,7 +1304,6 @@ instanceStateValue: true
license: 'basic', license: 'basic',
category: ruleObject.alertInfo.ruleTypeId, category: ruleObject.alertInfo.ruleTypeId,
ruleset: ruleObject.alertInfo.producer, ruleset: ruleObject.alertInfo.producer,
namespace: spaceId,
name: ruleObject.alertInfo.name, name: ruleObject.alertInfo.name,
}); });

View file

@ -81,12 +81,12 @@ export default function eventLogTests({ getService }: FtrProviderContext) {
errorMessage: 'Unable to decrypt attribute "apiKey"', errorMessage: 'Unable to decrypt attribute "apiKey"',
status: 'error', status: 'error',
reason: 'decrypt', reason: 'decrypt',
shouldHaveTask: true,
rule: { rule: {
id: alertId, id: alertId,
category: response.body.rule_type_id, category: response.body.rule_type_id,
license: 'basic', license: 'basic',
ruleset: 'alertsFixture', ruleset: 'alertsFixture',
namespace: spaceId,
}, },
}); });
}); });

View file

@ -406,6 +406,8 @@ export default function ({ getService }: FtrProviderContext) {
expect(startExecuteEvent?.message).to.eql(startMessage); expect(startExecuteEvent?.message).to.eql(startMessage);
} }
expect(event?.kibana?.task).to.eql(undefined);
if (errorMessage) { if (errorMessage) {
expect(executeEvent?.error?.message).to.eql(errorMessage); expect(executeEvent?.error?.message).to.eql(errorMessage);
} }

View file

@ -24,476 +24,512 @@ export default function eventLogTests({ getService }: FtrProviderContext) {
after(() => objectRemover.removeAll()); after(() => objectRemover.removeAll());
it('should generate expected events for normal operation', async () => { for (const space of [Spaces.default, Spaces.space1]) {
const { body: createdAction } = await supertest describe(`in space ${space.id}`, () => {
.post(`${getUrlPrefix(Spaces.space1.id)}/api/actions/connector`) it('should generate expected events for normal operation', async () => {
.set('kbn-xsrf', 'foo') const { body: createdAction } = await supertest
.send({ .post(`${getUrlPrefix(space.id)}/api/actions/connector`)
name: 'MY action', .set('kbn-xsrf', 'foo')
connector_type_id: 'test.noop', .send({
config: {}, name: 'MY action',
secrets: {}, connector_type_id: 'test.noop',
}) config: {},
.expect(200); secrets: {},
})
.expect(200);
// pattern of when the alert should fire // pattern of when the alert should fire
const pattern = { const pattern = {
instance: [false, true, true], instance: [false, true, true],
}; };
const response = await supertest const response = await supertest
.post(`${getUrlPrefix(Spaces.space1.id)}/api/alerting/rule`) .post(`${getUrlPrefix(space.id)}/api/alerting/rule`)
.set('kbn-xsrf', 'foo') .set('kbn-xsrf', 'foo')
.send( .send(
getTestAlertData({ getTestAlertData({
rule_type_id: 'test.patternFiring', rule_type_id: 'test.patternFiring',
schedule: { interval: '1s' }, schedule: { interval: '1s' },
throttle: null, throttle: null,
params: { params: {
pattern, pattern,
}, },
actions: [ actions: [
{ {
id: createdAction.id, id: createdAction.id,
group: 'default', group: 'default',
params: {}, params: {},
}, },
], ],
}) })
); );
expect(response.status).to.eql(200); expect(response.status).to.eql(200);
const alertId = response.body.id; const alertId = response.body.id;
objectRemover.add(Spaces.space1.id, alertId, 'rule', 'alerting'); objectRemover.add(space.id, alertId, 'rule', 'alerting');
// get the events we're expecting // get the events we're expecting
const events = await retry.try(async () => { const events = await retry.try(async () => {
return await getEventLog({ return await getEventLog({
getService, getService,
spaceId: Spaces.space1.id, spaceId: space.id,
type: 'alert', type: 'alert',
id: alertId, id: alertId,
provider: 'alerting', provider: 'alerting',
actions: new Map([ actions: new Map([
// make sure the counts of the # of events per type are as expected // make sure the counts of the # of events per type are as expected
['execute-start', { gte: 4 }], ['execute-start', { gte: 4 }],
['execute', { gte: 4 }], ['execute', { gte: 4 }],
['execute-action', { equal: 2 }], ['execute-action', { equal: 2 }],
['new-instance', { equal: 1 }], ['new-instance', { equal: 1 }],
['active-instance', { gte: 1 }], ['active-instance', { gte: 1 }],
['recovered-instance', { equal: 1 }], ['recovered-instance', { equal: 1 }],
]), ]),
});
});
// get the filtered events only with action 'new-instance'
const filteredEvents = await retry.try(async () => {
return await getEventLog({
getService,
spaceId: Spaces.space1.id,
type: 'alert',
id: alertId,
provider: 'alerting',
actions: new Map([['new-instance', { equal: 1 }]]),
filter: 'event.action:(new-instance)',
});
});
expect(getEventsByAction(filteredEvents, 'execute').length).equal(0);
expect(getEventsByAction(filteredEvents, 'execute-action').length).equal(0);
expect(getEventsByAction(events, 'new-instance').length).equal(1);
const executeEvents = getEventsByAction(events, 'execute');
const executeStartEvents = getEventsByAction(events, 'execute-start');
const executeActionEvents = getEventsByAction(events, 'execute-action');
const newInstanceEvents = getEventsByAction(events, 'new-instance');
const recoveredInstanceEvents = getEventsByAction(events, 'recovered-instance');
// make sure the events are in the right temporal order
const executeTimes = getTimestamps(executeEvents);
const executeStartTimes = getTimestamps(executeStartEvents);
const executeActionTimes = getTimestamps(executeActionEvents);
const newInstanceTimes = getTimestamps(newInstanceEvents);
const recoveredInstanceTimes = getTimestamps(recoveredInstanceEvents);
expect(executeTimes[0] < newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= newInstanceTimes[0]).to.be(true);
expect(executeTimes[2] > newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= executeActionTimes[0]).to.be(true);
expect(executeTimes[2] > executeActionTimes[0]).to.be(true);
expect(executeStartTimes.length === executeTimes.length).to.be(true);
executeStartTimes.forEach((est, index) => expect(est === executeTimes[index]).to.be(true));
expect(recoveredInstanceTimes[0] > newInstanceTimes[0]).to.be(true);
// validate each event
let executeCount = 0;
const executeStatuses = ['ok', 'active', 'active'];
for (const event of events) {
switch (event?.event?.action) {
case 'execute-start':
validateEvent(event, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `alert execution start: "${alertId}"`,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
},
}); });
break; });
case 'execute':
validateEvent(event, { // get the filtered events only with action 'new-instance'
spaceId: Spaces.space1.id, const filteredEvents = await retry.try(async () => {
savedObjects: [ return await getEventLog({
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' }, getService,
], spaceId: space.id,
outcome: 'success', type: 'alert',
message: `alert executed: test.patternFiring:${alertId}: 'abc'`, id: alertId,
status: executeStatuses[executeCount++], provider: 'alerting',
rule: { actions: new Map([['new-instance', { equal: 1 }]]),
id: alertId, filter: 'event.action:(new-instance)',
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name,
},
}); });
break; });
case 'execute-action':
expect(getEventsByAction(filteredEvents, 'execute').length).equal(0);
expect(getEventsByAction(filteredEvents, 'execute-action').length).equal(0);
expect(getEventsByAction(events, 'new-instance').length).equal(1);
const executeEvents = getEventsByAction(events, 'execute');
const executeStartEvents = getEventsByAction(events, 'execute-start');
const executeActionEvents = getEventsByAction(events, 'execute-action');
const newInstanceEvents = getEventsByAction(events, 'new-instance');
const recoveredInstanceEvents = getEventsByAction(events, 'recovered-instance');
// make sure the events are in the right temporal order
const executeTimes = getTimestamps(executeEvents);
const executeStartTimes = getTimestamps(executeStartEvents);
const executeActionTimes = getTimestamps(executeActionEvents);
const newInstanceTimes = getTimestamps(newInstanceEvents);
const recoveredInstanceTimes = getTimestamps(recoveredInstanceEvents);
expect(executeTimes[0] < newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= newInstanceTimes[0]).to.be(true);
expect(executeTimes[2] > newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= executeActionTimes[0]).to.be(true);
expect(executeTimes[2] > executeActionTimes[0]).to.be(true);
expect(executeStartTimes.length === executeTimes.length).to.be(true);
executeStartTimes.forEach((est, index) =>
expect(est === executeTimes[index]).to.be(true)
);
expect(recoveredInstanceTimes[0] > newInstanceTimes[0]).to.be(true);
// validate each event
let executeCount = 0;
const executeStatuses = ['ok', 'active', 'active'];
for (const event of events) {
switch (event?.event?.action) {
case 'execute-start':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `alert execution start: "${alertId}"`,
shouldHaveTask: true,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
},
});
break;
case 'execute':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
outcome: 'success',
message: `alert executed: test.patternFiring:${alertId}: 'abc'`,
status: executeStatuses[executeCount++],
shouldHaveTask: true,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
name: response.body.name,
},
});
break;
case 'execute-action':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
{ type: 'action', id: createdAction.id, type_id: 'test.noop' },
],
message: `alert: test.patternFiring:${alertId}: 'abc' instanceId: 'instance' scheduled actionGroup: 'default' action: test.noop:${createdAction.id}`,
instanceId: 'instance',
actionGroupId: 'default',
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
name: response.body.name,
},
});
break;
case 'new-instance':
validateInstanceEvent(event, `created new instance: 'instance'`, false);
break;
case 'recovered-instance':
validateInstanceEvent(event, `instance 'instance' has recovered`, true);
break;
case 'active-instance':
validateInstanceEvent(
event,
`active instance: 'instance' in actionGroup: 'default'`,
false
);
break;
// this will get triggered as we add new event actions
default:
throw new Error(`unexpected event action "${event?.event?.action}"`);
}
}
const actionEvents = await retry.try(async () => {
return await getEventLog({
getService,
spaceId: space.id,
type: 'action',
id: createdAction.id,
provider: 'actions',
actions: new Map([['execute', { gte: 1 }]]),
});
});
for (const event of actionEvents) {
switch (event?.event?.action) {
case 'execute':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'action', id: createdAction.id, rel: 'primary', type_id: 'test.noop' },
],
message: `action executed: test.noop:${createdAction.id}: MY action`,
outcome: 'success',
shouldHaveTask: true,
rule: undefined,
});
break;
}
}
function validateInstanceEvent(
event: IValidatedEvent,
subMessage: string,
shouldHaveEventEnd: boolean
) {
validateEvent(event, { validateEvent(event, {
spaceId: Spaces.space1.id, spaceId: space.id,
savedObjects: [ savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' }, { type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
{ type: 'action', id: createdAction.id, type_id: 'test.noop' },
], ],
message: `alert: test.patternFiring:${alertId}: 'abc' instanceId: 'instance' scheduled actionGroup: 'default' action: test.noop:${createdAction.id}`, message: `test.patternFiring:${alertId}: 'abc' ${subMessage}`,
instanceId: 'instance', instanceId: 'instance',
actionGroupId: 'default', actionGroupId: 'default',
shouldHaveEventEnd,
rule: { rule: {
id: alertId, id: alertId,
category: response.body.rule_type_id, category: response.body.rule_type_id,
license: 'basic', license: 'basic',
ruleset: 'alertsFixture', ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name, name: response.body.name,
}, },
}); });
break; }
case 'new-instance': });
validateInstanceEvent(event, `created new instance: 'instance'`, false);
break; it('should generate expected events for normal operation with subgroups', async () => {
case 'recovered-instance': const { body: createdAction } = await supertest
validateInstanceEvent(event, `instance 'instance' has recovered`, true); .post(`${getUrlPrefix(space.id)}/api/actions/connector`)
break; .set('kbn-xsrf', 'foo')
case 'active-instance': .send({
validateInstanceEvent( name: 'MY action',
event, connector_type_id: 'test.noop',
`active instance: 'instance' in actionGroup: 'default'`, config: {},
false secrets: {},
})
.expect(200);
// pattern of when the alert should fire
const [firstSubgroup, secondSubgroup] = [uuid.v4(), uuid.v4()];
const pattern = {
instance: [false, firstSubgroup, secondSubgroup],
};
const response = await supertest
.post(`${getUrlPrefix(space.id)}/api/alerting/rule`)
.set('kbn-xsrf', 'foo')
.send(
getTestAlertData({
rule_type_id: 'test.patternFiring',
schedule: { interval: '1s' },
throttle: null,
params: {
pattern,
},
actions: [
{
id: createdAction.id,
group: 'default',
params: {},
},
],
})
); );
break;
// this will get triggered as we add new event actions
default:
throw new Error(`unexpected event action "${event?.event?.action}"`);
}
}
function validateInstanceEvent( expect(response.status).to.eql(200);
event: IValidatedEvent, const alertId = response.body.id;
subMessage: string, objectRemover.add(space.id, alertId, 'rule', 'alerting');
shouldHaveEventEnd: boolean
) {
validateEvent(event, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `test.patternFiring:${alertId}: 'abc' ${subMessage}`,
instanceId: 'instance',
actionGroupId: 'default',
shouldHaveEventEnd,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name,
},
});
}
});
it('should generate expected events for normal operation with subgroups', async () => { // get the events we're expecting
const { body: createdAction } = await supertest const events = await retry.try(async () => {
.post(`${getUrlPrefix(Spaces.space1.id)}/api/actions/connector`) return await getEventLog({
.set('kbn-xsrf', 'foo') getService,
.send({ spaceId: space.id,
name: 'MY action', type: 'alert',
connector_type_id: 'test.noop', id: alertId,
config: {}, provider: 'alerting',
secrets: {}, actions: new Map([
}) // make sure the counts of the # of events per type are as expected
.expect(200); ['execute-start', { gte: 4 }],
['execute', { gte: 4 }],
// pattern of when the alert should fire ['execute-action', { equal: 2 }],
const [firstSubgroup, secondSubgroup] = [uuid.v4(), uuid.v4()]; ['new-instance', { equal: 1 }],
const pattern = { ['active-instance', { gte: 2 }],
instance: [false, firstSubgroup, secondSubgroup], ['recovered-instance', { equal: 1 }],
}; ]),
const response = await supertest
.post(`${getUrlPrefix(Spaces.space1.id)}/api/alerting/rule`)
.set('kbn-xsrf', 'foo')
.send(
getTestAlertData({
rule_type_id: 'test.patternFiring',
schedule: { interval: '1s' },
throttle: null,
params: {
pattern,
},
actions: [
{
id: createdAction.id,
group: 'default',
params: {},
},
],
})
);
expect(response.status).to.eql(200);
const alertId = response.body.id;
objectRemover.add(Spaces.space1.id, alertId, 'rule', 'alerting');
// get the events we're expecting
const events = await retry.try(async () => {
return await getEventLog({
getService,
spaceId: Spaces.space1.id,
type: 'alert',
id: alertId,
provider: 'alerting',
actions: new Map([
// make sure the counts of the # of events per type are as expected
['execute-start', { gte: 4 }],
['execute', { gte: 4 }],
['execute-action', { equal: 2 }],
['new-instance', { equal: 1 }],
['active-instance', { gte: 2 }],
['recovered-instance', { equal: 1 }],
]),
});
});
const executeEvents = getEventsByAction(events, 'execute');
const executeStartEvents = getEventsByAction(events, 'execute-start');
const executeActionEvents = getEventsByAction(events, 'execute-action');
const newInstanceEvents = getEventsByAction(events, 'new-instance');
const recoveredInstanceEvents = getEventsByAction(events, 'recovered-instance');
// make sure the events are in the right temporal order
const executeTimes = getTimestamps(executeEvents);
const executeStartTimes = getTimestamps(executeStartEvents);
const executeActionTimes = getTimestamps(executeActionEvents);
const newInstanceTimes = getTimestamps(newInstanceEvents);
const recoveredInstanceTimes = getTimestamps(recoveredInstanceEvents);
expect(executeTimes[0] < newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= newInstanceTimes[0]).to.be(true);
expect(executeTimes[2] > newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= executeActionTimes[0]).to.be(true);
expect(executeTimes[2] > executeActionTimes[0]).to.be(true);
expect(executeStartTimes.length === executeTimes.length).to.be(true);
executeStartTimes.forEach((est, index) => expect(est === executeTimes[index]).to.be(true));
expect(recoveredInstanceTimes[0] > newInstanceTimes[0]).to.be(true);
// validate each event
let executeCount = 0;
const executeStatuses = ['ok', 'active', 'active'];
for (const event of events) {
switch (event?.event?.action) {
case 'execute-start':
validateEvent(event, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `alert execution start: "${alertId}"`,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
},
}); });
break; });
case 'execute':
const executeEvents = getEventsByAction(events, 'execute');
const executeStartEvents = getEventsByAction(events, 'execute-start');
const executeActionEvents = getEventsByAction(events, 'execute-action');
const newInstanceEvents = getEventsByAction(events, 'new-instance');
const recoveredInstanceEvents = getEventsByAction(events, 'recovered-instance');
// make sure the events are in the right temporal order
const executeTimes = getTimestamps(executeEvents);
const executeStartTimes = getTimestamps(executeStartEvents);
const executeActionTimes = getTimestamps(executeActionEvents);
const newInstanceTimes = getTimestamps(newInstanceEvents);
const recoveredInstanceTimes = getTimestamps(recoveredInstanceEvents);
expect(executeTimes[0] < newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= newInstanceTimes[0]).to.be(true);
expect(executeTimes[2] > newInstanceTimes[0]).to.be(true);
expect(executeTimes[1] <= executeActionTimes[0]).to.be(true);
expect(executeTimes[2] > executeActionTimes[0]).to.be(true);
expect(executeStartTimes.length === executeTimes.length).to.be(true);
executeStartTimes.forEach((est, index) =>
expect(est === executeTimes[index]).to.be(true)
);
expect(recoveredInstanceTimes[0] > newInstanceTimes[0]).to.be(true);
// validate each event
let executeCount = 0;
const executeStatuses = ['ok', 'active', 'active'];
for (const event of events) {
switch (event?.event?.action) {
case 'execute-start':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `alert execution start: "${alertId}"`,
shouldHaveTask: true,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
},
});
break;
case 'execute':
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
outcome: 'success',
message: `alert executed: test.patternFiring:${alertId}: 'abc'`,
status: executeStatuses[executeCount++],
shouldHaveTask: true,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
name: response.body.name,
},
});
break;
case 'execute-action':
expect(
[firstSubgroup, secondSubgroup].includes(
event?.kibana?.alerting?.action_subgroup!
)
).to.be(true);
validateEvent(event, {
spaceId: space.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
{ type: 'action', id: createdAction.id, type_id: 'test.noop' },
],
message: `alert: test.patternFiring:${alertId}: 'abc' instanceId: 'instance' scheduled actionGroup(subgroup): 'default(${event?.kibana?.alerting?.action_subgroup})' action: test.noop:${createdAction.id}`,
instanceId: 'instance',
actionGroupId: 'default',
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
name: response.body.name,
},
});
break;
case 'new-instance':
validateInstanceEvent(event, `created new instance: 'instance'`, false);
break;
case 'recovered-instance':
validateInstanceEvent(event, `instance 'instance' has recovered`, true);
break;
case 'active-instance':
expect(
[firstSubgroup, secondSubgroup].includes(
event?.kibana?.alerting?.action_subgroup!
)
).to.be(true);
validateInstanceEvent(
event,
`active instance: 'instance' in actionGroup(subgroup): 'default(${event?.kibana?.alerting?.action_subgroup})'`,
false
);
break;
// this will get triggered as we add new event actions
default:
throw new Error(`unexpected event action "${event?.event?.action}"`);
}
}
function validateInstanceEvent(
event: IValidatedEvent,
subMessage: string,
shouldHaveEventEnd: boolean
) {
validateEvent(event, { validateEvent(event, {
spaceId: Spaces.space1.id, spaceId: space.id,
savedObjects: [ savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' }, { type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
], ],
outcome: 'success', message: `test.patternFiring:${alertId}: 'abc' ${subMessage}`,
message: `alert executed: test.patternFiring:${alertId}: 'abc'`,
status: executeStatuses[executeCount++],
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name,
},
});
break;
case 'execute-action':
expect(
[firstSubgroup, secondSubgroup].includes(event?.kibana?.alerting?.action_subgroup!)
).to.be(true);
validateEvent(event, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
{ type: 'action', id: createdAction.id, type_id: 'test.noop' },
],
message: `alert: test.patternFiring:${alertId}: 'abc' instanceId: 'instance' scheduled actionGroup(subgroup): 'default(${event?.kibana?.alerting?.action_subgroup})' action: test.noop:${createdAction.id}`,
instanceId: 'instance', instanceId: 'instance',
actionGroupId: 'default', actionGroupId: 'default',
shouldHaveEventEnd,
rule: { rule: {
id: alertId, id: alertId,
category: response.body.rule_type_id, category: response.body.rule_type_id,
license: 'basic', license: 'basic',
ruleset: 'alertsFixture', ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name, name: response.body.name,
}, },
}); });
break; }
case 'new-instance': });
validateInstanceEvent(event, `created new instance: 'instance'`, false);
break; it('should generate events for execution errors', async () => {
case 'recovered-instance': const response = await supertest
validateInstanceEvent(event, `instance 'instance' has recovered`, true); .post(`${getUrlPrefix(space.id)}/api/alerting/rule`)
break; .set('kbn-xsrf', 'foo')
case 'active-instance': .send(
expect( getTestAlertData({
[firstSubgroup, secondSubgroup].includes(event?.kibana?.alerting?.action_subgroup!) rule_type_id: 'test.throw',
).to.be(true); schedule: { interval: '1s' },
validateInstanceEvent( throttle: null,
event, })
`active instance: 'instance' in actionGroup(subgroup): 'default(${event?.kibana?.alerting?.action_subgroup})'`,
false
); );
break;
// this will get triggered as we add new event actions
default:
throw new Error(`unexpected event action "${event?.event?.action}"`);
}
}
function validateInstanceEvent( expect(response.status).to.eql(200);
event: IValidatedEvent, const alertId = response.body.id;
subMessage: string, objectRemover.add(space.id, alertId, 'rule', 'alerting');
shouldHaveEventEnd: boolean
) {
validateEvent(event, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `test.patternFiring:${alertId}: 'abc' ${subMessage}`,
instanceId: 'instance',
actionGroupId: 'default',
shouldHaveEventEnd,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
name: response.body.name,
},
});
}
});
it('should generate events for execution errors', async () => { const events = await retry.try(async () => {
const response = await supertest return await getEventLog({
.post(`${getUrlPrefix(Spaces.space1.id)}/api/alerting/rule`) getService,
.set('kbn-xsrf', 'foo') spaceId: space.id,
.send( type: 'alert',
getTestAlertData({ id: alertId,
rule_type_id: 'test.throw', provider: 'alerting',
schedule: { interval: '1s' }, actions: new Map([
throttle: null, ['execute-start', { gte: 1 }],
}) ['execute', { gte: 1 }],
); ]),
});
});
expect(response.status).to.eql(200); const startEvent = events[0];
const alertId = response.body.id; const executeEvent = events[1];
objectRemover.add(Spaces.space1.id, alertId, 'rule', 'alerting');
const events = await retry.try(async () => { expect(startEvent).to.be.ok();
return await getEventLog({ expect(executeEvent).to.be.ok();
getService,
spaceId: Spaces.space1.id, validateEvent(startEvent, {
type: 'alert', spaceId: space.id,
id: alertId, savedObjects: [
provider: 'alerting', { type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
actions: new Map([ ],
['execute-start', { gte: 1 }], message: `alert execution start: "${alertId}"`,
['execute', { gte: 1 }], shouldHaveTask: true,
]), rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
},
});
validateEvent(executeEvent, {
spaceId: space.id,
savedObjects: [{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.throw' }],
outcome: 'failure',
message: `alert execution failure: test.throw:${alertId}: 'abc'`,
errorMessage: 'this alert is intended to fail',
status: 'error',
reason: 'execute',
shouldHaveTask: true,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
},
});
}); });
}); });
}
const startEvent = events[0];
const executeEvent = events[1];
expect(startEvent).to.be.ok();
expect(executeEvent).to.be.ok();
validateEvent(startEvent, {
spaceId: Spaces.space1.id,
savedObjects: [
{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' },
],
message: `alert execution start: "${alertId}"`,
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
},
});
validateEvent(executeEvent, {
spaceId: Spaces.space1.id,
savedObjects: [{ type: 'alert', id: alertId, rel: 'primary', type_id: 'test.throw' }],
outcome: 'failure',
message: `alert execution failure: test.throw:${alertId}: 'abc'`,
errorMessage: 'this alert is intended to fail',
status: 'error',
reason: 'execute',
rule: {
id: alertId,
category: response.body.rule_type_id,
license: 'basic',
ruleset: 'alertsFixture',
namespace: Spaces.space1.id,
},
});
});
}); });
} }
@ -510,12 +546,13 @@ interface ValidateEventLogParams {
outcome?: string; outcome?: string;
message: string; message: string;
shouldHaveEventEnd?: boolean; shouldHaveEventEnd?: boolean;
shouldHaveTask?: boolean;
errorMessage?: string; errorMessage?: string;
status?: string; status?: string;
actionGroupId?: string; actionGroupId?: string;
instanceId?: string; instanceId?: string;
reason?: string; reason?: string;
rule: { rule?: {
id: string; id: string;
name?: string; name?: string;
version?: string; version?: string;
@ -529,7 +566,7 @@ interface ValidateEventLogParams {
} }
export function validateEvent(event: IValidatedEvent, params: ValidateEventLogParams): void { export function validateEvent(event: IValidatedEvent, params: ValidateEventLogParams): void {
const { spaceId, savedObjects, outcome, message, errorMessage, rule } = params; const { spaceId, savedObjects, outcome, message, errorMessage, rule, shouldHaveTask } = params;
const { status, actionGroupId, instanceId, reason, shouldHaveEventEnd } = params; const { status, actionGroupId, instanceId, reason, shouldHaveEventEnd } = params;
if (status) { if (status) {
@ -587,6 +624,16 @@ export function validateEvent(event: IValidatedEvent, params: ValidateEventLogPa
expect(event?.rule).to.eql(rule); expect(event?.rule).to.eql(rule);
if (shouldHaveTask) {
const task = event?.kibana?.task;
expect(task).to.be.ok();
expect(typeof Date.parse(typeof task?.scheduled)).to.be('number');
expect(typeof task?.schedule_delay).to.be('number');
expect(task?.schedule_delay).to.be.greaterThan(-1);
} else {
expect(event?.kibana?.task).to.be(undefined);
}
if (errorMessage) { if (errorMessage) {
expect(event?.error?.message).to.eql(errorMessage); expect(event?.error?.message).to.eql(errorMessage);
} }
@ -602,12 +649,13 @@ function getTimestamps(events: IValidatedEvent[]) {
function isSavedObjectInEvent( function isSavedObjectInEvent(
event: IValidatedEvent, event: IValidatedEvent,
namespace: string, spaceId: string,
type: string, type: string,
id: string, id: string,
rel?: string rel?: string
): boolean { ): boolean {
const savedObjects = event?.kibana?.saved_objects ?? []; const savedObjects = event?.kibana?.saved_objects ?? [];
const namespace = spaceId === 'default' ? undefined : spaceId;
for (const savedObject of savedObjects) { for (const savedObject of savedObjects) {
if ( if (