Add startup metrics that measure the performance of the first web contents.

chrome/browser/metrics/first_web_contents_profiler.cc

Index: chrome/browser/metrics/first_web_contents_profiler.cc
diff --git a/chrome/browser/metrics/first_web_contents_profiler.cc b/chrome/browser/metrics/first_web_contents_profiler.cc
new file mode 100644
index 0000000000000000000000000000000000000000..bce27bb7361e75978021ca4926175bee0b848eac
--- /dev/null
+++ b/chrome/browser/metrics/first_web_contents_profiler.cc
@@ -0,0 +1,127 @@
+// Copyright 2014 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.
+
+#include "chrome/browser/metrics/first_web_contents_profiler.h"
+
+#include "base/metrics/histogram.h"
+#include "base/process/process_info.h"
+#include "base/time/time.h"
+#include "chrome/browser/ui/browser.h"
+#include "chrome/browser/ui/browser_iterator.h"
+#include "chrome/browser/ui/tabs/tab_strip_model.h"
+#include "chrome/common/chrome_version_info.h"
+
+namespace {
+
+const int kHistogramMinTimeMilliseconds = 200;
+const int kHistogramMaxTimeSeconds = 45;
+
+// There is a lot of noise in the dev channel. One possible cause is that the
+// bucket ranges are too wide. The bucket count is chosen such that the size of
+// the bucket is 1% of its minimum. Notice that this also means that
+// subsequent buckets will satisfy Min(bucket N + 1) / Min(bucket N) = 1.01.
+// Then we want X, such that 1.01 ^ X = 45 * 1000 / 200. Some quick math shows
+// that X = 544.
+const int kHistogramBucketCount = 544;
+
+}  // namespace
+
+scoped_ptr<FirstWebContentsProfiler>
+FirstWebContentsProfiler::CreateProfilerForFirstWebContents(
+    FirstWebContentsProfilerDelegate* delegate) {
+  DCHECK(delegate);
+  for (chrome::BrowserIterator iterator; !iterator.done(); iterator.Next()) {
+    Browser* browser = *iterator;
+    content::WebContents* web_contents =
+        browser->tab_strip_model()->GetActiveWebContents();
+    if (web_contents) {
+      return scoped_ptr<FirstWebContentsProfiler>(
+          new FirstWebContentsProfiler(web_contents, delegate));
+    }
+  }
+  return nullptr;
+}
+
+bool FirstWebContentsProfiler::ShouldCollectMetrics() {
+  chrome::VersionInfo::Channel channel = chrome::VersionInfo::GetChannel();
+  return channel == chrome::VersionInfo::CHANNEL_CANARY ||
+         channel == chrome::VersionInfo::CHANNEL_DEV;
+}
+
+FirstWebContentsProfiler::FirstWebContentsProfiler(
+    content::WebContents* web_contents,
+    FirstWebContentsProfilerDelegate* delegate)
+    : content::WebContentsObserver(web_contents),
+      collected_paint_metric_(false),
+      collected_load_metric_(false),
+      delegate_(delegate) {
+}
+
+void FirstWebContentsProfiler::DidFirstVisuallyNonEmptyPaint() {
+  if (collected_paint_metric_)
+    return;
+  collected_paint_metric_ = true;
+  const base::Time process_creation_time =
+      base::CurrentProcessInfo::CreationTime();

[Alexei Svitkine (slow), 2014/12/03 20:05:57]

CreationTime() seems like it's doing a system call - at least on some platforms.

Since you call it in two places, how about doing it in the ctor and caching it
in a member?

[erikchen, 2014/12/03 21:38:41]

Done. I'm surprised that the function doesn't cache the result itself, since
it's called multiple times over the lifetime of Chrome, and the result isn't
expected to change.

+  if (!process_creation_time.is_null()) {

[Alexei Svitkine (slow), 2014/12/03 20:05:57]

Nit: Early return instead. Same below.

[erikchen, 2014/12/03 21:38:41]

That would change the behavior of this method (it would prevent
FinishedCollectingMetrics() from firing). While it would be possible to make it
early return by duplicating lines 85 & 86, that seems less clean.

I added documentation to collected_paint_metric_  and collected_load_metric_ to
indicate that the member is set to true even if the attempt fails, to prevent
this class from sitting around forever. I refrained from renaming the members,
since I couldn't think of a reasonably short member name that would convey more
precision to the meaning of the member.

+    base::TimeDelta elapsed = base::Time::Now() - process_creation_time;
+
+    // TODO(erikchen): Revisit these metrics once data has been collected to
+    // determine whether using more buckets reduces noise and provides higher
+    // quality information.
+    UMA_HISTOGRAM_CUSTOM_TIMES(
+        "Startup.Experimental.FirstWebContents.NonEmptyPaint."
+        "ManyBuckets",
+        elapsed,
+        base::TimeDelta::FromMilliseconds(kHistogramMinTimeMilliseconds),
+        base::TimeDelta::FromSeconds(kHistogramMaxTimeSeconds),
+        kHistogramBucketCount);
+    UMA_HISTOGRAM_TIMES(

[Alexei Svitkine (slow), 2014/12/03 20:05:57]

Use UMA_HISTOGRAM_TIMES_100

[erikchen, 2014/12/03 21:38:41]

Done.

+        "Startup.Experimental.FirstWebContents.NonEmptyPaint.StandardBuckets",
+        elapsed);
+  }
+
+  if (IsFinishedCollectingMetrics())
+    FinishedCollectingMetrics();
+}
+
+void FirstWebContentsProfiler::DocumentOnLoadCompletedInMainFrame() {
+  if (collected_load_metric_)
+    return;
+  collected_load_metric_ = true;
+  const base::Time process_creation_time =
+      base::CurrentProcessInfo::CreationTime();
+  if (!process_creation_time.is_null()) {
+    base::TimeDelta elapsed = base::Time::Now() - process_creation_time;
+
+    // TODO(erikchen): Revisit these metrics once data has been collected to
+    // determine whether using more buckets reduces noise and provides higher
+    // quality information.
+    UMA_HISTOGRAM_CUSTOM_TIMES(
+        "Startup.Experimental.FirstWebContents.MainFrameLoad."
+        "ManyBuckets",
+        elapsed,
+        base::TimeDelta::FromMilliseconds(kHistogramMinTimeMilliseconds),
+        base::TimeDelta::FromSeconds(kHistogramMaxTimeSeconds),
+        kHistogramBucketCount);
+    UMA_HISTOGRAM_TIMES(

[Alexei Svitkine (slow), 2014/12/03 20:05:57]

Ditto.

[erikchen, 2014/12/03 21:38:41]

Done.

+        "Startup.Experimental.FirstWebContents.MainFrameLoad.StandardBuckets",
+        elapsed);
+  }
+
+  if (IsFinishedCollectingMetrics())
+    FinishedCollectingMetrics();
+}
+
+void FirstWebContentsProfiler::WebContentsDestroyed() {
+  FinishedCollectingMetrics();
+}
+
+bool FirstWebContentsProfiler::IsFinishedCollectingMetrics() {
+  return collected_paint_metric_ && collected_load_metric_;
+}
+
+void FirstWebContentsProfiler::FinishedCollectingMetrics() {
+  delegate_->ProfilerFinishedCollectingMetrics();
+}