Page Abort Events for relevant navigations

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 df37a05170039af3a2dc72aef32bfb39e3572255..8652fe9d54b5b3b4f097dd68305d93e3102e72b3 100644
--- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc
+++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc
@@ -69,11 +69,6 @@ PageLoadTracker::PageLoadTracker(bool in_foreground)
 }
 
 PageLoadTracker::~PageLoadTracker() {
-  // Even a load that failed a provisional load should log
-  // that it aborted before first layout.
-  if (timing_.first_layout.is_zero())
-    RecordEvent(PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT);
-
   if (has_commit_)
     RecordTimingHistograms();
 }
@@ -85,21 +80,32 @@ void PageLoadTracker::WebContentsHidden() {
   }
 }
 
+void PageLoadTracker::WebContentsShown() {
+  // Only log the first time we foreground in a given page load.
+  // Don't log foreground time if we started foregrounded.

[Randy Smith (Not in Mondays), 2015/10/06 19:24:00]

I'm confused by this sentence.  If we started foregrounded and never go
background, foreground_time_ will be null and (presumably, haven't read the
paired code yet) won't be logged.  But if we started foreground, go background,
and then go foreground again, foregrount_time_ will not be null.  So shouldn't
we be testing started_in_foreground_?

(This may just be me bering confused by a comment that's not in the right place,
i.e. not near the code it refers to?)

[Charlie Harrison, 2015/10/06 19:35:36]

You're right this code could be more clear. Later we test
!foreground_time_.is_null() && !started_in_foreground_, but I'll move some of
that logic here.

+  if (foreground_time_.is_null()) {
+    foreground_time_ = base::TimeTicks::Now();
+  }
+}
+
 void PageLoadTracker::Commit() {
   has_commit_ = true;
+  // We only know page relevancy post-commit.
+  if (started_in_foreground_)
+    RecordEvent(PAGE_LOAD_RELEVANT_STARTED_IN_FOREGROUND);
+  else
+    RecordEvent(PAGE_LOAD_RELEVANT_STARTED_IN_BACKGROUND);
 }
 
 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)) {
+  bool valid_timing_descendent = timing_.navigation_start.is_null() ||

[Randy Smith (Not in Mondays), 2015/10/06 19:24:00]

nit, suggestion: I dislike creating temporary variables for single use.  To the
extent that documentation is needed, I'd rather have a comment.  But up to you.

Part of this is because I don't understand what "valid_timing_descendent" means;
whether you accept the above suggestion or not, could you add a comment
explaining that?

+      timing_.navigation_start == timing.navigation_start;
+  if (IsValidPageLoadTiming(timing) && valid_timing_descendent) {
     timing_ = timing;
     return true;
   }
+  RecordEvent(PAGE_LOAD_BAD_IPC);
   return false;
 }
 
@@ -135,7 +141,10 @@ void PageLoadTracker::RecordTimingHistograms() {
                           timing_.load_event_start);
     }
   }
-  if (!timing_.first_layout.is_zero()) {
+  if (timing_.first_layout.is_zero()) {
+    RecordEvent(PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT);
+    RecordEvent(PAGE_LOAD_RELEVANT_ABORTED_BEFORE_FIRST_LAYOUT);
+  } else {
     if (timing_.first_layout < background_delta) {
       PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstLayout",
                           timing_.first_layout);
@@ -146,7 +155,16 @@ void PageLoadTracker::RecordTimingHistograms() {
       RecordEvent(PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_BACKGROUND);
     }
   }
-
+  // Log time to first foreground / time to first background. Log counts that we
+  // started a relevant page load in the foreground / background.
+  if (started_in_foreground_ && !background_time_.is_null()) {
+    PAGE_LOAD_HISTOGRAM(
+        "PageLoad.Timing2.NavigationToFirstBackground", background_delta);
+  } else if (!started_in_foreground_ && !foreground_time_.is_null()) {
+    PAGE_LOAD_HISTOGRAM(
+      "PageLoad.Timing2.NavigationToFirstForeground",
+      WallTimeFromTimeTicks(foreground_time_) - timing_.navigation_start);
+  }
 }
 
 void PageLoadTracker::RecordEvent(PageLoadEvent event) {
@@ -198,8 +216,10 @@ void MetricsWebContentsObserver::DidFinishNavigation(
   // will be ignored.
   if (!navigation_handle->HasCommitted()) {
     finished_nav->RecordEvent(PAGE_LOAD_FAILED_BEFORE_COMMIT);
-    if (navigation_handle->GetNetErrorCode() == net::ERR_ABORTED)
+    if (navigation_handle->GetNetErrorCode() == net::ERR_ABORTED) {
       finished_nav->RecordEvent(PAGE_LOAD_ABORTED_BEFORE_COMMIT);
+      finished_nav->RecordEvent(PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT);
+    }
     return;
   }
 
@@ -220,6 +240,11 @@ void MetricsWebContentsObserver::DidFinishNavigation(
 
 void MetricsWebContentsObserver::WasShown() {
   in_foreground_ = true;
+  if (committed_load_)
+    committed_load_->WebContentsShown();
+  for (const auto& kv : provisional_loads_) {
+    kv.second->WebContentsShown();
+  }
 }
 
 void MetricsWebContentsObserver::WasHidden() {