| 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 a289253e1430e014d8050cfc04194255e8c40489..2ced04cffb3e2f2fd3b748bc219a61061d6cd456 100644
|
| --- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc
|
| +++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc
|
| @@ -260,9 +260,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
|
| @@ -329,6 +329,7 @@ void PageLoadTracker::WebContentsHidden() {
|
| // foregrounded.
|
| DCHECK_EQ(started_in_foreground_, foreground_time_.is_null());
|
| background_time_ = base::TimeTicks::Now();
|
| + ClampBrowserTimestampIfInterProcessTimeTickSkew(&background_time_);
|
| }
|
|
|
| for (const auto& observer : observers_)
|
| @@ -343,6 +344,7 @@ void PageLoadTracker::WebContentsShown() {
|
| // backgrounded.
|
| DCHECK_NE(started_in_foreground_, background_time_.is_null());
|
| foreground_time_ = base::TimeTicks::Now();
|
| + ClampBrowserTimestampIfInterProcessTimeTickSkew(&foreground_time_);
|
| }
|
|
|
| for (const auto& observer : observers_)
|
| @@ -353,6 +355,7 @@ 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);
|
| @@ -403,7 +406,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);
|
| @@ -422,28 +425,61 @@ 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) {
|
| + DCHECK(event_time != nullptr);
|
| + // Windows 10 GCE bot non-deterministically failed because TimeTicks::Now()
|
| + // 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.
|
| + // Note that navigation_start_ can also be set in the browser process in
|
| + // some cases and in those cases event_time should never be <
|
| + // navigation_start_. If it is due to a code error and it gets clamped in this
|
| + // function, on high resolution systems it should lead to a dcheck failure.
|
| +
|
| + // 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()) {
|
| + DCHECK(event_time->is_null() || *event_time >= navigation_start_);
|
| + return;
|
| + }
|
| +
|
| + if (!event_time->is_null() && *event_time < navigation_start_) {
|
| + RecordInternalError(ERR_INTER_PROCESS_TIME_TICK_SKEW);
|
| + *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_,
|
| @@ -451,17 +487,19 @@ PageLoadExtraInfo PageLoadTracker::GetPageLoadMetricsInfo() {
|
| }
|
|
|
| void PageLoadTracker::NotifyAbort(UserAbortType abort_type,
|
| - base::TimeTicks timestamp) {
|
| + base::TimeTicks timestamp,
|
| + bool is_certainly_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_certainly_browser_timestamp);
|
| }
|
|
|
| void PageLoadTracker::UpdateAbort(UserAbortType abort_type,
|
| - base::TimeTicks timestamp) {
|
| + base::TimeTicks timestamp,
|
| + bool is_certainly_browser_timestamp) {
|
| DCHECK_NE(abort_type, ABORT_NONE);
|
| DCHECK_NE(abort_type, ABORT_OTHER);
|
| DCHECK_EQ(abort_type_, ABORT_OTHER);
|
| @@ -469,7 +507,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_certainly_browser_timestamp);
|
| }
|
|
|
| bool PageLoadTracker::IsLikelyProvisionalAbort(
|
| @@ -488,7 +527,8 @@ bool PageLoadTracker::MatchesOriginalNavigation(
|
| }
|
|
|
| void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
|
| - base::TimeTicks timestamp) {
|
| + base::TimeTicks timestamp,
|
| + bool is_certainly_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
|
| @@ -498,7 +538,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();
|
| @@ -506,6 +546,10 @@ void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type,
|
| }
|
| abort_type_ = abort_type;
|
| abort_time_ = timestamp;
|
| +
|
| + if (is_certainly_browser_timestamp) {
|
| + ClampBrowserTimestampIfInterProcessTimeTickSkew(&abort_time_);
|
| + }
|
| }
|
|
|
| // static
|
| @@ -622,6 +666,12 @@ void MetricsWebContentsObserver::DidStartNavigation(
|
| 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())
|
| @@ -654,7 +704,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));
|
| }
|
|
|
| @@ -670,9 +720,11 @@ void MetricsWebContentsObserver::DidFinishNavigation(
|
| // 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.
|
| + // is_certainly_browser_timestamp is set to false because NavigationStart()
|
| + // could be set in either the renderer or browser process.
|
| NotifyAbortAllLoadsWithTimestamp(
|
| AbortTypeForPageTransition(navigation_handle->GetPageTransition()),
|
| - navigation_handle->NavigationStart());
|
| + navigation_handle->NavigationStart(), false);
|
|
|
| committed_load_ = std::move(finished_nav);
|
| aborted_provisional_loads_.clear();
|
| @@ -759,20 +811,24 @@ 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_certainly_browser_timestamp) {
|
| if (committed_load_)
|
| - committed_load_->NotifyAbort(abort_type, timestamp);
|
| + committed_load_->NotifyAbort(abort_type, timestamp,
|
| + is_certainly_browser_timestamp);
|
| for (const auto& kv : provisional_loads_) {
|
| - kv.second->NotifyAbort(abort_type, timestamp);
|
| + kv.second->NotifyAbort(abort_type, timestamp,
|
| + is_certainly_browser_timestamp);
|
| }
|
| for (const auto& tracker : aborted_provisional_loads_) {
|
| if (tracker->IsLikelyProvisionalAbort(timestamp))
|
| - tracker->UpdateAbort(abort_type, timestamp);
|
| + tracker->UpdateAbort(abort_type, timestamp,
|
| + is_certainly_browser_timestamp);
|
| }
|
| aborted_provisional_loads_.clear();
|
| }
|
| @@ -794,7 +850,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;
|
|
|