Optional <TimeDelta> since they may be non existent.

components/page_load_metrics/browser/metrics_web_contents_observer.cc

 // Copyright 2015 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 "components/page_load_metrics/browser/metrics_web_contents_observer.h"
 
 #include <algorithm>
 #include <string>
 #include <utility>
 
@@ skipping 241 matching lines @@
       embedder_interface_(embedder_interface) {
   DCHECK(!navigation_handle->HasCommitted());
   embedder_interface_->RegisterObservers(this);
   for (const auto& observer : observers_) {
     observer->OnStart(navigation_handle, currently_committed_url,
                       started_in_foreground_);
   }
 }
 
 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
   // chain length added to the next navigation. Take care not to double count
   // them. Also do not double count committed loads, which call this already.
   if (commit_time_.is_null() && abort_type_ != ABORT_UNKNOWN_NAVIGATION)
     LogAbortChainHistograms(nullptr);
 
   for (const auto& observer : observers_) {
     observer->OnComplete(timing_, info);
@@ skipping 40 matching lines @@
     default:
       NOTREACHED()
           << "LogAbortChainHistograms received unexpected ui::PageTransition: "
           << committed_transition;
       return;
   }
 }
 
 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()) {

[Bryan McQuade, 2016/05/26 00:10:05]

I think the call to OnHidden for each observer at the bottom of this function
expects to be invoked every time WebContentsHidden gets invoked, so we can't
early return here.

[shivanisha, 2016/06/07 17:58:19]

Good point. done.

+    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_);
 
   for (const auto& observer : observers_)
     observer->OnHidden();
 }
 
 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()) {

[Bryan McQuade, 2016/05/26 00:10:05]

same

[shivanisha, 2016/06/07 17:58:19]

done.

+    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_);
 
   for (const auto& observer : observers_)
     observer->OnShown();
 }
 
 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);
   }
   LogAbortChainHistograms(navigation_handle);
 }
 
 void PageLoadTracker::FailedProvisionalLoad(
     content::NavigationHandle* navigation_handle) {
   for (const auto& observer : observers_) {
@@ skipping 24 matching lines @@
       valid_behavior_descendent) {
     // There are some subtle ordering constraints here. GetPageLoadMetricsInfo()
     // must be called before DispatchObserverTimingCallbacks, but its
     // implementation depends on the state of metadata_, so we need to update
     // metadata_ before calling GetPageLoadMetricsInfo. Thus, we make a copy of
     // timing here, update timing_ and metadata_, and then proceed to dispatch
     // the observer timing callbacks.
     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);
     }
     return true;
   }
   return false;
 }
 
 void PageLoadTracker::set_renderer_tracked(bool renderer_tracked) {
   renderer_tracked_ = renderer_tracked;
 }
 
 void PageLoadTracker::AddObserver(
     std::unique_ptr<PageLoadMetricsObserver> observer) {
   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 TimeTicks::Now()

[Bryan McQuade, 2016/05/26 00:10:05]

just to be thorough let's add
DCHECK(event_time != nullptr);

that way we'll at least blow up early if someone ever passes a null TimeTicks

[shivanisha, 2016/06/07 17:58:19]

done.

+  // called in the browser process e.g. commit_time was less than
+  // navigation_start_ that was populated in the renderer 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).
+  if (base::TimeTicks::IsHighResolution()) {
+    return;
+  }
+
+  if (!event_time->is_null() && *event_time < navigation_start_) {
+    RecordInternalError(ERR_INTER_PROCESS_TIME_TICK_SKEW);

[Bryan McQuade, 2016/05/26 00:10:05]

awesome, glad to add this as an additional error to track. really helpful to
have this!

+    *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_,
       time_to_abort, metadata_);
 }
 
 void PageLoadTracker::NotifyAbort(UserAbortType abort_type,
-                                  base::TimeTicks timestamp) {
+                                  base::TimeTicks timestamp,
+                                  bool is_browser_timestamp) {
   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_timestamp);
 }
 
 void PageLoadTracker::UpdateAbort(UserAbortType abort_type,
-                                  base::TimeTicks timestamp) {
+                                  base::TimeTicks timestamp,
+                                  bool is_browser_timestamp) {
   DCHECK_NE(abort_type, ABORT_NONE);
   DCHECK_NE(abort_type, ABORT_OTHER);
   DCHECK_EQ(abort_type_, ABORT_OTHER);
 
   // 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_timestamp);
 }
 
 bool PageLoadTracker::IsLikelyProvisionalAbort(
     base::TimeTicks abort_cause_time) {
   // Note that |abort_cause_time - abort_time| can be negative.
   return abort_type_ == ABORT_OTHER &&
          (abort_cause_time - abort_time_).InMilliseconds() < 100;
 }
 
 bool PageLoadTracker::MatchesOriginalNavigation(
     content::NavigationHandle* navigation_handle) {
   // Neither navigation should have committed.
   DCHECK(!navigation_handle->HasCommitted());
   DCHECK(commit_time_.is_null());
   return navigation_handle->GetURL() == url_;
 }
 
 void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
