Bug 1405584 - Add telemetry to track toolbox open time. r=francois,jdescottes datareview=francois
authorAlexandre Poirot <poirot.alex@gmail.com>
Wed, 11 Oct 2017 11:43:25 +0200
changeset 386095 d6394715adb74585c26ec27c91d7d70461fc2dda
parent 386094 906745acb1ad4ab69116dfad1d2a19efe7568ad8
child 386096 a39ec568715b5d1efb06198c4be3664de056a7fd
push id53249
push userapoirot@mozilla.com
push dateFri, 13 Oct 2017 11:08:53 +0000
treeherderautoland@d6394715adb7 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfrancois, jdescottes
bugs1405584
milestone58.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1405584 - Add telemetry to track toolbox open time. r=francois,jdescottes datareview=francois MozReview-Commit-ID: EuaYQBx8rbE
devtools/client/framework/browser-menus.js
devtools/client/framework/devtools-browser.js
devtools/client/framework/devtools.js
devtools/client/menus.js
devtools/shim/DevToolsShim.jsm
devtools/shim/devtools-startup.js
toolkit/components/telemetry/Histograms.json
--- a/devtools/client/framework/browser-menus.js
+++ b/devtools/client/framework/browser-menus.js
@@ -71,17 +71,17 @@ function createToolMenuElements(toolDefi
 
   // Prevent multiple entries for the same tool.
   if (doc.getElementById(menuId)) {
     return;
   }
 
   let oncommand = function (id, event) {
     let window = event.target.ownerDocument.defaultView;
-    gDevToolsBrowser.selectToolCommand(window.gBrowser, id);
+    gDevToolsBrowser.selectToolCommand(window.gBrowser, id, window.performance.now());
   }.bind(null, id);
 
   let menuitem = createMenuItem({
     doc,
     id: "menuitem_" + id,
     label: toolDefinition.menuLabel || toolDefinition.label,
     accesskey: toolDefinition.accesskey
   });
--- a/devtools/client/framework/devtools-browser.js
+++ b/devtools/client/framework/devtools-browser.js
@@ -68,25 +68,29 @@ var gDevToolsBrowser = exports.gDevTools
   },
 
   /**
    * This function is for the benefit of Tools:DevToolbox in
    * browser/base/content/browser-sets.inc and should not be used outside
    * of there
    */
   // used by browser-sets.inc, command
