Repository: firebase/firebase-tools
Pull request #1416 (2019-06-19 03:53:19)

database:profile: Cannot read property 'millis' of undefined
<!--

Thank you for contributing to the Firebase community! Please fill out the form below.

Run the linter and test suite
==============================
Run `npm test` to make sure your changes compile properly and the tests all pass on your local machine. We've hooked up this repo with continuous integration to double check those things for you. 

-->

### Description

<!-- Are you fixing a bug? Implementing a new feature? Make sure we have the context around your change. Link to other relevant issues or pull requests. -->

Profiler records with undefined paths can break path collapsing logic because lodash can convert null object keys in the string key `'null'`. This change fixes https://github.com/firebase/firebase-tools/issues/1407 by special casing `concurrent-connect` and `concurrent-disconnect` profiler records to occur at path "null", and defaulting all other operations to take place at path `/`. We need to do the latter because the RTDB profiler will not define a `path` record field for any operation at the database root.
	 
### Scenarios Tested

<!-- Write a list of all the user journeys and edge cases you've tested. Instructions for manual testing can be found at https://github.com/firebase/firebase-tools/blob/master/.github/CONTRIBUTING.md#development-setup -->

I tested running the profiler command described in the PR under load and also opened and closed the firebase-console to trigger connects, disconnects, and unlistens (none of which contain `path` fields in their profiler records. There also appear to be some rest reads that don't contains paths.

### Sample Commands

<!-- Proposing a change to commands or flags? Provide examples of how they will be used. -->


coveralls: 
[![Coverage Status](https://coveralls.io/builds/24092962/badge)](https://coveralls.io/builds/24092962)

Coverage increased (+0.08%) to 62.038% when pulling **c832db1278d6170b0cdc493337cd8ad6abff1db8 on wyszynski/profiler-null-fix** into **e76bfde601bda1a04728ebdee7b7a737a8c50b83 on master**.

ryanpbrewster: `"null"` is a weird path, in part because it's a valid path under normal circumstances.

Do these things need paths? Perhaps we should just ignore these messages (but leave them in the` --raw` output)?

```
Uploaded Bytes

┌───────┬───────┬───────┬─────────┐
│ Path  │ Total │ Count │ Average │
├───────┼───────┼───────┼─────────┤
│ /null │ 2 B   │ 1     │ 2 B     │
└───────┴───────┴───────┴─────────┘
```
IanWyszynski: > `"null"` is a weird path, in part because it's a valid path under normal circumstances.
> 
> Do these things need paths? Perhaps we should just ignore these messages (but leave them in the` --raw` output)?
> 
> ```
> Uploaded Bytes
> 
> ┌───────┬───────┬───────┬─────────┐
> │ Path  │ Total │ Count │ Average │
> ├───────┼───────┼───────┼─────────┤
> │ /null │ 2 B   │ 1     │ 2 B     │
> └───────┴───────┴───────┴─────────┘
> ```

I agree, the "null" sentinel path will confuse developers. In the most recent commit I've added an alternate rendering path for operations that are not logically associated with any data in the realtime database. Now, they render like this:

```
Connect Speed

┌───────┬─────────────────────────┬──────────────────────┐
│ Count │ Average Execution Speed │ Average Pending Time │
└───────┴─────────────────────────┴──────────────────────┘

Disconnect Speed

┌───────┬─────────────────────────┬──────────────────────┐
│ Count │ Average Execution Speed │ Average Pending Time │
├───────┼─────────────────────────┼──────────────────────┤
│ 1     │ 0 ms                    │ 0 ms                 │
└───────┴─────────────────────────┴──────────────────────┘
```
IanWyszynski: > how do we test this? manually?

I've run manual tests to verify that tabular formatting, but there is also an [autotest](https://github.com/firebase/firebase-tools/blob/master/src/test/profilerReport.spec.js) that checks the raw output matches expectations defined [here](https://github.com/firebase/firebase-tools/blob/master/src/test/fixtures/profiler-data/sample-output.json).
IanWyszynski: Since we don't need to differentiate connect operations by path, I just use the toplevel `connectSpeed` object to store the stats for `concurrent-connect` ops in the latest commit. This gets rid of the sentinel path and gives us the aggregation we want for connects and disconnects.

This does mean we have separate codepaths for collection and rendering of "unpathed" operation stats.

Patch:
diff --git a/changelog.txt b/changelog.txt
index 3ca7ef50a..02d86bdc1 100644
--- a/changelog.txt
+++ b/changelog.txt
@@ -2,6 +2,7 @@
 * Make `functions:shell` respect the `--port` argument.
 * Improve error message when `firebase serve` can't acquire the right port.
 * Allow running the Firestore and RTDB emulators without a configuration.
+* Fixes bug where profiler table rendering crashes due to undefined `path`.
 * Allow the Firestore emulator to give more information about invalid rulesets.
 * Hot reload firestore rules on change.
 * Upgrade archiver dependency to 3.0.0.
diff --git a/src/profileReport.js b/src/profileReport.js
index 0e464c2cf..0c4a30dd6 100644
--- a/src/profileReport.js
+++ b/src/profileReport.js
@@ -62,10 +62,7 @@ ProfileReport.extractJSON = function(line, input) {
 };
 
 ProfileReport.pathString = function(path) {
-  if (path) {
-    return "/" + path.join("/");
-  }
-  return null;
+  return "/" + (path ? path.join("/") : "");
 };
 
 ProfileReport.formatNumber = function(num) {
@@ -125,6 +122,29 @@ ProfileReport.prototype.collectUnindexed = function(data, path) {
   indexNode.times += 1;
 };
 
+ProfileReport.prototype.collectSpeedUnpathed = function(data, opStats) {
+  if (Object.keys(opStats).length === 0) {
+    opStats.times = 0;
+    opStats.millis = 0;
+    opStats.pendingCount = 0;
+    opStats.pendingTime = 0;
+    opStats.rejected = 0;
+  }
+  opStats.times += 1;
+
+  if (data.hasOwnProperty("millis")) {
+    opStats.millis += data.millis;
+  }
+  if (data.hasOwnProperty("pendingTime")) {
+    opStats.pendingCount++;
+    opStats.pendingTime += data.pendingTime;
+  }
+  // Explictly check for false, in case its not defined.
+  if (data.allowed === false) {
+    opStats.rejected += 1;
+  }
+};
+
 ProfileReport.prototype.collectSpeed = function(data, path, opType) {
   if (!_.has(opType, path)) {
     opType[path] = {
@@ -182,12 +202,12 @@ ProfileReport.prototype.collectUnlisten = function(data, path) {
   this.collectSpeed(data, path, this.state.unlistenSpeed);
 };
 
-ProfileReport.prototype.collectConnect = function(data, path) {
-  this.collectSpeed(data, path, this.state.connectSpeed);
+ProfileReport.prototype.collectConnect = function(data) {
+  this.collectSpeedUnpathed(data, this.state.connectSpeed);
 };
 
-ProfileReport.prototype.collectDisconnect = function(data, path) {
-  this.collectSpeed(data, path, this.state.disconnectSpeed);
+ProfileReport.prototype.collectDisconnect = function(data) {
+  this.collectSpeedUnpathed(data, this.state.disconnectSpeed);
 };
 
 ProfileReport.prototype.collectWrite = function(data, path, bytes) {
@@ -204,10 +224,10 @@ ProfileReport.prototype.processOperation = function(data) {
   this.state.opCount++;
   switch (data.name) {
     case "concurrent-connect":
-      this.collectConnect(data, path);
+      this.collectConnect(data);
       break;
     case "concurrent-disconnect":
-      this.collectDisconnect(data, path);
+      this.collectDisconnect(data);
       break;
     case "realtime-read":
       this.collectRead(data, path, data.bytes);
@@ -382,6 +402,46 @@ ProfileReport.prototype.renderIncomingBandwidth = function() {
   return this.renderBandwidth(this.state.inband);
 };
 
+/*
+ * Some Realtime Database operations (concurrent-connect, concurrent-disconnect)
+ * are not logically associated with a path in the database. In this source
+ * file, we associate these operations with the sentinel path "null" so that
+ * they can still be aggregated in `collapsePaths`. So as to not confuse
+ * developers, we render aggregate statistics for such operations without a
+ * `path` table column.
+ */
+ProfileReport.prototype.renderUnpathedOperationSpeed = function(speedData, hasSecurity) {
+  var head = ["Count", "Average Execution Speed", "Average Pending Time"];
+  if (hasSecurity) {
+    head.push("Permission Denied");
+  }
+  var table = new Table({
+    head: head,
+    style: {
+      head: this.options.isFile ? [] : ["yellow"],
+      border: this.options.isFile ? [] : ["grey"],
+    },
+  });
+  /*
+   * If no unpathed opeartion was seen, the corresponding stats sub-object will
+   * be empty.
+   */
+  if (Object.keys(speedData).length > 0) {
+    var row = [
+      speedData.times,
+      ProfileReport.formatNumber(speedData.millis / speedData.times) + " ms",
+      ProfileReport.formatNumber(
+        speedData.pendingCount === 0 ? 0 : speedData.pendingTime / speedData.pendingCount
+      ) + " ms",
+    ];
+    if (hasSecurity) {
+      row.push(ProfileReport.formatNumber(speedData.rejected));
+    }
+    table.push(row);
+  }
+  return table;
+};
+
 ProfileReport.prototype.renderOperationSpeed = function(pureData, hasSecurity) {
   var head = ["Path", "Count", "Average Execution Speed", "Average Pending Time"];
   if (hasSecurity) {
@@ -443,11 +503,11 @@ ProfileReport.prototype.renderBroadcastSpeed = function() {
 };
 
 ProfileReport.prototype.renderConnectSpeed = function() {
-  return this.renderOperationSpeed(this.state.connectSpeed, false);
+  return this.renderUnpathedOperationSpeed(this.state.connectSpeed, false);
 };
 
 ProfileReport.prototype.renderDisconnectSpeed = function() {
-  return this.renderOperationSpeed(this.state.disconnectSpeed, false);
+  return this.renderUnpathedOperationSpeed(this.state.disconnectSpeed, false);
 };
 
 ProfileReport.prototype.renderUnlistenSpeed = function() {


Test patch:
diff --git a/src/test/fixtures/profiler-data/sample-output.json b/src/test/fixtures/profiler-data/sample-output.json
index 367197636..f0d39b019 100644
--- a/src/test/fixtures/profiler-data/sample-output.json
+++ b/src/test/fixtures/profiler-data/sample-output.json
@@ -176,14 +176,12 @@
   },
   "connectSpeed": {
     "legend": [
-      "Path",
       "Count",
       "Average Execution Speed",
       "Average Pending Time"
     ],
     "data": [
       [
-        "null",
         1,
         "0 ms",
         "2 ms"
@@ -193,14 +191,12 @@
   },
   "disconnectSpeed": {
     "legend": [
-      "Path",
       "Count",
       "Average Execution Speed",
       "Average Pending Time"
     ],
     "data": [
       [
-        "null",
         1,
         "0 ms",
         "3 ms"