-                                          base::TimeTicks timestamp) {
+                                          base::TimeTicks timestamp,
+                                          bool is_browser_timestamp) {
   // 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
   // aborted provisional loads started. Thus we ignore cases where the committed
   // load started before the aborted provisional load, as this would result in
   // recording a negative time-to-abort. The real issue here is that we have to
   // 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();
     return;
   }
   abort_type_ = abort_type;
   abort_time_ = timestamp;
+
+  if (is_browser_timestamp) {
+    ClampBrowserTimestampIfInterProcessTimeTickSkew(&abort_time_);
+  }
 }
 
 // static
 MetricsWebContentsObserver::MetricsWebContentsObserver(
     content::WebContents* web_contents,
     std::unique_ptr<PageLoadMetricsEmbedderInterface> embedder_interface)
     : content::WebContentsObserver(web_contents),
       in_foreground_(false),
       embedder_interface_(std::move(embedder_interface)),
       has_navigated_(false) {}
@@ skipping 75 matching lines @@
   // the MetricsWebContentsObserver owns them both list and they are torn down
   // after the PageLoadTracker. The PageLoadTracker does not hold on to
   // committed_load_ or navigation_handle beyond the scope of the constructor.
   provisional_loads_.insert(std::make_pair(
       navigation_handle,
       base::WrapUnique(new PageLoadTracker(
           in_foreground_, embedder_interface_.get(), currently_committed_url,
           navigation_handle, chain_size, chain_size_same_url))));
 }
 
+const PageLoadExtraInfo
+MetricsWebContentsObserver::GetPageLoadExtraInfoForCommittedLoad() {
+  DCHECK(committed_load_);
+  return committed_load_->ComputePageLoadExtraInfo();
+}
+
 void MetricsWebContentsObserver::DidFinishNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame())
     return;
 
   std::unique_ptr<PageLoadTracker> finished_nav(
       std::move(provisional_loads_[navigation_handle]));
   provisional_loads_.erase(navigation_handle);
 
   // There's a chance a navigation could have started before we were added to a
@@ skipping 12 matching lines @@
     net::Error error = navigation_handle->GetNetErrorCode();
 
     // net::OK: This case occurs when the NavigationHandle finishes and reports
     // !HasCommitted(), but reports no net::Error. This should not occur
     // pre-PlzNavigate, but afterwards it should represent the navigation
     // stopped by the user before it was ready to commit.
     // net::ERR_ABORTED: An aborted provisional load has error net::ERR_ABORTED.
     // 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));
     }
 
     return;
   }
 
   // Don't treat a same-page nav as a new page load.
   if (navigation_handle->IsSamePage())
     return;
 
   // Notify other loads that they may have been aborted by this committed load.
   // Note that by using the committed navigation start as the abort cause, we
   // lose data on provisional loads that were aborted by other provisional
   // loads. Those will either be listed as ABORT_OTHER or as being aborted by
   // this load.
   NotifyAbortAllLoadsWithTimestamp(
       AbortTypeForPageTransition(navigation_handle->GetPageTransition()),
-      navigation_handle->NavigationStart());
+      navigation_handle->NavigationStart(), false);

[Bryan McQuade, 2016/05/26 00:10:05]

i think the value for NavigationStart() can sometimes be set in the browser
process, so technically the false value for is_browser_timestamp may sometimes
be incorrect. that's fine since you'll clamp it any time this is false, and it's
not harmful to clamp timestamps from the browser process. but it's worth adding
a comment here to explain this, in case it confuses someone in the future. you
might also consider renaming is_browser_timestamp to
is_possibly_non_browser_timestamp which inverts the meaning of the bool but
makes the specific case here where NavigationStart() may be from a different
process consistent with the API. I don't feel strongly though (and it's worth
double checking with charles whether NavigationStart() can in fact we set in the
browser process).

