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" |
| 20 #include "chrome/browser/page_load_metrics/page_load_metrics_update_dispatcher.h
" |
18 #include "chrome/browser/page_load_metrics/page_load_tracker.h" | 21 #include "chrome/browser/page_load_metrics/page_load_tracker.h" |
19 #include "chrome/common/page_load_metrics/page_load_metrics_messages.h" | 22 #include "chrome/common/page_load_metrics/page_load_metrics_messages.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 { |
30 | 33 |
31 namespace { | 34 namespace { |
32 | 35 |
33 const char kDefaultTestUrl[] = "https://google.com/"; | 36 const char kDefaultTestUrl[] = "https://google.com/"; |
34 const char kDefaultTestUrlAnchor[] = "https://google.com/#samedocument"; | 37 const char kDefaultTestUrlAnchor[] = "https://google.com/#samedocument"; |
35 const char kDefaultTestUrl2[] = "https://whatever.com/"; | 38 const char kDefaultTestUrl2[] = "https://whatever.com/"; |
36 const char kFilteredStartUrl[] = "https://whatever.com/ignore-on-start"; | 39 const char kFilteredStartUrl[] = "https://whatever.com/ignore-on-start"; |
37 const char kFilteredCommitUrl[] = "https://whatever.com/ignore-on-commit"; | 40 const char kFilteredCommitUrl[] = "https://whatever.com/ignore-on-commit"; |
38 | 41 |
| 42 class WeakMockTimer : public base::MockTimer, |
| 43 public base::SupportsWeakPtr<WeakMockTimer> { |
| 44 public: |
| 45 WeakMockTimer() |
| 46 : MockTimer(false /* retain_user_task */, false /* is_repeating */) {} |
| 47 }; |
| 48 |
39 // Simple PageLoadMetricsObserver that copies observed PageLoadTimings into the | 49 // Simple PageLoadMetricsObserver that copies observed PageLoadTimings into the |
40 // provided std::vector, so they can be analyzed by unit tests. | 50 // provided std::vector, so they can be analyzed by unit tests. |
41 class TestPageLoadMetricsObserver : public PageLoadMetricsObserver { | 51 class TestPageLoadMetricsObserver : public PageLoadMetricsObserver { |
42 public: | 52 public: |
43 TestPageLoadMetricsObserver( | 53 TestPageLoadMetricsObserver( |
44 std::vector<mojom::PageLoadTimingPtr>* updated_timings, | 54 std::vector<mojom::PageLoadTimingPtr>* updated_timings, |
45 std::vector<mojom::PageLoadTimingPtr>* updated_subframe_timings, | 55 std::vector<mojom::PageLoadTimingPtr>* updated_subframe_timings, |
46 std::vector<mojom::PageLoadTimingPtr>* complete_timings, | 56 std::vector<mojom::PageLoadTimingPtr>* complete_timings, |
47 std::vector<GURL>* observed_committed_urls) | 57 std::vector<GURL>* observed_committed_urls) |
48 : updated_timings_(updated_timings), | 58 : updated_timings_(updated_timings), |
(...skipping 73 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
122 | 132 |
123 bool IsNewTabPageUrl(const GURL& url) override { return is_ntp_; } | 133 bool IsNewTabPageUrl(const GURL& url) override { return is_ntp_; } |
124 void set_is_ntp(bool is_ntp) { is_ntp_ = is_ntp; } | 134 void set_is_ntp(bool is_ntp) { is_ntp_ = is_ntp; } |
125 void RegisterObservers(PageLoadTracker* tracker) override { | 135 void RegisterObservers(PageLoadTracker* tracker) override { |
126 tracker->AddObserver(base::MakeUnique<TestPageLoadMetricsObserver>( | 136 tracker->AddObserver(base::MakeUnique<TestPageLoadMetricsObserver>( |
127 &updated_timings_, &updated_subframe_timings_, &complete_timings_, | 137 &updated_timings_, &updated_subframe_timings_, &complete_timings_, |
128 &observed_committed_urls_)); | 138 &observed_committed_urls_)); |
129 tracker->AddObserver(base::MakeUnique<FilteringPageLoadMetricsObserver>( | 139 tracker->AddObserver(base::MakeUnique<FilteringPageLoadMetricsObserver>( |
130 &completed_filtered_urls_)); | 140 &completed_filtered_urls_)); |
131 } | 141 } |
| 142 std::unique_ptr<base::Timer> CreateTimer() override { |
| 143 std::unique_ptr<WeakMockTimer> timer = base::MakeUnique<WeakMockTimer>(); |
| 144 most_recent_timer_ = timer->AsWeakPtr(); |
| 145 return std::move(timer); |
| 146 } |
132 const std::vector<mojom::PageLoadTimingPtr>& updated_timings() const { | 147 const std::vector<mojom::PageLoadTimingPtr>& updated_timings() const { |
133 return updated_timings_; | 148 return updated_timings_; |
134 } | 149 } |
135 const std::vector<mojom::PageLoadTimingPtr>& complete_timings() const { | 150 const std::vector<mojom::PageLoadTimingPtr>& complete_timings() const { |
136 return complete_timings_; | 151 return complete_timings_; |
137 } | 152 } |
138 const std::vector<mojom::PageLoadTimingPtr>& updated_subframe_timings() | 153 const std::vector<mojom::PageLoadTimingPtr>& updated_subframe_timings() |
139 const { | 154 const { |
140 return updated_subframe_timings_; | 155 return updated_subframe_timings_; |
141 } | 156 } |
142 | 157 |
143 // currently_committed_urls passed to OnStart(). | 158 // currently_committed_urls passed to OnStart(). |
144 const std::vector<GURL>& observed_committed_urls_from_on_start() const { | 159 const std::vector<GURL>& observed_committed_urls_from_on_start() const { |
145 return observed_committed_urls_; | 160 return observed_committed_urls_; |
146 } | 161 } |
147 | 162 |
148 // committed URLs passed to FilteringPageLoadMetricsObserver::OnComplete(). | 163 // committed URLs passed to FilteringPageLoadMetricsObserver::OnComplete(). |
149 const std::vector<GURL>& completed_filtered_urls() const { | 164 const std::vector<GURL>& completed_filtered_urls() const { |
150 return completed_filtered_urls_; | 165 return completed_filtered_urls_; |
151 } | 166 } |
| 167 base::MockTimer* GetMostRecentTimer() const { |
| 168 return most_recent_timer_.get(); |
| 169 } |
152 | 170 |
153 private: | 171 private: |
154 std::vector<mojom::PageLoadTimingPtr> updated_timings_; | 172 std::vector<mojom::PageLoadTimingPtr> updated_timings_; |
155 std::vector<mojom::PageLoadTimingPtr> updated_subframe_timings_; | 173 std::vector<mojom::PageLoadTimingPtr> updated_subframe_timings_; |
156 std::vector<mojom::PageLoadTimingPtr> complete_timings_; | 174 std::vector<mojom::PageLoadTimingPtr> complete_timings_; |
157 std::vector<GURL> observed_committed_urls_; | 175 std::vector<GURL> observed_committed_urls_; |
158 std::vector<GURL> completed_filtered_urls_; | 176 std::vector<GURL> completed_filtered_urls_; |
| 177 base::WeakPtr<WeakMockTimer> most_recent_timer_; |
159 bool is_ntp_; | 178 bool is_ntp_; |
160 }; | 179 }; |
161 | 180 |
| 181 void PopulatePageLoadTiming(mojom::PageLoadTiming* timing) { |
| 182 page_load_metrics::InitPageLoadTimingForTest(timing); |
| 183 timing->navigation_start = base::Time::FromDoubleT(1); |
| 184 timing->response_start = base::TimeDelta::FromMilliseconds(10); |
| 185 timing->parse_timing->parse_start = base::TimeDelta::FromMilliseconds(20); |
| 186 timing->document_timing->first_layout = base::TimeDelta::FromMilliseconds(30); |
| 187 } |
| 188 |
162 } // namespace | 189 } // namespace |
163 | 190 |
164 class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { | 191 class MetricsWebContentsObserverTest : public ChromeRenderViewHostTestHarness { |
165 public: | 192 public: |
166 MetricsWebContentsObserverTest() : num_errors_(0) {} | 193 MetricsWebContentsObserverTest() : num_errors_(0) {} |
167 | 194 |
168 void SetUp() override { | 195 void SetUp() override { |
169 ChromeRenderViewHostTestHarness::SetUp(); | 196 ChromeRenderViewHostTestHarness::SetUp(); |
170 AttachObserver(); | 197 AttachObserver(); |
171 } | 198 } |
172 | 199 |
173 void NavigateToUntrackedUrl() { | 200 void NavigateToUntrackedUrl() { |
174 content::WebContentsTester::For(web_contents()) | 201 content::WebContentsTester::For(web_contents()) |
175 ->NavigateAndCommit(GURL(url::kAboutBlankURL)); | 202 ->NavigateAndCommit(GURL(url::kAboutBlankURL)); |
176 } | 203 } |
177 | 204 |
| 205 // Returns the mock timer used for buffering updates in the |
| 206 // PageLoadMetricsUpdateDispatcher. |
| 207 base::MockTimer* GetMostRecentTimer() { |
| 208 return embedder_interface_->GetMostRecentTimer(); |
| 209 } |
| 210 |
178 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing) { | 211 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing) { |
179 SimulateTimingUpdate(timing, web_contents()->GetMainFrame()); | 212 SimulateTimingUpdate(timing, web_contents()->GetMainFrame()); |
180 } | 213 } |
181 | 214 |
182 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing, | 215 void SimulateTimingUpdate(const mojom::PageLoadTiming& timing, |
183 content::RenderFrameHost* render_frame_host) { | 216 content::RenderFrameHost* render_frame_host) { |
| 217 SimulateTimingUpdateWithoutFiringDispatchTimer(timing, render_frame_host); |
| 218 // If sending the timing update caused the PageLoadMetricsUpdateDispatcher |
| 219 // to schedule a buffering timer, then fire it now so metrics are dispatched |
| 220 // to observers. |
| 221 base::MockTimer* mock_timer = GetMostRecentTimer(); |
| 222 if (mock_timer && mock_timer->IsRunning()) |
| 223 mock_timer->Fire(); |
| 224 } |
| 225 |
| 226 void SimulateTimingUpdateWithoutFiringDispatchTimer( |
| 227 const mojom::PageLoadTiming& timing, |
| 228 content::RenderFrameHost* render_frame_host) { |
184 observer()->OnTimingUpdated(render_frame_host, timing, | 229 observer()->OnTimingUpdated(render_frame_host, timing, |
185 mojom::PageLoadMetadata()); | 230 mojom::PageLoadMetadata()); |
186 } | 231 } |
187 | 232 |
188 void AttachObserver() { | 233 void AttachObserver() { |
189 auto embedder_interface = | 234 auto embedder_interface = |
190 base::MakeUnique<TestPageLoadMetricsEmbedderInterface>(); | 235 base::MakeUnique<TestPageLoadMetricsEmbedderInterface>(); |
191 embedder_interface_ = embedder_interface.get(); | 236 embedder_interface_ = embedder_interface.get(); |
192 MetricsWebContentsObserver* observer = | 237 MetricsWebContentsObserver* observer = |
193 MetricsWebContentsObserver::CreateForWebContents( | 238 MetricsWebContentsObserver::CreateForWebContents( |
(...skipping 534 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
728 | 773 |
729 ASSERT_EQ(1, CountUpdatedTimingReported()); | 774 ASSERT_EQ(1, CountUpdatedTimingReported()); |
730 EXPECT_TRUE(timing.Equals(*updated_timings().back())); | 775 EXPECT_TRUE(timing.Equals(*updated_timings().back())); |
731 | 776 |
732 content::RenderFrameHostTester* rfh_tester = | 777 content::RenderFrameHostTester* rfh_tester = |
733 content::RenderFrameHostTester::For(main_rfh()); | 778 content::RenderFrameHostTester::For(main_rfh()); |
734 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); | 779 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); |
735 | 780 |
736 // Dispatch a timing update for the child frame that includes a first paint. | 781 // Dispatch a timing update for the child frame that includes a first paint. |
737 mojom::PageLoadTiming subframe_timing; | 782 mojom::PageLoadTiming subframe_timing; |
738 page_load_metrics::InitPageLoadTimingForTest(&subframe_timing); | 783 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 = | 784 subframe_timing.paint_timing->first_paint = |
746 base::TimeDelta::FromMilliseconds(40); | 785 base::TimeDelta::FromMilliseconds(40); |
747 content::RenderFrameHostTester* subframe_tester = | 786 content::RenderFrameHostTester* subframe_tester = |
748 content::RenderFrameHostTester::For(subframe); | 787 content::RenderFrameHostTester::For(subframe); |
749 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); | 788 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
750 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); | 789 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
751 SimulateTimingUpdate(subframe_timing, subframe); | 790 SimulateTimingUpdate(subframe_timing, subframe); |
752 subframe_tester->SimulateNavigationStop(); | 791 subframe_tester->SimulateNavigationStop(); |
753 | 792 |
754 // Though a first paint was dispatched in the child, it should not yet be | 793 // 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()); | 829 ASSERT_EQ(1, CountCompleteTimingReported()); |
791 ASSERT_EQ(2, CountUpdatedTimingReported()); | 830 ASSERT_EQ(2, CountUpdatedTimingReported()); |
792 ASSERT_EQ(0, CountEmptyCompleteTimingReported()); | 831 ASSERT_EQ(0, CountEmptyCompleteTimingReported()); |
793 | 832 |
794 ASSERT_EQ(1, CountUpdatedSubFrameTimingReported()); | 833 ASSERT_EQ(1, CountUpdatedSubFrameTimingReported()); |
795 EXPECT_TRUE(subframe_timing.Equals(*updated_subframe_timings().back())); | 834 EXPECT_TRUE(subframe_timing.Equals(*updated_subframe_timings().back())); |
796 | 835 |
797 CheckNoErrorEvents(); | 836 CheckNoErrorEvents(); |
798 } | 837 } |
799 | 838 |
| 839 // We buffer cross-frame paint updates to account for paint timings from |
| 840 // different frames arriving out of order. |
| 841 TEST_F(MetricsWebContentsObserverTest, OutOfOrderCrossFrameTiming2) { |
| 842 // Dispatch a timing update for the main frame that includes a first |
| 843 // paint. This should be buffered, with the dispatch timer running. |
| 844 mojom::PageLoadTiming timing; |
| 845 PopulatePageLoadTiming(&timing); |
| 846 timing.paint_timing->first_paint = base::TimeDelta::FromMilliseconds(1000); |
| 847 content::WebContentsTester* web_contents_tester = |
| 848 content::WebContentsTester::For(web_contents()); |
| 849 web_contents_tester->NavigateAndCommit(GURL(kDefaultTestUrl)); |
| 850 SimulateTimingUpdateWithoutFiringDispatchTimer(timing, main_rfh()); |
| 851 |
| 852 EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
| 853 ASSERT_EQ(0, CountUpdatedTimingReported()); |
| 854 |
| 855 content::RenderFrameHostTester* rfh_tester = |
| 856 content::RenderFrameHostTester::For(main_rfh()); |
| 857 |
| 858 // Dispatch a timing update for a child frame that includes a first paint. |
| 859 mojom::PageLoadTiming subframe_timing; |
| 860 PopulatePageLoadTiming(&subframe_timing); |
| 861 subframe_timing.paint_timing->first_paint = |
| 862 base::TimeDelta::FromMilliseconds(500); |
| 863 content::RenderFrameHost* subframe = rfh_tester->AppendChild("subframe"); |
| 864 content::RenderFrameHostTester* subframe_tester = |
| 865 content::RenderFrameHostTester::For(subframe); |
| 866 subframe_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
| 867 subframe_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
| 868 SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe); |
| 869 subframe_tester->SimulateNavigationStop(); |
| 870 |
| 871 histogram_tester_.ExpectTotalCount( |
| 872 page_load_metrics::internal::kHistogramOutOfOrderTiming, 1); |
| 873 |
| 874 EXPECT_TRUE(GetMostRecentTimer()->IsRunning()); |
| 875 ASSERT_EQ(0, CountUpdatedTimingReported()); |
| 876 |
| 877 // At this point, the timing update is buffered, waiting for the timer to |
| 878 // fire. |
| 879 GetMostRecentTimer()->Fire(); |
| 880 |
| 881 // Firing the timer should produce a timing update. The update should be a |
| 882 // merged view of the main frame timing, with a first paint timestamp from the |
| 883 // subframe. |
| 884 ASSERT_EQ(1, CountUpdatedTimingReported()); |
| 885 EXPECT_FALSE(timing.Equals(*updated_timings().back())); |
| 886 EXPECT_TRUE( |
| 887 updated_timings().back()->parse_timing->Equals(*timing.parse_timing)); |
| 888 EXPECT_TRUE(updated_timings().back()->document_timing->Equals( |
| 889 *timing.document_timing)); |
| 890 EXPECT_FALSE( |
| 891 updated_timings().back()->paint_timing->Equals(*timing.paint_timing)); |
| 892 EXPECT_TRUE(updated_timings().back()->paint_timing->first_paint); |
| 893 |
| 894 // The first paint value should be the min of all received first paints, wich |
| 895 // in this case is the first paint from the subframe. Since it is offset by |
| 896 // the subframe's navigation start, the received value should be >= the first |
| 897 // paint value specified in the subframe. |
| 898 EXPECT_GE(updated_timings().back()->paint_timing->first_paint, |
| 899 subframe_timing.paint_timing->first_paint); |
| 900 EXPECT_LT(updated_timings().back()->paint_timing->first_paint, |
| 901 timing.paint_timing->first_paint); |
| 902 |
| 903 base::TimeDelta initial_first_paint = |
| 904 updated_timings().back()->paint_timing->first_paint.value(); |
| 905 |
| 906 // Dispatch a timing update for an additional child frame, with an earlier |
| 907 // first paint time. This should cause an immediate update, without a timer |
| 908 // delay. |
| 909 subframe_timing.paint_timing->first_paint = |
| 910 base::TimeDelta::FromMilliseconds(50); |
| 911 content::RenderFrameHost* subframe2 = rfh_tester->AppendChild("subframe"); |
| 912 content::RenderFrameHostTester* subframe2_tester = |
| 913 content::RenderFrameHostTester::For(subframe2); |
| 914 subframe2_tester->SimulateNavigationStart(GURL(kDefaultTestUrl2)); |
| 915 subframe2_tester->SimulateNavigationCommit(GURL(kDefaultTestUrl2)); |
| 916 SimulateTimingUpdateWithoutFiringDispatchTimer(subframe_timing, subframe2); |
| 917 subframe2_tester->SimulateNavigationStop(); |
| 918 |
| 919 base::TimeDelta updated_first_paint = |
| 920 updated_timings().back()->paint_timing->first_paint.value(); |
| 921 |
| 922 EXPECT_FALSE(GetMostRecentTimer()->IsRunning()); |
| 923 ASSERT_EQ(2, CountUpdatedTimingReported()); |
| 924 EXPECT_LT(updated_first_paint, initial_first_paint); |
| 925 |
| 926 histogram_tester_.ExpectTotalCount( |
| 927 page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, 1); |
| 928 histogram_tester_.ExpectBucketCount( |
| 929 page_load_metrics::internal::kHistogramOutOfOrderTimingBuffered, |
| 930 (initial_first_paint - updated_first_paint).InMilliseconds(), 1); |
| 931 |
| 932 CheckNoErrorEvents(); |
| 933 } |
| 934 |
800 } // namespace page_load_metrics | 935 } // namespace page_load_metrics |
OLD | NEW |