Separate page load metrics for backgrounded pages

components/page_load_metrics/browser/metrics_web_contents_observer.cc

Index: components/page_load_metrics/browser/metrics_web_contents_observer.cc
diff --git a/components/page_load_metrics/browser/metrics_web_contents_observer.cc b/components/page_load_metrics/browser/metrics_web_contents_observer.cc
index 080f00b076152f9052e85a3fe361e88888520c83..3087e939a0e7d5ea9d5416d48e788c1478b15559 100644
--- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc
+++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc
@@ -49,14 +49,86 @@ bool IsValidPageLoadTiming(const PageLoadTiming& timing) {
 
 }  // namespace
 
+#define PAGE_LOAD_HISTOGRAM(name, sample)                           \
+  UMA_HISTOGRAM_CUSTOM_TIMES(name, sample,                          \
+                             base::TimeDelta::FromMilliseconds(10), \
+                             base::TimeDelta::FromMinutes(10), 100);
+
+PageLoadTracker::PageLoadTracker(bool in_foreground)
+    : has_commit_(false),
+      has_finished_(false),
+      page_load_stayed_in_foreground_(in_foreground) {}
+
+PageLoadTracker::~PageLoadTracker() {
+  if (has_commit_)
+    RecordTimingHistograms();
+}
+
+void PageLoadTracker::WebContentsHidden() {
+  if (!has_finished_)

[Bryan McQuade, 2015/09/24 18:21:52]

let's chat about this and some possible alternatives a bit next week. onload is
probably a decent signal for many pages, but there are others where the entire
page load, from a user standpoint, happens entirely after onload. if we can come
up with a mechanism that doesn't care about onload i think i'd prefer that. one
alternative would be to log metrics observed up until the time the web contents
got hidden, and then stop recording metrics for that page. that way, we log
metrics for what the user experienced only. let's chat more next week.

[Charlie Harrison, 2015/09/24 18:49:07]

Sounds good. I'm hesitant about logging partial structs before background unless
we name them something else. Otherwise they will be conflated with
failed/aborted loads.

+    page_load_stayed_in_foreground_ = false;
+}
+
+void PageLoadTracker::Commit() {
+  has_commit_ = true;
+}
+
+void PageLoadTracker::Finish() {
+  has_finished_ = true;
+}
+
+bool PageLoadTracker::UpdateTiming(const PageLoadTiming& timing) {
+  // Throw away IPCs that are not relevant to the current navigation.
+  if (!timing_.navigation_start.is_null() &&
+      timing_.navigation_start != timing.navigation_start) {
+    // TODO(csharrison) uma log a counter here
+    return false;
+  }
+  if (IsValidPageLoadTiming(timing)) {
+    timing_ = timing;
+    return true;
+  }
+  return false;
+}
+
+void PageLoadTracker::RecordTimingHistograms() {
+  DCHECK(has_commit_);
+  if (!timing_.dom_content_loaded_event_start.is_zero()) {
+    if (page_load_stayed_in_foreground_) {
+      PAGE_LOAD_HISTOGRAM(
+          "PageLoad.Timing.NavigationToDOMContentLoadedEventFired",
+          timing_.dom_content_loaded_event_start);
+    } else {
+      PAGE_LOAD_HISTOGRAM(
+          "PageLoad.Timing.BG.NavigationToDOMContentLoadedEventFired",
+          timing_.dom_content_loaded_event_start);
+    }
+  }
+  if (!timing_.load_event_start.is_zero()) {
+    if (page_load_stayed_in_foreground_) {
+      PAGE_LOAD_HISTOGRAM("PageLoad.Timing.NavigationToLoadEventFired",
+                          timing_.load_event_start);
+    } else {
+      PAGE_LOAD_HISTOGRAM("PageLoad.Timing.BG.NavigationToLoadEventFired",
+                          timing_.load_event_start);
+    }
+  }
+  if (!timing_.first_layout.is_zero()) {
+    if (page_load_stayed_in_foreground_) {
+      PAGE_LOAD_HISTOGRAM("PageLoad.Timing.NavigationToFirstLayout",
+                          timing_.first_layout);
+    } else {
+      PAGE_LOAD_HISTOGRAM("PageLoad.Timing.BG.NavigationToFirstLayout",
+                          timing_.first_layout);
+    }
+  }
+}
+
 MetricsWebContentsObserver::MetricsWebContentsObserver(
     content::WebContents* web_contents)
-    : content::WebContentsObserver(web_contents) {}
+    : content::WebContentsObserver(web_contents), in_foreground_(false) {}
 
