assert internal log.

elastic · Jul 8, 2021 · 987f44b · 987f44b
1 parent 5161477
commit 987f44b
Show file tree

Hide file tree

Showing 5 changed files with 63 additions and 13 deletions.
diff --git a/x-pack/plugins/apm/public/components/app/correlations/use_correlations.ts b/x-pack/plugins/apm/public/components/app/correlations/use_correlations.ts
@@ -36,6 +36,7 @@ interface RawResponse {
   took: number;
   values: SearchServiceValue[];
   overallHistogram: HistogramItem[];
+  log: string[];
 }
 
 export const useCorrelations = (params: CorrelationsOptions) => {

diff --git a/x-pack/plugins/apm/server/lib/search_strategies/correlations/async_search_service.ts b/x-pack/plugins/apm/server/lib/search_strategies/correlations/async_search_service.ts
@@ -24,13 +24,18 @@ import { fetchTransactionDurationFractions } from './query_fractions';
 const CORRELATION_THRESHOLD = 0.3;
 const KS_TEST_THRESHOLD = 0.1;
 
+const currentTimeAsString = () => new Date().toISOString();
+
 export const asyncSearchServiceProvider = (
   esClient: ElasticsearchClient,
   params: SearchServiceParams
 ) => {
   let isCancelled = false;
   let isRunning = true;
   let error: Error;
+  const log: string[] = [];
+  const logMessage = (message: string) =>
+    log.push(`${currentTimeAsString()}: ${message}`);
 
   const progress: AsyncSearchProviderProgress = {
     started: Date.now(),
@@ -53,22 +58,33 @@ export const asyncSearchServiceProvider = (
   let percentileThresholdValue: number;
 
   const cancel = () => {
+    logMessage(`Service cancelled.`);
     isCancelled = true;
   };
 
   const fetchCorrelations = async () => {
     try {
       // 95th percentile to be displayed as a marker in the log log chart
-      const percentileThreshold = await fetchTransactionDurationPercentiles(
+      const {
+        totalDocs,
+        percentiles: percentileThreshold,
+      } = await fetchTransactionDurationPercentiles(
         esClient,
         params,
         params.percentileThreshold ? [params.percentileThreshold] : undefined
       );
       percentileThresholdValue =
         percentileThreshold[`${params.percentileThreshold}.0`];
 
+      logMessage(
+        `Fetched ${params.percentileThreshold}th percentile value of ${percentileThresholdValue} based on ${totalDocs} documents.`
+      );
+
       // finish early if we weren't able to identify the percentileThresholdValue.
       if (percentileThresholdValue === undefined) {
+        logMessage(
+          `Abort service since percentileThresholdValue could not be determined.`
+        );
         progress.loadedHistogramStepsize = 1;
         progress.loadedOverallHistogram = 1;
         progress.loadedFieldCanditates = 1;
@@ -84,6 +100,8 @@ export const asyncSearchServiceProvider = (
       );
       progress.loadedHistogramStepsize = 1;
 
+      logMessage(`Loaded histogram range steps.`);
+
       if (isCancelled) {
         isRunning = false;
         return;
@@ -97,20 +115,22 @@ export const asyncSearchServiceProvider = (
       progress.loadedOverallHistogram = 1;
       overallHistogram = overallLogHistogramChartData;
 
+      logMessage(`Loaded overall histogram chart data.`);
+
       if (isCancelled) {
         isRunning = false;
         return;
       }
 
       // Create an array of ranges [2, 4, 6, ..., 98]
       const percents = Array.from(range(2, 100, 2));
-      const percentilesRecords = await fetchTransactionDurationPercentiles(
-        esClient,
-        params,
-        percents
-      );
+      const {
+        percentiles: percentilesRecords,
+      } = await fetchTransactionDurationPercentiles(esClient, params, percents);
       const percentiles = Object.values(percentilesRecords);
 
+      logMessage(`Loaded percentiles.`);
+
       if (isCancelled) {
         isRunning = false;
         return;
@@ -121,6 +141,8 @@ export const asyncSearchServiceProvider = (
         params
       );
 
+      logMessage(`Identified ${fieldCandidates.length} fieldCandidates.`);
+
       progress.loadedFieldCanditates = 1;
 
       const fieldValuePairs = await fetchTransactionDurationFieldValuePairs(
@@ -130,6 +152,8 @@ export const asyncSearchServiceProvider = (
         progress
       );
 
+      logMessage(`Identified ${fieldValuePairs.length} fieldValuePairs.`);
+
       if (isCancelled) {
         isRunning = false;
         return;
@@ -144,6 +168,8 @@ export const asyncSearchServiceProvider = (
         totalDocCount,
       } = await fetchTransactionDurationFractions(esClient, params, ranges);
 
+      logMessage(`Loaded fractions and totalDocCount of ${totalDocCount}.`);
+
       async function* fetchTransactionDurationHistograms() {
         for (const item of shuffle(fieldValuePairs)) {
           if (item === undefined || isCancelled) {
@@ -209,6 +235,10 @@ export const asyncSearchServiceProvider = (
         loadedHistograms++;
         progress.loadedHistograms = loadedHistograms / fieldValuePairs.length;
       }
+
+      logMessage(
+        `Identified ${values.length} significant correlations out of ${fieldValuePairs.length} field/value pairs.`
+      );
     } catch (e) {
       error = e;
     }
@@ -223,6 +253,7 @@ export const asyncSearchServiceProvider = (
 
     return {
       error,
+      log,
       isRunning,
       loaded: Math.round(progress.getOverallProgress() * 100),
       overallHistogram,

diff --git a/x-pack/plugins/apm/server/lib/search_strategies/correlations/query_percentiles.ts b/x-pack/plugins/apm/server/lib/search_strategies/correlations/query_percentiles.ts
@@ -62,7 +62,7 @@ export const fetchTransactionDurationPercentiles = async (
   percents?: number[],
   fieldName?: string,
   fieldValue?: string
-): Promise<Record<string, number>> => {
+): Promise<{ totalDocs: number; percentiles: Record<string, number> }> => {
   const resp = await esClient.search<ResponseHit>(
     getTransactionDurationPercentilesRequest(
       params,
@@ -74,7 +74,7 @@ export const fetchTransactionDurationPercentiles = async (
 
   // return early with no results if the search didn't return any documents
   if ((resp.body.hits.total as estypes.SearchTotalHits).value === 0) {
-    return {};
+    return { totalDocs: 0, percentiles: {} };
   }
 
   if (resp.body.aggregations === undefined) {
@@ -83,9 +83,11 @@ export const fetchTransactionDurationPercentiles = async (
     );
   }
 
-  return (
-    (resp.body.aggregations
-      .transaction_duration_percentiles as estypes.AggregationsTDigestPercentilesAggregate)
-      .values ?? {}
-  );
+  return {
+    totalDocs: (resp.body.hits.total as estypes.SearchTotalHits).value,
+    percentiles:
+      (resp.body.aggregations
+        .transaction_duration_percentiles as estypes.AggregationsTDigestPercentilesAggregate)
+        .values ?? {},
+  };
 };
diff --git a/x-pack/plugins/apm/server/lib/search_strategies/correlations/search_strategy.ts b/x-pack/plugins/apm/server/lib/search_strategies/correlations/search_strategy.ts
@@ -74,6 +74,7 @@ export const apmCorrelationsSearchStrategyProvider = (): ISearchStrategy<
 
       const {
         error,
+        log,
         isRunning,
         loaded,
         started,
@@ -101,6 +102,7 @@ export const apmCorrelationsSearchStrategyProvider = (): ISearchStrategy<
         isRunning,
         isPartial: isRunning,
         rawResponse: {
+          log,
           took,
           values,
           percentileThresholdValue,

diff --git a/x-pack/test/apm_api_integration/tests/correlations/latency_ml.ts b/x-pack/test/apm_api_integration/tests/correlations/latency_ml.ts
@@ -131,6 +131,10 @@ export default function ApiTest({ getService }: FtrProviderContext) {
         expect(finalRawResponse?.percentileThresholdValue).to.be(undefined);
         expect(finalRawResponse?.overallHistogram).to.be(undefined);
         expect(finalRawResponse?.values.length).to.be(0);
+        expect(finalRawResponse?.log.map((d: string) => d.split(': ')[1])).to.eql([
+          'Fetched 95th percentile value of undefined based on 0 documents.',
+          'Abort service since percentileThresholdValue could not be determined.',
+        ]);
       });
     }
   );
@@ -236,6 +240,16 @@ export default function ApiTest({ getService }: FtrProviderContext) {
 
         // TODO Identify a dataset that returns significant results
         expect(finalRawResponse?.values.length).to.be(0);
+        expect(finalRawResponse?.log.map((d: string) => d.split(': ')[1])).to.eql([
+          'Fetched 95th percentile value of 1855487.875 based on 4786 documents.',
+          'Loaded histogram range steps.',
+          'Loaded overall histogram chart data.',
+          'Loaded percentiles.',
+          'Identified 80 fieldCandidates.',
+          'Identified 430 fieldValuePairs.',
+          'Loaded fractions and totalDocCount of 4786.',
+          'Identified 0 significant correlations out of 430 field/value pairs.',
+        ]);
       });
     }
   );