OLD | NEW |
1 // Copyright 2015 The Chromium Authors. All rights reserved. | 1 // Copyright 2015 The Chromium Authors. All rights reserved. |
2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "chrome/browser/page_load_metrics/metrics_web_contents_observer.h" | 5 #include "chrome/browser/page_load_metrics/metrics_web_contents_observer.h" |
6 | 6 |
7 #include <memory> | 7 #include <memory> |
8 #include <vector> | 8 #include <vector> |
9 | 9 |
10 #include "base/macros.h" | 10 #include "base/macros.h" |
11 #include "base/memory/ptr_util.h" | 11 #include "base/memory/ptr_util.h" |
| 12 #include "base/memory/weak_ptr.h" |
12 #include "base/process/kill.h" | 13 #include "base/process/kill.h" |
13 #include "base/test/histogram_tester.h" | 14 #include "base/test/histogram_tester.h" |
14 #include "base/time/time.h" | 15 #include "base/time/time.h" |
| 16 #include "base/timer/mock_timer.h" |
15 #include "chrome/browser/page_load_metrics/metrics_navigation_throttle.h" | 17 #include "chrome/browser/page_load_metrics/metrics_navigation_throttle.h" |
16 #include "chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.
h" | 18 #include "chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.
h" |
17 #include "chrome/browser/page_load_metrics/page_load_metrics_observer.h" | 19 #include "chrome/browser/page_load_metrics/page_load_metrics_observer.h" |
18 #include "chrome/browser/page_load_metrics/page_load_tracker.h" | 20 #include "chrome/browser/page_load_metrics/page_load_tracker.h" |
19 #include "chrome/common/page_load_metrics/page_load_metrics_messages.h" | 21 #include "chrome/common/page_load_metrics/page_load_metrics_messages.h" |
| 22 #include "chrome/common/page_load_metrics/test/weak_mock_timer.h" |
20 #include "chrome/common/url_constants.h" | 23 #include "chrome/common/url_constants.h" |
21 #include "chrome/test/base/chrome_render_view_host_test_harness.h" | 24 #include "chrome/test/base/chrome_render_view_host_test_harness.h" |
22 #include "content/public/browser/navigation_handle.h" | 25 #include "content/public/browser/navigation_handle.h" |
23 #include "content/public/browser/render_frame_host.h" | 26 #include "content/public/browser/render_frame_host.h" |
24 #include "content/public/test/test_renderer_host.h" | 27 #include "content/public/test/test_renderer_host.h" |
25 #include "content/public/test/web_contents_tester.h" | 28 #include "content/public/test/web_contents_tester.h" |
26 #include "testing/gtest/include/gtest/gtest.h" | 29 #include "testing/gtest/include/gtest/gtest.h" |
27 #include "url/gurl.h" | 30 #include "url/gurl.h" |
28 | 31 |
29 namespace page_load_metrics { | 32 namespace page_load_metrics { |
(...skipping 79 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
109 void OnComplete(const mojom::PageLoadTiming& timing, | 112 void OnComplete(const mojom::PageLoadTiming& timing, |
110 const PageLoadExtraInfo& extra_info) override { | 113 const PageLoadExtraInfo& extra_info) override { |
111 completed_filtered_urls_->push_back(extra_info.url); | 114 completed_filtered_urls_->push_back(extra_info.url); |
112 } | 115 } |
113 | 116 |
114 private: | 117 private: |
115 std::vector<GURL>* const completed_filtered_urls_; | 118 std::vector<GURL>* const completed_filtered_urls_; |
116 }; | 119 }; |
117 | 120 |
118 class TestPageLoadMetricsEmbedderInterface | 121 class TestPageLoadMetricsEmbedderInterface |
119 : public PageLoadMetricsEmbedderInterface { | 122 : public PageLoadMetricsEmbedderInterface, |
| 123 public WeakMockTimerProvider { |
120 public: | 124 public: |
121 TestPageLoadMetricsEmbedderInterface() : is_ntp_(false) {} | 125 TestPageLoadMetricsEmbedderInterface() : is_ntp_(false) {} |
122 | 126 |
123 bool IsNewTabPageUrl(const GURL& url) override { return is_ntp_; } | 127 bool IsNewTabPageUrl(const GURL& url) override { return is_ntp_; } |
124 void set_is_ntp(bool is_ntp) { is_ntp_ = is_ntp; } | 128 void set_is_ntp(bool is_ntp) { is_ntp_ = is_ntp; } |
125 void RegisterObservers(PageLoadTracker* tracker) override { | 129 void RegisterObservers(PageLoadTracker* tracker) override { |
126 tracker->AddObserver(base::MakeUnique<TestPageLoadMetricsObserver>( | 130 tracker->AddObserver(base::MakeUnique<TestPageLoadMetricsObserver>( |
127 &updated_timings_, &updated_subframe_timings_, &complete_timings_, | 131 &updated_timings_, &updated_subframe_timings_, &complete_timings_, |
128 &observed_committed_urls_)); | 132 &observed_committed_urls_)); |
129 tracker->AddObserver(base::MakeUnique<FilteringPageLoadMetricsObserver>( | 133 tracker->AddObserver(base::MakeUnique<FilteringPageLoadMetricsObserver>( |
130 &completed_filtered_urls_)); | 134 &completed_filtered_urls_)); |
131 } | 135 } |
| 136 std::unique_ptr<base::Timer> CreateTimer() override { |
| 137 std::unique_ptr<WeakMockTimer> timer = base::MakeUnique<WeakMockTimer>(); |
| 138 SetMockTimer(timer->AsWeakPtr()); |
| 139 return std::move(timer); |
| 140 } |
132 const std::vector<mojom::PageLoadTimingPtr>& updated_timings() const { | 141 const std::vector<mojom::PageLoadTimingPtr>& updated_timings() const { |
133 return updated_timings_; | 142 return updated_timings_; |
134 } | 143 } |
135 const std::vector<mojom::PageLoadTimingPtr>& complete_timings() const { | 144 const std::vector<mojom::PageLoadTimingPtr>& complete_timings() const { |
136 return complete_timings_; | 145 return complete_timings_; |
137 } | 146 } |
138 const std::vector<mojom::PageLoadTimingPtr>& updated_subframe_timings() | 147 const std::vector<mojom::PageLoadTimingPtr>& updated_subframe_timings() |
139 const { | 148 const { |
140 return updated_subframe_timings_; | 149 return updated_subframe_timings_; |
141 } | 150 } |
(...skipping 10 matching lines...) Expand all Loading... |
152 | 161 |
153 private: | 162 private: |
154 std::vector<mojom::PageLoadTimingPtr> updated_timings_; | 163 std::vector<mojom::PageLoadTimingPtr> updated_timings_; |
155 std::vector<mojom::PageLoadTimingPtr> updated_subframe_timings_; | 164 std::vector<mojom::PageLoadTimingPtr> updated_subframe_timings_; |
156 std::vector<mojom::PageLoadTimingPtr> complete_timings_; | 165 std::vector<mojom::PageLoadTimingPtr> complete_timings_; |
157 std::vector<GURL> observed_committed_urls_; | 166 std::vector<GURL> observed_committed_urls_; |
158 std::vector<GURL> completed_filtered_urls_; | 167 std::vector<GURL> completed_filtered_urls_; |
159 bool is_ntp_; | 168 bool is_ntp_; |
160 }; | 169 }; |
161 | 170 |
| 171 void PopulatePageLoadTiming(mojom::PageLoadTiming* timing) { |
| 172 page_load_metrics::InitPageLoadTimingForTest(timing); |
| 173 timing->navigation_start = base::Time::FromDoubleT(1); |
| 174 timing->response_start = base::TimeDelta::FromMilliseconds(10); |
| 175 timing->parse_timing->parse_start = base::TimeDelta::FromMilliseconds(20); |
| 176 timing->document_timing->first_layout = base::TimeDelta::FromMilliseconds(30); |
| 177 } |
| 178 |
162 } // namespace | 179 } // namespace |
163 | 180 |
164 class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { | 181 class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { |
165 public: | 182 public: |
166 MetricsWebContentsObserverTest() : num_errors_(0) {} | 183 MetricsWebContentsObserverTest() : num_errors_(0) {} |
167 | 184 |
168 void SetUp() override { | 185 void SetUp() override { |
169 ChromeRenderViewHostTestHarness::SetUp(); | 186 ChromeRenderViewHostTestHarness::SetUp(); |
170 AttachObserver(); | 187 AttachObserver(); |
171 } | 188 } |
172 | 189 |
173 void NavigateToUntrackedUrl() { | 190 void NavigateToUntrackedUrl() { |
174 content::WebContentsTester::For(web_contents()) | 191 content::WebContentsTester::For(web_contents()) |
175 ->NavigateAndCommit(GURL(url::kAboutBlankURL)); | 192 ->NavigateAndCommit(GURL(url::kAboutBlankURL)); |
176 } | 193 } |
177 | 194 |
| 195 // Returns the mock timer used for buffering updates in the |
| 196 // PageLoadMetricsUpdateDispatcher. |
| 197 base::MockTimer* GetMostRecentTimer() { |
| 198 return embedder_interface_->GetMockTimer(); |
| 199 } |
| 200 |
178 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing) { | 201 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing) { |
179 SimulateTimingUpdate(timing, web_contents()->GetMainFrame()); | 202 SimulateTimingUpdate(timing, web_contents()->GetMainFrame()); |
180 } | 203 } |
181 | 204 |
182 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing, | 205 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing, |
183 content::RenderFrameHost* render_frame_host) { | 206 content::RenderFrameHost* render_frame_host) { |
| 207 SimulateTimingUpdateWithoutFiringDispatchTimer(timing, render_frame_host); |
| 208 // If sending the timing update caused the PageLoadMetricsUpdateDispatcher |
| 209 // to schedule a buffering timer, then fire it now so metrics are dispatched |
| 210 // to observers. |
| 211 base::MockTimer* mock_timer = GetMostRecentTimer(); |
| 212 if (mock_timer && mock_timer->IsRunning()) |
| 213 mock_timer->Fire(); |
| 214 } |
| 215 |
| 216 void SimulateTimingUpdateWithoutFiringDispatchTimer( |
| 217 const mojom::PageLoadTiming& timing, |
| 218 content::RenderFrameHost* render_frame_host) { |
184 observer()->OnTimingUpdated(render_frame_host, timing, | 219 observer()->OnTimingUpdated(render_frame_host, timing, |
185 mojom::PageLoadMetadata()); | 220 mojom::PageLoadMetadata()); |
186 } | 221 } |
187 | 222 |
188 void AttachObserver() { | 223 void AttachObserver() { |
189 auto embedder_interface = | 224 auto embedder_interface = |
190 base::MakeUnique<TestPageLoadMetricsEmbedderInterface>(); | 225 base::MakeUnique<TestPageLoadMetricsEmbedderInterface>(); |
191 embedder_interface_ = embedder_interface.get(); | 226 embedder_interface_ = embedder_interface.get(); |
192 MetricsWebContentsObserver* observer = | 227 MetricsWebContentsObserver* observer = |
193 MetricsWebContentsObserver::CreateForWebContents( | 228 MetricsWebContentsObserver::CreateForWebContents( |
(...skipping 534 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
728 | 763 |
729 ASSERT_EQ(1, CountUpdatedTimingReported()); | 764 ASSERT_EQ(1, CountUpdatedTimingReported()); |
730 EXPECT_TRUE(timing.Equals(*updated_timings().back())); | 765 EXPECT_TRUE(timing.Equals(*updated_timings().back())); |
731 | 766 |
732 content::RenderFrameHostTester* rfh_tester = | 767 content::RenderFrameHostTester* rfh_tester = |
733 content::RenderFrameHostTester::For(main_rfh()); | 768 content::RenderFrameHostTester::For(main_rfh()); |
734 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); | 769 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); |
735 | 770 |
736 // Dispatch a timing update for the child frame that includes a first paint. | 771 // Dispatch a timing update for the child frame that includes a first paint. |
737 mojom::PageLoadTiming subframe_timing; | 772 mojom::PageLoadTiming subframe_timing; |
738 page_load_metrics::InitPageLoadTimingForTest(&subframe_timing); | 773 PopulatePageLoadTiming(&subframe_timing); |
739 subframe_timing.navigation_start = base::Time::FromDoubleT(2); | |
740 subframe_timing.response_start = base::TimeDelta::FromMilliseconds(10); | |
741 subframe_timing.parse_timing->parse_start = | |
742 base::TimeDelta::FromMilliseconds(20); | |
743 subframe_timing.document_timing->first_layout = | |
744 base::TimeDelta::FromMilliseconds(30); | |
745 subframe_timing.paint_timing->first_paint = | 774 subframe_timing.paint_timing->first_paint = |
746 base::TimeDelta::FromMilliseconds(40); | 775 base::TimeDelta::FromMilliseconds(40); |
747 content::RenderFrameHostTester* subframe_tester = | 776 content::RenderFrameHostTester* subframe_tester = |
748 content::RenderFrameHostTester::For(subframe); | 777 content::RenderFrameHostTester::For(subframe); |
749 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); | 778 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
750 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); | 779 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
751 SimulateTimingUpdate(subframe_timing, subframe); | 780 SimulateTimingUpdate(subframe_timing, subframe); |
752 subframe_tester->SimulateNavigationStop(); | 781 subframe_tester->SimulateNavigationStop(); |
753 | 782 |
754 // Though a first paint was dispatched in the child, it should not yet be | 783 // Though a first paint was dispatched in the child, it should not yet be |
(...skipping 35 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
790 ASSERT_EQ(1, CountCompleteTimingReported()); | 819 ASSERT_EQ(1, CountCompleteTimingReported()); |
791 ASSERT_EQ(2, CountUpdatedTimingReported()); | 820 ASSERT_EQ(2, CountUpdatedTimingReported()); |
792 ASSERT_EQ(0, CountEmptyCompleteTimingReported()); | 821 ASSERT_EQ(0, CountEmptyCompleteTimingReported()); |
793 | 822 |
794 ASSERT_EQ(1, CountUpdatedSubFrameTimingReported()); | 823 ASSERT_EQ(1, CountUpdatedSubFrameTimingReported()); |
795 EXPECT_TRUE(subframe_timing.Equals(*updated_subframe_timings().back())); | 824 EXPECT_TRUE(subframe_timing.Equals(*updated_subframe_timings().back())); |
796 | 825 |
797 CheckNoErrorEvents(); | 826 CheckNoErrorEvents(); |
798 } | 827 } |
799 | 828 |
| 829 // We buffer cross-frame paint updates to account for paint timings from |
| 830 // different frames arriving out of order. |
| 831 TEST_F(MetricsWebContentsObserverTest, OutOfOrderCrossFrameTiming2) { |
| 832 // Dispatch a timing update for the main frame that includes a first |
| 833 // paint. This should be buffered, with the dispatch timer running. |
| 834 mojom::PageLoadTiming timing; |
| 835 PopulatePageLoadTiming(&timing); |
| 836 timing.paint_timing->first_paint = base::TimeDelta::FromMilliseconds(1000); |
| 837 content::WebContentsTester* web_contents_tester = |
| 838 content::WebContentsTester::For(web_contents()); |
| 839 web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); |
| 840 SimulateTimingUpdateWithoutFiringDispatchTimer(timing, main_rfh()); |
| 841 |
| 842 EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
| 843 ASSERT_EQ(0, CountUpdatedTimingReported()); |
| 844 |
| 845 content::RenderFrameHostTester* rfh_tester = |
| 846 content::RenderFrameHostTester::For(main_rfh()); |
| 847 |
| 848 // Dispatch a timing update for a child frame that includes a first paint. |
| 849 mojom::PageLoadTiming subframe_timing; |
| 850 PopulatePageLoadTiming(&subframe_timing); |
| 851 subframe_timing.paint_timing->first_paint = |
| 852 base::TimeDelta::FromMilliseconds(500); |
| 853 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); |
| 854 content::RenderFrameHostTester* subframe_tester = |
| 855 content::RenderFrameHostTester::For(subframe); |
| 856 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
| 857 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
| 858 SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe); |
| 859 subframe_tester->SimulateNavigationStop(); |
| 860 |
| 861 histogram_tester_.ExpectTotalCount( |
| 862 page_load_metrics::internal::kHistogramOutOfOrderTiming, 1); |
| 863 |
| 864 EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
| 865 ASSERT_EQ(0, CountUpdatedTimingReported()); |
| 866 |
| 867 // At this point, the timing update is buffered, waiting for the timer to |
| 868 // fire. |
| 869 GetMostRecentTimer()->Fire(); |
| 870 |
| 871 // Firing the timer should produce a timing update. The update should be a |
| 872 // merged view of the main frame timing, with a first paint timestamp from the |
| 873 // subframe. |
| 874 ASSERT_EQ(1, CountUpdatedTimingReported()); |
| 875 EXPECT_FALSE(timing.Equals(*updated_timings().back())); |
| 876 EXPECT_TRUE( |
| 877 updated_timings().back()->parse_timing->Equals(*timing.parse_timing)); |
| 878 EXPECT_TRUE(updated_timings().back()->document_timing->Equals( |
| 879 *timing.document_timing)); |
| 880 EXPECT_FALSE( |
| 881 updated_timings().back()->paint_timing->Equals(*timing.paint_timing)); |
| 882 EXPECT_TRUE(updated_timings().back()->paint_timing->first_paint); |
| 883 |
| 884 // The first paint value should be the min of all received first paints, which |
| 885 // in this case is the first paint from the subframe. Since it is offset by |
| 886 // the subframe's navigation start, the received value should be >= the first |
| 887 // paint value specified in the subframe. |
| 888 EXPECT_GE(updated_timings().back()->paint_timing->first_paint, |
| 889 subframe_timing.paint_timing->first_paint); |
| 890 EXPECT_LT(updated_timings().back()->paint_timing->first_paint, |
| 891 timing.paint_timing->first_paint); |
| 892 |
| 893 base::TimeDelta initial_first_paint = |
| 894 updated_timings().back()->paint_timing->first_paint.value(); |
| 895 |
| 896 // Dispatch a timing update for an additional child frame, with an earlier |
| 897 // first paint time. This should cause an immediate update, without a timer |
| 898 // delay. |
| 899 subframe_timing.paint_timing->first_paint = |
| 900 base::TimeDelta::FromMilliseconds(50); |
| 901 content::RenderFrameHost* subframe2 = rfh_tester->AppendChild("subframe"); |
| 902 content::RenderFrameHostTester* subframe2_tester = |
| 903 content::RenderFrameHostTester::For(subframe2); |
| 904 subframe2_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
| 905 subframe2_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
| 906 SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe2); |
| 907 subframe2_tester->SimulateNavigationStop(); |
| 908 |
| 909 base::TimeDelta updated_first_paint = |
| 910 updated_timings().back()->paint_timing->first_paint.value(); |
| 911 |
| 912 EXPECT_FALSE(GetMostRecentTimer()->IsRunning()); |
| 913 ASSERT_EQ(2, CountUpdatedTimingReported()); |
| 914 EXPECT_LT(updated_first_paint, initial_first_paint); |
| 915 |
| 916 histogram_tester_.ExpectTotalCount( |
| 917 page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, 1); |
| 918 histogram_tester_.ExpectBucketCount( |
| 919 page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, |
| 920 (initial_first_paint - updated_first_paint).InMilliseconds(), 1); |
| 921 |
| 922 CheckNoErrorEvents(); |
| 923 } |
| 924 |
| 925 TEST_F(MetricsWebContentsObserverTest, DispatchDelayedMetricsOnPageClose) { |
| 926 mojom::PageLoadTiming timing; |
| 927 PopulatePageLoadTiming(&timing); |
| 928 timing.paint_timing->first_paint = base::TimeDelta::FromMilliseconds(1000); |
| 929 content::WebContentsTester* web_contents_tester = |
| 930 content::WebContentsTester::For(web_contents()); |
| 931 web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); |
| 932 SimulateTimingUpdateWithoutFiringDispatchTimer(timing, main_rfh()); |
| 933 |
| 934 EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
| 935 ASSERT_EQ(0, CountUpdatedTimingReported()); |
| 936 ASSERT_EQ(0, CountCompleteTimingReported()); |
| 937 |
| 938 // Navigate to a new page. This should force dispatch of the buffered timing |
| 939 // update. |
| 940 NavigateToUntrackedUrl(); |
| 941 |
| 942 ASSERT_EQ(1, CountUpdatedTimingReported()); |
| 943 ASSERT_EQ(1, CountCompleteTimingReported()); |
| 944 EXPECT_TRUE(timing.Equals(*updated_timings().back())); |
| 945 EXPECT_TRUE(timing.Equals(*complete_timings().back())); |
| 946 |
| 947 CheckNoErrorEvents(); |
| 948 } |
| 949 |
800 } // namespace page_load_metrics | 950 } // namespace page_load_metrics |
OLD | NEW |