diff options
author | csharrison <csharrison@chromium.org> | 2015-10-19 08:32:46 -0700 |
---|---|---|
committer | Commit bot <commit-bot@chromium.org> | 2015-10-19 15:33:24 +0000 |
commit | 7a32ec9ce6c2522c65b3e9be5ecad54b5285bb0a (patch) | |
tree | 332641548f6d5f9e0e9b8ecd90c8c3ce7ee05b1e /components/page_load_metrics | |
parent | 8b573e8adecf7104b6d13ce1b97c191a9a066a8d (diff) | |
download | chromium_src-7a32ec9ce6c2522c65b3e9be5ecad54b5285bb0a.zip chromium_src-7a32ec9ce6c2522c65b3e9be5ecad54b5285bb0a.tar.gz chromium_src-7a32ec9ce6c2522c65b3e9be5ecad54b5285bb0a.tar.bz2 |
Page Abort Events for relevant navigations
BUG=544152
Review URL: https://codereview.chromium.org/1384213002
Cr-Commit-Position: refs/heads/master@{#354778}
Diffstat (limited to 'components/page_load_metrics')
3 files changed, 407 insertions, 128 deletions
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 2961f1e..70ae3ca 100644 --- a/components/page_load_metrics/browser/metrics_web_contents_observer.cc +++ b/components/page_load_metrics/browser/metrics_web_contents_observer.cc @@ -25,6 +25,22 @@ namespace page_load_metrics { namespace { +// The url we see from the renderer side is not always the same as what +// we see from the browser side (e.g. chrome://newtab). We want to be +// sure here that we aren't logging UMA for internal pages. +bool IsRelevantNavigation( + content::NavigationHandle* navigation_handle, + const GURL& browser_url, + const std::string& mime_type) { + DCHECK(navigation_handle->HasCommitted()); + return navigation_handle->IsInMainFrame() && + !navigation_handle->IsSamePage() && + !navigation_handle->IsErrorPage() && + navigation_handle->GetURL().SchemeIsHTTPOrHTTPS() && + browser_url.SchemeIsHTTPOrHTTPS() && + (mime_type == "text/html" || mime_type == "application/xhtml+xml"); +} + bool IsValidPageLoadTiming(const PageLoadTiming& timing) { if (timing.IsEmpty()) return false; @@ -56,6 +72,11 @@ base::Time WallTimeFromTimeTicks(base::TimeTicks time) { (time - base::TimeTicks::UnixEpoch()).InSecondsF()); } +void RecordInternalError(InternalErrorLoadEvent event) { + UMA_HISTOGRAM_ENUMERATION( + "PageLoad.Events.InternalError", event, ERR_LAST_ENTRY); +} + } // namespace #define PAGE_LOAD_HISTOGRAM(name, sample) \ @@ -64,47 +85,59 @@ base::Time WallTimeFromTimeTicks(base::TimeTicks time) { base::TimeDelta::FromMinutes(10), 100) PageLoadTracker::PageLoadTracker(bool in_foreground) - : has_commit_(false), started_in_foreground_(in_foreground) { - RecordEvent(PAGE_LOAD_STARTED); -} + : has_commit_(false), started_in_foreground_(in_foreground) {} PageLoadTracker::~PageLoadTracker() { - // Even a load that failed a provisional load should log - // that it aborted before first layout. - if (timing_.first_layout.is_zero()) - RecordEvent(PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT); - if (has_commit_) RecordTimingHistograms(); } void PageLoadTracker::WebContentsHidden() { // Only log the first time we background in a given page load. - if (background_time_.is_null()) { + if (started_in_foreground_ && background_time_.is_null()) background_time_ = base::TimeTicks::Now(); - } +} + +void PageLoadTracker::WebContentsShown() { + // Only log the first time we foreground in a given page load. + // Don't log foreground time if we started foregrounded. + if (!started_in_foreground_ && foreground_time_.is_null()) + foreground_time_ = base::TimeTicks::Now(); } void PageLoadTracker::Commit() { has_commit_ = true; + // We log the event that this load started. Because we don't know if a load is + // relevant or if it will commit before now, we have to log this event at + // commit time. + RecordCommittedEvent(COMMITTED_LOAD_STARTED, !started_in_foreground_); } -bool PageLoadTracker::UpdateTiming(const PageLoadTiming& timing) { +bool PageLoadTracker::UpdateTiming(const PageLoadTiming& new_timing) { // Throw away IPCs that are not relevant to the current navigation. - if (!timing_.navigation_start.is_null() && - timing_.navigation_start != timing.navigation_start) { - // TODO(csharrison) uma log a counter here - return false; - } - if (IsValidPageLoadTiming(timing)) { - timing_ = timing; + // Two timing structures cannot refer to the same navigation if they indicate + // that a navigation started at different times, so a new timing struct with a + // different start time from an earlier struct is considered invalid. + bool valid_timing_descendent = + timing_.navigation_start.is_null() || + timing_.navigation_start == new_timing.navigation_start; + if (IsValidPageLoadTiming(new_timing) && valid_timing_descendent) { + timing_ = new_timing; return true; } return false; } +bool PageLoadTracker::HasBackgrounded() { + return !started_in_foreground_ || !background_time_.is_null(); +} + void PageLoadTracker::RecordTimingHistograms() { DCHECK(has_commit_); + if (timing_.IsEmpty()) { + RecordInternalError(ERR_NO_IPCS_RECEIVED); + return; + } // This method is similar to how blink converts TimeTicks to epoch time. // There may be slight inaccuracies due to inter-process timestamps, but // this solution is the best we have right now. @@ -122,7 +155,7 @@ void PageLoadTracker::RecordTimingHistograms() { timing_.dom_content_loaded_event_start); } else { PAGE_LOAD_HISTOGRAM( - "PageLoad.Timing2.NavigationToDOMContentLoadedEventFired.BG", + "PageLoad.Timing2.NavigationToDOMContentLoadedEventFired.Background", timing_.dom_content_loaded_event_start); } } @@ -131,19 +164,23 @@ void PageLoadTracker::RecordTimingHistograms() { PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToLoadEventFired", timing_.load_event_start); } else { - PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToLoadEventFired.BG", - timing_.load_event_start); + PAGE_LOAD_HISTOGRAM( + "PageLoad.Timing2.NavigationToLoadEventFired.Background", + timing_.load_event_start); } } - if (!timing_.first_layout.is_zero()) { + if (timing_.first_layout.is_zero()) { + RecordCommittedEvent(COMMITTED_LOAD_FAILED_BEFORE_FIRST_LAYOUT, + HasBackgrounded()); + } else { if (timing_.first_layout < background_delta) { PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstLayout", timing_.first_layout); - RecordEvent(PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_FOREGROUND); + RecordCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, false); } else { - PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstLayout.BG", + PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstLayout.Background", timing_.first_layout); - RecordEvent(PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_BACKGROUND); + RecordCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, true); } } if (!timing_.first_text_paint.is_zero()) { @@ -151,15 +188,45 @@ void PageLoadTracker::RecordTimingHistograms() { PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstTextPaint", timing_.first_text_paint); } else { - PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstTextPaint.BG", - timing_.first_text_paint); + PAGE_LOAD_HISTOGRAM( + "PageLoad.Timing2.NavigationToFirstTextPaint.Background", + timing_.first_text_paint); } } + // Log time to first foreground / time to first background. Log counts that we + // started a relevant page load in the foreground / background. + if (!background_time_.is_null()) { + PAGE_LOAD_HISTOGRAM("PageLoad.Timing2.NavigationToFirstBackground", + background_delta); + } else if (!foreground_time_.is_null()) { + PAGE_LOAD_HISTOGRAM( + "PageLoad.Timing2.NavigationToFirstForeground", + WallTimeFromTimeTicks(foreground_time_) - timing_.navigation_start); + } } -void PageLoadTracker::RecordEvent(PageLoadEvent event) { - UMA_HISTOGRAM_ENUMERATION( - "PageLoad.EventCounts", event, PAGE_LOAD_LAST_ENTRY); +void PageLoadTracker::RecordProvisionalEvent(ProvisionalLoadEvent event) { + if (HasBackgrounded()) { + UMA_HISTOGRAM_ENUMERATION("PageLoad.Events.Provisional.Background", event, + PROVISIONAL_LOAD_LAST_ENTRY); + } else { + UMA_HISTOGRAM_ENUMERATION("PageLoad.Events.Provisional", event, + PROVISIONAL_LOAD_LAST_ENTRY); + } +} + +// RecordCommittedEvent needs a backgrounded input because we need to special +// case a few events that need either precise timing measurements, or different +// logic than simply "Did I background before logging this event?" +void PageLoadTracker::RecordCommittedEvent(CommittedLoadEvent event, + bool backgrounded) { + if (backgrounded) { + UMA_HISTOGRAM_ENUMERATION("PageLoad.Events.Committed.Background", event, + COMMITTED_LOAD_LAST_ENTRY); + } else { + UMA_HISTOGRAM_ENUMERATION("PageLoad.Events.Committed", event, + COMMITTED_LOAD_LAST_ENTRY); + } } MetricsWebContentsObserver::MetricsWebContentsObserver( @@ -203,13 +270,17 @@ void MetricsWebContentsObserver::DidFinishNavigation( DCHECK(finished_nav); // Handle a pre-commit error here. Navigations that result in an error page - // will be ignored. + // will be ignored. Note that downloads/204s will result in HasCommitted() + // returning false. if (!navigation_handle->HasCommitted()) { - finished_nav->RecordEvent(PAGE_LOAD_FAILED_BEFORE_COMMIT); - if (navigation_handle->GetNetErrorCode() == net::ERR_ABORTED) - finished_nav->RecordEvent(PAGE_LOAD_ABORTED_BEFORE_COMMIT); + net::Error error = navigation_handle->GetNetErrorCode(); + finished_nav->RecordProvisionalEvent( + error == net::OK ? PROVISIONAL_LOAD_STOPPED + : error == net::ERR_ABORTED ? PROVISIONAL_LOAD_ERR_ABORTED + : PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT); return; } + finished_nav->RecordProvisionalEvent(PROVISIONAL_LOAD_COMMITTED); // Don't treat a same-page nav as a new page load. if (navigation_handle->IsSamePage()) @@ -219,7 +290,11 @@ void MetricsWebContentsObserver::DidFinishNavigation( // navigation. committed_load_.reset(); - if (!IsRelevantNavigation(navigation_handle)) + const GURL& browser_url = web_contents()->GetLastCommittedURL(); + const std::string& mime_type = web_contents()->GetContentsMimeType(); + DCHECK(!browser_url.is_empty()); + DCHECK(!mime_type.empty()); + if (!IsRelevantNavigation(navigation_handle, browser_url, mime_type)) return; committed_load_ = finished_nav.Pass(); @@ -228,6 +303,11 @@ void MetricsWebContentsObserver::DidFinishNavigation( void MetricsWebContentsObserver::WasShown() { in_foreground_ = true; + if (committed_load_) + committed_load_->WebContentsShown(); + for (const auto& kv : provisional_loads_) { + kv.second->WebContentsShown(); + } } void MetricsWebContentsObserver::WasHidden() { @@ -250,34 +330,36 @@ void MetricsWebContentsObserver::RenderProcessGone( void MetricsWebContentsObserver::OnTimingUpdated( content::RenderFrameHost* render_frame_host, const PageLoadTiming& timing) { - if (!committed_load_) - return; + bool error = false; + if (!committed_load_) { + RecordInternalError(ERR_IPC_WITH_NO_COMMITTED_LOAD); + error = true; + } // We may receive notifications from frames that have been navigated away // from. We simply ignore them. - if (render_frame_host != web_contents()->GetMainFrame()) - return; + if (render_frame_host != web_contents()->GetMainFrame()) { + RecordInternalError(ERR_IPC_FROM_WRONG_FRAME); + error = true; + } // For urls like chrome://newtab, the renderer and browser disagree, // so we have to double check that the renderer isn't sending data from a // bad url like https://www.google.com/_/chrome/newtab. - if (!web_contents()->GetLastCommittedURL().SchemeIsHTTPOrHTTPS()) - return; + if (!web_contents()->GetLastCommittedURL().SchemeIsHTTPOrHTTPS()) { + RecordInternalError(ERR_IPC_FROM_BAD_URL_SCHEME); + error = true; + } - committed_load_->UpdateTiming(timing); -} + if (error) + return; -bool MetricsWebContentsObserver::IsRelevantNavigation( - content::NavigationHandle* navigation_handle) { - // The url we see from the renderer side is not always the same as what - // we see from the browser side (e.g. chrome://newtab). We want to be - // sure here that we aren't logging UMA for internal pages. - const GURL& browser_url = web_contents()->GetLastCommittedURL(); - return navigation_handle->IsInMainFrame() && - !navigation_handle->IsSamePage() && - !navigation_handle->IsErrorPage() && - navigation_handle->GetURL().SchemeIsHTTPOrHTTPS() && - browser_url.SchemeIsHTTPOrHTTPS(); + if (!committed_load_->UpdateTiming(timing)) { + // 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 diff --git a/components/page_load_metrics/browser/metrics_web_contents_observer.h b/components/page_load_metrics/browser/metrics_web_contents_observer.h index cf39dc9..95930e9 100644 --- a/components/page_load_metrics/browser/metrics_web_contents_observer.h +++ b/components/page_load_metrics/browser/metrics_web_contents_observer.h @@ -25,35 +25,102 @@ class Message; namespace page_load_metrics { -// If you add elements from this enum, make sure you update the enum +// NOTE: Some of these histograms are separated into a separate histogram +// specified by the ".Background" suffix. For these events, we put them into the +// background histogram if the web contents was ever in the background from +// navigation start to the event in question. + +// ProvisionalLoadEvents count all main frame navigations before they commit. +// The events in this enum are all disjoint, and summing them yields the total +// number of main frame provisional loads. +// +// If you add elements to this enum, make sure you update the enum // value in histograms.xml. Only add elements to the end to prevent // inconsistencies between versions. -enum PageLoadEvent { - PAGE_LOAD_STARTED, - - // A provisional load is a load before it commits, i.e. before it receives the - // first bytes of the response body or knows the encoding of the response - // body. A load failed before it was committed for any reason, e.g. from a - // user abort or a network timeout. - PAGE_LOAD_FAILED_BEFORE_COMMIT, - - // A subset of PAGE_LOAD_FAILED_BEFORE_COMMIT, this counts the - // specific failures due to user aborts. - PAGE_LOAD_ABORTED_BEFORE_COMMIT, - - // When a load is aborted anytime before the page's first layout, we increase - // these counts. This includes all failed provisional loads. - PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT, - - // We increase this count if a page load successfully has a layout. - // Differentiate between loads that were backgrounded before first layout. - // Note that a load that is backgrounded, then foregrounded before first - // layout will still end up in the backgrounded bucket. - PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_FOREGROUND, - PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_BACKGROUND, +enum ProvisionalLoadEvent { + // 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. + PROVISIONAL_LOAD_STOPPED, + + // 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. + PROVISIONAL_LOAD_ERR_ABORTED, + + // This event captures all the other ways a provisional load can fail. + PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT, + + // Counts the number of successful commits. + PROVISIONAL_LOAD_COMMITTED, + + // Add values before this final count. + PROVISIONAL_LOAD_LAST_ENTRY +}; + +// CommittedLoadEvents are events that occur on committed loads that we track. +// Note that we capture events only for committed loads that: +// - Are http/https. +// - Not same-page navigations. +// - Are not navigations to an error page. +// We only know these things about a navigation post-commit. +// +// If you add elements to this enum, make sure you update the enum +// value in histograms.xml. Only add elements to the end to prevent +// inconsistencies between versions. +enum CommittedLoadEvent { + // When a load that eventually commits started. Note we can't log this until + // commit time, but it represents when the actual page load started. Thus, we + // only separate this into .Background when a page load starts backgrounded. + COMMITTED_LOAD_STARTED, + + // These two events are disjoint. Sum them to find the total number of + // committed loads that we end up tracking. + COMMITTED_LOAD_FAILED_BEFORE_FIRST_LAYOUT, + COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, + + // TODO(csharrison) once first paint metrics are in place, add new events. // Add values before this final count. - PAGE_LOAD_LAST_ENTRY + COMMITTED_LOAD_LAST_ENTRY +}; + +// These errors are internal to the page_load_metrics subsystem and do not +// reflect actual errors that occur during a page load. +// +// If you add elements to this enum, make sure you update the enum +// value in histograms.xml. Only add elements to the end to prevent +// inconsistencies between versions. +enum InternalErrorLoadEvent { + // A timing IPC was sent from the renderer that did not line up with previous + // data we've received (i.e. navigation start is different or the timing + // struct is somehow invalid). This error can only occur once the IPC is + // vetted in other ways (see other errors). + ERR_BAD_TIMING_IPC, + + // The following IPCs are not mutually exclusive. + // + // We received an IPC when we weren't tracking a committed load. This will + // often happen if we get an IPC from a bad URL scheme (that is, the renderer + // sent us an IPC from a navigation we don't care about). + ERR_IPC_WITH_NO_COMMITTED_LOAD, + + // Received a notification from a frame that has been navigated away from. + ERR_IPC_FROM_WRONG_FRAME, + + // We received an IPC even through the last committed url from the browser + // was not http/s. This can happen with the renderer sending IPCs for the + // new tab page. This will often come paired with + // ERR_IPC_WITH_NO_COMMITTED_LOAD. + ERR_IPC_FROM_BAD_URL_SCHEME, + + // If we track a navigation, but the renderer sends us no IPCs. This could + // occur if the browser filters loads less aggressively than the renderer. + ERR_NO_IPCS_RECEIVED, + + // Add values before this final count. + ERR_LAST_ENTRY }; class PageLoadTracker { @@ -62,10 +129,13 @@ class PageLoadTracker { ~PageLoadTracker(); void Commit(); void WebContentsHidden(); + void WebContentsShown(); // Returns true if the timing was successfully updated. bool UpdateTiming(const PageLoadTiming& timing); - void RecordEvent(PageLoadEvent event); + void RecordProvisionalEvent(ProvisionalLoadEvent event); + void RecordCommittedEvent(CommittedLoadEvent event, bool backgrounded); + bool HasBackgrounded(); private: void RecordTimingHistograms(); @@ -74,8 +144,9 @@ class PageLoadTracker { // We record separate metrics for events that occur after a background, // because metrics like layout/paint are delayed artificially - // when they occur in the bacground. + // when they occur in the background. base::TimeTicks background_time_; + base::TimeTicks foreground_time_; bool started_in_foreground_; PageLoadTiming timing_; @@ -111,8 +182,6 @@ class MetricsWebContentsObserver void OnTimingUpdated(content::RenderFrameHost*, const PageLoadTiming& timing); - bool IsRelevantNavigation(content::NavigationHandle* navigation_handle); - // True if the web contents is currently in the foreground. bool in_foreground_; diff --git a/components/page_load_metrics/browser/metrics_web_contents_observer_unittest.cc b/components/page_load_metrics/browser/metrics_web_contents_observer_unittest.cc index fd06574..3354e5e 100644 --- a/components/page_load_metrics/browser/metrics_web_contents_observer_unittest.cc +++ b/components/page_load_metrics/browser/metrics_web_contents_observer_unittest.cc @@ -32,22 +32,32 @@ const char kHistogramNameLoad[] = "PageLoad.Timing2.NavigationToLoadEventFired"; const char kBGHistogramNameFirstLayout[] = - "PageLoad.Timing2.NavigationToFirstLayout.BG"; + "PageLoad.Timing2.NavigationToFirstLayout.Background"; const char kBGHistogramNameFirstTextPaint[] = - "PageLoad.Timing2.NavigationToFirstTextPaint.BG"; + "PageLoad.Timing2.NavigationToFirstTextPaint.Background"; const char kBGHistogramNameDomContent[] = - "PageLoad.Timing2.NavigationToDOMContentLoadedEventFired.BG"; + "PageLoad.Timing2.NavigationToDOMContentLoadedEventFired.Background"; const char kBGHistogramNameLoad[] = - "PageLoad.Timing2.NavigationToLoadEventFired.BG"; + "PageLoad.Timing2.NavigationToLoadEventFired.Background"; -const char kHistogramNameEvents[] = "PageLoad.EventCounts"; +const char kProvisionalEvents[] = "PageLoad.Events.Provisional"; +const char kCommittedEvents[] = "PageLoad.Events.Committed"; +const char kBGProvisionalEvents[] = "PageLoad.Events.Provisional.Background"; +const char kBGCommittedEvents[] = "PageLoad.Events.Committed.Background"; + +const char kErrorEvents[] = "PageLoad.Events.InternalError"; } // namespace class MetricsWebContentsObserverTest : public content::RenderViewHostTestHarness { public: - MetricsWebContentsObserverTest() {} + MetricsWebContentsObserverTest() + : num_provisional_events_(0), + num_provisional_events_bg_(0), + num_committed_events_(0), + num_committed_events_bg_(0), + num_errors_(0) {} void SetUp() override { RenderViewHostTestHarness::SetUp(); @@ -62,9 +72,58 @@ class MetricsWebContentsObserverTest histogram_tester_.ExpectTotalCount(kHistogramNameFirstTextPaint, 0); } + void CheckProvisionalEvent(ProvisionalLoadEvent event, + int count, + bool background) { + if (background) { + histogram_tester_.ExpectBucketCount(kBGProvisionalEvents, event, count); + num_provisional_events_bg_ += count; + } else { + histogram_tester_.ExpectBucketCount(kProvisionalEvents, event, count); + num_provisional_events_ += count; + } + } + + void CheckCommittedEvent(CommittedLoadEvent event, + int count, + bool background) { + if (background) { + histogram_tester_.ExpectBucketCount(kBGCommittedEvents, event, count); + num_committed_events_bg_ += count; + } else { + histogram_tester_.ExpectBucketCount(kCommittedEvents, event, count); + num_committed_events_ += count; + } + } + + void CheckErrorEvent(InternalErrorLoadEvent error, int count) { + histogram_tester_.ExpectBucketCount(kErrorEvents, error, count); + num_errors_ += count; + } + + void CheckTotalEvents() { + histogram_tester_.ExpectTotalCount(kProvisionalEvents, + num_provisional_events_); + histogram_tester_.ExpectTotalCount(kCommittedEvents, num_committed_events_); + histogram_tester_.ExpectTotalCount(kBGProvisionalEvents, + num_provisional_events_bg_); + histogram_tester_.ExpectTotalCount(kBGCommittedEvents, + num_committed_events_bg_); + histogram_tester_.ExpectTotalCount(kErrorEvents, num_errors_); + } + protected: base::HistogramTester histogram_tester_; scoped_ptr<MetricsWebContentsObserver> observer_; + + private: + int num_provisional_events_; + int num_provisional_events_bg_; + int num_committed_events_; + int num_committed_events_bg_; + int num_errors_; + + DISALLOW_COPY_AND_ASSIGN(MetricsWebContentsObserverTest); }; TEST_F(MetricsWebContentsObserverTest, NoMetrics) { @@ -371,15 +430,9 @@ TEST_F(MetricsWebContentsObserverTest, FailProvisionalLoad) { net::ERR_TIMED_OUT); rfh_tester->SimulateNavigationStop(); - histogram_tester_.ExpectTotalCount(kHistogramNameEvents, 3); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_STARTED, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_FAILED_BEFORE_COMMIT, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_ABORTED_BEFORE_COMMIT, 0); + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT, 1, false); + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_ABORTED, 0, false); + CheckTotalEvents(); } TEST_F(MetricsWebContentsObserverTest, AbortProvisionalLoad) { @@ -392,15 +445,71 @@ TEST_F(MetricsWebContentsObserverTest, AbortProvisionalLoad) { rfh_tester->SimulateNavigationError(GURL(kDefaultTestUrl), net::ERR_ABORTED); rfh_tester->SimulateNavigationStop(); - histogram_tester_.ExpectTotalCount(kHistogramNameEvents, 4); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_STARTED, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_FAILED_BEFORE_COMMIT, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT, 1); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_ABORTED_BEFORE_COMMIT, 1); + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT, 0, false); + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_ABORTED, 1, false); + CheckTotalEvents(); +} + +TEST_F(MetricsWebContentsObserverTest, AbortProvisionalLoadInBackground) { + content::WebContentsTester* web_contents_tester = + content::WebContentsTester::For(web_contents()); + + observer_->WasHidden(); + web_contents_tester->StartNavigation(GURL(kDefaultTestUrl)); + content::RenderFrameHostTester* rfh_tester = + content::RenderFrameHostTester::For(main_rfh()); + rfh_tester->SimulateNavigationError(GURL(kDefaultTestUrl), net::ERR_ABORTED); + rfh_tester->SimulateNavigationStop(); + + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT, 0, true); + CheckProvisionalEvent(PROVISIONAL_LOAD_ERR_ABORTED, 1, true); + CheckTotalEvents(); +} + +TEST_F(MetricsWebContentsObserverTest, DontLogIrrelevantNavigation) { + PageLoadTiming timing; + timing.navigation_start = base::Time::FromDoubleT(10); + + content::WebContentsTester* web_contents_tester = + content::WebContentsTester::For(web_contents()); + + GURL about_blank_url = GURL("about:blank"); + web_contents_tester->NavigateAndCommit(about_blank_url); + + observer_->OnMessageReceived( + PageLoadMetricsMsg_TimingUpdated(observer_->routing_id(), timing), + main_rfh()); + + web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); + + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 2, false); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 1, false); + CheckErrorEvent(ERR_IPC_FROM_BAD_URL_SCHEME, 1); + CheckErrorEvent(ERR_IPC_WITH_NO_COMMITTED_LOAD, 1); + CheckTotalEvents(); +} + +TEST_F(MetricsWebContentsObserverTest, NotInMainError) { + PageLoadTiming timing; + timing.navigation_start = base::Time::FromDoubleT(1); + timing.first_layout = base::TimeDelta::FromMilliseconds(1); + + content::WebContentsTester* web_contents_tester = + content::WebContentsTester::For(web_contents()); + web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); + + content::RenderFrameHostTester* rfh_tester = + content::RenderFrameHostTester::For(main_rfh()); + content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); + + content::RenderFrameHostTester* subframe_tester = + content::RenderFrameHostTester::For(subframe); + subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); + subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); + observer_->OnMessageReceived( + PageLoadMetricsMsg_TimingUpdated(observer_->routing_id(), timing), + subframe); + CheckErrorEvent(ERR_IPC_FROM_WRONG_FRAME, 1); } TEST_F(MetricsWebContentsObserverTest, AbortCommittedLoadBeforeFirstLayout) { @@ -417,16 +526,13 @@ TEST_F(MetricsWebContentsObserverTest, AbortCommittedLoadBeforeFirstLayout) { // Navigate again to force histogram logging. web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl2)); - // 3 events: 2 starts and one abort before first layout. - histogram_tester_.ExpectTotalCount(kHistogramNameEvents, 3); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_STARTED, 2); - histogram_tester_.ExpectBucketCount( - kHistogramNameEvents, PAGE_LOAD_ABORTED_BEFORE_FIRST_LAYOUT, 1); + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 2, false); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 2, false); + CheckCommittedEvent(COMMITTED_LOAD_FAILED_BEFORE_FIRST_LAYOUT, 1, false); + CheckTotalEvents(); } -TEST_F(MetricsWebContentsObserverTest, - SuccessfulFirstLayoutInForeGroundEvent) { +TEST_F(MetricsWebContentsObserverTest, SuccessfulFirstLayoutInForegroundEvent) { PageLoadTiming timing; timing.navigation_start = base::Time::FromDoubleT(10); timing.first_layout = base::TimeDelta::FromMilliseconds(100); @@ -441,12 +547,10 @@ TEST_F(MetricsWebContentsObserverTest, // Navigate again to force histogram logging. web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl2)); - // 3 events: 2 starts and one successful first layout. - histogram_tester_.ExpectTotalCount(kHistogramNameEvents, 3); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_STARTED, 2); - histogram_tester_.ExpectBucketCount( - kHistogramNameEvents, PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_FOREGROUND, 1); + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 2, false); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 2, false); + CheckCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, 1, false); + CheckTotalEvents(); } TEST_F(MetricsWebContentsObserverTest, @@ -459,9 +563,9 @@ TEST_F(MetricsWebContentsObserverTest, content::WebContentsTester* web_contents_tester = content::WebContentsTester::For(web_contents()); - web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); // Background the tab. observer_->WasHidden(); + web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); observer_->OnMessageReceived( PageLoadMetricsMsg_TimingUpdated(observer_->routing_id(), timing), @@ -471,11 +575,35 @@ TEST_F(MetricsWebContentsObserverTest, // Navigate again to force histogram logging. web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl2)); - // 3 events: 2 starts and one successful first layout. - histogram_tester_.ExpectTotalCount(kHistogramNameEvents, 3); - histogram_tester_.ExpectBucketCount(kHistogramNameEvents, - PAGE_LOAD_STARTED, 2); - histogram_tester_.ExpectBucketCount( - kHistogramNameEvents, PAGE_LOAD_SUCCESSFUL_FIRST_LAYOUT_BACKGROUND, 1); + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 1, true); + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 1, false); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 1, true); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 1, false); + CheckCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, 1, true); + CheckTotalEvents(); +} + +TEST_F(MetricsWebContentsObserverTest, BadIPC) { + PageLoadTiming timing; + timing.navigation_start = base::Time::FromDoubleT(10); + PageLoadTiming timing2; + timing2.navigation_start = base::Time::FromDoubleT(100); + + content::WebContentsTester* web_contents_tester = + content::WebContentsTester::For(web_contents()); + web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); + + observer_->OnMessageReceived( + PageLoadMetricsMsg_TimingUpdated(observer_->routing_id(), timing), + main_rfh()); + observer_->OnMessageReceived( + PageLoadMetricsMsg_TimingUpdated(observer_->routing_id(), timing2), + main_rfh()); + + CheckProvisionalEvent(PROVISIONAL_LOAD_COMMITTED, 1, false); + CheckCommittedEvent(COMMITTED_LOAD_STARTED, 1, false); + CheckErrorEvent(ERR_BAD_TIMING_IPC, 1); + CheckTotalEvents(); } + } // namespace page_load_metrics |