DevTools: Adding new performance histograms for launch of top 4 tools

This change adds 4 new performance histograms for the DevTools using the
prefix 'DevTools.Launch':
- DevTools.Launch.Console
- DevTools.Launch.Elements
- DevTools.Launch.Network
- DevTools.Launch.Sources

These histograms measure the time between the DevTools window being
shown during 'DevToolsWindow::ToggleDevToolsWindow' and a point in each
tool that corresponds to the 'ready' state as seen by a user. These end
points are unique to each tool but are as follows:
- Console: At the end of the ConsolePrompt constructor
- Elements: At the end of _updateMetrics when the styles panel has
  been populated for the initially selected node
- Network: After the panel is shown
- Sources: After the NetworkNavigatorView has been loaded

These tools were chosen as they represent the most popular in terms of
usage and will allow us to identify any significant performance impact
in the time taken to launch the DevTools when these panels open by
default.

To see time captured by the histograms in terms of a perf trace for
each tool please take a look at the following screenshots:
https://imgur.com/a/rcAgQ8h

In the traces you can see that the end marker for each load is at the
end of the trace near first meaningful paint, and just as the user
will see the content of the tool render fully.

To accomplish the histograms, a new native function has been added to
the DevTools ui bindings/embedder classes called
'recordPerformanceHistogram'. Along with the plumbing and a new helper
function in the frontend javascript Host.UserMetrics file called
'panelLoaded'

When the frontend javascript loads, it will store the initial panel to
be loaded from the preferences. Once that panel has been created and
the appropriate loaded marker has been hit, the duration of the launch
will be calculated using performance.now(). That duration is then sent
to the native code which will fire the appropriate histogram via the
'UMA_HISTOGRAM_TIMES' macros.

The mechanism is similar to the existing one used for enumerated
histograms and can be expanded to fire additional performance histograms
in the future.

Also added a new test for user-metrics to ensure that the panelLoaded
function will correctly record the histograms.

