Roll Clang 206824:209387
[chromium-blink-merge.git] / chrome / renderer / page_load_histograms.cc
blob5de81080eefb9fdfe71e8713bcfca052dc3b8016
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
5 #include "chrome/renderer/page_load_histograms.h"
7 #include <string>
9 #include "base/command_line.h"
10 #include "base/logging.h"
11 #include "base/metrics/field_trial.h"
12 #include "base/metrics/histogram.h"
13 #include "base/strings/string_number_conversions.h"
14 #include "base/strings/string_split.h"
15 #include "base/strings/string_util.h"
16 #include "base/strings/stringprintf.h"
17 #include "base/strings/utf_string_conversions.h"
18 #include "base/time/time.h"
19 #include "chrome/common/chrome_switches.h"
20 #include "chrome/renderer/chrome_content_renderer_client.h"
21 #include "content/public/common/content_constants.h"
22 #include "content/public/renderer/document_state.h"
23 #include "content/public/renderer/render_thread.h"
24 #include "content/public/renderer/render_view.h"
25 #include "extensions/common/url_pattern.h"
26 #include "net/base/url_util.h"
27 #include "net/http/http_response_headers.h"
28 #include "third_party/WebKit/public/platform/WebURLRequest.h"
29 #include "third_party/WebKit/public/platform/WebURLResponse.h"
30 #include "third_party/WebKit/public/web/WebDocument.h"
31 #include "third_party/WebKit/public/web/WebFrame.h"
32 #include "third_party/WebKit/public/web/WebPerformance.h"
33 #include "third_party/WebKit/public/web/WebView.h"
34 #include "url/gurl.h"
36 using blink::WebDataSource;
37 using blink::WebFrame;
38 using blink::WebPerformance;
39 using blink::WebString;
40 using base::Time;
41 using base::TimeDelta;
42 using content::DocumentState;
44 const size_t kPLTCount = 100;
46 namespace {
48 // ID indicating that no GWS-Chrome joint experiment is active.
49 const int kNoExperiment = 0;
51 // Max ID of GWS-Chrome joint experiment. If you change this value, please
52 // update PLT_HISTOGRAM_WITH_GWS_VARIANT accordingly.
53 const int kMaxExperimentID = 20;
55 TimeDelta kPLTMin() {
56 return TimeDelta::FromMilliseconds(10);
58 TimeDelta kPLTMax() {
59 return TimeDelta::FromMinutes(10);
62 // This function corresponds to PLT_HISTOGRAM macro invocation without caching.
63 // Use this for PLT histograms with dynamically generated names, which
64 // otherwise can't use the caching PLT_HISTOGRAM macro without code duplication.
65 void PltHistogramWithNoMacroCaching(const std::string& name,
66 const TimeDelta& sample) {
67 // The parameters should exacly match the parameters in
68 // UMA_HISTOGRAM_CUSTOM_TIMES macro.
69 base::HistogramBase* histogram_pointer = base::Histogram::FactoryTimeGet(
70 name, kPLTMin(), kPLTMax(), kPLTCount,
71 base::HistogramBase::kUmaTargetedHistogramFlag);
72 histogram_pointer->AddTime(sample);
75 // This records UMA corresponding to the PLT_HISTOGRAM macro without caching.
76 void PltHistogramWithGwsPreview(const char* name,
77 const TimeDelta& sample,
78 bool is_preview,
79 int experiment_id) {
80 std::string preview_suffix = is_preview ? "_Preview" : "_NoPreview";
81 PltHistogramWithNoMacroCaching(name + preview_suffix, sample);
83 if (experiment_id != kNoExperiment) {
84 std::string name_with_experiment_id = base::StringPrintf(
85 "%s%s_Experiment%d", name, preview_suffix.c_str(), experiment_id);
86 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample);
90 #define PLT_HISTOGRAM(name, sample) \
91 UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, kPLTMin(), kPLTMax(), kPLTCount);
93 #define PLT_HISTOGRAM_WITH_GWS_VARIANT( \
94 name, sample, came_from_websearch, websearch_chrome_joint_experiment_id, \
95 is_preview) { \
96 PLT_HISTOGRAM(name, sample); \
97 if (came_from_websearch) { \
98 PLT_HISTOGRAM(base::StringPrintf("%s_FromGWS", name), sample) \
99 if (websearch_chrome_joint_experiment_id != kNoExperiment) { \
100 std::string name_with_experiment_id = base::StringPrintf( \
101 "%s_FromGWS_Experiment%d", \
102 name, websearch_chrome_joint_experiment_id); \
103 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample); \
106 PltHistogramWithGwsPreview(name, sample, is_preview, \
107 websearch_chrome_joint_experiment_id); \
110 // In addition to PLT_HISTOGRAM, add the *_DataReductionProxy variant
111 // conditionally. This macro runs only in one thread.
112 #define PLT_HISTOGRAM_DRP(name, sample, data_reduction_proxy_was_used) \
113 do { \
114 static base::HistogramBase* counter(NULL); \
115 static base::HistogramBase* drp_counter(NULL); \
116 if (!counter) { \
117 DCHECK(drp_counter == NULL); \
118 counter = base::Histogram::FactoryTimeGet( \
119 name, kPLTMin(), kPLTMax(), kPLTCount, \
120 base::Histogram::kUmaTargetedHistogramFlag); \
122 counter->AddTime(sample); \
123 if (!data_reduction_proxy_was_used) break; \
124 if (!drp_counter) { \
125 drp_counter = base::Histogram::FactoryTimeGet( \
126 std::string(name) + "_DataReductionProxy", \
127 kPLTMin(), kPLTMax(), kPLTCount, \
128 base::Histogram::kUmaTargetedHistogramFlag); \
130 drp_counter->AddTime(sample); \
131 } while (0)
133 // Returns the scheme type of the given URL if its type is one for which we
134 // dump page load histograms. Otherwise returns NULL.
135 URLPattern::SchemeMasks GetSupportedSchemeType(const GURL& url) {
136 if (url.SchemeIs("http"))
137 return URLPattern::SCHEME_HTTP;
138 else if (url.SchemeIs("https"))
139 return URLPattern::SCHEME_HTTPS;
140 return static_cast<URLPattern::SchemeMasks>(0);
143 // Helper function to check for string in 'via' header. Returns true if
144 // |via_value| is one of the values listed in the Via header and the response
145 // was fetched via a proxy.
146 bool ViaHeaderContains(WebFrame* frame, const std::string& via_value) {
147 const char kViaHeaderName[] = "Via";
149 DocumentState* document_state =
150 DocumentState::FromDataSource(frame->dataSource());
151 if (!document_state->was_fetched_via_proxy())
152 return false;
154 std::vector<std::string> values;
155 // Multiple via headers have already been coalesced and hence each value
156 // separated by a comma corresponds to a proxy. The value added by a proxy is
157 // not expected to contain any commas.
158 // Example., Via: 1.0 Compression proxy, 1.1 Google Instant Proxy Preview
159 base::SplitString(
160 frame->dataSource()->response().httpHeaderField(kViaHeaderName).utf8(),
161 ',', &values);
162 return std::find(values.begin(), values.end(), via_value) != values.end();
165 // Returns true if the data reduction proxy was used. Note, this function will
166 // produce a false positive if a page is fetched using SPDY and using a proxy,
167 // and the data reduction proxy's via value is added to the Via header.
168 // TODO(bengr): Plumb the hostname of the proxy and check if it matches
169 // |SPDY_PROXY_AUTH_ORIGIN|.
170 bool DataReductionProxyWasUsed(WebFrame* frame) {
171 DocumentState* document_state =
172 DocumentState::FromDataSource(frame->dataSource());
173 if (!document_state->was_fetched_via_proxy())
174 return false;
176 std::string via_header =
177 base::UTF16ToUTF8(frame->dataSource()->response().httpHeaderField("Via"));
179 if (via_header.empty())
180 return false;
181 std::string headers = "HTTP/1.1 200 OK\nVia: " + via_header + "\n\n";
182 // Produce raw headers, expected by the |HttpResponseHeaders| constructor.
183 std::replace(headers.begin(), headers.end(), '\n', '\0');
184 scoped_refptr<net::HttpResponseHeaders> response_headers(
185 new net::HttpResponseHeaders(headers));
186 return response_headers->IsDataReductionProxyResponse();
189 // Returns true if the provided URL is a referrer string that came from
190 // a Google Web Search results page. This is a little non-deterministic
191 // because desktop and mobile websearch differ and sometimes just provide
192 // http://www.google.com/ as the referrer. In the case of /url we can be sure
193 // that it came from websearch but we will be generous and allow for cases
194 // where a non-Google URL was provided a bare Google URL as a referrer.
195 // The domain validation matches the code used by the prerenderer for similar
196 // purposes.
197 // TODO(pmeenan): Remove the fuzzy logic when the referrer is reliable
198 bool IsFromGoogleSearchResult(const GURL& url, const GURL& referrer) {
199 if (!StartsWithASCII(referrer.host(), "www.google.", true))
200 return false;
201 if (StartsWithASCII(referrer.path(), "/url", true))
202 return true;
203 bool is_possible_search_referrer =
204 referrer.path().empty() ||
205 referrer.path() == "/" ||
206 StartsWithASCII(referrer.path(), "/search", true) ||
207 StartsWithASCII(referrer.path(), "/webhp", true);
208 if (is_possible_search_referrer &&
209 !StartsWithASCII(url.host(), "www.google", true))
210 return true;
211 return false;
214 // Extracts a Google Web Search and Chrome joint experiment ID from a referrer
215 // that came from a Google Web Search results page. An experiment ID is embedded
216 // in a query string as a "gcjeid=" parameter value.
217 int GetQueryStringBasedExperiment(const GURL& referrer) {
218 std::string value;
219 if (!net::GetValueForKeyInQuery(referrer, "gcjeid", &value))
220 return kNoExperiment;
222 int experiment_id;
223 if (!base::StringToInt(value, &experiment_id))
224 return kNoExperiment;
225 if (0 < experiment_id && experiment_id <= kMaxExperimentID)
226 return experiment_id;
227 return kNoExperiment;
230 void DumpPerformanceTiming(const WebPerformance& performance,
231 DocumentState* document_state,
232 bool data_reduction_proxy_was_used,
233 bool came_from_websearch,
234 int websearch_chrome_joint_experiment_id,
235 bool is_preview) {
236 Time request = document_state->request_time();
238 Time navigation_start = Time::FromDoubleT(performance.navigationStart());
239 Time redirect_start = Time::FromDoubleT(performance.redirectStart());
240 Time redirect_end = Time::FromDoubleT(performance.redirectEnd());
241 Time fetch_start = Time::FromDoubleT(performance.fetchStart());
242 Time domain_lookup_start = Time::FromDoubleT(performance.domainLookupStart());
243 Time domain_lookup_end = Time::FromDoubleT(performance.domainLookupEnd());
244 Time connect_start = Time::FromDoubleT(performance.connectStart());
245 Time connect_end = Time::FromDoubleT(performance.connectEnd());
246 Time request_start = Time::FromDoubleT(performance.requestStart());
247 Time response_start = Time::FromDoubleT(performance.responseStart());
248 Time response_end = Time::FromDoubleT(performance.responseEnd());
249 Time dom_loading = Time::FromDoubleT(performance.domLoading());
250 Time dom_interactive = Time::FromDoubleT(performance.domInteractive());
251 Time dom_content_loaded_start =
252 Time::FromDoubleT(performance.domContentLoadedEventStart());
253 Time dom_content_loaded_end =
254 Time::FromDoubleT(performance.domContentLoadedEventEnd());
255 Time load_event_start = Time::FromDoubleT(performance.loadEventStart());
256 Time load_event_end = Time::FromDoubleT(performance.loadEventEnd());
257 Time begin = (request.is_null() ? navigation_start : request_start);
259 DCHECK(!navigation_start.is_null());
261 // It is possible for a document to have navigation_start time, but no
262 // request_start. An example is doing a window.open, which synchronously
263 // loads "about:blank", then using document.write add a meta http-equiv
264 // refresh tag, which causes a navigation. In such case, we will arrive at
265 // this function with no request/response timing data and identical load
266 // start/end values. Avoid logging this case, as it doesn't add any
267 // meaningful information to the histogram.
268 if (request_start.is_null())
269 return;
271 // TODO(dominich): Investigate conditions under which |load_event_start| and
272 // |load_event_end| may be NULL as in the non-PT_ case below. Examples in
273 // http://crbug.com/112006.
274 // DCHECK(!load_event_start.is_null());
275 // DCHECK(!load_event_end.is_null());
277 if (document_state->web_timing_histograms_recorded())
278 return;
279 document_state->set_web_timing_histograms_recorded(true);
281 if (!redirect_start.is_null() && !redirect_end.is_null()) {
282 PLT_HISTOGRAM_DRP("PLT.NT_Redirect", redirect_end - redirect_start,
283 data_reduction_proxy_was_used);
284 PLT_HISTOGRAM_DRP(
285 "PLT.NT_DelayBeforeFetchRedirect",
286 (fetch_start - navigation_start) - (redirect_end - redirect_start),
287 data_reduction_proxy_was_used);
288 } else {
289 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeFetch",
290 fetch_start - navigation_start,
291 data_reduction_proxy_was_used);
293 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomainLookup",
294 domain_lookup_start - fetch_start,
295 data_reduction_proxy_was_used);
296 PLT_HISTOGRAM_DRP("PLT.NT_DomainLookup",
297 domain_lookup_end - domain_lookup_start,
298 data_reduction_proxy_was_used);
299 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeConnect",
300 connect_start - domain_lookup_end,
301 data_reduction_proxy_was_used);
302 PLT_HISTOGRAM_DRP("PLT.NT_Connect", connect_end - connect_start,
303 data_reduction_proxy_was_used);
304 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeRequest",
305 request_start - connect_end,
306 data_reduction_proxy_was_used);
307 PLT_HISTOGRAM_DRP("PLT.NT_Request", response_start - request_start,
308 data_reduction_proxy_was_used);
309 PLT_HISTOGRAM_DRP("PLT.NT_Response", response_end - response_start,
310 data_reduction_proxy_was_used);
312 if (!dom_loading.is_null()) {
313 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomLoading",
314 dom_loading - response_start,
315 data_reduction_proxy_was_used);
317 if (!dom_interactive.is_null() && !dom_loading.is_null()) {
318 PLT_HISTOGRAM_DRP("PLT.NT_DomLoading",
319 dom_interactive - dom_loading,
320 data_reduction_proxy_was_used);
322 if (!dom_content_loaded_start.is_null() && !dom_interactive.is_null()) {
323 PLT_HISTOGRAM_DRP("PLT.NT_DomInteractive",
324 dom_content_loaded_start - dom_interactive,
325 data_reduction_proxy_was_used);
327 if (!dom_content_loaded_start.is_null() &&
328 !dom_content_loaded_end.is_null() ) {
329 PLT_HISTOGRAM_DRP("PLT.NT_DomContentLoaded",
330 dom_content_loaded_end - dom_content_loaded_start,
331 data_reduction_proxy_was_used);
333 if (!dom_content_loaded_end.is_null() && !load_event_start.is_null()) {
334 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeLoadEvent",
335 load_event_start - dom_content_loaded_end,
336 data_reduction_proxy_was_used);
339 // TODO(simonjam): There is no way to distinguish between abandonment and
340 // intentional Javascript navigation before the load event fires.
341 // TODO(dominich): Load type breakdown
342 if (!load_event_start.is_null()) {
343 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinishDoc",
344 load_event_start - begin,
345 came_from_websearch,
346 websearch_chrome_joint_experiment_id,
347 is_preview);
348 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinishDoc",
349 load_event_start - response_start,
350 came_from_websearch,
351 websearch_chrome_joint_experiment_id,
352 is_preview);
353 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinishDoc",
354 load_event_start - navigation_start,
355 came_from_websearch,
356 websearch_chrome_joint_experiment_id,
357 is_preview);
358 if (data_reduction_proxy_was_used) {
359 PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_DataReductionProxy",
360 load_event_start - begin);
361 PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_DataReductionProxy",
362 load_event_start - response_start);
363 PLT_HISTOGRAM("PLT.PT_RequestToFinishDoc_DataReductionProxy",
364 load_event_start - navigation_start);
367 if (!load_event_end.is_null()) {
368 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinish",
369 load_event_end - begin,
370 came_from_websearch,
371 websearch_chrome_joint_experiment_id,
372 is_preview);
373 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinish",
374 load_event_end - response_start,
375 came_from_websearch,
376 websearch_chrome_joint_experiment_id,
377 is_preview);
378 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinish",
379 load_event_end - navigation_start,
380 came_from_websearch,
381 websearch_chrome_joint_experiment_id,
382 is_preview);
383 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToFinish",
384 load_event_end - request_start,
385 came_from_websearch,
386 websearch_chrome_joint_experiment_id,
387 is_preview);
388 if (data_reduction_proxy_was_used) {
389 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy",
390 load_event_end - begin);
391 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy",
392 load_event_end - response_start);
393 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy",
394 load_event_end - navigation_start);
395 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy",
396 load_event_end - request_start);
399 if (!load_event_start.is_null() && !load_event_end.is_null()) {
400 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish",
401 load_event_end - load_event_start);
402 PLT_HISTOGRAM_DRP("PLT.NT_LoadEvent",
403 load_event_end - load_event_start,
404 data_reduction_proxy_was_used);
406 if (data_reduction_proxy_was_used)
407 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_DataReductionProxy",
408 load_event_end - load_event_start);
410 if (!dom_content_loaded_start.is_null()) {
411 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToDomContentLoaded",
412 dom_content_loaded_start - navigation_start,
413 came_from_websearch,
414 websearch_chrome_joint_experiment_id,
415 is_preview);
416 if (data_reduction_proxy_was_used)
417 PLT_HISTOGRAM("PLT.PT_RequestToDomContentLoaded_DataReductionProxy",
418 dom_content_loaded_start - navigation_start);
420 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToCommit",
421 response_start - begin,
422 came_from_websearch,
423 websearch_chrome_joint_experiment_id,
424 is_preview);
425 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToStart",
426 request_start - navigation_start,
427 came_from_websearch,
428 websearch_chrome_joint_experiment_id,
429 is_preview);
430 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToCommit",
431 response_start - request_start,
432 came_from_websearch,
433 websearch_chrome_joint_experiment_id,
434 is_preview);
435 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToCommit",
436 response_start - navigation_start,
437 came_from_websearch,
438 websearch_chrome_joint_experiment_id,
439 is_preview);
440 if (data_reduction_proxy_was_used) {
441 PLT_HISTOGRAM("PLT.PT_BeginToCommit_DataReductionProxy",
442 response_start - begin);
443 PLT_HISTOGRAM("PLT.PT_RequestToStart_DataReductionProxy",
444 request_start - navigation_start);
445 PLT_HISTOGRAM("PLT.PT_StartToCommit_DataReductionProxy",
446 response_start - request_start);
447 PLT_HISTOGRAM("PLT.PT_RequestToCommit_DataReductionProxy",
448 response_start - navigation_start);
452 enum MissingStartType {
453 START_MISSING = 0x1,
454 COMMIT_MISSING = 0x2,
455 NAV_START_MISSING = 0x4,
456 MISSING_START_TYPE_MAX = 0x8
459 enum AbandonType {
460 FINISH_DOC_MISSING = 0x1,
461 FINISH_ALL_LOADS_MISSING = 0x2,
462 LOAD_EVENT_START_MISSING = 0x4,
463 LOAD_EVENT_END_MISSING = 0x8,
464 ABANDON_TYPE_MAX = 0x10
467 } // namespace
469 PageLoadHistograms::PageLoadHistograms(content::RenderView* render_view)
470 : content::RenderViewObserver(render_view),
471 cross_origin_access_count_(0),
472 same_origin_access_count_(0) {
475 void PageLoadHistograms::Dump(WebFrame* frame) {
476 // We only dump histograms for main frames.
477 // In the future, it may be interesting to tag subframes and dump them too.
478 if (!frame || frame->parent())
479 return;
481 // Only dump for supported schemes.
482 URLPattern::SchemeMasks scheme_type =
483 GetSupportedSchemeType(frame->document().url());
484 if (scheme_type == 0)
485 return;
487 // Ignore multipart requests.
488 if (frame->dataSource()->response().isMultipartPayload())
489 return;
491 DocumentState* document_state =
492 DocumentState::FromDataSource(frame->dataSource());
494 bool data_reduction_proxy_was_used = DataReductionProxyWasUsed(frame);
495 bool came_from_websearch =
496 IsFromGoogleSearchResult(frame->document().url(),
497 GURL(frame->document().referrer()));
498 int websearch_chrome_joint_experiment_id = kNoExperiment;
499 bool is_preview = false;
500 if (came_from_websearch) {
501 websearch_chrome_joint_experiment_id =
502 GetQueryStringBasedExperiment(GURL(frame->document().referrer()));
503 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview");
506 // Times based on the Web Timing metrics.
507 // http://www.w3.org/TR/navigation-timing/
508 // TODO(tonyg, jar): We are in the process of vetting these metrics against
509 // the existing ones. Once we understand any differences, we will standardize
510 // on a single set of metrics.
511 DumpPerformanceTiming(frame->performance(), document_state,
512 data_reduction_proxy_was_used,
513 came_from_websearch,
514 websearch_chrome_joint_experiment_id,
515 is_preview);
517 // If we've already dumped, do nothing.
518 // This simple bool works because we only dump for the main frame.
519 if (document_state->load_histograms_recorded())
520 return;
522 // Collect measurement times.
523 Time start = document_state->start_load_time();
524 Time commit = document_state->commit_load_time();
526 // TODO(tonyg, jar): Start can be missing after an in-document navigation and
527 // possibly other cases like a very premature abandonment of the page.
528 // The PLT.MissingStart histogram should help us troubleshoot and then we can
529 // remove this.
530 Time navigation_start =
531 Time::FromDoubleT(frame->performance().navigationStart());
532 int missing_start_type = 0;
533 missing_start_type |= start.is_null() ? START_MISSING : 0;
534 missing_start_type |= commit.is_null() ? COMMIT_MISSING : 0;
535 missing_start_type |= navigation_start.is_null() ? NAV_START_MISSING : 0;
536 UMA_HISTOGRAM_ENUMERATION("PLT.MissingStart", missing_start_type,
537 MISSING_START_TYPE_MAX);
538 if (missing_start_type)
539 return;
541 // We properly handle null values for the next 3 variables.
542 Time request = document_state->request_time();
543 Time first_paint = document_state->first_paint_time();
544 Time first_paint_after_load = document_state->first_paint_after_load_time();
545 Time finish_doc = document_state->finish_document_load_time();
546 Time finish_all_loads = document_state->finish_load_time();
548 // TODO(tonyg, jar): We suspect a bug in abandonment counting, this temporary
549 // histogram should help us to troubleshoot.
550 Time load_event_start =
551 Time::FromDoubleT(frame->performance().loadEventStart());
552 Time load_event_end = Time::FromDoubleT(frame->performance().loadEventEnd());
553 int abandon_type = 0;
554 abandon_type |= finish_doc.is_null() ? FINISH_DOC_MISSING : 0;
555 abandon_type |= finish_all_loads.is_null() ? FINISH_ALL_LOADS_MISSING : 0;
556 abandon_type |= load_event_start.is_null() ? LOAD_EVENT_START_MISSING : 0;
557 abandon_type |= load_event_end.is_null() ? LOAD_EVENT_END_MISSING : 0;
558 UMA_HISTOGRAM_ENUMERATION("PLT.AbandonType", abandon_type, ABANDON_TYPE_MAX);
560 // Handle case where user hits "stop" or "back" before loading completely.
561 bool abandoned_page = finish_doc.is_null();
562 if (abandoned_page) {
563 finish_doc = Time::Now();
564 document_state->set_finish_document_load_time(finish_doc);
567 // TODO(jar): We should really discriminate the definition of "abandon" more
568 // finely. We should have:
569 // abandon_before_document_loaded
570 // abandon_before_onload_fired
572 if (finish_all_loads.is_null()) {
573 finish_all_loads = Time::Now();
574 document_state->set_finish_load_time(finish_all_loads);
575 } else {
576 DCHECK(!abandoned_page); // How can the doc have finished but not the page?
577 if (abandoned_page)
578 return; // Don't try to record a stat which is broken.
581 document_state->set_load_histograms_recorded(true);
583 // Note: Client side redirects will have no request time.
584 Time begin = request.is_null() ? start : request;
585 TimeDelta begin_to_finish_doc = finish_doc - begin;
586 TimeDelta begin_to_finish_all_loads = finish_all_loads - begin;
587 TimeDelta start_to_finish_all_loads = finish_all_loads - start;
588 TimeDelta start_to_commit = commit - start;
590 DocumentState::LoadType load_type = document_state->load_type();
592 // The above code sanitized all values of times, in preparation for creating
593 // actual histograms. The remainder of this code could be run at destructor
594 // time for the document_state, since all data is intact.
596 // Aggregate PLT data across all link types.
597 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned", abandoned_page ? 1 : 0, 2);
598 UMA_HISTOGRAM_ENUMERATION("PLT.LoadType", load_type,
599 DocumentState::kLoadTypeMax);
600 PLT_HISTOGRAM("PLT.StartToCommit", start_to_commit);
601 PLT_HISTOGRAM("PLT.CommitToFinishDoc", finish_doc - commit);
602 PLT_HISTOGRAM("PLT.FinishDocToFinish", finish_all_loads - finish_doc);
603 PLT_HISTOGRAM("PLT.BeginToCommit", commit - begin);
604 PLT_HISTOGRAM("PLT.StartToFinish", start_to_finish_all_loads);
605 if (!request.is_null()) {
606 PLT_HISTOGRAM("PLT.RequestToStart", start - request);
607 PLT_HISTOGRAM("PLT.RequestToFinish", finish_all_loads - request);
609 PLT_HISTOGRAM("PLT.CommitToFinish", finish_all_loads - commit);
611 scoped_ptr<TimeDelta> begin_to_first_paint;
612 scoped_ptr<TimeDelta> commit_to_first_paint;
613 if (!first_paint.is_null()) {
614 // 'first_paint' can be before 'begin' for an unknown reason.
615 // See bug http://crbug.com/125273 for details.
616 if (begin <= first_paint) {
617 begin_to_first_paint.reset(new TimeDelta(first_paint - begin));
618 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFirstPaint",
619 *begin_to_first_paint,
620 came_from_websearch,
621 websearch_chrome_joint_experiment_id,
622 is_preview);
624 DCHECK(commit <= first_paint);
625 commit_to_first_paint.reset(new TimeDelta(first_paint - commit));
626 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.CommitToFirstPaint",
627 *commit_to_first_paint,
628 came_from_websearch,
629 websearch_chrome_joint_experiment_id,
630 is_preview);
632 if (!first_paint_after_load.is_null()) {
633 // 'first_paint_after_load' can be before 'begin' for an unknown reason.
634 // See bug http://crbug.com/125273 for details.
635 if (begin <= first_paint_after_load) {
636 PLT_HISTOGRAM("PLT.BeginToFirstPaintAfterLoad",
637 first_paint_after_load - begin);
639 DCHECK(commit <= first_paint_after_load);
640 PLT_HISTOGRAM("PLT.CommitToFirstPaintAfterLoad",
641 first_paint_after_load - commit);
642 DCHECK(finish_all_loads <= first_paint_after_load);
643 PLT_HISTOGRAM("PLT.FinishToFirstPaintAfterLoad",
644 first_paint_after_load - finish_all_loads);
646 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinishDoc", begin_to_finish_doc,
647 came_from_websearch,
648 websearch_chrome_joint_experiment_id,
649 is_preview);
650 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinish", begin_to_finish_all_loads,
651 came_from_websearch,
652 websearch_chrome_joint_experiment_id,
653 is_preview);
655 // Load type related histograms.
656 switch (load_type) {
657 case DocumentState::UNDEFINED_LOAD:
658 PLT_HISTOGRAM("PLT.BeginToFinishDoc_UndefLoad", begin_to_finish_doc);
659 PLT_HISTOGRAM("PLT.BeginToFinish_UndefLoad", begin_to_finish_all_loads);
660 break;
661 case DocumentState::RELOAD:
662 PLT_HISTOGRAM("PLT.BeginToFinishDoc_Reload", begin_to_finish_doc);
663 PLT_HISTOGRAM("PLT.BeginToFinish_Reload", begin_to_finish_all_loads);
664 break;
665 case DocumentState::HISTORY_LOAD:
666 PLT_HISTOGRAM("PLT.BeginToFinishDoc_HistoryLoad", begin_to_finish_doc);
667 PLT_HISTOGRAM("PLT.BeginToFinish_HistoryLoad", begin_to_finish_all_loads);
668 break;
669 case DocumentState::NORMAL_LOAD:
670 PLT_HISTOGRAM("PLT.BeginToFinishDoc_NormalLoad", begin_to_finish_doc);
671 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad", begin_to_finish_all_loads);
672 break;
673 case DocumentState::LINK_LOAD_NORMAL:
674 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadNormal",
675 begin_to_finish_doc);
676 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal",
677 begin_to_finish_all_loads);
678 break;
679 case DocumentState::LINK_LOAD_RELOAD:
680 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadReload",
681 begin_to_finish_doc);
682 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadReload",
683 begin_to_finish_all_loads);
684 break;
685 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
686 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadStaleOk",
687 begin_to_finish_doc);
688 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadStaleOk",
689 begin_to_finish_all_loads);
690 break;
691 case DocumentState::LINK_LOAD_CACHE_ONLY:
692 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadCacheOnly",
693 begin_to_finish_doc);
694 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadCacheOnly",
695 begin_to_finish_all_loads);
696 break;
697 default:
698 break;
701 if (data_reduction_proxy_was_used) {
702 UMA_HISTOGRAM_ENUMERATION(
703 "PLT.Abandoned_SpdyProxy", abandoned_page ? 1 : 0, 2);
704 PLT_HISTOGRAM("PLT.BeginToFinishDoc_SpdyProxy", begin_to_finish_doc);
705 PLT_HISTOGRAM("PLT.BeginToFinish_SpdyProxy", begin_to_finish_all_loads);
708 if (document_state->was_prefetcher()) {
709 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcher",
710 begin_to_finish_doc);
711 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcher",
712 begin_to_finish_all_loads);
714 if (document_state->was_referred_by_prefetcher()) {
715 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcherReferrer",
716 begin_to_finish_doc);
717 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcherReferrer",
718 begin_to_finish_all_loads);
720 if (document_state->was_after_preconnect_request()) {
721 PLT_HISTOGRAM("PLT.BeginToFinishDoc_AfterPreconnectRequest",
722 begin_to_finish_doc);
723 PLT_HISTOGRAM("PLT.BeginToFinish_AfterPreconnectRequest",
724 begin_to_finish_all_loads);
727 // TODO(mpcomplete): remove the extension-related histograms after we collect
728 // enough data. http://crbug.com/100411
729 const bool use_adblock_histogram =
730 ChromeContentRendererClient::IsAdblockInstalled();
731 if (use_adblock_histogram) {
732 UMA_HISTOGRAM_ENUMERATION(
733 "PLT.Abandoned_ExtensionAdblock",
734 abandoned_page ? 1 : 0, 2);
735 switch (load_type) {
736 case DocumentState::NORMAL_LOAD:
737 PLT_HISTOGRAM(
738 "PLT.BeginToFinish_NormalLoad_ExtensionAdblock",
739 begin_to_finish_all_loads);
740 break;
741 case DocumentState::LINK_LOAD_NORMAL:
742 PLT_HISTOGRAM(
743 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblock",
744 begin_to_finish_all_loads);
745 break;
746 case DocumentState::LINK_LOAD_RELOAD:
747 PLT_HISTOGRAM(
748 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblock",
749 begin_to_finish_all_loads);
750 break;
751 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
752 PLT_HISTOGRAM(
753 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblock",
754 begin_to_finish_all_loads);
755 break;
756 default:
757 break;
761 const bool use_adblockplus_histogram =
762 ChromeContentRendererClient::IsAdblockPlusInstalled();
763 if (use_adblockplus_histogram) {
764 UMA_HISTOGRAM_ENUMERATION(
765 "PLT.Abandoned_ExtensionAdblockPlus",
766 abandoned_page ? 1 : 0, 2);
767 switch (load_type) {
768 case DocumentState::NORMAL_LOAD:
769 PLT_HISTOGRAM(
770 "PLT.BeginToFinish_NormalLoad_ExtensionAdblockPlus",
771 begin_to_finish_all_loads);
772 break;
773 case DocumentState::LINK_LOAD_NORMAL:
774 PLT_HISTOGRAM(
775 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblockPlus",
776 begin_to_finish_all_loads);
777 break;
778 case DocumentState::LINK_LOAD_RELOAD:
779 PLT_HISTOGRAM(
780 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblockPlus",
781 begin_to_finish_all_loads);
782 break;
783 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
784 PLT_HISTOGRAM(
785 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblockPlus",
786 begin_to_finish_all_loads);
787 break;
788 default:
789 break;
793 const bool use_webrequest_adblock_histogram =
794 ChromeContentRendererClient::IsAdblockWithWebRequestInstalled();
795 if (use_webrequest_adblock_histogram) {
796 UMA_HISTOGRAM_ENUMERATION(
797 "PLT.Abandoned_ExtensionWebRequestAdblock",
798 abandoned_page ? 1 : 0, 2);
799 switch (load_type) {
800 case DocumentState::NORMAL_LOAD:
801 PLT_HISTOGRAM(
802 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblock",
803 begin_to_finish_all_loads);
804 break;
805 case DocumentState::LINK_LOAD_NORMAL:
806 PLT_HISTOGRAM(
807 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblock",
808 begin_to_finish_all_loads);
809 break;
810 case DocumentState::LINK_LOAD_RELOAD:
811 PLT_HISTOGRAM(
812 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblock",
813 begin_to_finish_all_loads);
814 break;
815 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
816 PLT_HISTOGRAM(
817 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblock",
818 begin_to_finish_all_loads);
819 break;
820 default:
821 break;
825 const bool use_webrequest_adblockplus_histogram =
826 ChromeContentRendererClient::
827 IsAdblockPlusWithWebRequestInstalled();
828 if (use_webrequest_adblockplus_histogram) {
829 UMA_HISTOGRAM_ENUMERATION(
830 "PLT.Abandoned_ExtensionWebRequestAdblockPlus",
831 abandoned_page ? 1 : 0, 2);
832 switch (load_type) {
833 case DocumentState::NORMAL_LOAD:
834 PLT_HISTOGRAM(
835 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblockPlus",
836 begin_to_finish_all_loads);
837 break;
838 case DocumentState::LINK_LOAD_NORMAL:
839 PLT_HISTOGRAM(
840 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblockPlus",
841 begin_to_finish_all_loads);
842 break;
843 case DocumentState::LINK_LOAD_RELOAD:
844 PLT_HISTOGRAM(
845 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblockPlus",
846 begin_to_finish_all_loads);
847 break;
848 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
849 PLT_HISTOGRAM(
850 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblockPlus",
851 begin_to_finish_all_loads);
852 break;
853 default:
854 break;
858 const bool use_webrequest_other_histogram =
859 ChromeContentRendererClient::
860 IsOtherExtensionWithWebRequestInstalled();
861 if (use_webrequest_other_histogram) {
862 UMA_HISTOGRAM_ENUMERATION(
863 "PLT.Abandoned_ExtensionWebRequestOther",
864 abandoned_page ? 1 : 0, 2);
865 switch (load_type) {
866 case DocumentState::NORMAL_LOAD:
867 PLT_HISTOGRAM(
868 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestOther",
869 begin_to_finish_all_loads);
870 break;
871 case DocumentState::LINK_LOAD_NORMAL:
872 PLT_HISTOGRAM(
873 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestOther",
874 begin_to_finish_all_loads);
875 break;
876 case DocumentState::LINK_LOAD_RELOAD:
877 PLT_HISTOGRAM(
878 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestOther",
879 begin_to_finish_all_loads);
880 break;
881 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
882 PLT_HISTOGRAM(
883 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestOther",
884 begin_to_finish_all_loads);
885 break;
886 default:
887 break;
891 // Record SpdyCwnd results.
892 if (document_state->was_fetched_via_spdy()) {
893 switch (load_type) {
894 case DocumentState::LINK_LOAD_NORMAL:
895 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal_cwndDynamic",
896 begin_to_finish_all_loads);
897 PLT_HISTOGRAM("PLT.StartToFinish_LinkLoadNormal_cwndDynamic",
898 start_to_finish_all_loads);
899 PLT_HISTOGRAM("PLT.StartToCommit_LinkLoadNormal_cwndDynamic",
900 start_to_commit);
901 break;
902 case DocumentState::NORMAL_LOAD:
903 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad_cwndDynamic",
904 begin_to_finish_all_loads);
905 PLT_HISTOGRAM("PLT.StartToFinish_NormalLoad_cwndDynamic",
906 start_to_finish_all_loads);
907 PLT_HISTOGRAM("PLT.StartToCommit_NormalLoad_cwndDynamic",
908 start_to_commit);
909 break;
910 default:
911 break;
915 // Record page load time and abandonment rates for proxy cases.
916 if (document_state->was_fetched_via_proxy()) {
917 if (scheme_type == URLPattern::SCHEME_HTTPS) {
918 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.https", start_to_finish_all_loads);
919 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.https",
920 abandoned_page ? 1 : 0, 2);
921 } else {
922 DCHECK(scheme_type == URLPattern::SCHEME_HTTP);
923 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.http", start_to_finish_all_loads);
924 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.http",
925 abandoned_page ? 1 : 0, 2);
927 } else {
928 if (scheme_type == URLPattern::SCHEME_HTTPS) {
929 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.https",
930 start_to_finish_all_loads);
931 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.https",
932 abandoned_page ? 1 : 0, 2);
933 } else {
934 DCHECK(scheme_type == URLPattern::SCHEME_HTTP);
935 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.http",
936 start_to_finish_all_loads);
937 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.http",
938 abandoned_page ? 1 : 0, 2);
942 // Site isolation metrics.
943 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithCrossSiteFrameAccess",
944 cross_origin_access_count_);
945 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithSameSiteFrameAccess",
946 same_origin_access_count_);
948 // Log the PLT to the info log.
949 LogPageLoadTime(document_state, frame->dataSource());
951 // Since there are currently no guarantees that renderer histograms will be
952 // sent to the browser, we initiate a PostTask here to be sure that we send
953 // the histograms we generated. Without this call, pages that don't have an
954 // on-close-handler might generate data that is lost when the renderer is
955 // shutdown abruptly (perchance because the user closed the tab).
956 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it
957 // should post when the onload is complete, so that it doesn't interfere with
958 // the next load.
959 content::RenderThread::Get()->UpdateHistograms(
960 content::kHistogramSynchronizerReservedSequenceNumber);
963 void PageLoadHistograms::ResetCrossFramePropertyAccess() {
964 cross_origin_access_count_ = 0;
965 same_origin_access_count_ = 0;
968 void PageLoadHistograms::FrameWillClose(WebFrame* frame) {
969 Dump(frame);
972 void PageLoadHistograms::ClosePage() {
973 // TODO(davemoore) This code should be removed once willClose() gets
974 // called when a page is destroyed. page_load_histograms_.Dump() is safe
975 // to call multiple times for the same frame, but it will simplify things.
976 Dump(render_view()->GetWebView()->mainFrame());
977 ResetCrossFramePropertyAccess();
980 void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state,
981 const WebDataSource* ds) const {
982 // Because this function gets called on every page load,
983 // take extra care to optimize it away if logging is turned off.
984 if (logging::LOG_INFO < logging::GetMinLogLevel())
985 return;
987 DCHECK(document_state);
988 DCHECK(ds);
989 GURL url(ds->request().url());
990 Time start = document_state->start_load_time();
991 Time finish = document_state->finish_load_time();
992 // TODO(mbelshe): should we log more stats?
993 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms "
994 << url.spec();