diff --git a/x-pack/plugins/alerts/server/alert_instance/alert_instance.ts b/x-pack/plugins/alerts/server/alert_instance/alert_instance.ts index 661fb75f81c00..01790b2a4a0c0 100644 --- a/x-pack/plugins/alerts/server/alert_instance/alert_instance.ts +++ b/x-pack/plugins/alerts/server/alert_instance/alert_instance.ts @@ -51,6 +51,10 @@ export class AlertInstance< return false; } + getLastScheduledActions() { + return this.meta.lastScheduledActions; + } + getScheduledActionOptions() { return this.scheduledExecutionOptions; } diff --git a/x-pack/plugins/alerts/server/task_runner/create_execution_handler.test.ts b/x-pack/plugins/alerts/server/task_runner/create_execution_handler.test.ts index 2f0754d34492f..ed73fec24db26 100644 --- a/x-pack/plugins/alerts/server/task_runner/create_execution_handler.test.ts +++ b/x-pack/plugins/alerts/server/task_runner/create_execution_handler.test.ts @@ -113,6 +113,7 @@ test('enqueues execution per selected action', async () => { }, "kibana": Object { "alerting": Object { + "action_group_id": "default", "instance_id": "2", }, "saved_objects": Array [ diff --git a/x-pack/plugins/alerts/server/task_runner/create_execution_handler.ts b/x-pack/plugins/alerts/server/task_runner/create_execution_handler.ts index 21e642d228b4d..f49310c42c247 100644 --- a/x-pack/plugins/alerts/server/task_runner/create_execution_handler.ts +++ b/x-pack/plugins/alerts/server/task_runner/create_execution_handler.ts @@ -116,6 +116,7 @@ export function createExecutionHandler({ kibana: { alerting: { instance_id: alertInstanceId, + action_group_id: actionGroup, }, saved_objects: [ { rel: SAVED_OBJECT_REL_PRIMARY, type: 'alert', id: alertId, ...namespace }, diff --git a/x-pack/plugins/alerts/server/task_runner/task_runner.test.ts b/x-pack/plugins/alerts/server/task_runner/task_runner.test.ts index 4d0d69010914e..859b6ec4362ce 100644 --- a/x-pack/plugins/alerts/server/task_runner/task_runner.test.ts +++ b/x-pack/plugins/alerts/server/task_runner/task_runner.test.ts @@ -184,11 +184,15 @@ describe('Task Runner', () => { expect(eventLogger.logEvent).toHaveBeenCalledTimes(1); expect(eventLogger.logEvent.mock.calls[0][0]).toMatchInlineSnapshot(` Object { + "@timestamp": "1970-01-01T00:00:00.000Z", "event": Object { "action": "execute", "outcome": "success", }, "kibana": Object { + "alerting": Object { + "status": "ok", + }, "saved_objects": Array [ Object { "id": "1", @@ -249,29 +253,13 @@ describe('Task Runner', () => { const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; expect(eventLogger.logEvent).toHaveBeenCalledTimes(4); - expect(eventLogger.logEvent).toHaveBeenCalledWith({ - event: { - action: 'execute', - outcome: 'success', - }, - kibana: { - saved_objects: [ - { - id: '1', - namespace: undefined, - rel: 'primary', - type: 'alert', - }, - ], - }, - message: "alert executed: test:1: 'alert-name'", - }); - expect(eventLogger.logEvent).toHaveBeenCalledWith({ + expect(eventLogger.logEvent).toHaveBeenNthCalledWith(1, { event: { action: 'new-instance', }, kibana: { alerting: { + action_group_id: 'default', instance_id: '1', }, saved_objects: [ @@ -285,7 +273,7 @@ describe('Task Runner', () => { }, message: "test:1: 'alert-name' created new instance: '1'", }); - expect(eventLogger.logEvent).toHaveBeenCalledWith({ + expect(eventLogger.logEvent).toHaveBeenNthCalledWith(2, { event: { action: 'active-instance', }, @@ -305,13 +293,14 @@ describe('Task Runner', () => { }, message: "test:1: 'alert-name' active instance: '1' in actionGroup: 'default'", }); - expect(eventLogger.logEvent).toHaveBeenCalledWith({ + expect(eventLogger.logEvent).toHaveBeenNthCalledWith(3, { event: { action: 'execute-action', }, kibana: { alerting: { instance_id: '1', + action_group_id: 'default', }, saved_objects: [ { @@ -330,6 +319,27 @@ describe('Task Runner', () => { message: "alert: test:1: 'alert-name' instanceId: '1' scheduled actionGroup: 'default' action: action:1", }); + expect(eventLogger.logEvent).toHaveBeenNthCalledWith(4, { + '@timestamp': '1970-01-01T00:00:00.000Z', + event: { + action: 'execute', + outcome: 'success', + }, + kibana: { + alerting: { + status: 'active', + }, + saved_objects: [ + { + id: '1', + namespace: undefined, + rel: 'primary', + type: 'alert', + }, + ], + }, + message: "alert executed: test:1: 'alert-name'", + }); }); test('includes the apiKey in the request used to initialize the actionsClient', async () => { @@ -402,10 +412,13 @@ describe('Task Runner', () => { Array [ Object { "event": Object { - "action": "execute", - "outcome": "success", + "action": "new-instance", }, "kibana": Object { + "alerting": Object { + "action_group_id": "default", + "instance_id": "1", + }, "saved_objects": Array [ Object { "id": "1", @@ -415,17 +428,17 @@ describe('Task Runner', () => { }, ], }, - "message": "alert executed: test:1: 'alert-name'", + "message": "test:1: 'alert-name' created new instance: '1'", }, ], Array [ Object { "event": Object { - "action": "new-instance", + "action": "active-instance", }, "kibana": Object { "alerting": Object { - "action_group_id": undefined, + "action_group_id": "default", "instance_id": "1", }, "saved_objects": Array [ @@ -437,13 +450,13 @@ describe('Task Runner', () => { }, ], }, - "message": "test:1: 'alert-name' created new instance: '1'", + "message": "test:1: 'alert-name' active instance: '1' in actionGroup: 'default'", }, ], Array [ Object { "event": Object { - "action": "active-instance", + "action": "execute-action", }, "kibana": Object { "alerting": Object { @@ -457,19 +470,26 @@ describe('Task Runner', () => { "rel": "primary", "type": "alert", }, + Object { + "id": "1", + "namespace": undefined, + "type": "action", + }, ], }, - "message": "test:1: 'alert-name' active instance: '1' in actionGroup: 'default'", + "message": "alert: test:1: 'alert-name' instanceId: '1' scheduled actionGroup: 'default' action: action:1", }, ], Array [ Object { + "@timestamp": "1970-01-01T00:00:00.000Z", "event": Object { - "action": "execute-action", + "action": "execute", + "outcome": "success", }, "kibana": Object { "alerting": Object { - "instance_id": "1", + "status": "active", }, "saved_objects": Array [ Object { @@ -478,14 +498,9 @@ describe('Task Runner', () => { "rel": "primary", "type": "alert", }, - Object { - "id": "1", - "namespace": undefined, - "type": "action", - }, ], }, - "message": "alert: test:1: 'alert-name' instanceId: '1' scheduled actionGroup: 'default' action: action:1", + "message": "alert executed: test:1: 'alert-name'", }, ], ] @@ -498,6 +513,7 @@ describe('Task Runner', () => { executorServices.alertInstanceFactory('1').scheduleActions('default'); } ); + const date = new Date().toISOString(); const taskRunner = new TaskRunner( alertType, { @@ -505,8 +521,14 @@ describe('Task Runner', () => { state: { ...mockedTaskInstance.state, alertInstances: { - '1': { meta: {}, state: { bar: false } }, - '2': { meta: {}, state: { bar: false } }, + '1': { + meta: { lastScheduledActions: { group: 'default', date } }, + state: { bar: false }, + }, + '2': { + meta: { lastScheduledActions: { group: 'default', date } }, + state: { bar: false }, + }, }, }, }, @@ -545,10 +567,13 @@ describe('Task Runner', () => { Array [ Object { "event": Object { - "action": "execute", - "outcome": "success", + "action": "resolved-instance", }, "kibana": Object { + "alerting": Object { + "action_group_id": "default", + "instance_id": "2", + }, "saved_objects": Array [ Object { "id": "1", @@ -558,18 +583,18 @@ describe('Task Runner', () => { }, ], }, - "message": "alert executed: test:1: 'alert-name'", + "message": "test:1: 'alert-name' resolved instance: '2'", }, ], Array [ Object { "event": Object { - "action": "resolved-instance", + "action": "active-instance", }, "kibana": Object { "alerting": Object { - "action_group_id": undefined, - "instance_id": "2", + "action_group_id": "default", + "instance_id": "1", }, "saved_objects": Array [ Object { @@ -580,18 +605,19 @@ describe('Task Runner', () => { }, ], }, - "message": "test:1: 'alert-name' resolved instance: '2'", + "message": "test:1: 'alert-name' active instance: '1' in actionGroup: 'default'", }, ], Array [ Object { + "@timestamp": "1970-01-01T00:00:00.000Z", "event": Object { - "action": "active-instance", + "action": "execute", + "outcome": "success", }, "kibana": Object { "alerting": Object { - "action_group_id": "default", - "instance_id": "1", + "status": "active", }, "saved_objects": Array [ Object { @@ -602,7 +628,7 @@ describe('Task Runner', () => { }, ], }, - "message": "test:1: 'alert-name' active instance: '1' in actionGroup: 'default'", + "message": "alert executed: test:1: 'alert-name'", }, ], ] @@ -787,14 +813,19 @@ describe('Task Runner', () => { Array [ Array [ Object { + "@timestamp": "1970-01-01T00:00:00.000Z", "error": Object { "message": "OMG", }, "event": Object { "action": "execute", "outcome": "failure", + "reason": "execute", }, "kibana": Object { + "alerting": Object { + "status": "error", + }, "saved_objects": Array [ Object { "id": "1", @@ -834,6 +865,40 @@ describe('Task Runner', () => { "state": Object {}, } `); + + const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; + expect(eventLogger.logEvent).toHaveBeenCalledTimes(1); + expect(eventLogger.logEvent.mock.calls).toMatchInlineSnapshot(` + Array [ + Array [ + Object { + "@timestamp": "1970-01-01T00:00:00.000Z", + "error": Object { + "message": "OMG", + }, + "event": Object { + "action": "execute", + "outcome": "failure", + "reason": "decrypt", + }, + "kibana": Object { + "alerting": Object { + "status": "error", + }, + "saved_objects": Array [ + Object { + "id": "1", + "namespace": undefined, + "rel": "primary", + "type": "alert", + }, + ], + }, + "message": "test:1: execution failed", + }, + ], + ] + `); }); test('recovers gracefully when the Alert Task Runner throws an exception when getting internal Services', async () => { @@ -867,6 +932,40 @@ describe('Task Runner', () => { "state": Object {}, } `); + + const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; + expect(eventLogger.logEvent).toHaveBeenCalledTimes(1); + expect(eventLogger.logEvent.mock.calls).toMatchInlineSnapshot(` + Array [ + Array [ + Object { + "@timestamp": "1970-01-01T00:00:00.000Z", + "error": Object { + "message": "OMG", + }, + "event": Object { + "action": "execute", + "outcome": "failure", + "reason": "unknown", + }, + "kibana": Object { + "alerting": Object { + "status": "error", + }, + "saved_objects": Array [ + Object { + "id": "1", + "namespace": undefined, + "rel": "primary", + "type": "alert", + }, + ], + }, + "message": "test:1: execution failed", + }, + ], + ] + `); }); test('recovers gracefully when the Alert Task Runner throws an exception when fetching attributes', async () => { @@ -899,6 +998,40 @@ describe('Task Runner', () => { "state": Object {}, } `); + + const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; + expect(eventLogger.logEvent).toHaveBeenCalledTimes(1); + expect(eventLogger.logEvent.mock.calls).toMatchInlineSnapshot(` + Array [ + Array [ + Object { + "@timestamp": "1970-01-01T00:00:00.000Z", + "error": Object { + "message": "OMG", + }, + "event": Object { + "action": "execute", + "outcome": "failure", + "reason": "read", + }, + "kibana": Object { + "alerting": Object { + "status": "error", + }, + "saved_objects": Array [ + Object { + "id": "1", + "namespace": undefined, + "rel": "primary", + "type": "alert", + }, + ], + }, + "message": "test:1: execution failed", + }, + ], + ] + `); }); test('recovers gracefully when the Runner of a legacy Alert task which has no schedule throws an exception when fetching attributes', async () => { diff --git a/x-pack/plugins/alerts/server/task_runner/task_runner.ts b/x-pack/plugins/alerts/server/task_runner/task_runner.ts index 86bf7006e8d09..5bccf5c497a60 100644 --- a/x-pack/plugins/alerts/server/task_runner/task_runner.ts +++ b/x-pack/plugins/alerts/server/task_runner/task_runner.ts @@ -4,7 +4,7 @@ * you may not use this file except in compliance with the Elastic License. */ import type { PublicMethodsOf } from '@kbn/utility-types'; -import { Dictionary, pickBy, mapValues, without } from 'lodash'; +import { Dictionary, pickBy, mapValues, without, cloneDeep } from 'lodash'; import { Logger, KibanaRequest } from '../../../../../src/core/server'; import { TaskRunnerContext } from './task_runner_factory'; import { ConcreteTaskInstance, throwUnrecoverableError } from '../../../task_manager/server'; @@ -40,6 +40,8 @@ import { partiallyUpdateAlert } from '../saved_objects'; const FALLBACK_RETRY_INTERVAL = '5m'; +type Event = Exclude; + interface AlertTaskRunResult { state: AlertTaskState; schedule: IntervalSchedule | undefined; @@ -153,7 +155,8 @@ export class TaskRunner { alert: SanitizedAlert, params: AlertExecutorOptions['params'], executionHandler: ReturnType, - spaceId: string + spaceId: string, + event: Event ): Promise { const { throttle, muteAll, mutedInstanceIds, name, tags, createdBy, updatedBy } = alert; const { @@ -166,24 +169,10 @@ export class TaskRunner { alertRawInstances, (rawAlertInstance) => new AlertInstance(rawAlertInstance) ); + const originalAlertInstances = cloneDeep(alertInstances); - const originalAlertInstanceIds = Object.keys(alertInstances); const eventLogger = this.context.eventLogger; const alertLabel = `${this.alertType.id}:${alertId}: '${name}'`; - const event: IEvent = { - event: { action: EVENT_LOG_ACTIONS.execute }, - kibana: { - saved_objects: [ - { - rel: SAVED_OBJECT_REL_PRIMARY, - type: 'alert', - id: alertId, - namespace, - }, - ], - }, - }; - eventLogger.startTiming(event); let updatedAlertTypeState: void | Record; try { @@ -205,21 +194,17 @@ export class TaskRunner { updatedBy, }); } catch (err) { - eventLogger.stopTiming(event); event.message = `alert execution failure: ${alertLabel}`; event.error = event.error || {}; event.error.message = err.message; event.event = event.event || {}; event.event.outcome = 'failure'; - eventLogger.logEvent(event); throw new ErrorWithReason(AlertExecutionStatusErrorReasons.Execute, err); } - eventLogger.stopTiming(event); event.message = `alert executed: ${alertLabel}`; event.event = event.event || {}; event.event.outcome = 'success'; - eventLogger.logEvent(event); // Cleanup alert instances that are no longer scheduling actions to avoid over populating the alertInstances object const instancesWithScheduledActions = pickBy(alertInstances, (alertInstance: AlertInstance) => @@ -227,7 +212,7 @@ export class TaskRunner { ); generateNewAndResolvedInstanceEvents({ eventLogger, - originalAlertInstanceIds, + originalAlertInstances, currentAlertInstances: instancesWithScheduledActions, alertId, alertLabel, @@ -261,7 +246,8 @@ export class TaskRunner { async validateAndExecuteAlert( services: Services, apiKey: RawAlert['apiKey'], - alert: SanitizedAlert + alert: SanitizedAlert, + event: Event ) { const { params: { alertId, spaceId }, @@ -278,10 +264,17 @@ export class TaskRunner { alert.actions, alert.params ); - return this.executeAlertInstances(services, alert, validatedParams, executionHandler, spaceId); + return this.executeAlertInstances( + services, + alert, + validatedParams, + executionHandler, + spaceId, + event + ); } - async loadAlertAttributesAndRun(): Promise> { + async loadAlertAttributesAndRun(event: Event): Promise> { const { params: { alertId, spaceId }, } = this.taskInstance; @@ -304,7 +297,7 @@ export class TaskRunner { return { state: await promiseResult( - this.validateAndExecuteAlert(services, apiKey, alert) + this.validateAndExecuteAlert(services, apiKey, alert, event) ), schedule: asOk( // fetch the alert again to ensure we return the correct schedule as it may have @@ -322,18 +315,65 @@ export class TaskRunner { schedule: taskSchedule, } = this.taskInstance; - const { state, schedule } = await errorAsAlertTaskRunResult(this.loadAlertAttributesAndRun()); - const namespace = spaceId === 'default' ? undefined : spaceId; + const namespace = this.context.spaceIdToNamespace(spaceId); + const eventLogger = this.context.eventLogger; + const event: IEvent = { + // explicitly set execute timestamp so it will be before other events + // generated here (new-instance, schedule-action, etc) + '@timestamp': new Date().toISOString(), + event: { action: EVENT_LOG_ACTIONS.execute }, + kibana: { + saved_objects: [ + { + rel: SAVED_OBJECT_REL_PRIMARY, + type: 'alert', + id: alertId, + namespace, + }, + ], + }, + }; + eventLogger.startTiming(event); + + const { state, schedule } = await errorAsAlertTaskRunResult( + this.loadAlertAttributesAndRun(event) + ); const executionStatus: AlertExecutionStatus = map( state, (alertTaskState: AlertTaskState) => executionStatusFromState(alertTaskState), (err: Error) => executionStatusFromError(err) ); + + // set the executionStatus date to same as event, if it's set + if (event.event?.start) { + executionStatus.lastExecutionDate = new Date(event.event.start); + } + this.logger.debug( `alertExecutionStatus for ${this.alertType.id}:${alertId}: ${JSON.stringify(executionStatus)}` ); + eventLogger.stopTiming(event); + event.kibana = event.kibana || {}; + event.kibana.alerting = event.kibana.alerting || {}; + event.kibana.alerting.status = executionStatus.status; + + // if executionStatus indicates an error, fill in fields in + // event from it + if (executionStatus.error) { + event.event = event.event || {}; + event.event.reason = executionStatus.error?.reason || 'unknown'; + event.event.outcome = 'failure'; + event.error = event.error || {}; + event.error.message = event.error.message || executionStatus.error.message; + if (!event.message) { + event.message = `${this.alertType.id}:${alertId}: execution failed`; + } + } + + eventLogger.logEvent(event); + const client = this.context.internalSavedObjectsRepository; const attributes = { executionStatus: alertExecutionStatusToRaw(executionStatus), @@ -381,7 +421,7 @@ export class TaskRunner { interface GenerateNewAndResolvedInstanceEventsParams { eventLogger: IEventLogger; - originalAlertInstanceIds: string[]; + originalAlertInstances: Dictionary; currentAlertInstances: Dictionary; alertId: string; alertLabel: string; @@ -389,26 +429,23 @@ interface GenerateNewAndResolvedInstanceEventsParams { } function generateNewAndResolvedInstanceEvents(params: GenerateNewAndResolvedInstanceEventsParams) { - const { - eventLogger, - alertId, - namespace, - currentAlertInstances, - originalAlertInstanceIds, - } = params; + const { eventLogger, alertId, namespace, currentAlertInstances, originalAlertInstances } = params; + const originalAlertInstanceIds = Object.keys(originalAlertInstances); const currentAlertInstanceIds = Object.keys(currentAlertInstances); const newIds = without(currentAlertInstanceIds, ...originalAlertInstanceIds); const resolvedIds = without(originalAlertInstanceIds, ...currentAlertInstanceIds); for (const id of resolvedIds) { + const actionGroup = originalAlertInstances[id].getLastScheduledActions()?.group; const message = `${params.alertLabel} resolved instance: '${id}'`; - logInstanceEvent(id, EVENT_LOG_ACTIONS.resolvedInstance, message); + logInstanceEvent(id, EVENT_LOG_ACTIONS.resolvedInstance, message, actionGroup); } for (const id of newIds) { + const actionGroup = currentAlertInstances[id].getScheduledActionOptions()?.actionGroup; const message = `${params.alertLabel} created new instance: '${id}'`; - logInstanceEvent(id, EVENT_LOG_ACTIONS.newInstance, message); + logInstanceEvent(id, EVENT_LOG_ACTIONS.newInstance, message, actionGroup); } for (const id of currentAlertInstanceIds) { @@ -425,7 +462,7 @@ function generateNewAndResolvedInstanceEvents(params: GenerateNewAndResolvedInst kibana: { alerting: { instance_id: instanceId, - action_group_id: group, + ...(group ? { action_group_id: group } : {}), }, saved_objects: [ { diff --git a/x-pack/plugins/event_log/generated/mappings.json b/x-pack/plugins/event_log/generated/mappings.json index 5c7eb50117d9b..3131235ebcfbe 100644 --- a/x-pack/plugins/event_log/generated/mappings.json +++ b/x-pack/plugins/event_log/generated/mappings.json @@ -45,6 +45,10 @@ "outcome": { "ignore_above": 1024, "type": "keyword" + }, + "reason": { + "ignore_above": 1024, + "type": "keyword" } } }, @@ -85,6 +89,10 @@ "action_group_id": { "type": "keyword", "ignore_above": 1024 + }, + "status": { + "type": "keyword", + "ignore_above": 1024 } } }, diff --git a/x-pack/plugins/event_log/generated/schemas.ts b/x-pack/plugins/event_log/generated/schemas.ts index 3dbb43b15350f..d2024ea8ed14a 100644 --- a/x-pack/plugins/event_log/generated/schemas.ts +++ b/x-pack/plugins/event_log/generated/schemas.ts @@ -18,7 +18,7 @@ type DeepPartial = { [P in keyof T]?: T[P] extends Array ? Array> : DeepPartial; }; -export const ECS_VERSION = '1.5.0'; +export const ECS_VERSION = '1.6.0'; // types and config-schema describing the es structures export type IValidatedEvent = TypeOf; @@ -42,6 +42,7 @@ export const EventSchema = schema.maybe( duration: ecsNumber(), end: ecsDate(), outcome: ecsString(), + reason: ecsString(), }) ), error: schema.maybe( @@ -61,6 +62,7 @@ export const EventSchema = schema.maybe( schema.object({ instance_id: ecsString(), action_group_id: ecsString(), + status: ecsString(), }) ), saved_objects: schema.maybe( diff --git a/x-pack/plugins/event_log/scripts/mappings.js b/x-pack/plugins/event_log/scripts/mappings.js index c9af2b0aa57fb..bd05f84d4e2b8 100644 --- a/x-pack/plugins/event_log/scripts/mappings.js +++ b/x-pack/plugins/event_log/scripts/mappings.js @@ -22,6 +22,10 @@ exports.EcsKibanaExtensionsMappings = { type: 'keyword', ignore_above: 1024, }, + status: { + type: 'keyword', + ignore_above: 1024, + }, }, }, // array of saved object references, for "linking" via search @@ -63,11 +67,13 @@ exports.EcsEventLogProperties = [ 'event.duration', 'event.end', 'event.outcome', // optional, but one of failure, success, unknown + 'event.reason', 'error.message', 'user.name', 'kibana.server_uuid', 'kibana.alerting.instance_id', 'kibana.alerting.action_group_id', + 'kibana.alerting.status', 'kibana.saved_objects.rel', 'kibana.saved_objects.namespace', 'kibana.saved_objects.id', diff --git a/x-pack/plugins/event_log/server/event_logger.test.ts b/x-pack/plugins/event_log/server/event_logger.test.ts index 0ab3071f70efa..ea699af45ccd2 100644 --- a/x-pack/plugins/event_log/server/event_logger.test.ts +++ b/x-pack/plugins/event_log/server/event_logger.test.ts @@ -102,16 +102,16 @@ describe('EventLogger', () => { event: { provider: 'test-provider', action: 'a' }, }); - const ignoredTimestamp = '1999-01-01T00:00:00Z'; + const respectedTimestamp = '2999-01-01T00:00:00.000Z'; eventLogger.logEvent({ - '@timestamp': ignoredTimestamp, + '@timestamp': respectedTimestamp, event: { action: 'b', }, }); const event = await waitForLogEvent(systemLogger); - expect(event!['@timestamp']).not.toEqual(ignoredTimestamp); + expect(event!['@timestamp']).toEqual(respectedTimestamp); expect(event?.event?.action).toEqual('b'); }); diff --git a/x-pack/plugins/event_log/server/event_logger.ts b/x-pack/plugins/event_log/server/event_logger.ts index 8730870f9620b..658d90d809652 100644 --- a/x-pack/plugins/event_log/server/event_logger.ts +++ b/x-pack/plugins/event_log/server/event_logger.ts @@ -72,7 +72,6 @@ export class EventLogger implements IEventLogger { const event: IEvent = {}; const fixedProperties = { - '@timestamp': new Date().toISOString(), ecs: { version: ECS_VERSION, }, @@ -81,8 +80,12 @@ export class EventLogger implements IEventLogger { }, }; + const defaultProperties = { + '@timestamp': new Date().toISOString(), + }; + // merge the initial properties and event properties - merge(event, this.initialProperties, eventProperties, fixedProperties); + merge(event, defaultProperties, this.initialProperties, eventProperties, fixedProperties); let validatedEvent: IValidatedEvent; try { 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 new file mode 100644 index 0000000000000..385d8bfca4a9a --- /dev/null +++ b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/event_log.ts @@ -0,0 +1,84 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License; + * you may not use this file except in compliance with the Elastic License. + */ + +import expect from '@kbn/expect'; +import { Spaces } from '../../scenarios'; +import { getUrlPrefix, getTestAlertData, ObjectRemover, getEventLog } from '../../../common/lib'; +import { FtrProviderContext } from '../../../common/ftr_provider_context'; +import { validateEvent } from '../../../spaces_only/tests/alerting/event_log'; + +// eslint-disable-next-line import/no-default-export +export default function eventLogTests({ getService }: FtrProviderContext) { + const supertest = getService('supertest'); + const retry = getService('retry'); + + describe('eventLog', () => { + const objectRemover = new ObjectRemover(supertest); + + after(() => objectRemover.removeAll()); + + it('should generate events for alert decrypt errors', async () => { + const spaceId = Spaces[0].id; + const response = await supertest + .post(`${getUrlPrefix(spaceId)}/api/alerts/alert`) + .set('kbn-xsrf', 'foo') + .send( + getTestAlertData({ + alertTypeId: 'test.noop', + schedule: { interval: '1s' }, + throttle: null, + }) + ); + + expect(response.status).to.eql(200); + const alertId = response.body.id; + objectRemover.add(spaceId, alertId, 'alert', 'alerts'); + + // break AAD + await supertest + .put(`${getUrlPrefix(spaceId)}/api/alerts_fixture/saved_object/alert/${alertId}`) + .set('kbn-xsrf', 'foo') + .send({ + attributes: { + name: 'bar', + }, + }) + .expect(200); + + const events = await retry.try(async () => { + // there can be a successful execute before the error one + const someEvents = await getEventLog({ + getService, + spaceId, + type: 'alert', + id: alertId, + provider: 'alerting', + actions: ['execute'], + }); + const errorEvents = someEvents.filter( + (event) => event?.kibana?.alerting?.status === 'error' + ); + if (errorEvents.length === 0) { + throw new Error('no execute/error events yet'); + } + return errorEvents; + }); + + const event = events[0]; + expect(event).to.be.ok(); + + validateEvent(event, { + spaceId, + savedObjects: [{ type: 'alert', id: alertId, rel: 'primary' }], + outcome: 'failure', + message: `test.noop:${alertId}: execution failed`, + errorMessage: 'Unable to decrypt attribute "apiKey"', + status: 'error', + reason: 'decrypt', + }); + }); + }); +} diff --git a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/index.ts b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/index.ts index 1fbee9e18fdaa..4f8525cfcf683 100644 --- a/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/index.ts +++ b/x-pack/test/alerting_api_integration/security_and_spaces/tests/alerting/index.ts @@ -26,6 +26,7 @@ export default function alertingTests({ loadTestFile }: FtrProviderContext) { loadTestFile(require.resolve('./update')); loadTestFile(require.resolve('./update_api_key')); loadTestFile(require.resolve('./alerts')); + loadTestFile(require.resolve('./event_log')); // note that this test will destroy existing spaces loadTestFile(require.resolve('./rbac_legacy')); 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 dbf8eb162fca7..937045b6218c6 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 @@ -107,6 +107,8 @@ export default function eventLogTests({ getService }: FtrProviderContext) { expect(resolvedInstanceTimes[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': @@ -115,6 +117,7 @@ export default function eventLogTests({ getService }: FtrProviderContext) { savedObjects: [{ type: 'alert', id: alertId, rel: 'primary' }], outcome: 'success', message: `alert executed: test.patternFiring:${alertId}: 'abc'`, + status: executeStatuses[executeCount++], }); break; case 'execute-action': @@ -125,6 +128,8 @@ export default function eventLogTests({ getService }: FtrProviderContext) { { type: 'action', id: createdAction.id }, ], message: `alert: test.patternFiring:${alertId}: 'abc' instanceId: 'instance' scheduled actionGroup: 'default' action: test.noop:${createdAction.id}`, + instanceId: 'instance', + actionGroupId: 'default', }); break; case 'new-instance': @@ -147,6 +152,8 @@ export default function eventLogTests({ getService }: FtrProviderContext) { spaceId: Spaces.space1.id, savedObjects: [{ type: 'alert', id: alertId, rel: 'primary' }], message: `test.patternFiring:${alertId}: 'abc' ${subMessage}`, + instanceId: 'instance', + actionGroupId: 'default', }); } }); @@ -187,60 +194,83 @@ export default function eventLogTests({ getService }: FtrProviderContext) { outcome: 'failure', message: `alert execution failure: test.throw:${alertId}: 'abc'`, errorMessage: 'this alert is intended to fail', + status: 'error', + reason: 'execute', }); }); }); +} + +interface SavedObject { + type: string; + id: string; + rel?: string; +} + +interface ValidateEventLogParams { + spaceId: string; + savedObjects: SavedObject[]; + outcome?: string; + message: string; + errorMessage?: string; + status?: string; + actionGroupId?: string; + instanceId?: string; + reason?: string; +} + +export function validateEvent(event: IValidatedEvent, params: ValidateEventLogParams): void { + const { spaceId, savedObjects, outcome, message, errorMessage } = params; + const { status, actionGroupId, instanceId, reason } = params; - interface SavedObject { - type: string; - id: string; - rel?: string; + if (status) { + expect(event?.kibana?.alerting?.status).to.be(status); } - interface ValidateEventLogParams { - spaceId: string; - savedObjects: SavedObject[]; - outcome?: string; - message: string; - errorMessage?: string; + if (actionGroupId) { + expect(event?.kibana?.alerting?.action_group_id).to.be(actionGroupId); } - function validateEvent(event: IValidatedEvent, params: ValidateEventLogParams): void { - const { spaceId, savedObjects, outcome, message, errorMessage } = params; + if (instanceId) { + expect(event?.kibana?.alerting?.instance_id).to.be(instanceId); + } - const duration = event?.event?.duration; - const eventStart = Date.parse(event?.event?.start || 'undefined'); - const eventEnd = Date.parse(event?.event?.end || 'undefined'); - const dateNow = Date.now(); + if (reason) { + expect(event?.event?.reason).to.be(reason); + } - if (duration !== undefined) { - expect(typeof duration).to.be('number'); - expect(eventStart).to.be.ok(); - expect(eventEnd).to.be.ok(); + const duration = event?.event?.duration; + const eventStart = Date.parse(event?.event?.start || 'undefined'); + const eventEnd = Date.parse(event?.event?.end || 'undefined'); + const dateNow = Date.now(); - const durationDiff = Math.abs( - Math.round(duration! / NANOS_IN_MILLIS) - (eventEnd - eventStart) - ); + if (duration !== undefined) { + expect(typeof duration).to.be('number'); + expect(eventStart).to.be.ok(); + expect(eventEnd).to.be.ok(); - // account for rounding errors - expect(durationDiff < 1).to.equal(true); - expect(eventStart <= eventEnd).to.equal(true); - expect(eventEnd <= dateNow).to.equal(true); - } + const durationDiff = Math.abs( + Math.round(duration! / NANOS_IN_MILLIS) - (eventEnd - eventStart) + ); - expect(event?.event?.outcome).to.equal(outcome); + // account for rounding errors + expect(durationDiff < 1).to.equal(true); + expect(eventStart <= eventEnd).to.equal(true); + expect(eventEnd <= dateNow).to.equal(true); + } - for (const savedObject of savedObjects) { - expect( - isSavedObjectInEvent(event, spaceId, savedObject.type, savedObject.id, savedObject.rel) - ).to.be(true); - } + expect(event?.event?.outcome).to.equal(outcome); - expect(event?.message).to.eql(message); + for (const savedObject of savedObjects) { + expect( + isSavedObjectInEvent(event, spaceId, savedObject.type, savedObject.id, savedObject.rel) + ).to.be(true); + } - if (errorMessage) { - expect(event?.error?.message).to.eql(errorMessage); - } + expect(event?.message).to.eql(message); + + if (errorMessage) { + expect(event?.error?.message).to.eql(errorMessage); } }