diff --git a/x-pack/plugins/actions/server/lib/action_executor.test.ts b/x-pack/plugins/actions/server/lib/action_executor.test.ts index 37d461d6b2a50..188a9a0b9e08a 100644 --- a/x-pack/plugins/actions/server/lib/action_executor.test.ts +++ b/x-pack/plugins/actions/server/lib/action_executor.test.ts @@ -109,6 +109,77 @@ test('successfully executes', async () => { }); 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 = { + 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 () => { diff --git a/x-pack/plugins/actions/server/lib/action_executor.ts b/x-pack/plugins/actions/server/lib/action_executor.ts index e9e7b17288611..9e62b123951df 100644 --- a/x-pack/plugins/actions/server/lib/action_executor.ts +++ b/x-pack/plugins/actions/server/lib/action_executor.ts @@ -25,6 +25,9 @@ import { ActionsClient } from '../actions_client'; import { ActionExecutionSource } from './action_execution_source'; import { RelatedSavedObjects } from './related_saved_objects'; +// 1,000,000 nanoseconds in 1 millisecond +const Millis2Nanos = 1000 * 1000; + export interface ActionExecutorContext { logger: Logger; spaces?: SpacesServiceStart; @@ -39,11 +42,16 @@ export interface ActionExecutorContext { preconfiguredActions: PreConfiguredAction[]; } +export interface TaskInfo { + scheduled: Date; +} + export interface ExecuteOptions { actionId: string; request: KibanaRequest; params: Record; source?: ActionExecutionSource; + taskInfo?: TaskInfo; relatedSavedObjects?: RelatedSavedObjects; } @@ -71,6 +79,7 @@ export class ActionExecutor { params, request, source, + taskInfo, relatedSavedObjects, }: ExecuteOptions): Promise> { if (!this.isInitialized) { @@ -143,9 +152,19 @@ export class ActionExecutor { const actionLabel = `${actionTypeId}:${actionId}: ${name}`; logger.debug(`executing action ${actionLabel}`); + const task = taskInfo + ? { + task: { + scheduled: taskInfo.scheduled.toISOString(), + schedule_delay: Millis2Nanos * (Date.now() - taskInfo.scheduled.getTime()), + }, + } + : {}; + const event: IEvent = { event: { action: EVENT_LOG_ACTIONS.execute }, kibana: { + ...task, saved_objects: [ { rel: SAVED_OBJECT_REL_PRIMARY, diff --git a/x-pack/plugins/actions/server/lib/task_runner_factory.test.ts b/x-pack/plugins/actions/server/lib/task_runner_factory.test.ts index 2292994e3ccfd..495d638951b56 100644 --- a/x-pack/plugins/actions/server/lib/task_runner_factory.test.ts +++ b/x-pack/plugins/actions/server/lib/task_runner_factory.test.ts @@ -133,6 +133,9 @@ test('executes the task by calling the executor with proper parameters', async ( authorization: 'ApiKey MTIzOmFiYw==', }, }), + taskInfo: { + scheduled: new Date(), + }, }); const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; @@ -255,6 +258,9 @@ test('uses API key when provided', async () => { authorization: 'ApiKey MTIzOmFiYw==', }, }), + taskInfo: { + scheduled: new Date(), + }, }); const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; @@ -300,6 +306,9 @@ test('uses relatedSavedObjects when provided', async () => { authorization: 'ApiKey MTIzOmFiYw==', }, }), + taskInfo: { + scheduled: new Date(), + }, }); }); @@ -323,7 +332,6 @@ test('sanitizes invalid relatedSavedObjects when provided', async () => { }); await taskRunner.run(); - expect(mockedActionExecutor.execute).toHaveBeenCalledWith({ actionId: '2', params: { baz: true }, @@ -334,6 +342,9 @@ test('sanitizes invalid relatedSavedObjects when provided', async () => { authorization: 'ApiKey MTIzOmFiYw==', }, }), + taskInfo: { + scheduled: new Date(), + }, }); }); @@ -363,6 +374,9 @@ test(`doesn't use API key when not provided`, async () => { request: expect.objectContaining({ headers: {}, }), + taskInfo: { + scheduled: new Date(), + }, }); const [executeParams] = mockedActionExecutor.execute.mock.calls[0]; diff --git a/x-pack/plugins/actions/server/lib/task_runner_factory.ts b/x-pack/plugins/actions/server/lib/task_runner_factory.ts index 0515963ab82f4..64169de728f75 100644 --- a/x-pack/plugins/actions/server/lib/task_runner_factory.ts +++ b/x-pack/plugins/actions/server/lib/task_runner_factory.ts @@ -72,6 +72,10 @@ export class TaskRunnerFactory { getUnsecuredSavedObjectsClient, } = this.taskRunnerContext!; + const taskInfo = { + scheduled: taskInstance.runAt, + }; + return { async run() { const { spaceId, actionTaskParamsId } = taskInstance.params as Record; @@ -118,6 +122,7 @@ export class TaskRunnerFactory { actionId, request: fakeRequest, ...getSourceFromReferences(references), + taskInfo, relatedSavedObjects: validatedRelatedSavedObjects(logger, relatedSavedObjects), }); } catch (e) { diff --git a/x-pack/plugins/alerting/server/task_runner/create_execution_handler.test.ts b/x-pack/plugins/alerting/server/task_runner/create_execution_handler.test.ts index 033ffcceb6a0a..1dcd19119b6fd 100644 --- a/x-pack/plugins/alerting/server/task_runner/create_execution_handler.test.ts +++ b/x-pack/plugins/alerting/server/task_runner/create_execution_handler.test.ts @@ -195,7 +195,6 @@ test('enqueues execution per selected action', async () => { "id": "1", "license": "basic", "name": "name-of-alert", - "namespace": "test1", "ruleset": "alerts", }, }, diff --git a/x-pack/plugins/alerting/server/task_runner/create_execution_handler.ts b/x-pack/plugins/alerting/server/task_runner/create_execution_handler.ts index 968fff540dc03..3004ed599128e 100644 --- a/x-pack/plugins/alerting/server/task_runner/create_execution_handler.ts +++ b/x-pack/plugins/alerting/server/task_runner/create_execution_handler.ts @@ -209,7 +209,6 @@ export function createExecutionHandler< license: alertType.minimumLicenseRequired, category: alertType.id, ruleset: alertType.producer, - ...namespace, name: alertName, }, }; diff --git a/x-pack/plugins/alerting/server/task_runner/task_runner.test.ts b/x-pack/plugins/alerting/server/task_runner/task_runner.test.ts index 8ab267a5610d3..88d1b1b24a4ec 100644 --- a/x-pack/plugins/alerting/server/task_runner/task_runner.test.ts +++ b/x-pack/plugins/alerting/server/task_runner/task_runner.test.ts @@ -282,13 +282,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, } @@ -394,6 +397,10 @@ describe('Task Runner', () => { kind: 'alert', }, kibana: { + task: { + schedule_delay: 0, + scheduled: '1970-01-01T00:00:00.000Z', + }, saved_objects: [ { id: '1', @@ -409,7 +416,6 @@ describe('Task Runner', () => { category: 'test', id: '1', license: 'basic', - namespace: undefined, ruleset: 'alerts', }, }); @@ -518,6 +524,10 @@ describe('Task Runner', () => { alerting: { status: 'active', }, + task: { + schedule_delay: 0, + scheduled: '1970-01-01T00:00:00.000Z', + }, saved_objects: [ { id: '1', @@ -534,7 +544,6 @@ describe('Task Runner', () => { id: '1', license: 'basic', name: 'alert-name', - namespace: undefined, ruleset: 'alerts', }, }); @@ -603,6 +612,10 @@ describe('Task Runner', () => { kind: 'alert', }, kibana: { + task: { + schedule_delay: 0, + scheduled: '1970-01-01T00:00:00.000Z', + }, saved_objects: [ { id: '1', @@ -618,7 +631,6 @@ describe('Task Runner', () => { category: 'test', id: '1', license: 'basic', - namespace: undefined, ruleset: 'alerts', }, }); @@ -700,6 +712,10 @@ describe('Task Runner', () => { alerting: { status: 'active', }, + task: { + schedule_delay: 0, + scheduled: '1970-01-01T00:00:00.000Z', + }, saved_objects: [ { id: '1', @@ -716,7 +732,6 @@ describe('Task Runner', () => { id: '1', license: 'basic', name: 'alert-name', - namespace: undefined, ruleset: 'alerts', }, }); @@ -854,13 +869,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -897,7 +915,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -926,6 +943,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -933,7 +954,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1151,13 +1171,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1194,7 +1217,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1231,7 +1253,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1273,7 +1294,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1302,6 +1322,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -1309,7 +1333,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1433,13 +1456,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1476,7 +1502,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1513,7 +1538,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1555,7 +1579,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1597,7 +1620,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1626,6 +1648,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -1633,7 +1659,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -1968,13 +1993,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2012,7 +2040,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2049,7 +2076,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2078,6 +2104,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -2085,7 +2115,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2294,13 +2323,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2333,13 +2365,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution failure: test:1: 'alert-name'", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2397,13 +2432,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2436,13 +2474,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "test:1: execution failed", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2508,13 +2549,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2547,13 +2591,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "test:1: execution failed", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2619,13 +2666,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2658,13 +2708,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "test:1: execution failed", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2729,13 +2782,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -2768,13 +2824,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "test:1: execution failed", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3007,13 +3066,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3050,7 +3112,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3087,7 +3148,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3124,7 +3184,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3161,7 +3220,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3190,6 +3248,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -3197,7 +3259,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3291,13 +3352,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3334,7 +3398,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3371,7 +3434,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3400,6 +3462,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -3407,7 +3473,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3493,13 +3558,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3534,7 +3602,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3569,7 +3636,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3598,6 +3664,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -3605,7 +3675,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3686,13 +3755,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3729,7 +3801,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3766,7 +3837,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3795,6 +3865,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -3802,7 +3876,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3885,13 +3958,16 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert execution start: \\"1\\"", "rule": Object { "category": "test", "id": "1", "license": "basic", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3925,7 +4001,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3959,7 +4034,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, @@ -3988,6 +4062,10 @@ describe('Task Runner', () => { "type_id": "test", }, ], + "task": Object { + "schedule_delay": 0, + "scheduled": "1970-01-01T00:00:00.000Z", + }, }, "message": "alert executed: test:1: 'alert-name'", "rule": Object { @@ -3995,7 +4073,6 @@ describe('Task Runner', () => { "id": "1", "license": "basic", "name": "alert-name", - "namespace": undefined, "ruleset": "alerts", }, }, diff --git a/x-pack/plugins/alerting/server/task_runner/task_runner.ts b/x-pack/plugins/alerting/server/task_runner/task_runner.ts index b712b6237c8a7..c66c054bc8ac3 100644 --- a/x-pack/plugins/alerting/server/task_runner/task_runner.ts +++ b/x-pack/plugins/alerting/server/task_runner/task_runner.ts @@ -54,6 +54,9 @@ import { getEsErrorMessage } from '../lib/errors'; const FALLBACK_RETRY_INTERVAL = '5m'; +// 1,000,000 nanoseconds in 1 millisecond +const Millis2Nanos = 1000 * 1000; + type Event = Exclude; interface AlertTaskRunResult { @@ -489,15 +492,17 @@ export class TaskRunner< schedule: taskSchedule, } = this.taskInstance; - const runDate = new Date().toISOString(); - this.logger.debug(`executing alert ${this.alertType.id}:${alertId} at ${runDate}`); + const runDate = new Date(); + const runDateString = runDate.toISOString(); + this.logger.debug(`executing alert ${this.alertType.id}:${alertId} at ${runDateString}`); const namespace = this.context.spaceIdToNamespace(spaceId); const eventLogger = this.context.eventLogger; + const scheduleDelay = runDate.getTime() - this.taskInstance.runAt.getTime(); const event: IEvent = { // explicitly set execute timestamp so it will be before other events // generated here (new-instance, schedule-action, etc) - '@timestamp': runDate, + '@timestamp': runDateString, event: { action: EVENT_LOG_ACTIONS.execute, kind: 'alert', @@ -513,13 +518,16 @@ export class TaskRunner< namespace, }, ], + task: { + scheduled: this.taskInstance.runAt.toISOString(), + schedule_delay: Millis2Nanos * scheduleDelay, + }, }, rule: { id: alertId, license: this.alertType.minimumLicenseRequired, category: this.alertType.id, ruleset: this.alertType.producer, - namespace, }, }; @@ -814,7 +822,6 @@ function generateNewAndRecoveredInstanceEvents< license: ruleType.minimumLicenseRequired, category: ruleType.id, ruleset: ruleType.producer, - namespace, name: rule.name, }, }; diff --git a/x-pack/plugins/event_log/README.md b/x-pack/plugins/event_log/README.md index ffbd20dd6f2be..682bf2660c78b 100644 --- a/x-pack/plugins/event_log/README.md +++ b/x-pack/plugins/event_log/README.md @@ -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. kibana: { 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: { instance_id: "alert instance id, for relevant documents", action_group_id: "alert action group, for relevant documents", diff --git a/x-pack/plugins/event_log/generated/mappings.json b/x-pack/plugins/event_log/generated/mappings.json index 3eadcc21257b0..0f5f4af2052ee 100644 --- a/x-pack/plugins/event_log/generated/mappings.json +++ b/x-pack/plugins/event_log/generated/mappings.json @@ -214,10 +214,6 @@ "version": { "ignore_above": 1024, "type": "keyword" - }, - "namespace": { - "ignore_above": 1024, - "type": "keyword" } } }, @@ -241,6 +237,16 @@ "type": "keyword", "ignore_above": 1024 }, + "task": { + "properties": { + "scheduled": { + "type": "date" + }, + "schedule_delay": { + "type": "long" + } + } + }, "alerting": { "properties": { "instance_id": { diff --git a/x-pack/plugins/event_log/generated/schemas.ts b/x-pack/plugins/event_log/generated/schemas.ts index 2a066ca0bd15b..556ddec5a7001 100644 --- a/x-pack/plugins/event_log/generated/schemas.ts +++ b/x-pack/plugins/event_log/generated/schemas.ts @@ -91,7 +91,6 @@ export const EventSchema = schema.maybe( ruleset: ecsString(), uuid: ecsString(), version: ecsString(), - namespace: ecsString(), }) ), user: schema.maybe( @@ -102,6 +101,12 @@ export const EventSchema = schema.maybe( kibana: schema.maybe( schema.object({ server_uuid: ecsString(), + task: schema.maybe( + schema.object({ + scheduled: ecsDate(), + schedule_delay: ecsNumber(), + }) + ), alerting: schema.maybe( schema.object({ instance_id: ecsString(), diff --git a/x-pack/plugins/event_log/scripts/mappings.js b/x-pack/plugins/event_log/scripts/mappings.js index f2020e76b46ba..93fe053bd0cdf 100644 --- a/x-pack/plugins/event_log/scripts/mappings.js +++ b/x-pack/plugins/event_log/scripts/mappings.js @@ -17,6 +17,17 @@ exports.EcsCustomPropertyMappings = { type: 'keyword', ignore_above: 1024, }, + // task specific fields + task: { + properties: { + scheduled: { + type: 'date', + }, + schedule_delay: { + type: 'long', + }, + }, + }, // alerting specific fields alerting: { properties: { diff --git a/x-pack/plugins/event_log/server/event_logger.ts b/x-pack/plugins/event_log/server/event_logger.ts index 4af69de0f47a0..b985a173ccdbf 100644 --- a/x-pack/plugins/event_log/server/event_logger.ts +++ b/x-pack/plugins/event_log/server/event_logger.ts @@ -88,7 +88,7 @@ export class EventLogger implements IEventLogger { try { validatedEvent = validateEvent(this.eventLogService, event); } catch (err) { - this.systemLogger.warn(`invalid event logged: ${err.message}`); + this.systemLogger.warn(`invalid event logged: ${err.message}; ${JSON.stringify(event)})`); return; } diff --git a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/alerts.ts b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/alerts.ts index e9ed14fbcddcd..b3d83ae22f330 100644 --- a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/alerts.ts +++ b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/alerts.ts @@ -1304,7 +1304,6 @@ instanceStateValue: true license: 'basic', category: ruleObject.alertInfo.ruleTypeId, ruleset: ruleObject.alertInfo.producer, - namespace: spaceId, name: ruleObject.alertInfo.name, }); diff --git a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/event_log.ts b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/event_log.ts index 5d13d641367a4..940203a9b1f8c 100644 --- a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/event_log.ts +++ b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/event_log.ts @@ -81,12 +81,12 @@ export default function eventLogTests({ getService }: FtrProviderContext) { errorMessage: 'Unable to decrypt attribute "apiKey"', status: 'error', reason: 'decrypt', + shouldHaveTask: true, rule: { id: alertId, category: response.body.rule_type_id, license: 'basic', ruleset: 'alertsFixture', - namespace: spaceId, }, }); }); diff --git a/x-pack/test/alerting_api_integration/spaces_only/tests/actions/execute.ts b/x-pack/test/alerting_api_integration/spaces_only/tests/actions/execute.ts index d494c99c80e8f..1fa138149f29c 100644 --- a/x-pack/test/alerting_api_integration/spaces_only/tests/actions/execute.ts +++ b/x-pack/test/alerting_api_integration/spaces_only/tests/actions/execute.ts @@ -406,6 +406,8 @@ export default function ({ getService }: FtrProviderContext) { expect(startExecuteEvent?.message).to.eql(startMessage); } + expect(event?.kibana?.task).to.eql(undefined); + if (errorMessage) { expect(executeEvent?.error?.message).to.eql(errorMessage); } diff --git a/x-pack/test/alerting_api_integration/spaces_only/tests/alerting/event_log.ts b/x-pack/test/alerting_api_integration/spaces_only/tests/alerting/event_log.ts index fae5958d7827a..9bf7baf95d8d2 100644 --- a/x-pack/test/alerting_api_integration/spaces_only/tests/alerting/event_log.ts +++ b/x-pack/test/alerting_api_integration/spaces_only/tests/alerting/event_log.ts @@ -24,476 +24,512 @@ export default function eventLogTests({ getService }: FtrProviderContext) { after(() => objectRemover.removeAll()); - it('should generate expected events for normal operation', async () => { - const { body: createdAction } = await supertest - .post(`${getUrlPrefix(Spaces.space1.id)}/api/actions/connector`) - .set('kbn-xsrf', 'foo') - .send({ - name: 'MY action', - connector_type_id: 'test.noop', - config: {}, - secrets: {}, - }) - .expect(200); - - // pattern of when the alert should fire - const pattern = { - instance: [false, true, true], - }; - - 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: 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)', - }); - }); + for (const space of [Spaces.default, Spaces.space1]) { + describe(`in space ${space.id}`, () => { + it('should generate expected events for normal operation', async () => { + const { body: createdAction } = await supertest + .post(`${getUrlPrefix(space.id)}/api/actions/connector`) + .set('kbn-xsrf', 'foo') + .send({ + name: 'MY action', + connector_type_id: 'test.noop', + config: {}, + secrets: {}, + }) + .expect(200); + + // pattern of when the alert should fire + const pattern = { + instance: [false, true, true], + }; + + 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: {}, + }, + ], + }) + ); - 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, - }, + expect(response.status).to.eql(200); + const alertId = response.body.id; + objectRemover.add(space.id, alertId, 'rule', 'alerting'); + + // get the events we're expecting + const events = await retry.try(async () => { + return await getEventLog({ + getService, + spaceId: space.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: 1 }], + ['recovered-instance', { equal: 1 }], + ]), }); - break; - case 'execute': - validateEvent(event, { - spaceId: Spaces.space1.id, - savedObjects: [ - { type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' }, - ], - outcome: 'success', - 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, - }, + }); + + // get the filtered events only with action 'new-instance' + const filteredEvents = await retry.try(async () => { + return await getEventLog({ + getService, + spaceId: space.id, + type: 'alert', + id: alertId, + provider: 'alerting', + actions: new Map([['new-instance', { equal: 1 }]]), + filter: 'event.action:(new-instance)', }); - 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, { - spaceId: Spaces.space1.id, + 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}`, + 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, }, }); - 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}"`); - } - } - - function validateInstanceEvent( - event: IValidatedEvent, - subMessage: string, - 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 () => { - const { body: createdAction } = await supertest - .post(`${getUrlPrefix(Spaces.space1.id)}/api/actions/connector`) - .set('kbn-xsrf', 'foo') - .send({ - name: 'MY action', - connector_type_id: 'test.noop', - config: {}, - 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(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': - validateEvent(event, { - spaceId: Spaces.space1.id, - savedObjects: [ - { type: 'alert', id: alertId, rel: 'primary', type_id: 'test.patternFiring' }, - ], - outcome: 'success', - 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, - }, + it('should generate expected events for normal operation with subgroups', async () => { + const { body: createdAction } = await supertest + .post(`${getUrlPrefix(space.id)}/api/actions/connector`) + .set('kbn-xsrf', 'foo') + .send({ + name: 'MY action', + connector_type_id: 'test.noop', + config: {}, + 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: {}, + }, + ], + }) + ); + + expect(response.status).to.eql(200); + const alertId = response.body.id; + objectRemover.add(space.id, alertId, 'rule', 'alerting'); + + // get the events we're expecting + const events = await retry.try(async () => { + return await getEventLog({ + getService, + spaceId: space.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 }], + ]), }); - break; - case 'execute-action': - expect( - [firstSubgroup, secondSubgroup].includes(event?.kibana?.alerting?.action_subgroup!) - ).to.be(true); + }); + + 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, { - spaceId: Spaces.space1.id, + 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}`, + 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, }, }); - 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, { - 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 response = await supertest - .post(`${getUrlPrefix(Spaces.space1.id)}/api/alerting/rule`) - .set('kbn-xsrf', 'foo') - .send( - getTestAlertData({ - rule_type_id: 'test.throw', - schedule: { interval: '1s' }, - throttle: null, - }) - ); - - expect(response.status).to.eql(200); - const alertId = response.body.id; - objectRemover.add(Spaces.space1.id, alertId, 'rule', 'alerting'); - - const events = await retry.try(async () => { - return await getEventLog({ - getService, - spaceId: Spaces.space1.id, - type: 'alert', - id: alertId, - provider: 'alerting', - actions: new Map([ - ['execute-start', { gte: 1 }], - ['execute', { gte: 1 }], - ]), + } }); - }); - 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, - }, - }); + it('should generate events for execution errors', async () => { + const response = await supertest + .post(`${getUrlPrefix(space.id)}/api/alerting/rule`) + .set('kbn-xsrf', 'foo') + .send( + getTestAlertData({ + rule_type_id: 'test.throw', + schedule: { interval: '1s' }, + throttle: null, + }) + ); + + expect(response.status).to.eql(200); + const alertId = response.body.id; + objectRemover.add(space.id, alertId, 'rule', 'alerting'); + + const events = await retry.try(async () => { + return await getEventLog({ + getService, + spaceId: space.id, + type: 'alert', + id: alertId, + provider: 'alerting', + actions: new Map([ + ['execute-start', { gte: 1 }], + ['execute', { gte: 1 }], + ]), + }); + }); - 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, - }, + const startEvent = events[0]; + const executeEvent = events[1]; + + expect(startEvent).to.be.ok(); + expect(executeEvent).to.be.ok(); + + validateEvent(startEvent, { + 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', + }, + }); + + 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', + }, + }); + }); }); - }); + } }); } @@ -510,12 +546,13 @@ interface ValidateEventLogParams { outcome?: string; message: string; shouldHaveEventEnd?: boolean; + shouldHaveTask?: boolean; errorMessage?: string; status?: string; actionGroupId?: string; instanceId?: string; reason?: string; - rule: { + rule?: { id: string; name?: string; version?: string; @@ -529,7 +566,7 @@ interface ValidateEventLogParams { } 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; if (status) { @@ -587,6 +624,16 @@ export function validateEvent(event: IValidatedEvent, params: ValidateEventLogPa 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) { expect(event?.error?.message).to.eql(errorMessage); } @@ -602,12 +649,13 @@ function getTimestamps(events: IValidatedEvent[]) { function isSavedObjectInEvent( event: IValidatedEvent, - namespace: string, + spaceId: string, type: string, id: string, rel?: string ): boolean { const savedObjects = event?.kibana?.saved_objects ?? []; + const namespace = spaceId === 'default' ? undefined : spaceId; for (const savedObject of savedObjects) { if (