Change-Id: Ib9f0bf80c651231d6d2e308bee36c1a1223f04db
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1506388Reviewed-by: Tom Sepez <tsepez@chromium.org>
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Reviewed-by: Pavel Feldman <pfeldman@chromium.org>
Commit-Queue: James Lissiak <jalissia@microsoft.com>
Cr-Commit-Position: refs/heads/master@{#644407}

chrome/browser/devtools/devtools_embedder_message_dispatcher.cc

@@ -21,6 +21,10 @@ bool GetValue(const base::Value& value, int* result) {
   return value.GetAsInteger(result);
 }
 
+bool GetValue(const base::Value& value, double* result) {
+  return value.GetAsDouble(result);
+}
+
 bool GetValue(const base::Value& value, bool* result) {
   return value.GetAsBoolean(result);
 }
@@ -206,6 +210,8 @@ DevToolsEmbedderMessageDispatcher::CreateForDevToolsFrontend(
                      delegate);
   d->RegisterHandler("recordEnumeratedHistogram",
                      &Delegate::RecordEnumeratedHistogram, delegate);
+  d->RegisterHandler("recordPerformanceHistogram",
+                     &Delegate::RecordPerformanceHistogram, delegate);
   d->RegisterHandlerWithCallback("sendJsonRequest",
                                  &Delegate::SendJsonRequest, delegate);
   d->RegisterHandlerWithCallback("getPreferences",

chrome/browser/devtools/devtools_embedder_message_dispatcher.h

@@ -92,6 +92,8 @@ class DevToolsEmbedderMessageDispatcher {
     virtual void RecordEnumeratedHistogram(const std::string& name,
                                            int sample,
                                            int boundary_value) = 0;
+    virtual void RecordPerformanceHistogram(const std::string& name,
+                                            double duration) = 0;
     virtual void SendJsonRequest(const DispatchCallback& callback,
                                  const std::string& browser_id,
                                  const std::string& url) = 0;

chrome/browser/devtools/devtools_ui_bindings.cc

@@ -17,6 +17,7 @@
 #include "base/json/json_writer.h"
 #include "base/json/string_escape.h"
 #include "base/macros.h"
+#include "base/metrics/histogram_functions.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_split.h"
@@ -168,7 +169,6 @@ class DefaultBindingsDelegate : public DevToolsUIBindings::Delegate {
   InfoBarService* GetInfoBarService() override;
   void RenderProcessGone(bool crashed) override {}
   void ShowCertificateViewer(const std::string& cert_chain) override {}
-
   content::WebContents* web_contents_;
   DISALLOW_COPY_AND_ASSIGN(DefaultBindingsDelegate);
 };
@@ -1109,6 +1109,19 @@ void DevToolsUIBindings::RecordEnumeratedHistogram(const std::string& name,
     frontend_host_->BadMessageRecieved();
 }
 
+void DevToolsUIBindings::RecordPerformanceHistogram(const std::string& name,
+                                                    double duration) {
+  if (!frontend_host_)
+    return;
+  if (duration < 0) {
+    return;
+  }
+  // Use histogram_functions.h instead of macros as the name comes from the
+  // DevTools frontend javascript and so will always have the same call site.
+  base::TimeDelta delta = base::TimeDelta::FromMilliseconds(duration);
+  base::UmaHistogramTimes(name, delta);
+}
+
 void DevToolsUIBindings::SendJsonRequest(const DispatchCallback& callback,
                                          const std::string& browser_id,
                                          const std::string& url) {

chrome/browser/devtools/devtools_ui_bindings.h

@@ -150,6 +150,8 @@ class DevToolsUIBindings : public DevToolsEmbedderMessageDispatcher::Delegate,
   void RecordEnumeratedHistogram(const std::string& name,
                                  int sample,
                                  int boundary_value) override;
+  void RecordPerformanceHistogram(const std::string& name,
+                                  double duration) override;
   void SendJsonRequest(const DispatchCallback& callback,
                        const std::string& browser_id,
                        const std::string& url) override;

third_party/blink/renderer/devtools/front_end/console/ConsolePrompt.js

@@ -63,6 +63,9 @@ Console.ConsolePrompt = class extends UI.Widget {
       this._editor.widget().element.tabIndex = -1;
 
       this._editorSetForTest();
+
+      // Record the console tool load time after the console prompt constructor is complete.
+      Host.userMetrics.panelLoaded('console', 'DevTools.Launch.Console');
     }
   }
 

third_party/blink/renderer/devtools/front_end/devtools_compatibility.js

@@ -539,6 +539,15 @@
       DevToolsAPI.sendMessageToEmbedder('recordEnumeratedHistogram', [actionName, actionCode, bucketSize], null);
     }
 
+    /**
+     * @override
+     * @param {string} histogramName
+     * @param {number} duration
+     */
+    recordPerformanceHistogram(histogramName, duration) {
+      DevToolsAPI.sendMessageToEmbedder('recordPerformanceHistogram', [histogramName, duration], null);
+    }
+
     /**
      * @override
      */

third_party/blink/renderer/devtools/front_end/elements/MetricsSidebarPane.js

@@ -297,6 +297,9 @@ Elements.MetricsSidebarPane = class extends Elements.ElementsSidebarPane {
     metricsElement.addEventListener('mouseover', this._highlightDOMNode.bind(this, false, 'all'), false);
     this.contentElement.removeChildren();
     this.contentElement.appendChild(metricsElement);
+
+    // Record the elements tool load time after the sidepane has loaded.
+    Host.userMetrics.panelLoaded('elements', 'DevTools.Launch.Elements');
   }
 
   /**

third_party/blink/renderer/devtools/front_end/host/InspectorFrontendHost.js

@@ -220,6 +220,14 @@ Host.InspectorFrontendHostStub = class {
   recordEnumeratedHistogram(actionName, actionCode, bucketSize) {
   }
 
+  /**
+   * @override
+   * @param {string} histogramName
+   * @param {number} duration
+   */
+  recordPerformanceHistogram(histogramName, duration) {
+  }
+
   /**
    * @override
    */

third_party/blink/renderer/devtools/front_end/host/InspectorFrontendHostAPI.js

@@ -240,6 +240,12 @@ InspectorFrontendHostAPI.prototype = {
    */
   recordEnumeratedHistogram(actionName, actionCode, bucketSize) {},
 
+  /**
+   * @param {string} histogramName
+   * @param {number} duration
+   */
+  recordPerformanceHistogram(histogramName, duration) {},
+
   /**
    * @param {string} message
    */

third_party/blink/renderer/devtools/front_end/host/UserMetrics.js

@@ -39,6 +39,8 @@ Host.UserMetrics = class {
     const code = Host.UserMetrics._PanelCodes[panelName] || 0;
     const size = Object.keys(Host.UserMetrics._PanelCodes).length + 1;
     InspectorFrontendHost.recordEnumeratedHistogram('DevTools.PanelShown', code, size);
+    // Store that the user has changed the panel so we know launch histograms should not be fired.
+    this._panelChangedSinceLaunch = true;
   }
 
   /**
@@ -55,6 +57,42 @@ Host.UserMetrics = class {
     const size = Object.keys(Host.UserMetrics.Action).length + 1;
     InspectorFrontendHost.recordEnumeratedHistogram('DevTools.ActionTaken', action, size);
   }
+
+  /**
+   * @param {string} panelName
+   * @param {string} histogramName
+   * @suppressGlobalPropertiesCheck
+   */
+  panelLoaded(panelName, histogramName) {
+    if (this._firedLaunchHistogram || panelName !== this._launchPanelName)
+      return;
+
+    this._firedLaunchHistogram = true;
+    // Use rAF and setTimeout to ensure the marker is fired after layout and rendering.
+    // This will give the most accurate representation of the tool being ready for a user.
+    requestAnimationFrame(() => {
+      setTimeout(() => {
+        // Mark the load time so that we can pinpoint it more easily in a trace.
+        performance.mark(histogramName);
+        // If the user has switched panel before we finished loading, ignore the histogram,
+        // since the launch timings will have been affected and are no longer valid.
+        if (this._panelChangedSinceLaunch)
+          return;
+        // This fires the event for the appropriate launch histogram.
+        // The duration is measured as the time elapsed since the time origin of the document.
+        InspectorFrontendHost.recordPerformanceHistogram(histogramName, performance.now());
+      }, 0);
+    });
+  }
+
+  /**
+   * @param {?string} panelName
+   */
+  setLaunchPanel(panelName) {
+    // Store the panel name that we should use for the launch histogram.
+    // Other calls to panelLoaded will be ignored if the name does not match the one set here.
+    this._launchPanelName = panelName;
+  }
 };
 
 // Codes below are used to collect UMA histograms in the Chromium port.

third_party/blink/renderer/devtools/front_end/network/NetworkPanel.js

@@ -389,6 +389,9 @@ Network.NetworkPanel = class extends UI.Panel {
    */
   wasShown() {
     UI.context.setFlavor(Network.NetworkPanel, this);
+
+    // Record the network tool load time after the panel has loaded.
+    Host.userMetrics.panelLoaded('network', 'DevTools.Launch.Network');
   }
 
   /**

third_party/blink/renderer/devtools/front_end/sources/SourcesNavigator.js

@@ -33,6 +33,9 @@ Sources.NetworkNavigatorView = class extends Sources.NavigatorView {
   constructor() {
     super();
     SDK.targetManager.addEventListener(SDK.TargetManager.Events.InspectedURLChanged, this._inspectedURLChanged, this);
+
+    // Record the sources tool load time after the file navigator has loaded.
+    Host.userMetrics.panelLoaded('sources', 'DevTools.Launch.Sources');
   }
 
   /**

third_party/blink/renderer/devtools/front_end/ui/InspectorView.js

@@ -84,6 +84,9 @@ UI.InspectorView = class extends UI.VBox {
     this._tabbedPane.addEventListener(UI.TabbedPane.Events.TabSelected, this._tabSelected, this);
     this._tabbedPane.setAccessibleName(Common.UIString('Panels'));
 
+    // Store the initial selected panel for use in launch histograms
+    Host.userMetrics.setLaunchPanel(this._tabbedPane.selectedTabId);
+
     if (Host.isUnderTest())
       this._tabbedPane.setAutoSelectFirstItemOnShow(false);
     this._drawerSplitWidget.setMainWidget(this._tabbedPane);

third_party/blink/web_tests/http/tests/devtools/user-metrics-perf-expected.txt

+Tests list of user metrics performance codes and invocations.
+
+recordPanelLoaded:
+Performance mark: DevTools.Launch.Console
+Performance histogram: DevTools.Launch.Console - positive duration?: true
+Performance mark: DevTools.Launch.Elements
+Performance histogram: DevTools.Launch.Elements - positive duration?: true
+Performance mark: DevTools.Launch.Network
+Performance histogram: DevTools.Launch.Network - positive duration?: true
+Performance mark: DevTools.Launch.Sources
+Performance histogram: DevTools.Launch.Sources - positive duration?: true
+
+Test that loading the tool only triggers the marker:
+Performance mark: DevTools.Launch.Console
+Performance mark: DevTools.Launch.Elements
+Performance mark: DevTools.Launch.Network
+Performance mark: DevTools.Launch.Sources
+

third_party/blink/web_tests/http/tests/devtools/user-metrics-perf.js

+// Copyright 2017 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+(async function() {
+  TestRunner.addResult(`Tests list of user metrics performance codes and invocations.\n`);
+
+  const testHistogramRecording = (panel, histogram, expectHistogram, testExecutor) => {
+    let recordHistogramComplete;
+    performance.mark = function(name) {
+      TestRunner.addResult(`Performance mark: ${name}`);
+      if (!expectHistogram)
+        recordHistogramComplete();
+    };
+    InspectorFrontendHost.recordPerformanceHistogram = function(name, duration) {
+      TestRunner.addResult(`Performance histogram: ${name} - positive duration?: ${duration > 0}`);
+      recordHistogramComplete();
+    };
+
+    return new Promise((resolve, reject) => {
+      Host.userMetrics._firedLaunchHistogram = undefined;
+      Host.userMetrics.setLaunchPanel(panel);
+      testExecutor(panel, histogram);
+      recordHistogramComplete = resolve;
+    });
+  };
+
+  const testPanelLoaded = (panel, histogram) =>
+      testHistogramRecording(panel, histogram, true, Host.userMetrics.panelLoaded.bind(Host.userMetrics));
+
+  const testShowView = (panel, histogram) =>
+      testHistogramRecording(panel, histogram, false, UI.viewManager.showView.bind(UI.viewManager));
+
+  TestRunner.addResult('recordPanelLoaded:');
+  await testPanelLoaded('console', 'DevTools.Launch.Console');
+  await testPanelLoaded('elements', 'DevTools.Launch.Elements');
+  await testPanelLoaded('network', 'DevTools.Launch.Network');
+  await testPanelLoaded('sources', 'DevTools.Launch.Sources');
+
+  TestRunner.addResult('\nTest that loading the tool only triggers the marker:');
+  await testShowView('console', 'DevTools.Launch.Console');
+  await testShowView('elements', 'DevTools.Launch.Elements');
+  await testShowView('network', 'DevTools.Launch.Network');
+  await testShowView('sources', 'DevTools.Launch.Sources');
+
+  TestRunner.completeTest();
+})();

tools/metrics/histograms/histograms.xml

@@ -22792,6 +22792,16 @@ uploading your change for review.
   </summary>
 </histogram>
 
+<histogram base="true" name="DevTools.Launch" units="ms">
+<!-- Name completed by histogram_suffixes name="DevToolsLaunchPanels" -->
+
+  <owner>pfeldman@chromium.org</owner>
+  <summary>
+    Measures the time until a given tool is interactive during a cold start of
+    the DevTools.
+  </summary>
+</histogram>
+
 <histogram name="DevTools.PanelShown" enum="DevToolsPanel">
   <owner>alph@chromium.org</owner>
   <owner>pfeldman@chromium.org</owner>
@@ -138742,6 +138752,14 @@ uploading your change for review.
   <affected-histogram name="DesktopIOSPromotion.VariationSigninReason"/>
 </histogram_suffixes>
 
+<histogram_suffixes name="DevToolsLaunchPanels" separator=".">
+  <suffix name="Console" label="DevTools launched to the Console panel"/>
+  <suffix name="Elements" label="DevTools launched to the Elements panel"/>
+  <suffix name="Network" label="DevTools launched to the Network panel"/>
+  <suffix name="Sources" label="DevTools launched to the Sources panel"/>
+  <affected-histogram name="DevTools.Launch"/>
+</histogram_suffixes>
+
 <histogram_suffixes name="DialogTypes" separator="." ordering="prefix">
   <suffix name="BubbleDialogDelegateView"
       label="Counts dialog boxes created using BubbleDialogDelegateView.