diff --git a/x-pack/plugins/alerting/common/rule_task_instance.ts b/x-pack/plugins/alerting/common/rule_task_instance.ts index 529b65e719ddd..6bb36a8635b61 100644 --- a/x-pack/plugins/alerting/common/rule_task_instance.ts +++ b/x-pack/plugins/alerting/common/rule_task_instance.ts @@ -18,6 +18,7 @@ export const ruleStateSchema = t.partial({ const ruleExecutionMetricsSchema = t.partial({ numSearches: t.number, + numSearchSourceSearches: t.number, totalSearchDurationMs: t.number, esSearchDurationMs: t.number, }); diff --git a/x-pack/plugins/alerting/server/lib/merge_search_metrics.ts b/x-pack/plugins/alerting/server/lib/merge_search_metrics.ts new file mode 100644 index 0000000000000..af954bbf514b0 --- /dev/null +++ b/x-pack/plugins/alerting/server/lib/merge_search_metrics.ts @@ -0,0 +1,24 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0; you may not use this file except in compliance with the Elastic License + * 2.0. + */ + +import { RuleExecutionMetrics } from '../types'; +import type { ScopedClusterClientMetrics } from './wrap_scoped_cluster_client'; +import type { SearchSourceClientMetrics } from './wrap_search_source_fetch'; + +export const mergeSearchMetrics = ( + scopedClusterClientMetrics: ScopedClusterClientMetrics, + searchSourceMetrics: SearchSourceClientMetrics +): RuleExecutionMetrics => { + return { + numSearches: scopedClusterClientMetrics.numSearches, + numSearchSourceSearches: searchSourceMetrics.numSearchSourceSearches, + totalSearchDurationMs: + scopedClusterClientMetrics.totalSearchDurationMs + searchSourceMetrics.totalSearchDurationMs, + esSearchDurationMs: + scopedClusterClientMetrics.esSearchDurationMs + searchSourceMetrics.esSearchDurationMs, + }; +}; diff --git a/x-pack/plugins/alerting/server/lib/wrap_scoped_cluster_client.ts b/x-pack/plugins/alerting/server/lib/wrap_scoped_cluster_client.ts index b1dd7ec8617d0..6bc60d3ae9a71 100644 --- a/x-pack/plugins/alerting/server/lib/wrap_scoped_cluster_client.ts +++ b/x-pack/plugins/alerting/server/lib/wrap_scoped_cluster_client.ts @@ -21,7 +21,6 @@ import type { AggregationsAggregate, } from '@elastic/elasticsearch/lib/api/typesWithBodyKey'; import { IScopedClusterClient, ElasticsearchClient, Logger } from '@kbn/core/server'; -import { RuleExecutionMetrics } from '../types'; import { LogSearchMetricsOpts, RuleInfo } from './types'; export type LogSearchMetricsFn = (metrics: LogSearchMetricsOpts) => void; @@ -41,6 +40,12 @@ type WrapScopedClusterClientOpts = WrapScopedClusterClientFactoryOpts & { logMetricsFn: LogSearchMetricsFn; }; +export interface ScopedClusterClientMetrics { + esSearchDurationMs: number; + totalSearchDurationMs: number; + numSearches: number; +} + export function createWrappedScopedClusterClientFactory(opts: WrapScopedClusterClientFactoryOpts) { let numSearches: number = 0; let esSearchDurationMs: number = 0; @@ -56,7 +61,7 @@ export function createWrappedScopedClusterClientFactory(opts: WrapScopedClusterC return { client: () => wrappedClient, - getMetrics: (): RuleExecutionMetrics => { + getMetrics: (): ScopedClusterClientMetrics => { return { esSearchDurationMs, totalSearchDurationMs, diff --git a/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.test.ts b/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.test.ts index 40182ca98345c..ac0afdba1195e 100644 --- a/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.test.ts +++ b/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.test.ts @@ -98,7 +98,7 @@ describe('wrapSearchSourceFetch', () => { expect(searchSourceInstanceMock.fetch).toHaveBeenCalledTimes(3); const stats = getMetrics(); - expect(stats.numSearches).toEqual(3); + expect(stats.numSearchSourceSearches).toEqual(3); expect(stats.esSearchDurationMs).toEqual(999); expect(logger.debug).toHaveBeenCalledWith( diff --git a/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.ts b/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.ts index 8ffa58afbd8bc..bd830bede38af 100644 --- a/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.ts +++ b/x-pack/plugins/alerting/server/lib/wrap_search_source_fetch.ts @@ -7,9 +7,14 @@ import { Logger } from '@kbn/core/server'; import { ISearchSource } from '@kbn/data-plugin/common'; -import { RuleExecutionMetrics } from '../types'; import { LogSearchMetricsOpts, RuleInfo } from './types'; +export interface SearchSourceClientMetrics { + esSearchDurationMs: number; + totalSearchDurationMs: number; + numSearchSourceSearches: number; +} + export function wrapSearchSourceFetch({ logger, rule, @@ -19,12 +24,12 @@ export function wrapSearchSourceFetch({ rule: RuleInfo; abortController: AbortController; }) { - let numSearches: number = 0; + let numSearchSourceSearches: number = 0; let esSearchDurationMs: number = 0; let totalSearchDurationMs: number = 0; function logMetrics(metrics: LogSearchMetricsOpts) { - numSearches++; + numSearchSourceSearches++; esSearchDurationMs += metrics.esSearchDuration; totalSearchDurationMs += metrics.totalSearchDuration; } @@ -48,10 +53,10 @@ export function wrapSearchSourceFetch({ throw e; } }, - getMetrics: (): RuleExecutionMetrics => ({ + getMetrics: (): SearchSourceClientMetrics => ({ esSearchDurationMs, totalSearchDurationMs, - numSearches, + numSearchSourceSearches, }), }; } 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 4a5be740949ad..ff754b08e5bf9 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 @@ -240,7 +240,7 @@ describe('Task Runner', () => { expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z'); expect(logger.debug).nthCalledWith( 2, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}' ); const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; @@ -320,7 +320,7 @@ describe('Task Runner', () => { ); expect(logger.debug).nthCalledWith( 3, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger; @@ -428,7 +428,7 @@ describe('Task Runner', () => { ); expect(logger.debug).nthCalledWith( 4, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; @@ -593,7 +593,7 @@ describe('Task Runner', () => { ); expect(logger.debug).nthCalledWith( 4, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); expect(mockUsageCounter.incrementCounter).not.toHaveBeenCalled(); } @@ -1121,7 +1121,7 @@ describe('Task Runner', () => { ); expect(logger.debug).nthCalledWith( 4, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"numberOfGeneratedActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":2,"numberOfGeneratedActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger; @@ -1262,7 +1262,7 @@ describe('Task Runner', () => { ); expect(logger.debug).nthCalledWith( 4, - `ruleExecutionStatus for test:${alertId}: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":2,"numberOfGeneratedActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}` + 'ruleExecutionStatus for test:e558aaad-fd81-46d2-96fc-3bd8fc3dc03f: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":2,"numberOfGeneratedActions":2,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = customTaskRunnerFactoryInitializerParams.eventLogger; @@ -2489,7 +2489,7 @@ describe('Task Runner', () => { expect(logger.debug).nthCalledWith(1, 'executing rule test:1 at 1970-01-01T00:00:00.000Z'); expect(logger.debug).nthCalledWith( 2, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"ok"}' ); const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; 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 7374cebf817e1..d37adac2a90b7 100644 --- a/x-pack/plugins/alerting/server/task_runner/task_runner.ts +++ b/x-pack/plugins/alerting/server/task_runner/task_runner.ts @@ -74,6 +74,7 @@ import { import { createWrappedScopedClusterClientFactory } from '../lib/wrap_scoped_cluster_client'; import { wrapSearchSourceFetch } from '../lib/wrap_search_source_fetch'; import { AlertExecutionStore } from '../lib/alert_execution_store'; +import { mergeSearchMetrics } from '../lib/merge_search_metrics'; const FALLBACK_RETRY_INTERVAL = '5m'; const CONNECTIVITY_RETRY_INTERVAL = '5m'; @@ -461,12 +462,10 @@ export class TaskRunner< name: rule.name, }; - const scopedClusterClientMetrics = wrappedScopedClusterClient.getMetrics(); - const searchSourceMetrics = wrappedSearchSourceFetch.getMetrics(); - - const searchMetrics = !!scopedClusterClientMetrics.numSearches - ? scopedClusterClientMetrics - : searchSourceMetrics; + const searchMetrics = mergeSearchMetrics( + wrappedScopedClusterClient.getMetrics(), + wrappedSearchSourceFetch.getMetrics() + ); // Cleanup alerts that are no longer scheduling actions to avoid over populating the alertInstances object const alertsWithScheduledActions = pickBy( diff --git a/x-pack/plugins/alerting/server/task_runner/task_runner_cancel.test.ts b/x-pack/plugins/alerting/server/task_runner/task_runner_cancel.test.ts index e0b7449d09b41..6ab68213be1bd 100644 --- a/x-pack/plugins/alerting/server/task_runner/task_runner_cancel.test.ts +++ b/x-pack/plugins/alerting/server/task_runner/task_runner_cancel.test.ts @@ -523,7 +523,7 @@ describe('Task Runner Cancel', () => { ); expect(logger.debug).nthCalledWith( 7, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":0,"numberOfGeneratedActions":0,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = taskRunnerFactoryInitializerParams.eventLogger; @@ -683,7 +683,7 @@ describe('Task Runner Cancel', () => { ); expect(logger.debug).nthCalledWith( 6, - 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"esSearchDurationMs":33,"totalSearchDurationMs":23423},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' + 'ruleExecutionStatus for test:1: {"metrics":{"numSearches":3,"numSearchSourceSearches":0,"totalSearchDurationMs":23423,"esSearchDurationMs":33},"numberOfTriggeredActions":1,"numberOfGeneratedActions":1,"lastExecutionDate":"1970-01-01T00:00:00.000Z","status":"active"}' ); const eventLogger = taskRunnerFactoryInitializerParams.eventLogger;