Log First User Interaction in Page Load Metrics

chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc

Index: chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc
diff --git a/chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc b/chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc
index 612e5cca70428eb8a38deaebfdff20fecf98aa2e..fdc51b77f3d5c1e7a51e85243b3f2ac90e016c68 100644
--- a/chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc
+++ b/chrome/browser/page_load_metrics/observers/from_gws_page_load_metrics_observer.cc
@@ -44,32 +44,46 @@ const char kHistogramFromGWSAbortUnknownNavigationBeforeCommit[] =
 const char kHistogramFromGWSAbortNewNavigationBeforePaint[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.NewNavigation.AfterCommit."
     "BeforePaint";
+const char kHistogramFromGWSAbortNewNavigationBeforeInteraction[] =
+    "PageLoad.Clients.FromGoogleSearch.AbortTiming.NewNavigation.AfterPaint."
+    "BeforeInteraction";
 const char kHistogramFromGWSAbortStopBeforeCommit[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Stop.BeforeCommit";
 const char kHistogramFromGWSAbortStopBeforePaint[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Stop.AfterCommit."
     "BeforePaint";
+const char kHistogramFromGWSAbortStopBeforeInteraction[] =
+    "PageLoad.Clients.FromGoogleSearch.AbortTiming.Stop.AfterPaint."
+    "BeforeInteraction";
 const char kHistogramFromGWSAbortCloseBeforeCommit[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Close.BeforeCommit";
 const char kHistogramFromGWSAbortCloseBeforePaint[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Close.AfterCommit."
     "BeforePaint";
-
+const char kHistogramFromGWSAbortCloseBeforeInteraction[] =
+    "PageLoad.Clients.FromGoogleSearch.AbortTiming.Close.AfterPaint."
+    "BeforeInteraction";
 const char kHistogramFromGWSAbortOtherBeforeCommit[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Other.BeforeCommit";
 const char kHistogramFromGWSAbortReloadBeforePaint[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.Reload.AfterCommit."
     "BeforePaint";
+const char kHistogramFromGWSAbortReloadBeforeInteraction[] =
+    "PageLoad.Clients.FromGoogleSearch.AbortTiming.Reload.AfterPaint."
+    "Before1sDelayedInteraction";
 const char kHistogramFromGWSAbortForwardBackBeforePaint[] =
     "PageLoad.Clients.FromGoogleSearch.AbortTiming.ForwardBackNavigation."
     "AfterCommit.BeforePaint";
+const char kHistogramFromGWSAbortForwardBackBeforeInteraction[] =
+    "PageLoad.Clients.FromGoogleSearch.AbortTiming.ForwardBackNavigation."
+    "AfterPaint.Before1sDelayedInteraction";
 
 }  // namespace internal
 
 namespace {
 
 void LogCommittedAbortsBeforePaint(UserAbortType abort_type,
-                        base::TimeDelta time_to_abort) {
+                                   base::TimeDelta time_to_abort) {
   switch (abort_type) {
     case UserAbortType::ABORT_STOP:
       PAGE_LOAD_HISTOGRAM(internal::kHistogramFromGWSAbortStopBeforePaint,
@@ -101,6 +115,41 @@ void LogCommittedAbortsBeforePaint(UserAbortType abort_type,
   }
 }
 
+void LogAbortsAfterPaintBeforeInteraction(UserAbortType abort_type,
+                                          base::TimeDelta time_to_abort) {
+  switch (abort_type) {
+    case UserAbortType::ABORT_STOP:
+      PAGE_LOAD_HISTOGRAM(internal::kHistogramFromGWSAbortStopBeforeInteraction,
+                          time_to_abort);
+      break;
+    case UserAbortType::ABORT_CLOSE:
+      PAGE_LOAD_HISTOGRAM(
+          internal::kHistogramFromGWSAbortCloseBeforeInteraction,
+          time_to_abort);
+      break;
+    case UserAbortType::ABORT_NEW_NAVIGATION:
+      PAGE_LOAD_HISTOGRAM(
+          internal::kHistogramFromGWSAbortNewNavigationBeforeInteraction,
+          time_to_abort);
+      break;
+    case UserAbortType::ABORT_RELOAD:
+      PAGE_LOAD_HISTOGRAM(
+          internal::kHistogramFromGWSAbortReloadBeforeInteraction,
+          time_to_abort);
+      break;
+    case UserAbortType::ABORT_FORWARD_BACK:
+      PAGE_LOAD_HISTOGRAM(
+          internal::kHistogramFromGWSAbortForwardBackBeforeInteraction,
+          time_to_abort);
+      break;
+    default:
+      // These should only be logged for provisional aborts.
+      DCHECK_NE(abort_type, UserAbortType::ABORT_OTHER);
+      DCHECK_NE(abort_type, UserAbortType::ABORT_UNKNOWN_NAVIGATION);
+      break;
+  }
+}
+
 void LogProvisionalAborts(UserAbortType abort_type,
                           base::TimeDelta time_to_abort) {
   switch (abort_type) {
@@ -133,11 +182,15 @@ void LogProvisionalAborts(UserAbortType abort_type,
 bool WasAbortedInForeground(UserAbortType abort_type,
                             base::TimeDelta time_to_abort,
                             const page_load_metrics::PageLoadExtraInfo& info) {
-  if (time_to_abort.is_zero())
-    return false;
   if (abort_type == UserAbortType::ABORT_NONE)
     return false;
-  if (WasStartedInForegroundEventInForeground(time_to_abort, info))
+  // This is a modified version of WasStartedInForegroundEventInForeground,
+  // which does not check time_to_abort is non-zero
+  // TODO(mushan): change back with WasStartedInForegroundEventInForeground
+  // once crbug.com/616901 is addressed
+  if (info.started_in_foreground &&
+      (info.first_background_time.is_zero() ||
+       time_to_abort < info.first_background_time))
     return true;
   if (!info.started_in_foreground)
     return false;
@@ -151,6 +204,28 @@ bool WasAbortedInForeground(UserAbortType abort_type,
   return false;
 }
 
+bool WasAbortedBeforeInteraction(UserAbortType abort_type,
+                                 base::TimeDelta time_to_interaction,
+                                 base::TimeDelta time_to_abort) {
+  // For the case the abort is a reload or forward_back. Since pull to
+  // reload / forward_back is the most common user case such aborts being
+  // triggered, add a sanitization threshold here: if the first user
+  // interaction are received before a reload / forward_back in a very
+  // short time, treat the interaction as a gesture to perform the abort.
+
+  // Why 1000ms?
+  // 1000ms is enough to perform a pull to reload / forward_back gesture.
+  // It's also too short a time for a user to consume any content
+  // revealed by the interaction.
+  if (abort_type == UserAbortType::ABORT_RELOAD ||
+      abort_type == UserAbortType::ABORT_FORWARD_BACK) {
+    return time_to_interaction + base::TimeDelta::FromMilliseconds(1000) >
+           time_to_abort;
+  } else {
+    return time_to_interaction >= time_to_abort;
+  }
+}
+
 }  // namespace
 
 // See
@@ -329,6 +404,8 @@ void FromGWSPageLoadMetricsObserver::OnCommit(
                                    ui::PAGE_TRANSITION_LINK) &&
       ui::PageTransitionIsNewNavigation(
           navigation_handle->GetPageTransition()));
+
+  logger_.SetNavigationStart(navigation_handle->NavigationStart());
 }
 
 void FromGWSPageLoadMetricsObserver::OnDomContentLoadedEventStart(
@@ -385,6 +462,11 @@ void FromGWSPageLoadMetricsObserver::OnComplete(
   logger_.OnComplete(timing, extra_info);
 }
 
+void FromGWSPageLoadMetricsObserver::OnUserInput(
+    const blink::WebInputEvent& event) {
+  logger_.OnUserInput(event);
+}
+
 void FromGWSPageLoadMetricsLogger::OnComplete(
     const page_load_metrics::PageLoadTiming& timing,
     const page_load_metrics::PageLoadExtraInfo& extra_info) {
@@ -398,19 +480,29 @@ void FromGWSPageLoadMetricsLogger::OnComplete(
   // loads when tracking aborts after commit.
   UserAbortType abort_type = extra_info.abort_type;
   base::TimeDelta time_to_abort = extra_info.time_to_abort;
-  bool aborted_in_foreground =
-      WasAbortedInForeground(abort_type, time_to_abort, extra_info);
-
-  if (!extra_info.committed_url.is_empty()) {
-    bool aborted_before_paint =
-        aborted_in_foreground && !timing.IsEmpty() &&
-        (timing.first_paint.is_zero() || timing.first_paint >= time_to_abort);
-    if (aborted_before_paint)
-      LogCommittedAbortsBeforePaint(abort_type, time_to_abort);
-  } else {
-    if (aborted_in_foreground)
-      LogProvisionalAborts(abort_type, time_to_abort);
+  if (!WasAbortedInForeground(abort_type, time_to_abort, extra_info))
+    return;
+
+  if (extra_info.committed_url.is_empty()) {
+    LogProvisionalAborts(abort_type, time_to_abort);
+    return;
   }
+
+  // If we didn't receive any timing data but did commit, this is likely not a
+  // renderer-tracked navigation, so ignore it.
+  if (timing.IsEmpty())
+    return;
+
+  if (timing.first_paint.is_zero() || timing.first_paint >= time_to_abort)
+    LogCommittedAbortsBeforePaint(abort_type, time_to_abort);
+
+  // Temporary hack as we can't distinguish TimeDelta unset from zero
+  // TODO(bmcquade): change back to else if once crbug.com/616901 is addressed
+  if (first_paint_triggered_ && timing.first_paint <= time_to_abort &&
+      (!has_user_interaction_after_paint_ ||
+       WasAbortedBeforeInteraction(
+           abort_type, first_user_interaction_after_paint_, time_to_abort)))
+    LogAbortsAfterPaintBeforeInteraction(abort_type, time_to_abort);
 }
 
 bool FromGWSPageLoadMetricsLogger::ShouldLogMetrics(const GURL& committed_url) {
@@ -487,6 +579,7 @@ void FromGWSPageLoadMetricsLogger::OnFirstPaint(
     PAGE_LOAD_HISTOGRAM(internal::kHistogramFromGWSFirstPaint,
                         timing.first_paint);
   }
+  first_paint_triggered_ = true;
 }
 
 void FromGWSPageLoadMetricsLogger::OnFirstTextPaint(
@@ -544,3 +637,13 @@ void FromGWSPageLoadMetricsLogger::OnParseStop(
                         timing.parse_stop - timing.parse_start);
   }
 }
+
+void FromGWSPageLoadMetricsLogger::OnUserInput(
+    const blink::WebInputEvent& event) {
+  if (first_paint_triggered_ && first_user_interaction_after_paint_.is_zero()) {
+    has_user_interaction_after_paint_ = true;
+    DCHECK(!navigation_start_.is_null());
+    first_user_interaction_after_paint_ =
+        base::TimeTicks::Now() - navigation_start_;
+  }
+}