[shivanisha, 2016/06/07 17:58:19]

That's right. Also confirmed with Charles that it is possible for
navigation_start to be in browser process. 

The assumption in this patch is that an event time will be clamped if its for
sure set in the browser process but if it is NavigationStart(), then do not
clamp it. So in case it is NavigationStart() set in the browser it will not be
clamped. Changing the variable name to is_certainly_browser_timestamp (as
opposed to is_possibly_non_browser_timestamp) to keep it consistent with its
usage before calling ClampBrowserTimestampIfInterProcessTimeTickSkew(). Also
added a comment here.

This also needs to be explained in the
ClampBrowserTimestampIfInterProcessTimeTickSkew() function since that also
assumes that navigation_start_ will always be set in renderer.
Clamping against a browser set navigation_start_ should ideally never happen due
to the condition that browser_event_time should be strictly less than browser
set navigation_start_ which is not possible. But let's say it happens due to a
code error , it should also happen on other platforms(high resolution) where it
will be caught with Dchecks. So adding this in the comment in
ClampBrowserTimestampIfInterProcessTimeTickSkew.

 
   committed_load_ = std::move(finished_nav);
   aborted_provisional_loads_.clear();
 
   const GURL& browser_url = web_contents()->GetLastCommittedURL();
   const std::string& mime_type = web_contents()->GetContentsMimeType();
   DCHECK(!browser_url.is_empty());
   DCHECK(!mime_type.empty());
   committed_load_->set_renderer_tracked(
       IsRelevantNavigation(navigation_handle, browser_url, mime_type));
@@ skipping 52 matching lines @@
   }
 
   // If this is a crash, eagerly log the aborted provisional loads and the
   // committed load. |provisional_loads_| don't need to be destroyed here
   // because their lifetime is tied to the NavigationHandle.
   committed_load_.reset();
   aborted_provisional_loads_.clear();
 }
 
 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_timestamp) {
   if (committed_load_)
-    committed_load_->NotifyAbort(abort_type, timestamp);
+    committed_load_->NotifyAbort(abort_type, timestamp, is_browser_timestamp);
   for (const auto& kv : provisional_loads_) {
-    kv.second->NotifyAbort(abort_type, timestamp);
+    kv.second->NotifyAbort(abort_type, timestamp, is_browser_timestamp);
   }
   for (const auto& tracker : aborted_provisional_loads_) {
     if (tracker->IsLikelyProvisionalAbort(timestamp))
-      tracker->UpdateAbort(abort_type, timestamp);
+      tracker->UpdateAbort(abort_type, timestamp, is_browser_timestamp);
   }
   aborted_provisional_loads_.clear();
 }
 
 std::unique_ptr<PageLoadTracker>
 MetricsWebContentsObserver::NotifyAbortedProvisionalLoadsNewNavigation(
     content::NavigationHandle* new_navigation) {
   // If there are multiple aborted loads that can be attributed to this one,
   // just count the latest one for simplicity. Other loads will fall into the
   // OTHER bucket, though there shouldn't be very many.
   if (aborted_provisional_loads_.size() == 0)
     return nullptr;
   if (aborted_provisional_loads_.size() > 1)
     RecordInternalError(ERR_NAVIGATION_SIGNALS_MULIPLE_ABORTED_LOADS);
 
   std::unique_ptr<PageLoadTracker> last_aborted_load =
       std::move(aborted_provisional_loads_.back());
   aborted_provisional_loads_.pop_back();
 
   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;
 }
 
 void MetricsWebContentsObserver::OnTimingUpdated(
     content::RenderFrameHost* render_frame_host,
     const PageLoadTiming& timing,
     const PageLoadMetadata& metadata) {
   bool error = false;
@@ skipping 22 matching lines @@
 
   if (!committed_load_->UpdateTiming(timing, metadata)) {
     // If the page load tracker cannot update its timing, something is wrong
     // with the IPC (it's from another load, or it's invalid in some other way).
     // We expect this to be a rare occurrence.
     RecordInternalError(ERR_BAD_TIMING_IPC);
   }
 }
 
 }  // namespace page_load_metrics