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 <algorithm> | 7 #include <algorithm> |
8 #include <ostream> | 8 #include <ostream> |
9 #include <string> | 9 #include <string> |
10 #include <utility> | 10 #include <utility> |
11 | 11 |
12 #include "base/location.h" | 12 #include "base/location.h" |
13 #include "base/logging.h" | |
14 #include "base/memory/ptr_util.h" | 13 #include "base/memory/ptr_util.h" |
15 #include "base/metrics/histogram_macros.h" | 14 #include "base/metrics/histogram_macros.h" |
16 #include "base/metrics/user_metrics.h" | 15 #include "base/metrics/user_metrics.h" |
17 #include "chrome/browser/page_load_metrics/browser_page_track_decider.h" | 16 #include "chrome/browser/page_load_metrics/browser_page_track_decider.h" |
| 17 #include "chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.
h" |
18 #include "chrome/browser/page_load_metrics/page_load_metrics_util.h" | 18 #include "chrome/browser/page_load_metrics/page_load_metrics_util.h" |
| 19 #include "chrome/browser/page_load_metrics/page_load_tracker.h" |
19 #include "chrome/common/page_load_metrics/page_load_metrics_messages.h" | 20 #include "chrome/common/page_load_metrics/page_load_metrics_messages.h" |
20 #include "chrome/common/page_load_metrics/page_load_timing.h" | 21 #include "chrome/common/page_load_metrics/page_load_timing.h" |
21 #include "content/public/browser/browser_thread.h" | 22 #include "content/public/browser/browser_thread.h" |
22 #include "content/public/browser/navigation_details.h" | 23 #include "content/public/browser/navigation_details.h" |
23 #include "content/public/browser/navigation_handle.h" | 24 #include "content/public/browser/navigation_handle.h" |
24 #include "content/public/browser/render_frame_host.h" | 25 #include "content/public/browser/render_frame_host.h" |
25 #include "content/public/browser/render_view_host.h" | 26 #include "content/public/browser/render_view_host.h" |
26 #include "content/public/browser/web_contents.h" | 27 #include "content/public/browser/web_contents.h" |
27 #include "content/public/browser/web_contents_observer.h" | 28 #include "content/public/browser/web_contents_observer.h" |
28 #include "content/public/browser/web_contents_user_data.h" | 29 #include "content/public/browser/web_contents_user_data.h" |
29 #include "ipc/ipc_message.h" | 30 #include "ipc/ipc_message.h" |
30 #include "ipc/ipc_message_macros.h" | 31 #include "ipc/ipc_message_macros.h" |
| 32 #include "net/base/net_errors.h" |
31 #include "ui/base/page_transition_types.h" | 33 #include "ui/base/page_transition_types.h" |
32 | 34 |
33 DEFINE_WEB_CONTENTS_USER_DATA_KEY( | 35 DEFINE_WEB_CONTENTS_USER_DATA_KEY( |
34 page_load_metrics::MetricsWebContentsObserver); | 36 page_load_metrics::MetricsWebContentsObserver); |
35 | 37 |
36 // This macro invokes the specified method on each observer, passing the | |
37 // variable length arguments as the method's arguments, and removes the observer | |
38 // from the list of observers if the given method returns STOP_OBSERVING. | |
39 #define INVOKE_AND_PRUNE_OBSERVERS(observers, Method, ...) \ | |
40 for (auto it = observers.begin(); it != observers.end();) { \ | |
41 if ((*it)->Method(__VA_ARGS__) == \ | |
42 PageLoadMetricsObserver::STOP_OBSERVING) { \ | |
43 it = observers.erase(it); \ | |
44 } else { \ | |
45 ++it; \ | |
46 } \ | |
47 } | |
48 | |
49 namespace page_load_metrics { | 38 namespace page_load_metrics { |
50 | 39 |
51 namespace internal { | |
52 | |
53 const char kErrorEvents[] = "PageLoad.Internal.ErrorCode"; | |
54 const char kAbortChainSizeReload[] = | |
55 "PageLoad.Internal.ProvisionalAbortChainSize.Reload"; | |
56 const char kAbortChainSizeForwardBack[] = | |
57 "PageLoad.Internal.ProvisionalAbortChainSize.ForwardBack"; | |
58 const char kAbortChainSizeNewNavigation[] = | |
59 "PageLoad.Internal.ProvisionalAbortChainSize.NewNavigation"; | |
60 const char kAbortChainSizeSameURL[] = | |
61 "PageLoad.Internal.ProvisionalAbortChainSize.SameURL"; | |
62 const char kAbortChainSizeNoCommit[] = | |
63 "PageLoad.Internal.ProvisionalAbortChainSize.NoCommit"; | |
64 const char kClientRedirectFirstPaintToNavigation[] = | |
65 "PageLoad.Internal.ClientRedirect.FirstPaintToNavigation"; | |
66 const char kClientRedirectWithoutPaint[] = | |
67 "PageLoad.Internal.ClientRedirect.NavigationWithoutPaint"; | |
68 const char kPageLoadCompletedAfterAppBackground[] = | |
69 "PageLoad.Internal.PageLoadCompleted.AfterAppBackground"; | |
70 | |
71 } // namespace internal | |
72 | |
73 namespace { | |
74 | |
75 // Helper to allow use of Optional<> values in LOG() messages. | |
76 std::ostream& operator<<(std::ostream& os, | |
77 const base::Optional<base::TimeDelta>& opt) { | |
78 if (opt) | |
79 os << opt.value(); | |
80 else | |
81 os << "(unset)"; | |
82 return os; | |
83 } | |
84 | |
85 // If second is non-zero, first must also be non-zero and less than or equal to | |
86 // second. | |
87 bool EventsInOrder(const base::Optional<base::TimeDelta>& first, | |
88 const base::Optional<base::TimeDelta>& second) { | |
89 if (!second) { | |
90 return true; | |
91 } | |
92 return first && first <= second; | |
93 } | |
94 | |
95 bool IsValidPageLoadTiming(const PageLoadTiming& timing) { | |
96 if (timing.IsEmpty()) | |
97 return false; | |
98 | |
99 // If we have a non-empty timing, it should always have a navigation start. | |
100 if (timing.navigation_start.is_null()) { | |
101 NOTREACHED() << "Received null navigation_start."; | |
102 return false; | |
103 } | |
104 | |
105 // Verify proper ordering between the various timings. | |
106 | |
107 if (!EventsInOrder(timing.response_start, timing.parse_start)) { | |
108 // We sometimes get a zero response_start with a non-zero parse start. See | |
109 // crbug.com/590212. | |
110 DLOG(ERROR) << "Invalid response_start " << timing.response_start | |
111 << " for parse_start " << timing.parse_start; | |
112 return false; | |
113 } | |
114 | |
115 if (!EventsInOrder(timing.parse_start, timing.parse_stop)) { | |
116 NOTREACHED() << "Invalid parse_start " << timing.parse_start | |
117 << " for parse_stop " << timing.parse_stop; | |
118 return false; | |
119 } | |
120 | |
121 if (timing.parse_stop) { | |
122 const base::TimeDelta parse_duration = | |
123 timing.parse_stop.value() - timing.parse_start.value(); | |
124 if (timing.parse_blocked_on_script_load_duration > parse_duration) { | |
125 NOTREACHED() << "Invalid parse_blocked_on_script_load_duration " | |
126 << timing.parse_blocked_on_script_load_duration | |
127 << " for parse duration " << parse_duration; | |
128 return false; | |
129 } | |
130 if (timing.parse_blocked_on_script_execution_duration > parse_duration) { | |
131 NOTREACHED() << "Invalid parse_blocked_on_script_execution_duration " | |
132 << timing.parse_blocked_on_script_execution_duration | |
133 << " for parse duration " << parse_duration; | |
134 return false; | |
135 } | |
136 } | |
137 | |
138 if (timing.parse_blocked_on_script_load_from_document_write_duration > | |
139 timing.parse_blocked_on_script_load_duration) { | |
140 NOTREACHED() | |
141 << "Invalid parse_blocked_on_script_load_from_document_write_duration " | |
142 << timing.parse_blocked_on_script_load_from_document_write_duration | |
143 << " for parse_blocked_on_script_load_duration " | |
144 << timing.parse_blocked_on_script_load_duration; | |
145 return false; | |
146 } | |
147 | |
148 if (timing.parse_blocked_on_script_execution_from_document_write_duration > | |
149 timing.parse_blocked_on_script_execution_duration) { | |
150 NOTREACHED() | |
151 << "Invalid " | |
152 "parse_blocked_on_script_execution_from_document_write_duration " | |
153 << timing.parse_blocked_on_script_execution_from_document_write_duration | |
154 << " for parse_blocked_on_script_execution_duration " | |
155 << timing.parse_blocked_on_script_execution_duration; | |
156 return false; | |
157 } | |
158 | |
159 if (!EventsInOrder(timing.parse_stop, | |
160 timing.dom_content_loaded_event_start)) { | |
161 NOTREACHED() << "Invalid parse_stop " << timing.parse_stop | |
162 << " for dom_content_loaded_event_start " | |
163 << timing.dom_content_loaded_event_start; | |
164 return false; | |
165 } | |
166 | |
167 if (!EventsInOrder(timing.dom_content_loaded_event_start, | |
168 timing.load_event_start)) { | |
169 NOTREACHED() << "Invalid dom_content_loaded_event_start " | |
170 << timing.dom_content_loaded_event_start | |
171 << " for load_event_start " << timing.load_event_start; | |
172 return false; | |
173 } | |
174 | |
175 if (!EventsInOrder(timing.parse_start, timing.first_layout)) { | |
176 NOTREACHED() << "Invalid parse_start " << timing.parse_start | |
177 << " for first_layout " << timing.first_layout; | |
178 return false; | |
179 } | |
180 | |
181 if (!EventsInOrder(timing.first_layout, timing.first_paint)) { | |
182 // This can happen when we process an XHTML document that doesn't contain | |
183 // well formed XML. See crbug.com/627607. | |
184 DLOG(ERROR) << "Invalid first_layout " << timing.first_layout | |
185 << " for first_paint " << timing.first_paint; | |
186 return false; | |
187 } | |
188 | |
189 if (!EventsInOrder(timing.first_paint, timing.first_text_paint)) { | |
190 NOTREACHED() << "Invalid first_paint " << timing.first_paint | |
191 << " for first_text_paint " << timing.first_text_paint; | |
192 return false; | |
193 } | |
194 | |
195 if (!EventsInOrder(timing.first_paint, timing.first_image_paint)) { | |
196 NOTREACHED() << "Invalid first_paint " << timing.first_paint | |
197 << " for first_image_paint " << timing.first_image_paint; | |
198 return false; | |
199 } | |
200 | |
201 if (!EventsInOrder(timing.first_paint, timing.first_contentful_paint)) { | |
202 NOTREACHED() << "Invalid first_paint " << timing.first_paint | |
203 << " for first_contentful_paint " | |
204 << timing.first_contentful_paint; | |
205 return false; | |
206 } | |
207 | |
208 if (!EventsInOrder(timing.first_paint, timing.first_meaningful_paint)) { | |
209 NOTREACHED() << "Invalid first_paint " << timing.first_paint | |
210 << " for first_meaningful_paint " | |
211 << timing.first_meaningful_paint; | |
212 return false; | |
213 } | |
214 | |
215 return true; | |
216 } | |
217 | |
218 void RecordInternalError(InternalErrorLoadEvent event) { | |
219 UMA_HISTOGRAM_ENUMERATION(internal::kErrorEvents, event, ERR_LAST_ENTRY); | |
220 } | |
221 | |
222 void RecordAppBackgroundPageLoadCompleted(bool completed_after_background) { | |
223 UMA_HISTOGRAM_BOOLEAN(internal::kPageLoadCompletedAfterAppBackground, | |
224 completed_after_background); | |
225 } | |
226 | |
227 // TODO(csharrison): Add a case for client side redirects, which is what JS | |
228 // initiated window.location / window.history navigations get set to. | |
229 UserAbortType AbortTypeForPageTransition(ui::PageTransition transition) { | |
230 if (transition & ui::PAGE_TRANSITION_CLIENT_REDIRECT) { | |
231 return ABORT_CLIENT_REDIRECT; | |
232 } | |
233 if (ui::PageTransitionCoreTypeIs(transition, ui::PAGE_TRANSITION_RELOAD)) | |
234 return ABORT_RELOAD; | |
235 if (transition & ui::PAGE_TRANSITION_FORWARD_BACK) | |
236 return ABORT_FORWARD_BACK; | |
237 if (ui::PageTransitionIsNewNavigation(transition)) | |
238 return ABORT_NEW_NAVIGATION; | |
239 NOTREACHED() | |
240 << "AbortTypeForPageTransition received unexpected ui::PageTransition: " | |
241 << transition; | |
242 return ABORT_OTHER; | |
243 } | |
244 | |
245 void LogAbortChainSameURLHistogram(int aborted_chain_size_same_url) { | |
246 if (aborted_chain_size_same_url > 0) { | |
247 UMA_HISTOGRAM_COUNTS(internal::kAbortChainSizeSameURL, | |
248 aborted_chain_size_same_url); | |
249 } | |
250 } | |
251 | |
252 void DispatchObserverTimingCallbacks(PageLoadMetricsObserver* observer, | |
253 const PageLoadTiming& last_timing, | |
254 const PageLoadTiming& new_timing, | |
255 const PageLoadMetadata& last_metadata, | |
256 const PageLoadExtraInfo& extra_info) { | |
257 if (last_timing != new_timing) | |
258 observer->OnTimingUpdate(new_timing, extra_info); | |
259 if (new_timing.dom_content_loaded_event_start && | |
260 !last_timing.dom_content_loaded_event_start) | |
261 observer->OnDomContentLoadedEventStart(new_timing, extra_info); | |
262 if (new_timing.load_event_start && !last_timing.load_event_start) | |
263 observer->OnLoadEventStart(new_timing, extra_info); | |
264 if (new_timing.first_layout && !last_timing.first_layout) | |
265 observer->OnFirstLayout(new_timing, extra_info); | |
266 if (new_timing.first_paint && !last_timing.first_paint) | |
267 observer->OnFirstPaint(new_timing, extra_info); | |
268 if (new_timing.first_text_paint && !last_timing.first_text_paint) | |
269 observer->OnFirstTextPaint(new_timing, extra_info); | |
270 if (new_timing.first_image_paint && !last_timing.first_image_paint) | |
271 observer->OnFirstImagePaint(new_timing, extra_info); | |
272 if (new_timing.first_contentful_paint && !last_timing.first_contentful_paint) | |
273 observer->OnFirstContentfulPaint(new_timing, extra_info); | |
274 if (new_timing.first_meaningful_paint && !last_timing.first_meaningful_paint) | |
275 observer->OnFirstMeaningfulPaint(new_timing, extra_info); | |
276 if (new_timing.parse_start && !last_timing.parse_start) | |
277 observer->OnParseStart(new_timing, extra_info); | |
278 if (new_timing.parse_stop && !last_timing.parse_stop) | |
279 observer->OnParseStop(new_timing, extra_info); | |
280 if (extra_info.metadata.behavior_flags != last_metadata.behavior_flags) | |
281 observer->OnLoadingBehaviorObserved(extra_info); | |
282 } | |
283 | |
284 // TODO(crbug.com/617904): Browser initiated navigations should have | |
285 // HasUserGesture() set to true. Update this once we get enough data from just | |
286 // renderer initiated aborts. | |
287 bool IsNavigationUserInitiated(content::NavigationHandle* handle) { | |
288 return handle->HasUserGesture(); | |
289 } | |
290 | |
291 } // namespace | |
292 | |
293 PageLoadTracker::PageLoadTracker( | |
294 bool in_foreground, | |
295 PageLoadMetricsEmbedderInterface* embedder_interface, | |
296 const GURL& currently_committed_url, | |
297 content::NavigationHandle* navigation_handle, | |
298 int aborted_chain_size, | |
299 int aborted_chain_size_same_url) | |
300 : did_stop_tracking_(false), | |
301 app_entered_background_(false), | |
302 navigation_start_(navigation_handle->NavigationStart()), | |
303 start_url_(navigation_handle->GetURL()), | |
304 abort_type_(ABORT_NONE), | |
305 abort_user_initiated_(false), | |
306 started_in_foreground_(in_foreground), | |
307 page_transition_(navigation_handle->GetPageTransition()), | |
308 num_cache_requests_(0), | |
309 num_network_requests_(0), | |
310 user_gesture_(IsNavigationUserInitiated(navigation_handle)), | |
311 aborted_chain_size_(aborted_chain_size), | |
312 aborted_chain_size_same_url_(aborted_chain_size_same_url), | |
313 embedder_interface_(embedder_interface) { | |
314 DCHECK(!navigation_handle->HasCommitted()); | |
315 if (embedder_interface_->IsPrerendering( | |
316 navigation_handle->GetWebContents())) { | |
317 DCHECK(!started_in_foreground_); | |
318 // For the time being, we do not track prerenders. See crbug.com/648338 for | |
319 // details. | |
320 StopTracking(); | |
321 return; | |
322 } | |
323 | |
324 embedder_interface_->RegisterObservers(this); | |
325 INVOKE_AND_PRUNE_OBSERVERS(observers_, OnStart, navigation_handle, | |
326 currently_committed_url, started_in_foreground_); | |
327 } | |
328 | |
329 PageLoadTracker::~PageLoadTracker() { | |
330 if (app_entered_background_) { | |
331 RecordAppBackgroundPageLoadCompleted(true); | |
332 } | |
333 | |
334 if (did_stop_tracking_) | |
335 return; | |
336 | |
337 if (committed_url_.is_empty()) { | |
338 if (!failed_provisional_load_info_) | |
339 RecordInternalError(ERR_NO_COMMIT_OR_FAILED_PROVISIONAL_LOAD); | |
340 | |
341 // Don't include any aborts that resulted in a new navigation, as the chain | |
342 // length will be included in the aborter PageLoadTracker. | |
343 if (abort_type_ != ABORT_RELOAD && abort_type_ != ABORT_FORWARD_BACK && | |
344 abort_type_ != ABORT_NEW_NAVIGATION) { | |
345 LogAbortChainHistograms(nullptr); | |
346 } | |
347 } else if (timing_.IsEmpty()) { | |
348 RecordInternalError(ERR_NO_IPCS_RECEIVED); | |
349 } | |
350 | |
351 const PageLoadExtraInfo info = ComputePageLoadExtraInfo(); | |
352 for (const auto& observer : observers_) { | |
353 if (failed_provisional_load_info_) { | |
354 observer->OnFailedProvisionalLoad(*failed_provisional_load_info_, info); | |
355 } else if (!info.committed_url.is_empty()) { | |
356 observer->OnComplete(timing_, info); | |
357 } | |
358 } | |
359 } | |
360 | |
361 void PageLoadTracker::LogAbortChainHistograms( | |
362 content::NavigationHandle* final_navigation) { | |
363 if (aborted_chain_size_ == 0) | |
364 return; | |
365 // Note that this could be broken out by this navigation's abort type, if more | |
366 // granularity is needed. Add one to the chain size to count the current | |
367 // navigation. In the other cases, the current navigation is the final | |
368 // navigation (which commits). | |
369 if (!final_navigation) { | |
370 UMA_HISTOGRAM_COUNTS(internal::kAbortChainSizeNoCommit, | |
371 aborted_chain_size_ + 1); | |
372 LogAbortChainSameURLHistogram(aborted_chain_size_same_url_ + 1); | |
373 return; | |
374 } | |
375 | |
376 // The following is only executed for committing trackers. | |
377 DCHECK(!committed_url_.is_empty()); | |
378 | |
379 // Note that histograms could be separated out by this commit's transition | |
380 // type, but for simplicity they will all be bucketed together. | |
381 LogAbortChainSameURLHistogram(aborted_chain_size_same_url_); | |
382 | |
383 ui::PageTransition committed_transition = | |
384 final_navigation->GetPageTransition(); | |
385 switch (AbortTypeForPageTransition(committed_transition)) { | |
386 case ABORT_RELOAD: | |
387 UMA_HISTOGRAM_COUNTS(internal::kAbortChainSizeReload, | |
388 aborted_chain_size_); | |
389 return; | |
390 case ABORT_FORWARD_BACK: | |
391 UMA_HISTOGRAM_COUNTS(internal::kAbortChainSizeForwardBack, | |
392 aborted_chain_size_); | |
393 return; | |
394 // TODO(csharrison): Refactor this code so it is based on the WillStart* | |
395 // code path instead of the committed load code path. Then, for every abort | |
396 // chain, log a histogram of the counts of each of these metrics. For now, | |
397 // merge client redirects with new navigations, which was (basically) the | |
398 // previous behavior. | |
399 case ABORT_CLIENT_REDIRECT: | |
400 case ABORT_NEW_NAVIGATION: | |
401 UMA_HISTOGRAM_COUNTS(internal::kAbortChainSizeNewNavigation, | |
402 aborted_chain_size_); | |
403 return; | |
404 default: | |
405 NOTREACHED() | |
406 << "LogAbortChainHistograms received unexpected ui::PageTransition: " | |
407 << committed_transition; | |
408 return; | |
409 } | |
410 } | |
411 | |
412 void PageLoadTracker::WebContentsHidden() { | |
413 // Only log the first time we background in a given page load. | |
414 if (background_time_.is_null()) { | |
415 // Make sure we either started in the foreground and haven't been | |
416 // foregrounded yet, or started in the background and have already been | |
417 // foregrounded. | |
418 DCHECK_EQ(started_in_foreground_, foreground_time_.is_null()); | |
419 background_time_ = base::TimeTicks::Now(); | |
420 ClampBrowserTimestampIfInterProcessTimeTickSkew(&background_time_); | |
421 // Though most cases where a tab is backgrounded are user initiated, we | |
422 // can't be certain that we were backgrounded due to a user action. For | |
423 // example, on Android, the screen times out after a period of inactivity, | |
424 // resulting in a non-user-initiated backgrounding. | |
425 const bool abort_is_user_initiated = false; | |
426 NotifyAbort(ABORT_BACKGROUND, abort_is_user_initiated, background_time_, | |
427 true); | |
428 } | |
429 | |
430 for (const auto& observer : observers_) | |
431 observer->OnHidden(); | |
432 } | |
433 | |
434 void PageLoadTracker::WebContentsShown() { | |
435 // Only log the first time we foreground in a given page load. | |
436 if (foreground_time_.is_null()) { | |
437 // Make sure we either started in the background and haven't been | |
438 // backgrounded yet, or started in the foreground and have already been | |
439 // backgrounded. | |
440 DCHECK_NE(started_in_foreground_, background_time_.is_null()); | |
441 foreground_time_ = base::TimeTicks::Now(); | |
442 ClampBrowserTimestampIfInterProcessTimeTickSkew(&foreground_time_); | |
443 } | |
444 | |
445 for (const auto& observer : observers_) | |
446 observer->OnShown(); | |
447 } | |
448 | |
449 void PageLoadTracker::Commit(content::NavigationHandle* navigation_handle) { | |
450 committed_url_ = navigation_handle->GetURL(); | |
451 // Some transitions (like CLIENT_REDIRECT) are only known at commit time. | |
452 page_transition_ = navigation_handle->GetPageTransition(); | |
453 user_gesture_ = navigation_handle->HasUserGesture(); | |
454 | |
455 INVOKE_AND_PRUNE_OBSERVERS(observers_, OnCommit, navigation_handle); | |
456 LogAbortChainHistograms(navigation_handle); | |
457 } | |
458 | |
459 void PageLoadTracker::FailedProvisionalLoad( | |
460 content::NavigationHandle* navigation_handle) { | |
461 DCHECK(!failed_provisional_load_info_); | |
462 failed_provisional_load_info_.reset(new FailedProvisionalLoadInfo( | |
463 base::TimeTicks::Now() - navigation_handle->NavigationStart(), | |
464 navigation_handle->GetNetErrorCode())); | |
465 } | |
466 | |
467 void PageLoadTracker::Redirect(content::NavigationHandle* navigation_handle) { | |
468 for (const auto& observer : observers_) { | |
469 observer->OnRedirect(navigation_handle); | |
470 } | |
471 } | |
472 | |
473 void PageLoadTracker::OnInputEvent(const blink::WebInputEvent& event) { | |
474 for (const auto& observer : observers_) { | |
475 observer->OnUserInput(event); | |
476 } | |
477 } | |
478 | |
479 void PageLoadTracker::FlushMetricsOnAppEnterBackground() { | |
480 if (!app_entered_background_) { | |
481 RecordAppBackgroundPageLoadCompleted(false); | |
482 app_entered_background_ = true; | |
483 } | |
484 | |
485 const PageLoadExtraInfo info = ComputePageLoadExtraInfo(); | |
486 INVOKE_AND_PRUNE_OBSERVERS(observers_, FlushMetricsOnAppEnterBackground, | |
487 timing_, info); | |
488 } | |
489 | |
490 void PageLoadTracker::NotifyClientRedirectTo( | |
491 const PageLoadTracker& destination) { | |
492 if (timing_.first_paint) { | |
493 base::TimeTicks first_paint_time = | |
494 navigation_start() + timing_.first_paint.value(); | |
495 base::TimeDelta first_paint_to_navigation; | |
496 if (destination.navigation_start() > first_paint_time) | |
497 first_paint_to_navigation = | |
498 destination.navigation_start() - first_paint_time; | |
499 PAGE_LOAD_HISTOGRAM(internal::kClientRedirectFirstPaintToNavigation, | |
500 first_paint_to_navigation); | |
501 } else { | |
502 UMA_HISTOGRAM_BOOLEAN(internal::kClientRedirectWithoutPaint, true); | |
503 } | |
504 } | |
505 | |
506 bool PageLoadTracker::UpdateTiming(const PageLoadTiming& new_timing, | |
507 const PageLoadMetadata& new_metadata) { | |
508 // Throw away IPCs that are not relevant to the current navigation. | |
509 // Two timing structures cannot refer to the same navigation if they indicate | |
510 // that a navigation started at different times, so a new timing struct with a | |
511 // different start time from an earlier struct is considered invalid. | |
512 bool valid_timing_descendent = | |
513 timing_.navigation_start.is_null() || | |
514 timing_.navigation_start == new_timing.navigation_start; | |
515 // Ensure flags sent previously are still present in the new metadata fields. | |
516 bool valid_behavior_descendent = | |
517 (metadata_.behavior_flags & new_metadata.behavior_flags) == | |
518 metadata_.behavior_flags; | |
519 if (IsValidPageLoadTiming(new_timing) && valid_timing_descendent && | |
520 valid_behavior_descendent) { | |
521 DCHECK(!committed_url_.is_empty()); // OnCommit() must be called first. | |
522 // There are some subtle ordering constraints here. GetPageLoadMetricsInfo() | |
523 // must be called before DispatchObserverTimingCallbacks, but its | |
524 // implementation depends on the state of metadata_, so we need to update | |
525 // metadata_ before calling GetPageLoadMetricsInfo. Thus, we make a copy of | |
526 // timing here, update timing_ and metadata_, and then proceed to dispatch | |
527 // the observer timing callbacks. | |
528 const PageLoadTiming last_timing = timing_; | |
529 timing_ = new_timing; | |
530 | |
531 const PageLoadMetadata last_metadata = metadata_; | |
532 metadata_ = new_metadata; | |
533 const PageLoadExtraInfo info = ComputePageLoadExtraInfo(); | |
534 for (const auto& observer : observers_) { | |
535 DispatchObserverTimingCallbacks(observer.get(), last_timing, new_timing, | |
536 last_metadata, info); | |
537 } | |
538 return true; | |
539 } | |
540 return false; | |
541 } | |
542 | |
543 void PageLoadTracker::OnLoadedSubresource(bool was_cached) { | |
544 if (was_cached) { | |
545 ++num_cache_requests_; | |
546 } else { | |
547 ++num_network_requests_; | |
548 } | |
549 } | |
550 | |
551 void PageLoadTracker::StopTracking() { | |
552 did_stop_tracking_ = true; | |
553 observers_.clear(); | |
554 } | |
555 | |
556 void PageLoadTracker::AddObserver( | |
557 std::unique_ptr<PageLoadMetricsObserver> observer) { | |
558 observers_.push_back(std::move(observer)); | |
559 } | |
560 | |
561 void PageLoadTracker::ClampBrowserTimestampIfInterProcessTimeTickSkew( | |
562 base::TimeTicks* event_time) { | |
563 DCHECK(event_time != nullptr); | |
564 // Windows 10 GCE bot non-deterministically failed because TimeTicks::Now() | |
565 // called in the browser process e.g. commit_time was less than | |
566 // navigation_start_ that was populated in the renderer process because the | |
567 // clock was not system-wide monotonic. | |
568 // Note that navigation_start_ can also be set in the browser process in | |
569 // some cases and in those cases event_time should never be < | |
570 // navigation_start_. If it is due to a code error and it gets clamped in this | |
571 // function, on high resolution systems it should lead to a dcheck failure. | |
572 | |
573 // TODO(shivanisha): Currently IsHighResolution is the best way to check | |
574 // if the clock is system-wide monotonic. However IsHighResolution | |
575 // does a broader check to see if the clock in use is high resolution | |
576 // which also implies it is system-wide monotonic (on Windows). | |
577 if (base::TimeTicks::IsHighResolution()) { | |
578 DCHECK(event_time->is_null() || *event_time >= navigation_start_); | |
579 return; | |
580 } | |
581 | |
582 if (!event_time->is_null() && *event_time < navigation_start_) { | |
583 RecordInternalError(ERR_INTER_PROCESS_TIME_TICK_SKEW); | |
584 *event_time = navigation_start_; | |
585 } | |
586 } | |
587 | |
588 PageLoadExtraInfo PageLoadTracker::ComputePageLoadExtraInfo() { | |
589 base::Optional<base::TimeDelta> first_background_time; | |
590 base::Optional<base::TimeDelta> first_foreground_time; | |
591 base::Optional<base::TimeDelta> time_to_abort; | |
592 | |
593 if (!background_time_.is_null()) { | |
594 DCHECK_GE(background_time_, navigation_start_); | |
595 first_background_time = background_time_ - navigation_start_; | |
596 } | |
597 | |
598 if (!foreground_time_.is_null()) { | |
599 DCHECK_GE(foreground_time_, navigation_start_); | |
600 first_foreground_time = foreground_time_ - navigation_start_; | |
601 } | |
602 | |
603 if (abort_type_ != ABORT_NONE) { | |
604 DCHECK_GE(abort_time_, navigation_start_); | |
605 time_to_abort = abort_time_ - navigation_start_; | |
606 } else { | |
607 DCHECK(abort_time_.is_null()); | |
608 } | |
609 | |
610 // abort_type_ == ABORT_NONE implies !abort_user_initiated_. | |
611 DCHECK(abort_type_ != ABORT_NONE || !abort_user_initiated_); | |
612 return PageLoadExtraInfo( | |
613 first_background_time, first_foreground_time, started_in_foreground_, | |
614 user_gesture_, committed_url_, start_url_, abort_type_, | |
615 abort_user_initiated_, time_to_abort, num_cache_requests_, | |
616 num_network_requests_, metadata_); | |
617 } | |
618 | |
619 void PageLoadTracker::NotifyAbort(UserAbortType abort_type, | |
620 bool user_initiated, | |
621 base::TimeTicks timestamp, | |
622 bool is_certainly_browser_timestamp) { | |
623 DCHECK_NE(abort_type, ABORT_NONE); | |
624 // Use UpdateAbort to update an already notified PageLoadTracker. | |
625 if (abort_type_ != ABORT_NONE) | |
626 return; | |
627 | |
628 UpdateAbortInternal(abort_type, user_initiated, timestamp, | |
629 is_certainly_browser_timestamp); | |
630 } | |
631 | |
632 void PageLoadTracker::UpdateAbort(UserAbortType abort_type, | |
633 bool user_initiated, | |
634 base::TimeTicks timestamp, | |
635 bool is_certainly_browser_timestamp) { | |
636 DCHECK_NE(abort_type, ABORT_NONE); | |
637 DCHECK_NE(abort_type, ABORT_OTHER); | |
638 DCHECK_EQ(abort_type_, ABORT_OTHER); | |
639 | |
640 // For some aborts (e.g. navigations), the initiated timestamp can be earlier | |
641 // than the timestamp that aborted the load. Taking the minimum gives the | |
642 // closest user initiated time known. | |
643 UpdateAbortInternal(abort_type, user_initiated, | |
644 std::min(abort_time_, timestamp), | |
645 is_certainly_browser_timestamp); | |
646 } | |
647 | |
648 bool PageLoadTracker::IsLikelyProvisionalAbort( | |
649 base::TimeTicks abort_cause_time) const { | |
650 // Note that |abort_cause_time - abort_time| can be negative. | |
651 return abort_type_ == ABORT_OTHER && | |
652 (abort_cause_time - abort_time_).InMilliseconds() < 100; | |
653 } | |
654 | |
655 bool PageLoadTracker::MatchesOriginalNavigation( | |
656 content::NavigationHandle* navigation_handle) { | |
657 // Neither navigation should have committed. | |
658 DCHECK(!navigation_handle->HasCommitted()); | |
659 DCHECK(committed_url_.is_empty()); | |
660 return navigation_handle->GetURL() == start_url_; | |
661 } | |
662 | |
663 void PageLoadTracker::UpdateAbortInternal(UserAbortType abort_type, | |
664 bool user_initiated, | |
665 base::TimeTicks timestamp, | |
666 bool is_certainly_browser_timestamp) { | |
667 // When a provisional navigation commits, that navigation's start time is | |
668 // interpreted as the abort time for other provisional loads in the tab. | |
669 // However, this only makes sense if the committed load started after the | |
670 // aborted provisional loads started. Thus we ignore cases where the committed | |
671 // load started before the aborted provisional load, as this would result in | |
672 // recording a negative time-to-abort. The real issue here is that we have to | |
673 // infer the cause of aborts. It would be better if the navigation code could | |
674 // instead report the actual cause of an aborted navigation. See crbug/571647 | |
675 // for details. | |
676 if (timestamp < navigation_start_) { | |
677 RecordInternalError(ERR_ABORT_BEFORE_NAVIGATION_START); | |
678 abort_type_ = ABORT_NONE; | |
679 abort_time_ = base::TimeTicks(); | |
680 return; | |
681 } | |
682 abort_type_ = abort_type; | |
683 abort_time_ = timestamp; | |
684 abort_user_initiated_ = user_initiated && abort_type != ABORT_CLIENT_REDIRECT; | |
685 | |
686 if (is_certainly_browser_timestamp) { | |
687 ClampBrowserTimestampIfInterProcessTimeTickSkew(&abort_time_); | |
688 } | |
689 } | |
690 | |
691 // static | 40 // static |
692 MetricsWebContentsObserver::MetricsWebContentsObserver( | 41 MetricsWebContentsObserver::MetricsWebContentsObserver( |
693 content::WebContents* web_contents, | 42 content::WebContents* web_contents, |
694 std::unique_ptr<PageLoadMetricsEmbedderInterface> embedder_interface) | 43 std::unique_ptr<PageLoadMetricsEmbedderInterface> embedder_interface) |
695 : content::WebContentsObserver(web_contents), | 44 : content::WebContentsObserver(web_contents), |
696 in_foreground_(false), | 45 in_foreground_(false), |
697 embedder_interface_(std::move(embedder_interface)), | 46 embedder_interface_(std::move(embedder_interface)), |
698 has_navigated_(false) { | 47 has_navigated_(false) { |
699 RegisterInputEventObserver(web_contents->GetRenderViewHost()); | 48 RegisterInputEventObserver(web_contents->GetRenderViewHost()); |
700 } | 49 } |
(...skipping 389 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1090 content::NavigationHandle* navigation_handle) const { | 439 content::NavigationHandle* navigation_handle) const { |
1091 DCHECK(navigation_handle->IsInMainFrame()); | 440 DCHECK(navigation_handle->IsInMainFrame()); |
1092 DCHECK(!navigation_handle->HasCommitted() || | 441 DCHECK(!navigation_handle->HasCommitted() || |
1093 !navigation_handle->IsSamePage()); | 442 !navigation_handle->IsSamePage()); |
1094 | 443 |
1095 return BrowserPageTrackDecider(embedder_interface_.get(), web_contents(), | 444 return BrowserPageTrackDecider(embedder_interface_.get(), web_contents(), |
1096 navigation_handle).ShouldTrack(); | 445 navigation_handle).ShouldTrack(); |
1097 } | 446 } |
1098 | 447 |
1099 } // namespace page_load_metrics | 448 } // namespace page_load_metrics |
OLD | NEW |