Index: chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc |
diff --git a/chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc b/chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc |
index dd8592193b71f0dbc49d9029d338c3dc7a7070b0..bf448aab3cc2ded68e8d814956b87097cd401861 100644 |
--- a/chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc |
+++ b/chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc |
@@ -9,12 +9,15 @@ |
#include "base/macros.h" |
#include "base/memory/ptr_util.h" |
+#include "base/memory/weak_ptr.h" |
#include "base/process/kill.h" |
#include "base/test/histogram_tester.h" |
#include "base/time/time.h" |
+#include "base/timer/mock_timer.h" |
#include "chrome/browser/page_load_metrics/metrics_navigation_throttle.h" |
#include "chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.h" |
#include "chrome/browser/page_load_metrics/page_load_metrics_observer.h" |
+#include "chrome/browser/page_load_metrics/page_load_metrics_update_dispatcher.h" |
#include "chrome/browser/page_load_metrics/page_load_tracker.h" |
#include "chrome/common/page_load_metrics/page_load_metrics_messages.h" |
#include "chrome/common/url_constants.h" |
@@ -36,6 +39,13 @@ const char kDefaultTestUrl2[] = "https://whatever.com/"; |
const char kFilteredStartUrl[] = "https://whatever.com/ignore-on-start"; |
const char kFilteredCommitUrl[] = "https://whatever.com/ignore-on-commit"; |
+class WeakMockTimer : public base::MockTimer, |
+ public base::SupportsWeakPtr<WeakMockTimer> { |
+ public: |
+ WeakMockTimer() |
+ : MockTimer(false /* retain_user_task */, false /* is_repeating */) {} |
+}; |
+ |
// Simple PageLoadMetricsObserver that copies observed PageLoadTimings into the |
// provided std::vector, so they can be analyzed by unit tests. |
class TestPageLoadMetricsObserver : public PageLoadMetricsObserver { |
@@ -129,6 +139,11 @@ class TestPageLoadMetricsEmbedderInterface |
tracker->AddObserver(base::MakeUnique<FilteringPageLoadMetricsObserver>( |
&completed_filtered_urls_)); |
} |
+ std::unique_ptr<base::Timer> CreateTimer() override { |
+ std::unique_ptr<WeakMockTimer> timer = base::MakeUnique<WeakMockTimer>(); |
+ most_recent_timer_ = timer->AsWeakPtr(); |
+ return std::move(timer); |
+ } |
const std::vector<mojom::PageLoadTimingPtr>& updated_timings() const { |
return updated_timings_; |
} |
@@ -149,6 +164,9 @@ class TestPageLoadMetricsEmbedderInterface |
const std::vector<GURL>& completed_filtered_urls() const { |
return completed_filtered_urls_; |
} |
+ base::MockTimer* GetMostRecentTimer() const { |
+ return most_recent_timer_.get(); |
+ } |
private: |
std::vector<mojom::PageLoadTimingPtr> updated_timings_; |
@@ -156,9 +174,18 @@ class TestPageLoadMetricsEmbedderInterface |
std::vector<mojom::PageLoadTimingPtr> complete_timings_; |
std::vector<GURL> observed_committed_urls_; |
std::vector<GURL> completed_filtered_urls_; |
+ base::WeakPtr<WeakMockTimer> most_recent_timer_; |
bool is_ntp_; |
}; |
+void PopulatePageLoadTiming(mojom::PageLoadTiming* timing) { |
+ page_load_metrics::InitPageLoadTimingForTest(timing); |
+ timing->navigation_start = base::Time::FromDoubleT(1); |
+ timing->response_start = base::TimeDelta::FromMilliseconds(10); |
+ timing->parse_timing->parse_start = base::TimeDelta::FromMilliseconds(20); |
+ timing->document_timing->first_layout = base::TimeDelta::FromMilliseconds(30); |
+} |
+ |
} // namespace |
class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { |
@@ -175,12 +202,30 @@ class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { |
->NavigateAndCommit(GURL(url::kAboutBlankURL)); |
} |
+ // Returns the mock timer used for buffering updates in the |
+ // PageLoadMetricsUpdateDispatcher. |
+ base::MockTimer* GetMostRecentTimer() { |
+ return embedder_interface_->GetMostRecentTimer(); |
+ } |
+ |
void SimulateTimingUpdate(const mojom::PageLoadTiming& timing) { |
SimulateTimingUpdate(timing, web_contents()->GetMainFrame()); |
} |
void SimulateTimingUpdate(const mojom::PageLoadTiming& timing, |
content::RenderFrameHost* render_frame_host) { |
+ SimulateTimingUpdateWithoutFiringDispatchTimer(timing, render_frame_host); |
+ // If sending the timing update caused the PageLoadMetricsUpdateDispatcher |
+ // to schedule a buffering timer, then fire it now so metrics are dispatched |
+ // to observers. |
+ base::MockTimer* mock_timer = GetMostRecentTimer(); |
+ if (mock_timer && mock_timer->IsRunning()) |
+ mock_timer->Fire(); |
+ } |
+ |
+ void SimulateTimingUpdateWithoutFiringDispatchTimer( |
+ const mojom::PageLoadTiming& timing, |
+ content::RenderFrameHost* render_frame_host) { |
observer()->OnTimingUpdated(render_frame_host, timing, |
mojom::PageLoadMetadata()); |
} |
@@ -735,13 +780,7 @@ TEST_F(MetricsWebContentsObserverTest, OutOfOrderCrossFrameTiming) { |
// Dispatch a timing update for the child frame that includes a first paint. |
mojom::PageLoadTiming subframe_timing; |
- page_load_metrics::InitPageLoadTimingForTest(&subframe_timing); |
- subframe_timing.navigation_start = base::Time::FromDoubleT(2); |
- subframe_timing.response_start = base::TimeDelta::FromMilliseconds(10); |
- subframe_timing.parse_timing->parse_start = |
- base::TimeDelta::FromMilliseconds(20); |
- subframe_timing.document_timing->first_layout = |
- base::TimeDelta::FromMilliseconds(30); |
+ PopulatePageLoadTiming(&subframe_timing); |
subframe_timing.paint_timing->first_paint = |
base::TimeDelta::FromMilliseconds(40); |
content::RenderFrameHostTester* subframe_tester = |
@@ -797,4 +836,100 @@ TEST_F(MetricsWebContentsObserverTest, OutOfOrderCrossFrameTiming) { |
CheckNoErrorEvents(); |
} |
+// We buffer cross-frame paint updates to account for paint timings from |
+// different frames arriving out of order. |
+TEST_F(MetricsWebContentsObserverTest, OutOfOrderCrossFrameTiming2) { |
+ // Dispatch a timing update for the main frame that includes a first |
+ // paint. This should be buffered, with the dispatch timer running. |
+ mojom::PageLoadTiming timing; |
+ PopulatePageLoadTiming(&timing); |
+ timing.paint_timing->first_paint = base::TimeDelta::FromMilliseconds(1000); |
+ content::WebContentsTester* web_contents_tester = |
+ content::WebContentsTester::For(web_contents()); |
+ web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); |
+ SimulateTimingUpdateWithoutFiringDispatchTimer(timing, main_rfh()); |
+ |
+ EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
+ ASSERT_EQ(0, CountUpdatedTimingReported()); |
+ |
+ content::RenderFrameHostTester* rfh_tester = |
+ content::RenderFrameHostTester::For(main_rfh()); |
+ |
+ // Dispatch a timing update for a child frame that includes a first paint. |
+ mojom::PageLoadTiming subframe_timing; |
+ PopulatePageLoadTiming(&subframe_timing); |
+ subframe_timing.paint_timing->first_paint = |
+ base::TimeDelta::FromMilliseconds(500); |
+ 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)); |
+ SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe); |
+ subframe_tester->SimulateNavigationStop(); |
+ |
+ histogram_tester_.ExpectTotalCount( |
+ page_load_metrics::internal::kHistogramOutOfOrderTiming, 1); |
+ |
+ EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
+ ASSERT_EQ(0, CountUpdatedTimingReported()); |
+ |
+ // At this point, the timing update is buffered, waiting for the timer to |
+ // fire. |
+ GetMostRecentTimer()->Fire(); |
+ |
+ // Firing the timer should produce a timing update. The update should be a |
+ // merged view of the main frame timing, with a first paint timestamp from the |
+ // subframe. |
+ ASSERT_EQ(1, CountUpdatedTimingReported()); |
+ EXPECT_FALSE(timing.Equals(*updated_timings().back())); |
+ EXPECT_TRUE( |
+ updated_timings().back()->parse_timing->Equals(*timing.parse_timing)); |
+ EXPECT_TRUE(updated_timings().back()->document_timing->Equals( |
+ *timing.document_timing)); |
+ EXPECT_FALSE( |
+ updated_timings().back()->paint_timing->Equals(*timing.paint_timing)); |
+ EXPECT_TRUE(updated_timings().back()->paint_timing->first_paint); |
+ |
+ // The first paint value should be the min of all received first paints, wich |
Charlie Harrison
2017/05/26 19:31:34
which
Bryan McQuade
2017/05/26 20:07:32
Done
|
+ // in this case is the first paint from the subframe. Since it is offset by |
+ // the subframe's navigation start, the received value should be >= the first |
+ // paint value specified in the subframe. |
+ EXPECT_GE(updated_timings().back()->paint_timing->first_paint, |
+ subframe_timing.paint_timing->first_paint); |
+ EXPECT_LT(updated_timings().back()->paint_timing->first_paint, |
+ timing.paint_timing->first_paint); |
+ |
+ base::TimeDelta initial_first_paint = |
+ updated_timings().back()->paint_timing->first_paint.value(); |
+ |
+ // Dispatch a timing update for an additional child frame, with an earlier |
+ // first paint time. This should cause an immediate update, without a timer |
+ // delay. |
+ subframe_timing.paint_timing->first_paint = |
+ base::TimeDelta::FromMilliseconds(50); |
+ content::RenderFrameHost* subframe2 = rfh_tester->AppendChild("subframe"); |
+ content::RenderFrameHostTester* subframe2_tester = |
+ content::RenderFrameHostTester::For(subframe2); |
+ subframe2_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
+ subframe2_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
+ SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe2); |
+ subframe2_tester->SimulateNavigationStop(); |
+ |
+ base::TimeDelta updated_first_paint = |
+ updated_timings().back()->paint_timing->first_paint.value(); |
+ |
+ EXPECT_FALSE(GetMostRecentTimer()->IsRunning()); |
+ ASSERT_EQ(2, CountUpdatedTimingReported()); |
+ EXPECT_LT(updated_first_paint, initial_first_paint); |
+ |
+ histogram_tester_.ExpectTotalCount( |
+ page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, 1); |
+ histogram_tester_.ExpectBucketCount( |
+ page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, |
+ (initial_first_paint - updated_first_paint).InMilliseconds(), 1); |
+ |
+ CheckNoErrorEvents(); |
+} |
+ |
} // namespace page_load_metrics |