fix(explain-plan-helper): use execution time of cursor stage COMPASS-…

…5858 (#3170)
mongodb-js · Jun 7, 2022 · 0ae8aa6 · 0ae8aa6
1 parent 7b3bc20
commit 0ae8aa6
Show file tree

Hide file tree

Showing 3 changed files with 109 additions and 6 deletions.
diff --git a/packages/explain-plan-helper/src/get-execution-stats.ts b/packages/explain-plan-helper/src/get-execution-stats.ts
@@ -38,10 +38,7 @@ const _getUnshardedAggregationStats = (explain: Stage): ExecutionStats => {
 
   const stats = _getFindStats(firstStage[cursorKey]);
   stats.nReturned = lastStage.nReturned;
-  stats.executionTimeMillis = sumArrayProp(
-    explain.stages,
-    'executionTimeMillisEstimate'
-  );
+  stats.executionTimeMillis = getExecutionTime(stats, explain.stages);
   return stats;
 };
 const _getShardedAggregationStats = (explain: Stage): ExecutionStats => {
@@ -87,3 +84,13 @@ const _getFindStats = (explain: Stage): ExecutionStats => {
 function sumArrayProp<T>(arr: T[], prop: keyof T): number {
   return arr.reduce((acc, x) => acc + Number(x[prop] ?? 0), 0);
 }
+
+function getExecutionTime(stats: ExecutionStats, stages: Stage[]): number {
+  // We sum executionTimeMillisEstimate from all the stages, except for first
+  // as we use its executationStats.executionTimeMillis
+  const [, ...allStages] = stages;
+  return (
+    stats.executionTimeMillis +
+    sumArrayProp(allStages, 'executionTimeMillisEstimate')
+  );
+}
diff --git a/packages/explain-plan-helper/src/index.spec.ts b/packages/explain-plan-helper/src/index.spec.ts
@@ -287,6 +287,16 @@ describe('explain-plan-plan', function () {
           expect(plan.usedIndexes).to.deep.equal([]);
         });
       });
+
+      describe('execution time', function () {
+        beforeEach(async function () {
+          plan = await loadExplainFixture('aggregate_stages_with_no_time.json');
+        });
+
+        it('should sum estimate time correctly', function () {
+          expect(plan.executionStats.executionTimeMillis).to.equal(21317);
+        });
+      });
     });
     context('Sharded aggregation', function () {
       describe('single shard with stages', function () {
@@ -334,7 +344,8 @@ describe('explain-plan-plan', function () {
         });
         it('should have correct execution metrics', function () {
           expect(plan.executionStats.nReturned).to.equal(422); // nReturned is from the last stage
-          expect(plan.executionStats.executionTimeMillis).to.equal(30); // sum of executionTimeMillis from each stage
+          // executionTimeMillis from each stage (except $cursor) + executionTimeMillis of $cursor stage for each shard
+          expect(plan.executionStats.executionTimeMillis).to.equal(32);
           expect(plan.executionStats.totalKeysExamined).to.equal(719);
           expect(plan.executionStats.totalDocsExamined).to.equal(490);
         });
@@ -439,7 +450,8 @@ describe('explain-plan-plan', function () {
         });
         it('should have correct execution metrics', function () {
           expect(plan.executionStats.nReturned).to.equal(485); // sum of nReturned from the last stage of each shard
-          expect(plan.executionStats.executionTimeMillis).to.equal(13); // sum of executionTimeMillis from each stage of each shard
+          // executionTimeMillis from each stage (except $cursor) + executionTimeMillis of $cursor stage for each shard
+          expect(plan.executionStats.executionTimeMillis).to.equal(28);
           expect(plan.executionStats.totalKeysExamined).to.equal(719);
           expect(plan.executionStats.totalDocsExamined).to.equal(490);
         });

diff --git a/packages/explain-plan-helper/test/fixtures/aggregate_stages_with_no_time.json b/packages/explain-plan-helper/test/fixtures/aggregate_stages_with_no_time.json
@@ -0,0 +1,84 @@
+{
+  "stages": [
+    {
+      "$cursor": {
+        "query": {},
+        "queryPlanner": {
+          "plannerVersion": 1,
+          "namespace": "Corporate-Registrations.corporations",
+          "indexFilterSet": false,
+          "parsedQuery": {},
+          "queryHash": "8B3D4AB8",
+          "planCacheKey": "8B3D4AB8",
+          "winningPlan": {
+            "stage": "COLLSCAN",
+            "direction": "forward"
+          },
+          "rejectedPlans": []
+        },
+        "executionStats": {
+          "executionSuccess": true,
+          "nReturned": 1454504,
+          "executionTimeMillis": 21317,
+          "totalKeysExamined": 0,
+          "totalDocsExamined": 1454504,
+          "executionStages": {
+            "stage": "COLLSCAN",
+            "nReturned": 1454504,
+            "executionTimeMillisEstimate": 2907,
+            "works": 1454506,
+            "advanced": 1454504,
+            "needTime": 1,
+            "needYield": 0,
+            "saveState": 12965,
+            "restoreState": 12965,
+            "isEOF": 1,
+            "direction": "forward",
+            "docsExamined": 1454504
+          },
+          "allPlansExecution": []
+        }
+      }
+    },
+    {
+      "$sort": {
+        "sortKey": {
+          "name": -1
+        },
+        "limit": 100
+      }
+    }
+  ],
+  "serverInfo": {
+    "host": "compass-data-sets-shard-00-02-e06dc.mongodb.net",
+    "port": 27017,
+    "version": "4.2.20",
+    "gitVersion": "15c0712952c356cb711c13a42cb3bca8617d4ebc"
+  },
+  "ok": 1,
+  "$clusterTime": {
+    "clusterTime": {
+      "$timestamp": {
+        "t": 1654600046,
+        "i": 1
+      }
+    },
+    "signature": {
+      "hash": {
+        "$binary": {
+          "base64": "fZvzeYr8VLiaudW20Gm/bfaOdT0=",
+          "subType": "00"
+        }
+      },
+      "keyId": {
+        "$numberLong": "7065695976194834434"
+      }
+    }
+  },
+  "operationTime": {
+    "$timestamp": {
+      "t": 1654600046,
+      "i": 1
+    }
+  }
+}