Bug 1423517 - Helps tracking JS allocations when running DevTools tests. r=jdescottes

MozReview-Commit-ID: 7PWgsUyR54Q

--HG--
extra : rebase_source : d620f8b704e9da6e8ee7326715a21addeb08bd06

devtools/client/framework/test/shared-head.js

@@ -99,6 +99,23 @@ registerCleanupFunction(() => {
   Services.obs.removeObserver(ConsoleObserver, "console-api-log-event");
 });
 
+// Print allocation count if DEBUG_DEVTOOLS_ALLOCATIONS is set to "normal",
+// and allocation sites if DEBUG_DEVTOOLS_ALLOCATIONS is set to "verbose".
+const env = Cc["@mozilla.org/process/environment;1"].getService(Ci.nsIEnvironment);
+const DEBUG_ALLOCATIONS = env.get("DEBUG_DEVTOOLS_ALLOCATIONS");
+if (DEBUG_ALLOCATIONS) {
+  const { allocationTracker } = require("devtools/shared/test-helpers/allocation-tracker");
+  let tracker = allocationTracker();
+  registerCleanupFunction(() => {
+    if (DEBUG_ALLOCATIONS == "normal") {
+      tracker.logCount();
+    } else if (DEBUG_ALLOCATIONS == "verbose") {
+      tracker.logAllocationSites();
+    }
+    tracker.stop();
+  });
+}
+
 var waitForTime = DevToolsUtils.waitForTime;
 
 function getFrameScript() {

devtools/shared/moz.build

@@ -33,6 +33,10 @@ DIRS += [
     'worker',
 ]
 
+# Only ship test helpers in local builds
+if not CONFIG['MOZILLA_OFFICIAL']:
+    DIRS += ['test-helpers']
+
 BROWSER_CHROME_MANIFESTS += ['tests/browser/browser.ini']
 MOCHITEST_CHROME_MANIFESTS += ['tests/mochitest/chrome.ini']
 XPCSHELL_TESTS_MANIFESTS += ['tests/unit/xpcshell.ini']

devtools/shared/test-helpers/allocation-tracker.js

@@ -0,0 +1,188 @@
+/* this source code form is subject to the terms of the mozilla public
+ * license, v. 2.0. if a copy of the mpl was not distributed with this
+ * file, you can obtain one at http://mozilla.org/mpl/2.0/. */
+
+/*
+ * This file helps tracking Javascript object allocations.
+ * It is only included in local builds as a debugging helper.
+ *
+ * It is typicaly used when running DevTools tests (either mochitests or DAMP).
+ * To use it, you need to set the following environment variable:
+ *   DEBUG_DEVTOOLS_ALLOCATIONS="normal"
+ *     This will only print the number of JS objects created during your test.
+ *   DEBUG_DEVTOOLS_ALLOCATIONS="verbose"
+ *     This will print the allocation sites of all the JS objects created during your
+ *     test. i.e. from which files and lines the objects have been created.
+ * In both cases, look for "DEVTOOLS ALLOCATION" in your terminal to see tracker's
+ * output.
+ *
+ * But you can also import it from your test script if you want to focus on one
+ * particular piece of code:
+ *   const { allocationTracker } =
+ *     require("devtools/shared/test-helpers/allocation-tracker");
+ *   // Calling `allocationTracker` will immediately start recording allocations
+ *   let tracker = allocationTracker();
+ *
+ *   // Do something
+ *
+ *   // If you want to log all the allocation sites, call this method:
+ *   tracker.logAllocationSites();
+ *   // Or, if you want to only print the number of objects being allocated, call this:
+ *   tracker.logCount();
+ *   // Once you are done, stop the tracker as it slow down execution a lot.
+ *   tracker.stop();
+ */
+
+"use strict";
+
+let { Cu } = require("chrome");
+
+// Get a "Debugger" constructor. Can't call `addDebuggerToGlobal`
+// on the frame script global, so call it on jsdebugger one...
+let global = Cu.import("resource://gre/modules/jsdebugger.jsm", {});
+const {addDebuggerToGlobal} = global;
+addDebuggerToGlobal(global);
+let { Debugger } = global;
+
+exports.allocationTracker = function () {
+  dump("DEVTOOLS ALLOCATION: Start logging allocations\n");
+  let dbg = new Debugger();
+
+  // Enable allocation site tracking, to have the stack for each allocation
+  dbg.memory.trackingAllocationSites = true;
+  // Force saving *all* the allocation sites
+  dbg.memory.allocationSamplingProbability = 1.0;
+  // Bumps the default buffer size, which may prevent recording all the test allocations
+  dbg.memory.maxAllocationsLogLength = 5000000;
+
+  // Watch all globals
+  dbg.addAllGlobalsAsDebuggees();
+
+  // Remove this global to ignore all its object/JS
+  dbg.removeDebuggee(Cu.getGlobalForObject({}));
+
+  // addAllGlobalsAsDebuggees won't automatically track new ones,
+  // so ensure tracking all new globals
+  dbg.onNewGlobalObject = function (g) {
+    dbg.addDebuggee(g);
+  };
+
+  return {
+    get overflowed() {
+      return dbg.memory.allocationsLogOverflowed;
+    },
+
+    /**
+     * Print to stdout data about all recorded allocations
+     *
+     * It prints an array of allocations per file, sorted by files allocating the most
+     * objects. And get detail of allocation per line.
+     *
+     *   [{ src: "chrome://devtools/content/framework/toolbox.js",
+     *      count: 210, // Total # of allocs for toolbox.js
+     *      lines: [
+     *       "10: 200", // toolbox.js allocation 200 objects on line 10
+     *       "124: 10
+     *      ]
+     *    },
+     *    { src: "chrome://devtools/content/inspector/inspector.js",
+     *      count: 12,
+     *      lines: [
+     *       "20: 12",
+     *      ]
+     *    }]
+     *
+     * @param first Number
+     *        Retrieve only the top $first script allocation the most
+     *        objects
+     */
+    logAllocationSites({ first = 5 } = {}) {
+      // Fetch all allocation sites from Debugger API
+      let allocations = dbg.memory.drainAllocationsLog();
+
+      // Process Debugger API data to store allocations by file
+      // sources = {
+      //   "chrome://devtools/content/framework/toolbox.js": {
+      //     count: 10, // total # of allocs for toolbox.js
+      //     lines: {
+      //       10: 200, // total # of allocs for toolbox.js line 10
+      //       124: 10, // same, for line 124
+      //       ..
+      //     }
+      //   }
+      // }
+      let sources = {};
+      for (let alloc of allocations) {
+        let { frame } = alloc;
+        let src = "UNKNOWN";
+        let line = -1;
+        try {
+          if (frame) {
+            src = frame.source || "UNKNOWN";
+            line = frame.line || -1;
+          }
+        } catch (e) {
+          // For some frames accessing source throws
+        }
+
+        let item = sources[src];
+        if (!item) {
+          item = sources[src] = { count: 0, lines: {} };
+        }
+        item.count++;
+        if (line != -1) {
+          if (!item.lines[line]) {
+            item.lines[line] = 0;
+          }
+          item.lines[line]++;
+        }
+      }
+
+      let allocationList = Object.entries(sources)
+        // Sort by number of total object
+        .sort(([srcA, itemA], [srcB, itemB]) => itemA.count < itemB.count)
+        // Keep only the first 5 sources, with the most allocations
+        .filter((_, i) => i < first)
+        .map(([src, item]) => {
+          let lines = [];
+          Object.entries(item.lines)
+            .filter(([line, count]) => count > 5)
+            .sort(([lineA, countA], [lineB, countB]) => {
+              if (countA != countB) {
+                return countA < countB;
+              }
+              return lineA < lineB;
+            })
+            .forEach(([line, count]) => {
+              // Compress the data to make it readable on stdout
+              lines.push(line + ": " + count);
+            });
+          return { src, count: item.count, lines };
+        });
+      dump("DEVTOOLS ALLOCATION: Javascript object allocations: " + allocations.length +
+           "\n" + JSON.stringify(allocationList, null, 2) + "\n");
+    },
+
+    logCount() {
+      dump("DEVTOOLS ALLOCATION: Javascript object allocations: " +
+           this.countAllocations() + "\n");
+    },
+
+    countAllocations() {
+      // Fetch all allocation sites from Debugger API
+      let allocations = dbg.memory.drainAllocationsLog();
+      return allocations.length;
+    },
+
+    flushAllocations() {
+      dbg.memory.drainAllocationsLog();
+    },
+
+    stop() {
+      dump("DEVTOOLS ALLOCATION: Stop logging allocations\n");
+      dbg.onNewGlobalObject = undefined;
+      dbg.removeAllDebuggees();
+      dbg = null;
+    }
+  };
+};

devtools/shared/test-helpers/moz.build

@@ -0,0 +1,15 @@
+# -*- Mode: python; indent-tabs-mode: nil; tab-width: 40 -*-
+# vim: set filetype=python:
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+
+# This directory is only processed for local build
+# where MOZILLA_OFFICIAL isn't set
+
+DevToolsModules(
+    'allocation-tracker.js',
+)
+
+with Files('**'):
+    BUG_COMPONENT = ('Firefox', 'Developer Tools')

testing/talos/talos/tests/devtools/addon/content/damp.js

@@ -1,6 +1,8 @@
+const Ci = Components.interfaces;
 const { Services } = Components.utils.import("resource://gre/modules/Services.jsm", {});
 const { XPCOMUtils } = Cu.import("resource://gre/modules/XPCOMUtils.jsm", {});
 const gMgr = Cc["@mozilla.org/memory-reporter-manager;1"].getService(Ci.nsIMemoryReporterManager);
+const env = Cc["@mozilla.org/process/environment;1"].getService(Ci.nsIEnvironment);
 
 XPCOMUtils.defineLazyGetter(this, "require", function() {
   let { require } =
@@ -29,6 +31,11 @@ const SIMPLE_URL = webserver + "/tests/devtools/addon/content/pages/simple.html"
 const COMPLICATED_URL = webserver + "/tests/tp5n/bild.de/www.bild.de/index.html";
 const CUSTOM_URL = webserver + "/tests/devtools/addon/content/pages/custom/$TOOL.html";
 
+// Record allocation count in new subtests if DEBUG_DEVTOOLS_ALLOCATIONS is set to
+// "normal". Print allocation sites to stdout if DEBUG_DEVTOOLS_ALLOCATIONS is set to
+// "verbose".
+const DEBUG_ALLOCATIONS = env.get("DEBUG_DEVTOOLS_ALLOCATIONS");
+
 function getMostRecentBrowserWindow() {
   return Services.wm.getMostRecentWindow("navigator:browser");
 }
@@ -231,6 +238,14 @@ Damp.prototype = {
    *         and we should record its duration.
    */
   runTest(label) {
+    if (DEBUG_ALLOCATIONS) {
+      if (!this.allocationTracker) {
+        this.allocationTracker = this.startAllocationTracker();
+      }
+      // Flush the current allocations before running the test
+      this.allocationTracker.flushAllocations();
+    }
+
     let startLabel = label + ".start";
     performance.mark(startLabel);
     let start = performance.now();
@@ -244,6 +259,15 @@ Damp.prototype = {
           name: label,
           value: duration
         });
+
+        if (DEBUG_ALLOCATIONS == "normal") {
+          this._results.push({
+            name: label + ".allocations",
+            value: this.allocationTracker.countAllocations()
+          });
+        } else if (DEBUG_ALLOCATIONS == "verbose") {
+          this.allocationTracker.logAllocationSites();
+        }
       }
     };
   },
@@ -944,6 +968,10 @@ async _consoleOpenWithCachedMessagesTest() {
   _onTestComplete: null,
 
   _doneInternal() {
+    if (this.allocationTracker) {
+      this.allocationTracker.stop();
+      this.allocationTracker = null;
+    }
     this._logLine("DAMP_RESULTS_JSON=" + JSON.stringify(this._results));
     this._reportAllResults();
     this._win.gBrowser.selectedTab = this._dampTab;
@@ -1005,6 +1033,11 @@ async _consoleOpenWithCachedMessagesTest() {
     });
   },
 
+  startAllocationTracker() {
+    const { allocationTracker } = require("devtools/shared/test-helpers/allocation-tracker");
+    return allocationTracker();
+  },
+
   startTest(doneCallback, config) {
     this._onTestComplete = function(results) {
       TalosParentProfiler.pause("DAMP - end");
@@ -1012,7 +1045,6 @@ async _consoleOpenWithCachedMessagesTest() {
     };
     this._config = config;
 
-    const Ci = Components.interfaces;
     var wm = Components.classes["@mozilla.org/appshell/window-mediator;1"].getService(Ci.nsIWindowMediator);
     this._win = wm.getMostRecentWindow("navigator:browser");
     this._dampTab = this._win.gBrowser.selectedTab;
@@ -1092,6 +1124,8 @@ async _consoleOpenWithCachedMessagesTest() {
     // related to Firefox startup or DAMP setup during the first test.
     garbageCollect().then(() => {
       this._doSequence(sequenceArray, this._doneInternal);
+    }).catch(e => {
+      dump("Exception while running DAMP tests: " + e + "\n" + e.stack + "\n");
     });
   }
 };