Add Startup.BrowserView.FirstPaint / .CompositingEnded histograms.

components/startup_metric_utils/browser/startup_metric_utils.cc

Index: components/startup_metric_utils/browser/startup_metric_utils.cc
diff --git a/components/startup_metric_utils/browser/startup_metric_utils.cc b/components/startup_metric_utils/browser/startup_metric_utils.cc
index f1ad613d5df94bc95887beaafc255f963664c4c6..31c13b854b2c130abe3a1cf754ae3217fd1f6f9a 100644
--- a/components/startup_metric_utils/browser/startup_metric_utils.cc
+++ b/components/startup_metric_utils/browser/startup_metric_utils.cc
@@ -39,7 +39,7 @@ namespace {
 
 // Mark as volatile to defensively make sure usage is thread-safe.
 // Note that at the time of this writing, access is only on the UI thread.
-volatile bool g_non_browser_ui_displayed = false;
+volatile bool g_main_window_startup_interrupted = false;
 
 base::LazyInstance<base::TimeTicks>::Leaky g_process_creation_ticks =
     LAZY_INSTANCE_INITIALIZER;
@@ -388,12 +388,12 @@ void RecordHardFaultHistogram() {
 // also the time taken to synchronously resolve base::Time::Now() and
 // base::TimeTicks::Now() at play, but in practice it is pretty much instant
 // compared to multi-seconds startup timings.
-base::TimeTicks StartupTimeToTimeTicks(const base::Time& time) {
-  // First get a base which represents the same point in time in both units.
-  // Bump the priority of this thread while doing this as the wall clock time it
-  // takes to resolve these two calls affects the precision of this method and
-  // bumping the priority reduces the likelihood of a context switch interfering
-  // with this computation.
+base::TimeTicks StartupTimeToTimeTicks(const base::Time time) {
+// First get a base which represents the same point in time in both units.
+// Bump the priority of this thread while doing this as the wall clock time it
+// takes to resolve these two calls affects the precision of this method and
+// bumping the priority reduces the likelihood of a context switch interfering
+// with this computation.
 
 // Enabling this logic on OS X causes a significant performance regression.
 // https://crbug.com/601270
@@ -455,9 +455,9 @@ void RecordMainEntryTimeHistogram() {
 
 // Record renderer main entry time histogram.
 void RecordRendererMainEntryHistogram() {
-  const base::TimeTicks& browser_main_entry_point_ticks =
+  const base::TimeTicks browser_main_entry_point_ticks =
       g_browser_main_entry_point_ticks.Get();
-  const base::TimeTicks& renderer_main_entry_point_ticks =
+  const base::TimeTicks renderer_main_entry_point_ticks =
       g_renderer_main_entry_point_ticks.Get();
 
   if (!browser_main_entry_point_ticks.is_null() &&
@@ -548,6 +548,11 @@ void RecordSameVersionStartupCount(PrefService* pref_service) {
                            g_startups_with_current_version);
 }
 
+bool ShouldLogProcessCreationTicksHistogram() {
+  return !WasMainWindowStartupInterrupted() &&
+         !g_process_creation_ticks.Get().is_null();
+}
+
 }  // namespace
 
 void RegisterPrefs(PrefRegistrySimple* registry) {
@@ -557,21 +562,25 @@ void RegisterPrefs(PrefRegistrySimple* registry) {
   registry->RegisterIntegerPref(prefs::kSameVersionStartupCount, 0);
 }
 
-bool WasNonBrowserUIDisplayed() {
-  return g_non_browser_ui_displayed;
+bool WasMainWindowStartupInterrupted() {
+  return g_main_window_startup_interrupted;
 }
 
 void SetNonBrowserUIDisplayed() {
-  g_non_browser_ui_displayed = true;
+  g_main_window_startup_interrupted = true;
+}
+
+void SetBackgroundModeEnabled() {
+  g_main_window_startup_interrupted = true;
 }
 
-void RecordStartupProcessCreationTime(const base::Time& time) {
+void RecordStartupProcessCreationTime(const base::Time time) {
   DCHECK(g_process_creation_ticks.Get().is_null());
   g_process_creation_ticks.Get() = StartupTimeToTimeTicks(time);
   DCHECK(!g_process_creation_ticks.Get().is_null());
 }
 
-void RecordMainEntryPointTime(const base::Time& time) {
+void RecordMainEntryPointTime(const base::Time time) {
   DCHECK(g_browser_main_entry_point_ticks.Get().is_null());
   g_browser_main_entry_point_ticks.Get() = StartupTimeToTimeTicks(time);
   DCHECK(!g_browser_main_entry_point_ticks.Get().is_null());
@@ -583,13 +592,13 @@ void RecordMainEntryPointTime(const base::Time& time) {
   DCHECK(!g_browser_main_entry_point_time.Get().is_null());
 }
 
-void RecordExeMainEntryPointTicks(const base::TimeTicks& ticks) {
+void RecordExeMainEntryPointTicks(const base::TimeTicks ticks) {
   DCHECK(g_browser_exe_main_entry_point_ticks.Get().is_null());
   g_browser_exe_main_entry_point_ticks.Get() = ticks;
   DCHECK(!g_browser_exe_main_entry_point_ticks.Get().is_null());
 }
 
-void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
+void RecordBrowserMainMessageLoopStart(const base::TimeTicks ticks,
                                        bool is_first_run,
                                        PrefService* pref_service) {
   DCHECK(pref_service);
@@ -604,8 +613,7 @@ void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
   // Record timing of the browser message-loop start time.
   base::StackSamplingProfiler::SetProcessMilestone(
       metrics::CallStackProfileMetricsProvider::MAIN_LOOP_START);
-  const base::TimeTicks& process_creation_ticks =
-      g_process_creation_ticks.Get();
+  const base::TimeTicks process_creation_ticks = g_process_creation_ticks.Get();
   if (!is_first_run && !process_creation_ticks.is_null()) {
     UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
         UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime",
@@ -657,12 +665,12 @@ void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
   }
 }
 
-void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) {
+void RecordBrowserWindowDisplay(const base::TimeTicks ticks) {

[Alexei Svitkine (slow), 2017/04/19 16:52:16]

Nit: We don't usually keep const in the qualifiers for non-ref parameters, so
suggest removing them.

[themblsha, 2017/04/19 17:27:41]

I thought that it offers protection from unintended modification, and
semantically suggests that it shouldn't be modified inside the function.

const is already used inside several of the functions for local variables in
this file and parameters are local variables as well.

[Peter Kasting, 2017/04/19 18:12:12]

const on locals is fine.  const on params is more questionable:
* It looks to readers as if this was intended to be a const ref, so people try
to figure out what the intent was or waste time "fixing" things that weren't
broken.
* If the "const" is also used in the declaration, it exposes this implementation
detail to callers.  If it is not, then the declaration and definition have
different qualifiers, which is legal in this case but surprising to readers.

So even though I'm a big fan of local const, I suggest not using it on params.

[themblsha, 2017/04/20 10:42:23]

Thanks for explaining this point, now it's clear to me.

   static bool is_first_call = true;
   if (!is_first_call || ticks.is_null())
     return;
   is_first_call = false;
-  if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
+  if (!ShouldLogProcessCreationTicksHistogram())
     return;
 
   UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
@@ -670,7 +678,7 @@ void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) {
       g_process_creation_ticks.Get(), ticks);
 }
 
-void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) {
+void RecordBrowserOpenTabsDelta(const base::TimeDelta delta) {
   static bool is_first_call = true;
   if (!is_first_call)
     return;
@@ -680,19 +688,19 @@ void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) {
       UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserOpenTabs", delta);
 }
 
-void RecordRendererMainEntryTime(const base::TimeTicks& ticks) {
+void RecordRendererMainEntryTime(const base::TimeTicks ticks) {
   // Record the renderer main entry time, but don't log the UMA metric
   // immediately because the startup temperature is not known yet.
   if (g_renderer_main_entry_point_ticks.Get().is_null())
     g_renderer_main_entry_point_ticks.Get() = ticks;
 }
 
-void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) {
+void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks ticks) {
   static bool is_first_call = true;
   if (!is_first_call || ticks.is_null())
     return;
   is_first_call = false;
-  if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
+  if (!ShouldLogProcessCreationTicksHistogram())
     return;
 
   UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
@@ -700,7 +708,7 @@ void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) {
       g_process_creation_ticks.Get(), ticks);
 }
 
-void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
+void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks ticks) {
   static bool is_first_call = true;
   if (!is_first_call || ticks.is_null())
     return;
@@ -710,7 +718,7 @@ void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
   // entry time and the startup temperature are known.
   RecordRendererMainEntryHistogram();
 
-  if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
+  if (!ShouldLogProcessCreationTicksHistogram())
     return;
 
   base::StackSamplingProfiler::SetProcessMilestone(
@@ -720,13 +728,13 @@ void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
       g_process_creation_ticks.Get(), ticks);
 }
 
-void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks,
+void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks ticks,
                                                WebContentsWorkload workload) {
   static bool is_first_call = true;
   if (!is_first_call || ticks.is_null())
     return;
   is_first_call = false;
-  if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
+  if (!ShouldLogProcessCreationTicksHistogram())
     return;
 
   base::StackSamplingProfiler::SetProcessMilestone(
@@ -752,13 +760,12 @@ void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks,
   }
 }
 
-void RecordFirstWebContentsMainNavigationFinished(
-    const base::TimeTicks& ticks) {
+void RecordFirstWebContentsMainNavigationFinished(const base::TimeTicks ticks) {
   static bool is_first_call = true;
   if (!is_first_call || ticks.is_null())
     return;
   is_first_call = false;
-  if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
+  if (!ShouldLogProcessCreationTicksHistogram())
     return;
 
   base::StackSamplingProfiler::SetProcessMilestone(
@@ -769,6 +776,34 @@ void RecordFirstWebContentsMainNavigationFinished(
       g_process_creation_ticks.Get(), ticks);
 }
 
+void RecordBrowserWindowFirstPaint(const base::TimeTicks ticks) {
+  static bool is_first_call = true;
+  if (!is_first_call || ticks.is_null())
+    return;
+  is_first_call = false;
+  if (!ShouldLogProcessCreationTicksHistogram())
+    return;
+
+  UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE(
+      UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserWindow.FirstPaint",
+      g_process_creation_ticks.Get(), ticks);
+}
+
+void RecordBrowserWindowFirstPaintCompositingEnded(
+    const base::TimeTicks ticks) {
+  static bool is_first_call = true;
+  if (!is_first_call || ticks.is_null())
+    return;
+  is_first_call = false;
+  if (!ShouldLogProcessCreationTicksHistogram())
+    return;
+
+  UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE(
+      UMA_HISTOGRAM_LONG_TIMES_100,
+      "Startup.BrowserWindow.FirstPaint.CompositingEnded",
+      g_process_creation_ticks.Get(), ticks);
+}
+
 base::TimeTicks MainEntryPointTicks() {
   return g_browser_main_entry_point_ticks.Get();
 }