-// This object is tied to a single WebContents for its entire lifetime.
-MetricsWebContentsObserver::~MetricsWebContentsObserver() {
-  RecordTimingHistograms();
-}
+MetricsWebContentsObserver::~MetricsWebContentsObserver() {}
 
 bool MetricsWebContentsObserver::OnMessageReceived(
     const IPC::Message& message,
@@ -73,30 +145,67 @@ bool MetricsWebContentsObserver::OnMessageReceived(
 
 void MetricsWebContentsObserver::DidCommitNavigation(
     content::NavigationHandle* navigation_handle) {
-  if (navigation_handle->IsInMainFrame() && !navigation_handle->IsSamePage())
-    RecordTimingHistograms();
-  if (IsRelevantNavigation(navigation_handle))
-    current_timing_.reset(new PageLoadTiming());
+  if (!navigation_handle->IsInMainFrame())
+    return;
+
+  // If the provisional load is a relevant navigation (which we only know for
+  // sure after commit), then we update |committed_load_|. We always remove a
+  // provisional navigation from |provisional_loads_| on commit.
+  if (IsRelevantNavigation(navigation_handle)) {
+    // Updating |committed_load_| will trigger RecordTimingHistograms on a
+    // previous PageLoadTracker.
+    committed_load_ = provisional_loads_.take_and_erase(navigation_handle);
+    DCHECK(committed_load_);
+    committed_load_->Commit();
+  } else {
+    provisional_loads_.erase(navigation_handle);

[Bryan McQuade, 2015/09/24 18:21:52]

should we also call
committed_load_.reset();
here to force logging of the previous tracker if any?

Perhaps instead we should just do that unconditionally above the call to
IsRelevantNavigation(...) along with a comment just to be super explicit that we
want to destruct the previous one if any in order to trigger recording of
histograms.

[Charlie Harrison, 2015/09/24 18:49:07]

I'm not sure. Can't a same-page navigation commit before a page has fully
loaded? Best to wait as long as possible to log so we don't log early.

+  }
 }
 
-// This will occur when the process for the main RenderFrameHost exits.
-// This will happen with a normal exit or a crash.
-void MetricsWebContentsObserver::RenderProcessGone(
-    base::TerminationStatus status) {
-  RecordTimingHistograms();
+void MetricsWebContentsObserver::DidStartNavigation(
+    content::NavigationHandle* navigation_handle) {
+  if (!navigation_handle->IsInMainFrame())
+    return;
+  // We can have two provisional loads in some cases. E.g. a same-site
+  // navigation can have a concurrent cross-process navigation started
+  // from the omnibox.
+  DCHECK(provisional_loads_.size() < 2);
+  provisional_loads_.insert(
+      navigation_handle, make_scoped_ptr(new PageLoadTracker(in_foreground_)));
 }
 
-#define PAGE_LOAD_HISTOGRAM(name, sample)                           \
-  UMA_HISTOGRAM_CUSTOM_TIMES(name, sample,                          \
-                             base::TimeDelta::FromMilliseconds(10), \
-                             base::TimeDelta::FromMinutes(10), 100);
+void MetricsWebContentsObserver::DidFinishLoad(
+    content::RenderFrameHost* render_frame_host,
+    const GURL& validated_url) {
+  if (render_frame_host == web_contents()->GetMainFrame() && committed_load_)
+    committed_load_->Finish();
+}
+
+void MetricsWebContentsObserver::DidFailLoad(
+    content::RenderFrameHost* render_frame_host,
+    const GURL& validated_url,
+    int error_code,
+    const base::string16& error_description,
+    bool was_ignored_by_handler) {
+  if (render_frame_host == web_contents()->GetMainFrame() && committed_load_)
+    committed_load_->Finish();
+}
+
+void MetricsWebContentsObserver::WasShown() {
+  in_foreground_ = true;
+}
+void MetricsWebContentsObserver::WasHidden() {
+  in_foreground_ = false;
+  if (committed_load_)
+    committed_load_->WebContentsHidden();
+  for (auto kv : provisional_loads_) {

[Bryan McQuade, 2015/09/24 18:21:52]

auto is awesome but subtle. if you just say 'auto' it's equivalent to just
typing the type of the object (non-const, non-reference) which can cause a copy
constructor to be invoked in some cases as you iterate each element. just to be
sure to avoid that, i like to do:
const auto& kv : provisional_loads_
or if operating on non-const data:
auto& kv : provisional_loads_
which avoids a copy in many cases

[Charlie Harrison, 2015/09/24 18:49:07]

Yeah good idea.

+    kv.second->WebContentsHidden();
+  }
+}
 
 void MetricsWebContentsObserver::OnTimingUpdated(
     content::RenderFrameHost* render_frame_host,
     const PageLoadTiming& timing) {
-  if (!current_timing_)

[Bryan McQuade, 2015/09/24 18:21:52]

should we still continue to return if committed_load_ is null?

-    return;
-
   // We may receive notifications from frames that have been navigated away
   // from. We simply ignore them.
   if (render_frame_host != web_contents()->GetMainFrame())
@@ -108,36 +217,7 @@ void MetricsWebContentsObserver::OnTimingUpdated(
   if (!web_contents()->GetLastCommittedURL().SchemeIsHTTPOrHTTPS())
     return;
 
-  // Throw away IPCs that are not relevant to the current navigation.
-  if (!current_timing_->navigation_start.is_null() &&
-      timing.navigation_start != current_timing_->navigation_start) {
-    // TODO(csharrison) uma log a counter here
-    return;
-  }
-
-  *current_timing_ = timing;
-}
-
-void MetricsWebContentsObserver::RecordTimingHistograms() {
-  if (!current_timing_ || !IsValidPageLoadTiming(*current_timing_))
-    return;
-
-  if (!current_timing_->dom_content_loaded_event_start.is_zero()) {
-    PAGE_LOAD_HISTOGRAM(
-        "PageLoad.Timing.NavigationToDOMContentLoadedEventFired",
-        current_timing_->dom_content_loaded_event_start);
-  }
-
-  if (!current_timing_->load_event_start.is_zero()) {
-    PAGE_LOAD_HISTOGRAM("PageLoad.Timing.NavigationToLoadEventFired",
-                        current_timing_->load_event_start);
-  }
-
-  if (!current_timing_->first_layout.is_zero()) {
-    PAGE_LOAD_HISTOGRAM("PageLoad.Timing.NavigationToFirstLayout",
-                        current_timing_->first_layout);
-  }
-  current_timing_.reset();
+  committed_load_->UpdateTiming(timing);
 }
 
 bool MetricsWebContentsObserver::IsRelevantNavigation(