[Alerting] Add event log entry when an action starts executing

[chrisronline]

Resolves #102358

This PR adds an additional event to the event log that indicates when an action starts executing. Currently, we only log to the event log when the action finishes execution which helps us understand what actions finished execution (technically, just scheduled as we do not wait for action execution to completely finish) and when, but it does not tell us which actions started executing but never finished. This PR aims to address this which will help diagnose issues with actions not executing as expected.

[elasticmachine]

Pinging @elastic/kibana-alerting-services (Team:Alerting Services)

[ymao1]

Do you think this belongs in the actions plugin instead of the alerting plugin?

There is already an execute-action in the alerting plugin and this execute-action-start looks pretty much identical to that document.

In the actions plugin, there is an execute event that is logged at the end of an action execution that includes start/duration/end. I think the execute-start should be added there to log the start time of the action in case the action fails and the execute event isn't logged.

[ymao1]

For reference, this is the new execute-action-start event that I am seeing with this PR. It is provided by alerting and there is no start time logged.

{
	"@timestamp": "2021-06-21T11:42:01.088Z",
	"event": {
		"provider": "alerting",
		"action": "execute-action-start",
		"kind": "alert",
		"category": [
			"AlertingExample"
		]
	},
	"kibana": {
		"alerting": {
			"instance_id": "625c54fb-e987-4a6b-9924-5200d8f03362",
			"action_group_id": "small"
		},
		"saved_objects": [{
				"rel": "primary",
				"type": "alert",
				"id": "aea36800-d285-11eb-b53f-9728526aae03",
				"type_id": "example.always-firing"
			},
			{
				"type": "action",
				"id": "a96fc590-d285-11eb-b53f-9728526aae03",
				"type_id": ".server-log"
			}
		],
		"server_uuid": "5b2de169-2785-441b-ae8c-186a1936b17d"
	},
	"rule": {
		"id": "aea36800-d285-11eb-b53f-9728526aae03",
		"license": "basic",
		"category": "example.always-firing",
		"ruleset": "AlertingExample",
		"name": "test"
	},
	"message": "alert: example.always-firing:aea36800-d285-11eb-b53f-9728526aae03: 'test' instanceId: '625c54fb-e987-4a6b-9924-5200d8f03362' start schedule actionGroup: 'small' action: .server-log:a96fc590-d285-11eb-b53f-9728526aae03",
	"ecs": {
		"version": "1.8.0"
	}
}

[chrisronline]

@ymao1 You're absolutely right - I'll move it, thanks!

I also should update the tests here to include this new event log type: https://github.com/elastic/kibana/blob/master/x-pack/test/alerting_api_integration/spaces_only/tests/actions/execute.ts

[ymao1]

LGTM! Verified there was an execute-start event provided by the actions plugin with a start time for every action execution

[pmuellr]

LGTM

[kibanamachine]

💚 Build Succeeded

• continuous-integration/kibana-ci/pull-request
• Commit: 2247b20
• Storybooks Preview

Metrics [docs]

✅ unchanged

History

• 💔 Build #133243 failed 9ece8f2
• 💔 Build #133143 failed 6f534c2
• 💚 Build #132697 succeeded 4ab04f2
• 💚 Build #132303 succeeded b7d2b31
• 💔 Build #132227 failed 0c9cdf1

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream