Bug 1405584 - Add telemetry to track toolbox open time. r=jdescottes datareview=francois draft
authorAlexandre Poirot <poirot.alex@gmail.com>
Wed, 11 Oct 2017 11:43:25 +0200
changeset 680032 a0aab4dd5ee0e79f44864efc46acb9095d82351b
parent 680024 196dadb2fe500e75c6fbddcac78106648676cf10
child 735740 c6eb8ff1deec4378694eaa4a4b1c5dcbc80d7661
push id84373
push userbmo:poirot.alex@gmail.com
push dateFri, 13 Oct 2017 11:07:12 +0000
reviewersjdescottes
bugs1405584
milestone58.0a1
Bug 1405584 - Add telemetry to track toolbox open time. r=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."
   },