Skip to content

Commit

Permalink
[alerts] add executionStatus to event log doc for action execute
Browse files Browse the repository at this point in the history 
resolves #79785

Until now, the execution status was available in the the event
log document for the execute action.  In this PR we add it.

The event log is extended to add the following fields:

- `kibana.alerting.status` - from executionStatus.status
- `event.reason`           - from executionStatus.error.reason

The date from the executionStatus and start date in the event
log will be set to the same value.

Previously, errors encountered while trying to execute an
alert executor, eg decrypting the alert, would not end up
with an event doc generated.  Now they will.

interim commits:

fix timestamp in alert:execute event doc
fix jest tests
add functional test
add jest tests for the eventlog reasons
  • Loading branch information
@pmuellr
pmuellr committed Nov 8, 2020
1 parent b264498 commit eb34d38
Show file tree
Hide file tree
Showing 10 changed files with 464 additions and 129 deletions.
211 changes: 167 additions & 44 deletions x-pack/plugins/alerts/server/task_runner/task_runner.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down Expand Up @@ -249,24 +253,7 @@ 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',
},
Expand All @@ -285,7 +272,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',
},
Expand All @@ -304,7 +291,7 @@ describe('Task Runner', () => {
},
message: "test:1: 'alert-name' active instance: '1'",
});
expect(eventLogger.logEvent).toHaveBeenCalledWith({
expect(eventLogger.logEvent).toHaveBeenNthCalledWith(3, {
event: {
action: 'execute-action',
},
Expand All @@ -329,6 +316,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 () => {
Expand Down Expand Up @@ -401,10 +409,12 @@ describe('Task Runner', () => {
Array [
Object {
"event": Object {
"action": "execute",
"outcome": "success",
"action": "new-instance",
},
"kibana": Object {
"alerting": Object {
"instance_id": "1",
},
"saved_objects": Array [
Object {
"id": "1",
Expand All @@ -414,13 +424,13 @@ 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 {
Expand All @@ -435,13 +445,13 @@ describe('Task Runner', () => {
},
],
},
"message": "test:1: 'alert-name' created new instance: '1'",
"message": "test:1: 'alert-name' active instance: '1'",
},
],
Array [
Object {
"event": Object {
"action": "active-instance",
"action": "execute-action",
},
"kibana": Object {
"alerting": Object {
Expand All @@ -454,19 +464,26 @@ describe('Task Runner', () => {
"rel": "primary",
"type": "alert",
},
Object {
"id": "1",
"namespace": undefined,
"type": "action",
},
],
},
"message": "test:1: 'alert-name' active instance: '1'",
"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 {
Expand All @@ -475,14 +492,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'",
},
],
]
Expand Down Expand Up @@ -542,10 +554,12 @@ describe('Task Runner', () => {
Array [
Object {
"event": Object {
"action": "execute",
"outcome": "success",
"action": "resolved-instance",
},
"kibana": Object {
"alerting": Object {
"instance_id": "2",
},
"saved_objects": Array [
Object {
"id": "1",
Expand All @@ -555,17 +569,17 @@ 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 {
"instance_id": "2",
"instance_id": "1",
},
"saved_objects": Array [
Object {
Expand All @@ -576,17 +590,19 @@ describe('Task Runner', () => {
},
],
},
"message": "test:1: 'alert-name' resolved instance: '2'",
"message": "test:1: 'alert-name' active instance: '1'",
},
],
Array [
Object {
"@timestamp": "1970-01-01T00:00:00.000Z",
"event": Object {
"action": "active-instance",
"action": "execute",
"outcome": "success",
},
"kibana": Object {
"alerting": Object {
"instance_id": "1",
"status": "active",
},
"saved_objects": Array [
Object {
Expand All @@ -597,7 +613,7 @@ describe('Task Runner', () => {
},
],
},
"message": "test:1: 'alert-name' active instance: '1'",
"message": "alert executed: test:1: 'alert-name'",
},
],
]
Expand Down Expand Up @@ -782,14 +798,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",
Expand Down Expand Up @@ -829,6 +850,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 () => {
Expand Down Expand Up @@ -862,6 +917,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 () => {
Expand Down Expand Up @@ -894,6 +983,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 () => {
Expand Down
Loading

0 comments on commit eb34d38

Please sign in to comment.