[Discover] merge search clients metrics

elastic · Apr 26, 2022 · 7d03945 · 7d03945
1 parent 4f1a917
commit 7d03945
Show file tree

Hide file tree

Showing 8 changed files with 57 additions and 23 deletions.
diff --git 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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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;