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 c0da0d4e8bea0b866280b95ebd29982e26f91d5d..f80480910b4c29cfbd93f9f381223ce73351daf0 100644 |
--- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc |
+++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc |
@@ -228,9 +228,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 |
@@ -291,30 +291,41 @@ 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()) { |
+ 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(); |
+#if defined(OS_WIN) |
+ RebaseBrowserTimestampIfInterProcessTimeTickSkew(background_time_); |
+#endif |
} |
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(); |
+#if defined(OS_WIN) |
+ RebaseBrowserTimestampIfInterProcessTimeTickSkew(foreground_time_); |
+#endif |
} |
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(); |
+#if defined(OS_WIN) |
+ RebaseBrowserTimestampIfInterProcessTimeTickSkew(commit_time_); |
+#endif |
url_ = navigation_handle->GetURL(); |
for (const auto& observer : observers_) { |
observer->OnCommit(navigation_handle); |
@@ -366,28 +377,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()) |
+#if defined(OS_WIN) |
+void PageLoadTracker::RebaseBrowserTimestampIfInterProcessTimeTickSkew( |
+ base::TimeTicks& event_time) { |
Bryan McQuade
2016/05/02 18:32:40
style guide wants 'out' params (or inout params) t
shivanisha
2016/05/18 17:36:39
done.
|
+ // Windows 10 GCE bot non-deterministically failed because |
+ // TimeTicks::Now() called in the browser process e.g. for commit_time |
+ // was lesser 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_) { |
+ event_time = navigation_start_; |
Bryan McQuade
2016/05/02 18:32:40
if we still have some kind of uma counter for erro
shivanisha
2016/05/18 17:36:39
done. Added a new enumeration for this case.
|
+ } |
+} |
+#endif |
+ |
+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_, |
@@ -395,17 +434,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); |
@@ -413,7 +454,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( |
@@ -432,7 +474,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 |
@@ -442,7 +485,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(); |
@@ -450,6 +493,12 @@ void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type, |
} |
abort_type_ = abort_type; |
abort_time_ = timestamp; |
+ |
+ if (is_browser_timetick) { |
+#if defined(OS_WIN) |
+ RebaseBrowserTimestampIfInterProcessTimeTickSkew(abort_time_); |
+#endif |
+ } |
} |
// static |
@@ -577,7 +626,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)); |
} |
@@ -595,7 +644,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(); |
@@ -668,20 +717,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(); |
} |
@@ -703,7 +753,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; |