[Infrastructure UI] Add logging to Inventory Threshold Rule (#127838)

* [Infrastructure UI] Add logging to Inventory Threshold Rule

* Adding alertId and executionId to log messages

* Adding alertExecutionDetails to tests

* Refactor logger instead of passing around AlertExecutionDetails

* Removing unused deps

* Adding warn, error, fatal to scopedLogger

x-pack/plugins/infra/common/alerting/metrics/types.ts

@@ -112,3 +112,8 @@ export type MetricExpressionParams = NonCountMetricExpressionParams | CountMetri
 export const QUERY_INVALID: unique symbol = Symbol('QUERY_INVALID');
 
 export type FilterQuery = string | typeof QUERY_INVALID;
+
+export interface AlertExecutionDetails {
+  alertId: string;
+  executionId: string;
+}

x-pack/plugins/infra/server/lib/alerting/common/utils.ts

@@ -5,8 +5,10 @@
  * 2.0.
  */
 
-import { isEmpty } from 'lodash';
+import { isEmpty, isError } from 'lodash';
 import { schema } from '@kbn/config-schema';
+import { Logger, LogMeta } from '@kbn/logging';
+import { AlertExecutionDetails } from '../../../../common/alerting/metrics/types';
 
 export const oneOfLiterals = (arrayOfLiterals: Readonly<string[]>) =>
   schema.string({
@@ -33,3 +35,43 @@ export const validateIsStringElasticsearchJSONFilter = (value: string) => {
 };
 
 export const UNGROUPED_FACTORY_KEY = '*';
+
+export const createScopedLogger = (
+  logger: Logger,
+  scope: string,
+  alertExecutionDetails: AlertExecutionDetails
+): Logger => {
+  const scopedLogger = logger.get(scope);
+  const fmtMsg = (msg: string) =>
+    `[AlertId: ${alertExecutionDetails.alertId}][ExecutionId: ${alertExecutionDetails.executionId}] ${msg}`;
+  return {
+    ...scopedLogger,
+    info: <Meta extends LogMeta = LogMeta>(msg: string, meta?: Meta) =>
+      scopedLogger.info(fmtMsg(msg), meta),
+    debug: <Meta extends LogMeta = LogMeta>(msg: string, meta?: Meta) =>
+      scopedLogger.debug(fmtMsg(msg), meta),
+    trace: <Meta extends LogMeta = LogMeta>(msg: string, meta?: Meta) =>
+      scopedLogger.trace(fmtMsg(msg), meta),
+    warn: <Meta extends LogMeta = LogMeta>(errorOrMessage: string | Error, meta?: Meta) => {
+      if (isError(errorOrMessage)) {
+        scopedLogger.warn(errorOrMessage, meta);
+      } else {
+        scopedLogger.warn(fmtMsg(errorOrMessage), meta);
+      }
+    },
+    error: <Meta extends LogMeta = LogMeta>(errorOrMessage: string | Error, meta?: Meta) => {
+      if (isError(errorOrMessage)) {
+        scopedLogger.error(errorOrMessage, meta);
+      } else {
+        scopedLogger.error(fmtMsg(errorOrMessage), meta);
+      }
+    },
+    fatal: <Meta extends LogMeta = LogMeta>(errorOrMessage: string | Error, meta?: Meta) => {
+      if (isError(errorOrMessage)) {
+        scopedLogger.fatal(errorOrMessage, meta);
+      } else {
+        scopedLogger.fatal(fmtMsg(errorOrMessage), meta);
+      }
+    },
+  };
+};

x-pack/plugins/infra/server/lib/alerting/inventory_metric_threshold/evaluate_condition.ts

@@ -8,6 +8,7 @@
 import { ElasticsearchClient } from 'kibana/server';
 import { mapValues } from 'lodash';
 import moment from 'moment';
+import { Logger } from '@kbn/logging';
 import { InventoryMetricConditions } from '../../../../common/alerting/metrics';
 import { InfraTimerangeInput } from '../../../../common/http_api';
 import { InventoryItemType } from '../../../../common/inventory_models/types';
@@ -34,6 +35,7 @@ export const evaluateCondition = async ({
   filterQuery,
   lookbackSize,
   startTime,
+  logger,
 }: {
   condition: InventoryMetricConditions;
   nodeType: InventoryItemType;
@@ -44,6 +46,7 @@ export const evaluateCondition = async ({
   filterQuery?: string;
   lookbackSize?: number;
   startTime?: number;
+  logger: Logger;
 }): Promise<Record<string, ConditionResult>> => {
   const { metric, customMetric } = condition;
 
@@ -69,6 +72,7 @@ export const evaluateCondition = async ({
     logQueryFields,
     compositeSize,
     condition,
+    logger,
     filterQuery,
     customMetric
   );

x-pack/plugins/infra/server/lib/alerting/inventory_metric_threshold/inventory_metric_threshold_executor.ts

@@ -32,6 +32,7 @@ import {
   // buildRecoveredAlertReason,
   stateToAlertMessage,
 } from '../common/messages';
+import { createScopedLogger } from '../common/utils';
 import { evaluateCondition } from './evaluate_condition';
 
 type InventoryMetricThresholdAllowedActionGroups = ActionGroupIdsOf<
@@ -61,9 +62,11 @@ export const createInventoryMetricThresholdExecutor = (libs: InfraBackendLibs) =
     InventoryMetricThresholdAlertState,
     InventoryMetricThresholdAlertContext,
     InventoryMetricThresholdAllowedActionGroups
-  >(async ({ services, params }) => {
+  >(async ({ services, params, alertId, executionId }) => {
+    const startTime = Date.now();
     const { criteria, filterQuery, sourceId, nodeType, alertOnNoData } = params;
     if (criteria.length === 0) throw new Error('Cannot execute an alert with 0 conditions');
+    const logger = createScopedLogger(libs.logger, 'inventoryRule', { alertId, executionId });
     const { alertWithLifecycle, savedObjectsClient } = services;
     const alertFactory: InventoryMetricThresholdAlertFactory = (id, reason) =>
       alertWithLifecycle({
@@ -79,6 +82,7 @@ export const createInventoryMetricThresholdExecutor = (libs: InfraBackendLibs) =
         const { fromKueryExpression } = await import('@kbn/es-query');
         fromKueryExpression(params.filterQueryText);
       } catch (e) {
+        logger.error(e.message);
         const actionGroupId = FIRED_ACTIONS.id; // Change this to an Error action group when able
         const reason = buildInvalidQueryAlertReason(params.filterQueryText);
         const alert = alertFactory('*', reason);
@@ -117,9 +121,11 @@ export const createInventoryMetricThresholdExecutor = (libs: InfraBackendLibs) =
           esClient: services.scopedClusterClient.asCurrentUser,
           compositeSize,
           filterQuery,
+          logger,
         })
       )
     );
+    let scheduledActionsCount = 0;
     const inventoryItems = Object.keys(first(results)!);
     for (const group of inventoryItems) {
       // AND logic; all criteria must be across the threshold
@@ -187,6 +193,7 @@ export const createInventoryMetricThresholdExecutor = (libs: InfraBackendLibs) =
             : FIRED_ACTIONS.id;
 
         const alert = alertFactory(`${group}`, reason);
+        scheduledActionsCount++;
         alert.scheduleActions(
           /**
            * TODO: We're lying to the compiler here as explicitly  calling `scheduleActions` on
@@ -207,6 +214,8 @@ export const createInventoryMetricThresholdExecutor = (libs: InfraBackendLibs) =
         );
       }
     }
+    const stopTime = Date.now();
+    logger.debug(`Scheduled ${scheduledActionsCount} actions in ${stopTime - startTime}ms`);
   });
 
 const formatThreshold = (metric: SnapshotMetricType, value: number) => {

x-pack/plugins/infra/server/lib/alerting/inventory_metric_threshold/lib/get_data.ts

@@ -6,6 +6,7 @@
  */
 
 import { ElasticsearchClient } from 'kibana/server';
+import type { Logger } from '@kbn/logging';
 import { InventoryMetricConditions } from '../../../../../common/alerting/metrics';
 import { InfraTimerangeInput, SnapshotCustomMetricInput } from '../../../../../common/http_api';
 import {
@@ -44,6 +45,7 @@ export const getData = async (
   logQueryFields: LogQueryFields | undefined,
   compositeSize: number,
   condition: InventoryMetricConditions,
+  logger: Logger,
   filterQuery?: string,
   customMetric?: SnapshotCustomMetricInput,
   afterKey?: BucketKey,
@@ -70,6 +72,7 @@ export const getData = async (
         logQueryFields,
         compositeSize,
         condition,
+        logger,
         filterQuery,
         customMetric,
         nextAfterKey,
@@ -94,7 +97,9 @@ export const getData = async (
     filterQuery,
     customMetric
   );
+  logger.trace(`Request: ${JSON.stringify(request)}`);
   const body = await esClient.search<undefined, ResponseAggregations>(request);
+  logger.trace(`Response: ${JSON.stringify(body)}`);
   if (body.aggregations) {
     return handleResponse(body.aggregations, previousNodes);
   }

x-pack/plugins/infra/server/lib/infra_types.ts

@@ -5,6 +5,7 @@
  * 2.0.
  */
 
+import { Logger } from '@kbn/logging';
 import { handleEsError } from '../../../../../src/plugins/es_ui_shared/server';
 import { InfraConfig } from '../types';
 import { GetLogQueryFields } from '../services/log_queries/get_log_query_fields';
@@ -31,4 +32,5 @@ export interface InfraBackendLibs extends InfraDomainLibs {
   handleEsError: typeof handleEsError;
   logsRules: RulesServiceSetup;
   metricsRules: RulesServiceSetup;
+  logger: Logger;
 }

x-pack/plugins/infra/server/plugin.ts

@@ -154,6 +154,7 @@ export class InfraServerPlugin implements Plugin<InfraPluginSetup> {
       handleEsError,
       logsRules: this.logsRules.setup(core, plugins),
       metricsRules: this.metricsRules.setup(core, plugins),
+      logger: this.logger,
     };
 
     plugins.features.registerKibanaFeature(METRICS_FEATURE);

x-pack/test/api_integration/apis/metrics_ui/inventory_threshold_alert.ts

@@ -6,6 +6,8 @@
  */
 
 import expect from '@kbn/expect';
+import type { Logger, LogMeta } from 'kibana/server';
+import sinon from 'sinon';
 import {
   Comparator,
   InventoryMetricConditions,
@@ -22,6 +24,21 @@ import { DATES } from './constants';
 export default function ({ getService }: FtrProviderContext) {
   const esArchiver = getService('esArchiver');
   const esClient = getService('es');
+  const log = getService('log');
+
+  const fakeLogger = <Meta extends LogMeta = LogMeta>(msg: string, meta?: Meta) =>
+    meta ? log.debug(msg, meta) : log.debug(msg);
+
+  const logger = {
+    trace: fakeLogger,
+    debug: fakeLogger,
+    info: fakeLogger,
+    warn: fakeLogger,
+    error: fakeLogger,
+    fatal: fakeLogger,
+    log: sinon.stub(),
+    get: sinon.stub(),
+  } as Logger;
 
   const baseCondition: InventoryMetricConditions = {
     metric: 'cpu',
@@ -77,6 +94,7 @@ export default function ({ getService }: FtrProviderContext) {
     logQueryFields: void 0,
     compositeSize: 10000,
     startTime: DATES['8.0.0'].hosts_only.max,
+    logger,
   };
 
   describe('Inventory Threshold Rule Executor', () => {