-  toggleToolboxCommand(gBrowser) {
+  toggleToolboxCommand(gBrowser, startTime) {
     let target = TargetFactory.forTab(gBrowser.selectedTab);
     let toolbox = gDevTools.getToolbox(target);
 
     // If a toolbox exists, using toggle from the Main window :
     // - should close a docked toolbox
     // - should focus a windowed toolbox
     let isDocked = toolbox && toolbox.hostType != Toolbox.HostType.WINDOW;
-    isDocked ? gDevTools.closeToolbox(target) : gDevTools.showToolbox(target);
+    if (isDocked) {
+      gDevTools.closeToolbox(target);
+    } else {
+      gDevTools.showToolbox(target, null, null, null, startTime);
+    }
   },
 
   /**
    * This function ensures the right commands are enabled in a window,
    * depending on their relevant prefs. It gets run when a window is registered,
    * or when any of the devtools prefs change.
    */
   updateCommandAvailability(win) {
@@ -211,17 +215,17 @@ var gDevToolsBrowser = exports.gDevTools
    *   we select it
    * - if the toolbox is open, and the targeted tool is selected,
    *   and the host is NOT a window, we close the toolbox
    * - if the toolbox is open, and the targeted tool is selected,
    *   and the host is a window, we raise the toolbox window
    */
   // Used when: - registering a new tool
   //            - new xul window, to add menu items
-  selectToolCommand(gBrowser, toolId) {
+  selectToolCommand(gBrowser, toolId, startTime) {
     let target = TargetFactory.forTab(gBrowser.selectedTab);
     let toolbox = gDevTools.getToolbox(target);
     let toolDefinition = gDevTools.getToolDefinition(toolId);
 
     if (toolbox &&
         (toolbox.currentToolId == toolId ||
           (toolId == "webconsole" && toolbox.splitConsole))) {
       toolbox.fireCustomKey(toolId);
@@ -229,17 +233,17 @@ var gDevToolsBrowser = exports.gDevTools
       if (toolDefinition.preventClosingOnKey ||
           toolbox.hostType == Toolbox.HostType.WINDOW) {
         toolbox.raise();
       } else {
         gDevTools.closeToolbox(target);
       }
       gDevTools.emit("select-tool-command", toolId);
     } else {
-      gDevTools.showToolbox(target, toolId).then(newToolbox => {
+      gDevTools.showToolbox(target, toolId, null, null, startTime).then(newToolbox => {
         newToolbox.fireCustomKey(toolId);
         gDevTools.emit("select-tool-command", toolId);
       });
     }
   },
 
   /**
    * Called by devtools/client/devtools-startup.js when a key shortcut is pressed
@@ -248,28 +252,31 @@ var gDevToolsBrowser = exports.gDevTools
    *         The top level browser window from which the key shortcut is pressed.
    * @param  {Object} key
    *         Key object describing the key shortcut being pressed. It comes
    *         from devtools-startup.js's KeyShortcuts array. The useful fields here
    *         are:
    *         - `toolId` used to identify a toolbox's panel like inspector or webconsole,
    *         - `id` used to identify any other key shortcuts like scratchpad or
    *         about:debugging
+   * @param {Number} startTime
+   *        Optional, indicates the time at which the key event fired. This is a
+   *        `performance.now()` timing.
    */
-  onKeyShortcut(window, key) {
+  onKeyShortcut(window, key, startTime) {
     // If this is a toolbox's panel key shortcut, delegate to selectToolCommand
     if (key.toolId) {
-      gDevToolsBrowser.selectToolCommand(window.gBrowser, key.toolId);
+      gDevToolsBrowser.selectToolCommand(window.gBrowser, key.toolId, startTime);
       return;
     }
     // Otherwise implement all other key shortcuts individually here
     switch (key.id) {
       case "toggleToolbox":
       case "toggleToolboxF12":
-        gDevToolsBrowser.toggleToolboxCommand(window.gBrowser);
+        gDevToolsBrowser.toggleToolboxCommand(window.gBrowser, startTime);
         break;
       case "toggleToolbar":
         gDevToolsBrowser.getDeveloperToolbar(window).focusToggle();
         break;
       case "webide":
         gDevToolsBrowser.openWebIDE();
         break;
       case "browserToolbox":
--- a/devtools/client/framework/devtools.js
+++ b/devtools/client/framework/devtools.js
@@ -417,36 +417,45 @@ DevTools.prototype = {
     }
 
     if (browserConsole && !HUDService.getBrowserConsole()) {
       HUDService.toggleBrowserConsole();
     }
   },
 
   /**
+   * Boolean, true, if we never opened a toolbox.
+   * Used to implement the telemetry tracking toolbox opening.
+   */
+  _firstShowToolbox: true,
+
+  /**
    * Show a Toolbox for a target (either by creating a new one, or if a toolbox
    * already exists for the target, by bring to the front the existing one)
    * If |toolId| is specified then the displayed toolbox will have the
    * specified tool selected.
    * If |hostType| is specified then the toolbox will be displayed using the
    * specified HostType.
    *
    * @param {Target} target
    *         The target the toolbox will debug
    * @param {string} toolId
    *        The id of the tool to show
    * @param {Toolbox.HostType} hostType
    *        The type of host (bottom, window, side)
    * @param {object} hostOptions
    *        Options for host specifically
+   * @param {Number} startTime
+   *        Optional, indicates the time at which the user event related to this toolbox
+   *        opening started. This is a `performance.now()` timing.
    *
    * @return {Toolbox} toolbox
    *        The toolbox that was opened
    */
-  showToolbox: Task.async(function* (target, toolId, hostType, hostOptions) {
+  showToolbox: Task.async(function* (target, toolId, hostType, hostOptions, startTime) {
     let toolbox = this._toolboxes.get(target);
     if (toolbox) {
       if (hostType != null && toolbox.hostType != hostType) {
         yield toolbox.switchHost(hostType);
       }
 
       if (toolId != null && toolbox.currentToolId != toolId) {
         yield toolbox.selectTool(toolId);
@@ -460,20 +469,47 @@ DevTools.prototype = {
       let promise = this._creatingToolboxes.get(target);
       if (promise) {
         return yield promise;
       }
       let toolboxPromise = this.createToolbox(target, toolId, hostType, hostOptions);
       this._creatingToolboxes.set(target, toolboxPromise);
       toolbox = yield toolboxPromise;
       this._creatingToolboxes.delete(target);
+
+      if (startTime) {
+        this.logToolboxOpenTime(toolbox.currentToolId, startTime);
+      }
+      this._firstShowToolbox = false;
     }
     return toolbox;
   }),
 
+  /**
+   * Log telemetry related to toolbox opening.
+   * Two distinct probes are logged. One for cold startup, when we open the very first
+   * toolbox. This one includes devtools framework loading. And a second one for all
+   * subsequent toolbox opening, which should all be faster.
+   * These two probes are indexed by Tool ID.
+   *
+   * @param {String} toolId
+   *        The id of the opened tool.
+   * @param {Number} startTime
+   *        Indicates the time at which the user event related to the toolbox
+   *        opening started. This is a `performance.now()` timing.
+   */
+  logToolboxOpenTime(toolId, startTime) {
+    let { performance } = Services.appShell.hiddenDOMWindow;
+    let delay = performance.now() - startTime;
+    let telemetryKey = this._firstShowToolbox ?
+      "DEVTOOLS_COLD_TOOLBOX_OPEN_DELAY_MS" : "DEVTOOLS_WARM_TOOLBOX_OPEN_DELAY_MS";
+    let histogram = Services.telemetry.getKeyedHistogramById(telemetryKey);
+    histogram.add(toolId, delay);
+  },
+
   createToolbox: Task.async(function* (target, toolId, hostType, hostOptions) {
     let manager = new ToolboxHostManager(target, hostType, hostOptions);
 
     let toolbox = yield manager.create(toolId);
 
     this._toolboxes.set(target, toolbox);
 
     this.emit("toolbox-created", toolbox);
@@ -570,23 +606,26 @@ DevTools.prototype = {
    * Called from the DevToolsShim, used by nsContextMenu.js.
    *
    * @param {XULTab} tab
    *        The browser tab on which inspect node was used.
    * @param {Array} selectors
    *        An array of CSS selectors to find the target node. Several selectors can be
    *        needed if the element is nested in frames and not directly in the root
    *        document.
+   * @param {Number} startTime
+   *        Optional, indicates the time at which the user event related to this node
+   *        inspection started. This is a `performance.now()` timing.
    * @return {Promise} a promise that resolves when the node is selected in the inspector
    *         markup view.
    */
-  async inspectNode(tab, nodeSelectors) {
+  async inspectNode(tab, nodeSelectors, startTime) {
     let target = TargetFactory.forTab(tab);
 
-    let toolbox = await gDevTools.showToolbox(target, "inspector");
+    let toolbox = await gDevTools.showToolbox(target, "inspector", null, null, startTime);
     let inspector = toolbox.getCurrentPanel();
 
     // new-node-front tells us when the node has been selected, whether the
     // browser is remote or not.
     let onNewNode = inspector.selection.once("new-node-front");
 
     // Evaluate the cross iframes query selectors
     async function querySelectors(nodeFront) {
--- a/devtools/client/menus.js
+++ b/devtools/client/menus.js
@@ -36,17 +36,17 @@ loader.lazyRequireGetter(this, "Responsi
 loader.lazyImporter(this, "BrowserToolboxProcess", "resource://devtools/client/framework/ToolboxProcess.jsm");
 loader.lazyImporter(this, "ScratchpadManager", "resource://devtools/client/scratchpad/scratchpad-manager.jsm");
 
 exports.menuitems = [
   { id: "menu_devToolbox",
     l10nKey: "devToolboxMenuItem",
     oncommand(event) {
       let window = event.target.ownerDocument.defaultView;
-      gDevToolsBrowser.toggleToolboxCommand(window.gBrowser);
+      gDevToolsBrowser.toggleToolboxCommand(window.gBrowser, window.performance.now());
     },
     keyId: "toggleToolbox",
     checkbox: true
   },
   { id: "menu_devtools_separator",
     separator: true },
   { id: "menu_devToolbar",
     l10nKey: "devToolbarMenu",
--- a/devtools/shim/DevToolsShim.jsm
+++ b/devtools/shim/DevToolsShim.jsm
@@ -155,22 +155,28 @@ this.DevToolsShim = {
    * @param {Array} selectors
    *        An array of CSS selectors to find the target node. Several selectors can be
    *        needed if the element is nested in frames and not directly in the root
    *        document.
    * @return {Promise} a promise that resolves when the node is selected in the inspector
    *         markup view or that resolves immediately if DevTools are not installed.
    */
   inspectNode: function (tab, selectors) {
+    // Record the timing at which this event started in order to compute later in
+    // gDevTools.showToolbox, the complete time it takes to open the toolbox.
+    // i.e. especially take `DevtoolsStartup.initDevTools` into account.
+    let { performance } = Services.appShell.hiddenDOMWindow;
+    let startTime = performance.now();
+
     let devtoolsReady = this._maybeInitializeDevTools("ContextMenu");
     if (!devtoolsReady) {
       return Promise.resolve();
     }
 
-    return this._gDevTools.inspectNode(tab, selectors);
+    return this._gDevTools.inspectNode(tab, selectors, startTime);
   },
 
   _onDevToolsRegistered: function () {
     // Register all pending event listeners on the real gDevTools object.
     for (let [event, listener] of this.listeners) {
       this._gDevTools.on(event, listener);
     }
 
--- a/devtools/shim/devtools-startup.js
+++ b/devtools/shim/devtools-startup.js
@@ -444,21 +444,25 @@ DevToolsStartup.prototype = {
     // Appending a <key> element is not always enough. The <keyset> needs
     // to be detached and reattached to make sure the <key> is taken into
     // account (see bug 832984).
     let mainKeyset = doc.getElementById("mainKeyset");
     mainKeyset.parentNode.insertBefore(keyset, mainKeyset);
   },
 
   onKey(window, key) {
+    // Record the timing at which this event started in order to compute later in
+    // gDevTools.showToolbox, the complete time it takes to open the toolbox.
+    // i.e. especially take `initDevTools` into account.
+    let startTime = window.performance.now();
     let require = this.initDevTools("KeyShortcut");
     if (require) {
       // require might be null if initDevTools was called while DevTools are disabled.
       let { gDevToolsBrowser } = require("devtools/client/framework/devtools-browser");
-      gDevToolsBrowser.onKeyShortcut(window, key);
+      gDevToolsBrowser.onKeyShortcut(window, key, startTime);
     }
   },
 
   // Create a <xul:key> DOM Element
   createKey(doc, { id, toolId, shortcut, modifiers: mod }, oncommand) {
     let k = doc.createElement("key");
     k.id = "key_" + (id || toolId);
 
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -8397,16 +8397,38 @@
      "alert_emails": ["carnold@mozilla.org"],
      "bug_numbers": [1287587],
      "expires_in_version": "60",
      "kind": "count",
      "keyed": true,
      "releaseChannelCollection": "opt-out",
      "description": "A counter incremented every time the user prints a document."
    },
+  "DEVTOOLS_COLD_TOOLBOX_OPEN_DELAY_MS": {
+    "record_in_processes": ["main"],
+    "alert_emails": ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"],
+    "bug_numbers": [1405584],
+    "expires_in_version": "62",
+    "kind": "exponential",
+    "high": 60000,
+    "n_buckets": 100,
+    "keyed": true,
+    "description": "Time taken (in ms) to open the first DevTools toolbox. This is keyed by tool ID being opened [inspector, webconsole, jsdebugger, styleeditor, shadereditor, canvasdebugger, performance, memory, netmonitor, storage, webaudioeditor, scratchpad, dom]."
+  },
+  "DEVTOOLS_WARM_TOOLBOX_OPEN_DELAY_MS": {
+    "record_in_processes": ["main"],
+    "alert_emails": ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"],
+    "bug_numbers": [1405584],
+    "expires_in_version": "62",
+    "kind": "exponential",
+    "high": 60000,
+    "n_buckets": 100,
+    "keyed": true,
+    "description": "Time taken (in ms) to open all but first DevTools toolbox. This is keyed by tool ID being opened [inspector, webconsole, jsdebugger, styleeditor, shadereditor, canvasdebugger, performance, memory, netmonitor, storage, webaudioeditor, scratchpad, dom]."
+  },
   "DEVTOOLS_DEBUGGER_DISPLAY_SOURCE_LOCAL_MS": {
     "record_in_processes": ["main", "content"],
     "expires_in_version": "never",
     "kind": "exponential",
     "high": 10000,
     "n_buckets": 1000,
     "description": "The time (in milliseconds) that it took to display a selected source to the user."
   },