Optional <TimeDelta> since they may be non existent.

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 0f40c4ba17a3c29ea60e852e49da36ff7a357de7..7452edca2476df9745b1662047233c86ce632382 100644
--- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc
+++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc
@@ -258,9 +258,9 @@ PageLoadTracker::PageLoadTracker(
 }
 
 PageLoadTracker::~PageLoadTracker() {
-  const PageLoadExtraInfo info = GetPageLoadMetricsInfo();
-  if (!info.time_to_commit.is_zero() && renderer_tracked() &&
-      timing_.IsEmpty()) {
+  const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
+
+  if (info.time_to_commit && renderer_tracked() && timing_.IsEmpty()) {
     RecordInternalError(ERR_NO_IPCS_RECEIVED);
   }
   // Recall that trackers that are given ABORT_UNKNOWN_NAVIGATION have their
@@ -321,30 +321,35 @@ void PageLoadTracker::LogAbortChainHistograms(
 
 void PageLoadTracker::WebContentsHidden() {
   // Only log the first time we background in a given page load.
-  if (background_time_.is_null()) {
-    // Make sure we either started in the foreground and haven't been
-    // foregrounded yet, or started in the background and have already been
-    // foregrounded.
-    DCHECK_EQ(started_in_foreground_, foreground_time_.is_null());
-    background_time_ = base::TimeTicks::Now();
+  if (!background_time_.is_null()) {

[Charlie Harrison, 2016/05/19 18:20:49]

Why not convert fg and bg time to optionals too? Up to you, but maybe it's
clearer than a TimeTicks with a null value.

[shivanisha, 2016/05/23 15:06:43]

Either way is fine,
Since TimeTicks has the semantics of is_null representing an empty TimeTicks we
are good without using Optional, for now. 
It will be more robust though, to use Optionals to reduce bugs which could crop
up if a code doesn't consider 0 valued TimeTicks as empty. Adding this to be
considered while working on the related bug: 
https://bugs.chromium.org/p/chromium/issues/detail?id=590212

+    return;
   }
+  // Make sure we either started in the foreground and haven't been
+  // foregrounded yet, or started in the background and have already been
+  // foregrounded.
+  DCHECK_EQ(started_in_foreground_, foreground_time_.is_null());
+  background_time_ = base::TimeTicks::Now();
+  ClampBrowserTimestampIfInterProcessTimeTickSkew(&background_time_);
 }
 
 void PageLoadTracker::WebContentsShown() {
   // Only log the first time we foreground in a given page load.
-  if (foreground_time_.is_null()) {
-    // Make sure we either started in the background and haven't been
-    // backgrounded yet, or started in the foreground and have already been
-    // backgrounded.
-    DCHECK_NE(started_in_foreground_, background_time_.is_null());
-    foreground_time_ = base::TimeTicks::Now();
+  if (!foreground_time_.is_null()) {
+    return;
   }
+  // Make sure we either started in the background and haven't been
+  // backgrounded yet, or started in the foreground and have already been
+  // backgrounded.
+  DCHECK_NE(started_in_foreground_, background_time_.is_null());
+  foreground_time_ = base::TimeTicks::Now();
+  ClampBrowserTimestampIfInterProcessTimeTickSkew(&foreground_time_);
 }
 
 void PageLoadTracker::Commit(content::NavigationHandle* navigation_handle) {
   // TODO(bmcquade): To improve accuracy, consider adding commit time to
   // NavigationHandle. Taking a timestamp here should be close enough for now.
   commit_time_ = base::TimeTicks::Now();
+  ClampBrowserTimestampIfInterProcessTimeTickSkew(&commit_time_);
   url_ = navigation_handle->GetURL();
   for (const auto& observer : observers_) {
     observer->OnCommit(navigation_handle);
@@ -389,7 +394,7 @@ bool PageLoadTracker::UpdateTiming(const PageLoadTiming& new_timing,
     const PageLoadTiming last_timing = timing_;
     timing_ = new_timing;
     metadata_ = new_metadata;
-    const PageLoadExtraInfo info = GetPageLoadMetricsInfo();
+    const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
     for (const auto& observer : observers_) {
       DispatchObserverTimingCallbacks(observer.get(), last_timing, new_timing,
                                       info);
@@ -408,28 +413,56 @@ void PageLoadTracker::AddObserver(
   observers_.push_back(std::move(observer));
 }
 
-PageLoadExtraInfo PageLoadTracker::GetPageLoadMetricsInfo() {
-  base::TimeDelta first_background_time;
-  base::TimeDelta first_foreground_time;
-  base::TimeDelta time_to_abort;
-  base::TimeDelta time_to_commit;
-  if (!background_time_.is_null())
+void PageLoadTracker::ClampBrowserTimestampIfInterProcessTimeTickSkew(
+    base::TimeTicks* event_time) {
+  // Windows 10 GCE bot non-deterministically failed because

[Charlie Harrison, 2016/05/19 18:20:49]

Looks like you can fit more words on this line.

[shivanisha, 2016/05/23 15:06:43]

done

+  // TimeTicks::Now() called in the browser process e.g. for commit_time
+  // was lesser than navigation_start_ that was populated in the renderer

[Charlie Harrison, 2016/05/19 18:20:49]

s/lesser/less

[shivanisha, 2016/05/23 15:06:43]

done

+  // process because the clock was not system-wide monotonic.
+
+  // TODO (shivanisha) Currently IsHighResolution is the best way to check
+  // if the clock is system-wide monotonic. However IsHighResolution
+  // does a broader check to see if the clock in use is high resolution
+  // which also implies it is system-wide monotonic (on Windows).

[Charlie Harrison, 2016/05/19 18:20:48]

Are you sure this check is always correct in finding system-wide monotonicity?

[shivanisha, 2016/05/23 15:06:43]

That's how it is currently implemented on Windows. It returns true if underlying
clock uses QPC which is syetm-wide monotonic as mentioned here
(https://msdn.microsoft.com/en-us/library/windows/desktop/dn553408(v=vs.85).aspx)
else it returns false.
On other platforms it returns true.

+  if (base::TimeTicks::IsHighResolution()) {
+    return;
+  }
+
+  if (!event_time->is_null() && *event_time < navigation_start_) {
+    UMA_HISTOGRAM_ENUMERATION(internal::kErrorEvents,
+                              ERR_INTER_PROCESS_TIME_TICK_SKEW, ERR_LAST_ENTRY);
+    *event_time = navigation_start_;
+  }
+}
+
+PageLoadExtraInfo PageLoadTracker::ComputePageLoadExtraInfo() {
+  base::Optional<base::TimeDelta> first_background_time;
+  base::Optional<base::TimeDelta> first_foreground_time;
+  base::Optional<base::TimeDelta> time_to_abort;
+  base::Optional<base::TimeDelta> time_to_commit;
+
+  if (!background_time_.is_null()) {
+    DCHECK_GE(background_time_, navigation_start_);
     first_background_time = background_time_ - navigation_start_;
-  if (!foreground_time_.is_null())
+  }
+
+  if (!foreground_time_.is_null()) {
+    DCHECK_GE(foreground_time_, navigation_start_);
     first_foreground_time = foreground_time_ - navigation_start_;
+  }
+
   if (abort_type_ != ABORT_NONE) {
-    DCHECK_GT(abort_time_, navigation_start_);
+    DCHECK_GE(abort_time_, navigation_start_);
     time_to_abort = abort_time_ - navigation_start_;
   } else {
     DCHECK(abort_time_.is_null());
   }
 
   if (!commit_time_.is_null()) {
-    DCHECK_GT(commit_time_, navigation_start_);
+    DCHECK_GE(commit_time_, navigation_start_);
     time_to_commit = commit_time_ - navigation_start_;
-  } else {
-    DCHECK(commit_time_.is_null());
   }
+
   return PageLoadExtraInfo(
       first_background_time, first_foreground_time, started_in_foreground_,
       commit_time_.is_null() ? GURL() : url_, time_to_commit, abort_type_,
@@ -437,17 +470,19 @@ PageLoadExtraInfo PageLoadTracker::GetPageLoadMetricsInfo() {
 }
 
 void PageLoadTracker::NotifyAbort(UserAbortType abort_type,
-                                  base::TimeTicks timestamp) {
+                                  base::TimeTicks timestamp,
+                                  bool is_browser_timetick) {
   DCHECK_NE(abort_type, ABORT_NONE);
   // Use UpdateAbort to update an already notified PageLoadTracker.
   if (abort_type_ != ABORT_NONE)
     return;
 
-  UpdateAbortInternal(abort_type, timestamp);
+  UpdateAbortInternal(abort_type, timestamp, is_browser_timetick);
 }
 
 void PageLoadTracker::UpdateAbort(UserAbortType abort_type,
-                                  base::TimeTicks timestamp) {
+                                  base::TimeTicks timestamp,
+                                  bool is_browser_timetick) {
   DCHECK_NE(abort_type, ABORT_NONE);
   DCHECK_NE(abort_type, ABORT_OTHER);
   DCHECK_EQ(abort_type_, ABORT_OTHER);
@@ -455,7 +490,8 @@ void PageLoadTracker::UpdateAbort(UserAbortType abort_type,
   // For some aborts (e.g. navigations), the initiated timestamp can be earlier
   // than the timestamp that aborted the load. Taking the minimum gives the
   // closest user initiated time known.
-  UpdateAbortInternal(abort_type, std::min(abort_time_, timestamp));
+  UpdateAbortInternal(abort_type, std::min(abort_time_, timestamp),
+                      is_browser_timetick);
 }
 
 bool PageLoadTracker::IsLikelyProvisionalAbort(
@@ -474,7 +510,8 @@ bool PageLoadTracker::MatchesOriginalNavigation(
 }
 
 void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
-                                          base::TimeTicks timestamp) {
+                                          base::TimeTicks timestamp,
+                                          bool is_browser_timetick) {
   // When a provisional navigation commits, that navigation's start time is
   // interpreted as the abort time for other provisional loads in the tab.
   // However, this only makes sense if the committed load started after the
@@ -484,7 +521,7 @@ void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
   // infer the cause of aborts. It would be better if the navigation code could
   // instead report the actual cause of an aborted navigation. See crbug/571647
   // for details.
-  if (timestamp <= navigation_start_) {
+  if (timestamp < navigation_start_) {
     RecordInternalError(ERR_ABORT_BEFORE_NAVIGATION_START);
     abort_type_ = ABORT_NONE;
     abort_time_ = base::TimeTicks();
@@ -492,6 +529,10 @@ void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
   }
   abort_type_ = abort_type;
   abort_time_ = timestamp;
+
+  if (is_browser_timetick) {
+    ClampBrowserTimestampIfInterProcessTimeTickSkew(&abort_time_);
+  }
 }
 
 // static
@@ -587,6 +628,12 @@ void MetricsWebContentsObserver::DidStartNavigation(
           navigation_handle, chain_size, chain_size_same_url))));
 }
 
+const PageLoadExtraInfo
+MetricsWebContentsObserver::GetPageLoadExtraInfoCommittedLoad() {
+  DCHECK(committed_load_);
+  return committed_load_->ComputePageLoadExtraInfo();
+}
+
 void MetricsWebContentsObserver::DidFinishNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame())
@@ -619,7 +666,7 @@ void MetricsWebContentsObserver::DidFinishNavigation(
     // Note that this can come from some non user-initiated errors, such as
     // downloads, or 204 responses. See crbug.com/542369.
     if ((error == net::OK) || (error == net::ERR_ABORTED)) {
-      finished_nav->NotifyAbort(ABORT_OTHER, base::TimeTicks::Now());
+      finished_nav->NotifyAbort(ABORT_OTHER, base::TimeTicks::Now(), true);
       aborted_provisional_loads_.push_back(std::move(finished_nav));
     }
 
@@ -637,7 +684,7 @@ void MetricsWebContentsObserver::DidFinishNavigation(
   // this load.
   NotifyAbortAllLoadsWithTimestamp(
       AbortTypeForPageTransition(navigation_handle->GetPageTransition()),
-      navigation_handle->NavigationStart());
+      navigation_handle->NavigationStart(), false);
 
   committed_load_ = std::move(finished_nav);
   aborted_provisional_loads_.clear();
@@ -710,20 +757,21 @@ void MetricsWebContentsObserver::RenderProcessGone(
 }
 
 void MetricsWebContentsObserver::NotifyAbortAllLoads(UserAbortType abort_type) {
-  NotifyAbortAllLoadsWithTimestamp(abort_type, base::TimeTicks::Now());
+  NotifyAbortAllLoadsWithTimestamp(abort_type, base::TimeTicks::Now(), true);
 }
 
 void MetricsWebContentsObserver::NotifyAbortAllLoadsWithTimestamp(
     UserAbortType abort_type,
-    base::TimeTicks timestamp) {
+    base::TimeTicks timestamp,
+    bool is_browser_timetick) {
   if (committed_load_)
-    committed_load_->NotifyAbort(abort_type, timestamp);
+    committed_load_->NotifyAbort(abort_type, timestamp, is_browser_timetick);
   for (const auto& kv : provisional_loads_) {
-    kv.second->NotifyAbort(abort_type, timestamp);
+    kv.second->NotifyAbort(abort_type, timestamp, is_browser_timetick);
   }
   for (const auto& tracker : aborted_provisional_loads_) {
     if (tracker->IsLikelyProvisionalAbort(timestamp))
-      tracker->UpdateAbort(abort_type, timestamp);
+      tracker->UpdateAbort(abort_type, timestamp, is_browser_timetick);
   }
   aborted_provisional_loads_.clear();
 }
@@ -745,7 +793,7 @@ MetricsWebContentsObserver::NotifyAbortedProvisionalLoadsNewNavigation(
 
   base::TimeTicks timestamp = new_navigation->NavigationStart();
   if (last_aborted_load->IsLikelyProvisionalAbort(timestamp))
-    last_aborted_load->UpdateAbort(ABORT_UNKNOWN_NAVIGATION, timestamp);
+    last_aborted_load->UpdateAbort(ABORT_UNKNOWN_NAVIGATION, timestamp, false);
 
   aborted_provisional_loads_.clear();
   return last_aborted_load;