?  search:
summary | log | graphiclog1 | graphiclog2 | commit | commitdiff | tree | refs | edit | fork
blame | history | raw | HEAD
Roll ANGLE e754fb8..6ffeb74
[chromium-blink-merge.git] / chrome / renderer / page_load_histograms.cc
blob0723709c4fa652c61ceae8b89d14d878b55fc8a4
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.
4
5 #include "chrome/renderer/page_load_histograms.h"
6
7 #include <string>
8
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 "components/data_reduction_proxy/content/common/data_reduction_proxy_messages.h"
22 #include "content/public/common/content_constants.h"
23 #include "content/public/renderer/document_state.h"
24 #include "content/public/renderer/render_thread.h"
25 #include "content/public/renderer/render_view.h"
26 #include "extensions/common/url_pattern.h"
27 #include "net/base/url_util.h"
28 #include "net/http/http_response_headers.h"
29 #include "third_party/WebKit/public/platform/WebURLRequest.h"
30 #include "third_party/WebKit/public/platform/WebURLResponse.h"
31 #include "third_party/WebKit/public/web/WebDocument.h"
32 #include "third_party/WebKit/public/web/WebFrame.h"
33 #include "third_party/WebKit/public/web/WebPerformance.h"
34 #include "third_party/WebKit/public/web/WebView.h"
35 #include "url/gurl.h"
36
37 using blink::WebDataSource;
38 using blink::WebFrame;
39 using blink::WebPerformance;
40 using blink::WebString;
41 using base::Time;
42 using base::TimeDelta;
43 using content::DocumentState;
44
45 const size_t kPLTCount = 100;
46
47 namespace {
48
49 // ID indicating that no GWS-Chrome joint experiment is active.
50 const int kNoExperiment = 0;
51
52 // Max ID of GWS-Chrome joint experiment. If you change this value, please
53 // update PLT_HISTOGRAM_WITH_GWS_VARIANT accordingly.
54 const int kMaxExperimentID = 20;
55
56 TimeDelta kPLTMin() {
57 return TimeDelta::FromMilliseconds(10);
58 }
59 TimeDelta kPLTMax() {
60 return TimeDelta::FromMinutes(10);
61 }
62
63 // This function corresponds to PLT_HISTOGRAM macro invocation without caching.
64 // Use this for PLT histograms with dynamically generated names, which
65 // otherwise can't use the caching PLT_HISTOGRAM macro without code duplication.
66 void PltHistogramWithNoMacroCaching(const std::string& name,
67 const TimeDelta& sample) {
68 // The parameters should exacly match the parameters in
69 // UMA_HISTOGRAM_CUSTOM_TIMES macro.
70 base::HistogramBase* histogram_pointer = base::Histogram::FactoryTimeGet(
71 name, kPLTMin(), kPLTMax(), kPLTCount,
72 base::HistogramBase::kUmaTargetedHistogramFlag);
73 histogram_pointer->AddTime(sample);
74 }
75
76 // This records UMA corresponding to the PLT_HISTOGRAM macro without caching.
77 void PltHistogramWithGwsPreview(const char* name,
78 const TimeDelta& sample,
79 bool is_preview,
80 int experiment_id) {
81 std::string preview_suffix = is_preview ? "_Preview" : "_NoPreview";
82 PltHistogramWithNoMacroCaching(name + preview_suffix, sample);
83
84 if (experiment_id != kNoExperiment) {
85 std::string name_with_experiment_id = base::StringPrintf(
86 "%s%s_Experiment%d", name, preview_suffix.c_str(), experiment_id);
87 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample);
88 }
89 }
90
91 #define PLT_HISTOGRAM(name, sample) \
92 UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, kPLTMin(), kPLTMax(), kPLTCount);
93
94 #define PLT_HISTOGRAM_WITH_GWS_VARIANT( \
95 name, sample, came_from_websearch, websearch_chrome_joint_experiment_id, \
96 is_preview) { \
97 PLT_HISTOGRAM(name, sample); \
98 if (came_from_websearch) { \
99 PLT_HISTOGRAM(base::StringPrintf("%s_FromGWS", name), sample) \
100 if (websearch_chrome_joint_experiment_id != kNoExperiment) { \
101 std::string name_with_experiment_id = base::StringPrintf( \
102 "%s_FromGWS_Experiment%d", \
103 name, websearch_chrome_joint_experiment_id); \
104 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample); \
105 } \
106 } \
107 PltHistogramWithGwsPreview(name, sample, is_preview, \
108 websearch_chrome_joint_experiment_id); \
109 }
110
111 // In addition to PLT_HISTOGRAM, add the *_DataReductionProxy variant
112 // conditionally. This macro runs only in one thread.
113 #define PLT_HISTOGRAM_DRP( \
114 name, sample, data_reduction_proxy_was_used, scheme_type) \
115 do { \
116 static base::HistogramBase* counter(NULL); \
117 static base::HistogramBase* drp_counter(NULL); \
118 static base::HistogramBase* https_drp_counter(NULL); \
119 if (!counter) { \
120 DCHECK(drp_counter == NULL); \
121 DCHECK(https_drp_counter == NULL); \
122 counter = base::Histogram::FactoryTimeGet( \
123 name, kPLTMin(), kPLTMax(), kPLTCount, \
124 base::Histogram::kUmaTargetedHistogramFlag); \
125 } \
126 counter->AddTime(sample); \
127 if (!data_reduction_proxy_was_used) break; \
128 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) { \
129 if (!https_drp_counter) { \
130 https_drp_counter = base::Histogram::FactoryTimeGet( \
131 std::string(name) + "_DataReductionProxy", \
132 kPLTMin(), kPLTMax(), kPLTCount, \
133 base::Histogram::kUmaTargetedHistogramFlag); \
134 } \
135 https_drp_counter->AddTime(sample); \
136 } else { \
137 if (!drp_counter) { \
138 drp_counter = base::Histogram::FactoryTimeGet( \
139 std::string(name) + "_HTTPS_DataReductionProxy", \
140 kPLTMin(), kPLTMax(), kPLTCount, \
141 base::Histogram::kUmaTargetedHistogramFlag); \
142 } \
143 drp_counter->AddTime(sample); \
144 } \
145 } while (0)
146
147 // Returns the scheme type of the given URL if its type is one for which we
148 // dump page load histograms. Otherwise returns NULL.
149 URLPattern::SchemeMasks GetSupportedSchemeType(const GURL& url) {
150 if (url.SchemeIs("http"))
151 return URLPattern::SCHEME_HTTP;
152 else if (url.SchemeIs("https"))
153 return URLPattern::SCHEME_HTTPS;
154 return static_cast<URLPattern::SchemeMasks>(0);
155 }
156
157 // Helper function to check for string in 'via' header. Returns true if
158 // |via_value| is one of the values listed in the Via header.
159 bool ViaHeaderContains(WebFrame* frame, const std::string& via_value) {
160 const char kViaHeaderName[] = "Via";
161 std::vector<std::string> values;
162 // Multiple via headers have already been coalesced and hence each value
163 // separated by a comma corresponds to a proxy. The value added by a proxy is
164 // not expected to contain any commas.
165 // Example., Via: 1.0 Compression proxy, 1.1 Google Instant Proxy Preview
166 base::SplitString(
167 frame->dataSource()->response().httpHeaderField(kViaHeaderName).utf8(),
168 ',', &values);
169 return std::find(values.begin(), values.end(), via_value) != values.end();
170 }
171
172 // Returns true if the provided URL is a referrer string that came from
173 // a Google Web Search results page. This is a little non-deterministic
174 // because desktop and mobile websearch differ and sometimes just provide
175 // http://www.google.com/ as the referrer. In the case of /url we can be sure
176 // that it came from websearch but we will be generous and allow for cases
177 // where a non-Google URL was provided a bare Google URL as a referrer.
178 // The domain validation matches the code used by the prerenderer for similar
179 // purposes.
180 // TODO(pmeenan): Remove the fuzzy logic when the referrer is reliable
181 bool IsFromGoogleSearchResult(const GURL& url, const GURL& referrer) {
182 if (!StartsWithASCII(referrer.host(), "www.google.", true))
183 return false;
184 if (StartsWithASCII(referrer.path(), "/url", true))
185 return true;
186 bool is_possible_search_referrer =
187 referrer.path().empty() ||
188 referrer.path() == "/" ||
189 StartsWithASCII(referrer.path(), "/search", true) ||
190 StartsWithASCII(referrer.path(), "/webhp", true);
191 if (is_possible_search_referrer &&
192 !StartsWithASCII(url.host(), "www.google", true))
193 return true;
194 return false;
195 }
196
197 // Extracts a Google Web Search and Chrome joint experiment ID from a referrer
198 // that came from a Google Web Search results page. An experiment ID is embedded
199 // in a query string as a "gcjeid=" parameter value.
200 int GetQueryStringBasedExperiment(const GURL& referrer) {
201 std::string value;
202 if (!net::GetValueForKeyInQuery(referrer, "gcjeid", &value))
203 return kNoExperiment;
204
205 int experiment_id;
206 if (!base::StringToInt(value, &experiment_id))
207 return kNoExperiment;
208 if (0 < experiment_id && experiment_id <= kMaxExperimentID)
209 return experiment_id;
210 return kNoExperiment;
211 }
212
213 void DumpHistograms(const WebPerformance& performance,
214 DocumentState* document_state,
215 bool data_reduction_proxy_was_used,
216 data_reduction_proxy::LoFiStatus lofi_status,
217 bool came_from_websearch,
218 int websearch_chrome_joint_experiment_id,
219 bool is_preview,
220 URLPattern::SchemeMasks scheme_type) {
221 // This function records new histograms based on the Navigation Timing
222 // records. As such, the histograms should not depend on the deprecated timing
223 // information collected in DocumentState. However, here for some reason we
224 // check if document_state->request_time() is null. TODO(ppi): find out why
225 // and remove DocumentState from the parameter list.
226 Time request = document_state->request_time();
227
228 Time navigation_start = Time::FromDoubleT(performance.navigationStart());
229 Time redirect_start = Time::FromDoubleT(performance.redirectStart());
230 Time redirect_end = Time::FromDoubleT(performance.redirectEnd());
231 Time fetch_start = Time::FromDoubleT(performance.fetchStart());
232 Time domain_lookup_start = Time::FromDoubleT(performance.domainLookupStart());
233 Time domain_lookup_end = Time::FromDoubleT(performance.domainLookupEnd());
234 Time connect_start = Time::FromDoubleT(performance.connectStart());
235 Time connect_end = Time::FromDoubleT(performance.connectEnd());
236 Time request_start = Time::FromDoubleT(performance.requestStart());
237 Time response_start = Time::FromDoubleT(performance.responseStart());
238 Time response_end = Time::FromDoubleT(performance.responseEnd());
239 Time dom_loading = Time::FromDoubleT(performance.domLoading());
240 Time dom_interactive = Time::FromDoubleT(performance.domInteractive());
241 Time dom_content_loaded_start =
242 Time::FromDoubleT(performance.domContentLoadedEventStart());
243 Time dom_content_loaded_end =
244 Time::FromDoubleT(performance.domContentLoadedEventEnd());
245 Time load_event_start = Time::FromDoubleT(performance.loadEventStart());
246 Time load_event_end = Time::FromDoubleT(performance.loadEventEnd());
247 Time begin = (request.is_null() ? navigation_start : request_start);
248 Time first_paint = document_state->first_paint_time();
249
250 DCHECK(!navigation_start.is_null());
251
252 // It is possible for a document to have navigation_start time, but no
253 // request_start. An example is doing a window.open, which synchronously
254 // loads "about:blank", then using document.write add a meta http-equiv
255 // refresh tag, which causes a navigation. In such case, we will arrive at
256 // this function with no request/response timing data and identical load
257 // start/end values. Avoid logging this case, as it doesn't add any
258 // meaningful information to the histogram.
259 if (request_start.is_null())
260 return;
261
262 // TODO(dominich): Investigate conditions under which |load_event_start| and
263 // |load_event_end| may be NULL as in the non-PT_ case below. Examples in
264 // http://crbug.com/112006.
265 // DCHECK(!load_event_start.is_null());
266 // DCHECK(!load_event_end.is_null());
267
268 if (document_state->web_timing_histograms_recorded())
269 return;
270 document_state->set_web_timing_histograms_recorded(true);
271
272 if (!redirect_start.is_null() && !redirect_end.is_null()) {
273 PLT_HISTOGRAM_DRP("PLT.NT_Redirect",
274 redirect_end - redirect_start,
275 data_reduction_proxy_was_used,
276 scheme_type);
277 PLT_HISTOGRAM_DRP(
278 "PLT.NT_DelayBeforeFetchRedirect",
279 (fetch_start - navigation_start) - (redirect_end - redirect_start),
280 data_reduction_proxy_was_used,
281 scheme_type);
282 } else {
283 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeFetch",
284 fetch_start - navigation_start,
285 data_reduction_proxy_was_used,
286 scheme_type);
287 }
288 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomainLookup",
289 domain_lookup_start - fetch_start,
290 data_reduction_proxy_was_used,
291 scheme_type);
292 PLT_HISTOGRAM_DRP("PLT.NT_DomainLookup",
293 domain_lookup_end - domain_lookup_start,
294 data_reduction_proxy_was_used,
295 scheme_type);
296 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeConnect",
297 connect_start - domain_lookup_end,
298 data_reduction_proxy_was_used,
299 scheme_type);
300 PLT_HISTOGRAM_DRP("PLT.NT_Connect",
301 connect_end - connect_start,
302 data_reduction_proxy_was_used,
303 scheme_type);
304 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeRequest",
305 request_start - connect_end,
306 data_reduction_proxy_was_used,
307 scheme_type);
308 PLT_HISTOGRAM_DRP("PLT.NT_Request",
309 response_start - request_start,
310 data_reduction_proxy_was_used,
311 scheme_type);
312 PLT_HISTOGRAM_DRP("PLT.NT_Response",
313 response_end - response_start,
314 data_reduction_proxy_was_used,
315 scheme_type);
316
317 if (!dom_loading.is_null()) {
318 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomLoading",
319 dom_loading - response_start,
320 data_reduction_proxy_was_used,
321 scheme_type);
322 }
323 if (!dom_interactive.is_null() && !dom_loading.is_null()) {
324 PLT_HISTOGRAM_DRP("PLT.NT_DomLoading",
325 dom_interactive - dom_loading,
326 data_reduction_proxy_was_used,
327 scheme_type);
328 }
329 if (!dom_content_loaded_start.is_null() && !dom_interactive.is_null()) {
330 PLT_HISTOGRAM_DRP("PLT.NT_DomInteractive",
331 dom_content_loaded_start - dom_interactive,
332 data_reduction_proxy_was_used,
333 scheme_type);
334 }
335 if (!dom_content_loaded_start.is_null() &&
336 !dom_content_loaded_end.is_null() ) {
337 PLT_HISTOGRAM_DRP("PLT.NT_DomContentLoaded",
338 dom_content_loaded_end - dom_content_loaded_start,
339 data_reduction_proxy_was_used,
340 scheme_type);
341 }
342 if (!dom_content_loaded_end.is_null() && !load_event_start.is_null()) {
343 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeLoadEvent",
344 load_event_start - dom_content_loaded_end,
345 data_reduction_proxy_was_used,
346 scheme_type);
347 }
348
349 // TODO(simonjam): There is no way to distinguish between abandonment and
350 // intentional Javascript navigation before the load event fires.
351 // TODO(dominich): Load type breakdown
352 if (!load_event_start.is_null()) {
353 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinishDoc",
354 load_event_start - begin,
355 came_from_websearch,
356 websearch_chrome_joint_experiment_id,
357 is_preview);
358 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinishDoc",
359 load_event_start - response_start,
360 came_from_websearch,
361 websearch_chrome_joint_experiment_id,
362 is_preview);
363 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinishDoc",
364 load_event_start - navigation_start,
365 came_from_websearch,
366 websearch_chrome_joint_experiment_id,
367 is_preview);
368 if (data_reduction_proxy_was_used) {
369 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) {
370 PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_DataReductionProxy",
371 load_event_start - begin);
372 PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_DataReductionProxy",
373 load_event_start - response_start);
374 PLT_HISTOGRAM("PLT.PT_RequestToFinishDoc_DataReductionProxy",
375 load_event_start - navigation_start);
376 } else {
377 PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_HTTPS_DataReductionProxy",
378 load_event_start - begin);
379 PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_HTTPS_DataReductionProxy",
380 load_event_start - response_start);
381 PLT_HISTOGRAM("PLT.PT_RequestToFinishDoc_HTTPS_DataReductionProxy",
382 load_event_start - navigation_start);
383 }
384 }
385 }
386 if (!load_event_end.is_null()) {
387 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinish",
388 load_event_end - begin,
389 came_from_websearch,
390 websearch_chrome_joint_experiment_id,
391 is_preview);
392 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinish",
393 load_event_end - response_start,
394 came_from_websearch,
395 websearch_chrome_joint_experiment_id,
396 is_preview);
397 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinish",
398 load_event_end - navigation_start,
399 came_from_websearch,
400 websearch_chrome_joint_experiment_id,
401 is_preview);
402 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToFinish",
403 load_event_end - request_start,
404 came_from_websearch,
405 websearch_chrome_joint_experiment_id,
406 is_preview);
407 if (data_reduction_proxy_was_used) {
408 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) {
409 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy",
410 load_event_end - begin);
411 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy",
412 load_event_end - response_start);
413 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy",
414 load_event_end - navigation_start);
415 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy",
416 load_event_end - request_start);
417 if (lofi_status == data_reduction_proxy::LOFI_STATUS_ACTIVE) {
418 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy_AutoLoFiOn",
419 load_event_end - begin);
420 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy_AutoLoFiOn",
421 load_event_end - response_start);
422 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy_AutoLoFiOn",
423 load_event_end - navigation_start);
424 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy_AutoLoFiOn",
425 load_event_end - request_start);
426 if (!first_paint.is_null()) {
427 PLT_HISTOGRAM("PLT.BeginToFirstPaint_DataReductionProxy_AutoLoFiOn",
428 first_paint - begin);
429 }
430 } else if (lofi_status ==
431 data_reduction_proxy::LOFI_STATUS_ACTIVE_CONTROL) {
432 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy_AutoLoFiOff",
433 load_event_end - begin);
434 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy_AutoLoFiOff",
435 load_event_end - response_start);
436 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy_AutoLoFiOff",
437 load_event_end - navigation_start);
438 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy_AutoLoFiOff",
439 load_event_end - request_start);
440 if (!first_paint.is_null()) {
441 PLT_HISTOGRAM(
442 "PLT.BeginToFirstPaint_DataReductionProxy_AutoLoFiOff",
443 first_paint - begin);
444 }
445 }
446 } else {
447 PLT_HISTOGRAM("PLT.PT_BeginToFinish_HTTPS_DataReductionProxy",
448 load_event_end - begin);
449 PLT_HISTOGRAM("PLT.PT_CommitToFinish_HTTPS_DataReductionProxy",
450 load_event_end - response_start);
451 PLT_HISTOGRAM("PLT.PT_RequestToFinish_HTTPS_DataReductionProxy",
452 load_event_end - navigation_start);
453 PLT_HISTOGRAM("PLT.PT_StartToFinish_HTTPS_DataReductionProxy",
454 load_event_end - request_start);
455 if (lofi_status == data_reduction_proxy::LOFI_STATUS_ACTIVE) {
456 PLT_HISTOGRAM(
457 "PLT.PT_BeginToFinish_HTTPS_DataReductionProxy_AutoLoFiOn",
458 load_event_end - begin);
459 PLT_HISTOGRAM(
460 "PLT.PT_CommitToFinish_HTTPS_DataReductionProxy_AutoLoFiOn",
461 load_event_end - response_start);
462 PLT_HISTOGRAM(
463 "PLT.PT_RequestToFinish_HTTPS_DataReductionProxy_AutoLoFiOn",
464 load_event_end - navigation_start);
465 PLT_HISTOGRAM(
466 "PLT.PT_StartToFinish_HTTPS_DataReductionProxy_AutoLoFiOn",
467 load_event_end - request_start);
468 if (!first_paint.is_null()) {
469 PLT_HISTOGRAM(
470 "PLT.BeginToFirstPaint_HTTPS_DataReductionProxy_AutoLoFiOn",
471 first_paint - begin);
472 }
473 } else if (lofi_status ==
474 data_reduction_proxy::LOFI_STATUS_ACTIVE_CONTROL) {
475 PLT_HISTOGRAM(
476 "PLT.PT_BeginToFinish_HTTPS_DataReductionProxy_AutoLoFiOff",
477 load_event_end - begin);
478 PLT_HISTOGRAM(
479 "PLT.PT_CommitToFinish_HTTPS_DataReductionProxy_AutoLoFiOff",
480 load_event_end - response_start);
481 PLT_HISTOGRAM(
482 "PLT.PT_RequestToFinish_HTTPS_DataReductionProxy_AutoLoFiOff",
483 load_event_end - navigation_start);
484 PLT_HISTOGRAM(
485 "PLT.PT_StartToFinish_HTTPS_DataReductionProxy_AutoLoFiOff",
486 load_event_end - request_start);
487 if (!first_paint.is_null()) {
488 PLT_HISTOGRAM(
489 "PLT.BeginToFirstPaint_HTTPS_DataReductionProxy_AutoLoFiOff",
490 first_paint - begin);
491 }
492 }
493 }
494 }
495 }
496 if (!load_event_start.is_null() && !load_event_end.is_null()) {
497 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish",
498 load_event_end - load_event_start);
499 PLT_HISTOGRAM_DRP("PLT.NT_LoadEvent",
500 load_event_end - load_event_start,
501 data_reduction_proxy_was_used,
502 scheme_type);
503
504 if (data_reduction_proxy_was_used) {
505 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) {
506 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_DataReductionProxy",
507 load_event_end - load_event_start);
508 } else {
509 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_HTTPS_DataReductionProxy",
510 load_event_end - load_event_start);
511 }
512 }
513 }
514 if (!dom_content_loaded_start.is_null()) {
515 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToDomContentLoaded",
516 dom_content_loaded_start - navigation_start,
517 came_from_websearch,
518 websearch_chrome_joint_experiment_id,
519 is_preview);
520 if (data_reduction_proxy_was_used) {
521 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) {
522 PLT_HISTOGRAM("PLT.PT_RequestToDomContentLoaded_DataReductionProxy",
523 dom_content_loaded_start - navigation_start);
524 if (lofi_status == data_reduction_proxy::LOFI_STATUS_ACTIVE) {
525 PLT_HISTOGRAM(
526 "PLT.PT_RequestToDomContentLoaded_DataReductionProxy_AutoLoFiOn",
527 dom_content_loaded_start - navigation_start);
528 } else if (lofi_status ==
529 data_reduction_proxy::LOFI_STATUS_ACTIVE_CONTROL) {
530 PLT_HISTOGRAM(
531 "PLT.PT_RequestToDomContentLoaded_DataReductionProxy_AutoLoFiOff",
532 dom_content_loaded_start - navigation_start);
533 }
534 } else {
535 PLT_HISTOGRAM(
536 "PLT.PT_RequestToDomContentLoaded_HTTPS_DataReductionProxy",
537 dom_content_loaded_start - navigation_start);
538 if (lofi_status == data_reduction_proxy::LOFI_STATUS_ACTIVE) {
539 PLT_HISTOGRAM(
540 "PLT.PT_RequestToDomContentLoaded_HTTPS_DataReductionProxy_"
541 "AutoLoFiOn",
542 dom_content_loaded_start - navigation_start);
543 } else if (lofi_status ==
544 data_reduction_proxy::LOFI_STATUS_ACTIVE_CONTROL) {
545 PLT_HISTOGRAM(
546 "PLT.PT_RequestToDomContentLoaded_HTTPS_DataReductionProxy_"
547 "AutoLoFiOff",
548 dom_content_loaded_start - navigation_start);
549 }
550 }
551 }
552 }
553 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToCommit",
554 response_start - begin,
555 came_from_websearch,
556 websearch_chrome_joint_experiment_id,
557 is_preview);
558 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToStart",
559 request_start - navigation_start,
560 came_from_websearch,
561 websearch_chrome_joint_experiment_id,
562 is_preview);
563 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToCommit",
564 response_start - request_start,
565 came_from_websearch,
566 websearch_chrome_joint_experiment_id,
567 is_preview);
568 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToCommit",
569 response_start - navigation_start,
570 came_from_websearch,
571 websearch_chrome_joint_experiment_id,
572 is_preview);
573 if (data_reduction_proxy_was_used) {
574 if ((scheme_type & URLPattern::SCHEME_HTTPS) == 0) {
575 PLT_HISTOGRAM("PLT.PT_BeginToCommit_DataReductionProxy",
576 response_start - begin);
577 PLT_HISTOGRAM("PLT.PT_RequestToStart_DataReductionProxy",
578 request_start - navigation_start);
579 PLT_HISTOGRAM("PLT.PT_StartToCommit_DataReductionProxy",
580 response_start - request_start);
581 PLT_HISTOGRAM("PLT.PT_RequestToCommit_DataReductionProxy",
582 response_start - navigation_start);
583 } else {
584 PLT_HISTOGRAM("PLT.PT_BeginToCommit_HTTPS_DataReductionProxy",
585 response_start - begin);
586 PLT_HISTOGRAM("PLT.PT_RequestToStart_HTTPS_DataReductionProxy",
587 request_start - navigation_start);
588 PLT_HISTOGRAM("PLT.PT_StartToCommit_HTTPS_DataReductionProxy",
589 response_start - request_start);
590 PLT_HISTOGRAM("PLT.PT_RequestToCommit_HTTPS_DataReductionProxy",
591 response_start - navigation_start);
592 }
593 }
594 }
595
596 // These histograms are based on the timing information collected in
597 // DocumentState. They should be transitioned to equivalents based on the
598 // Navigation Timing records (see DumpPerformanceTiming()) or dropped if not
599 // needed. Please do not add new metrics based on DocumentState.
600 void DumpDeprecatedHistograms(const WebPerformance& performance,
601 DocumentState* document_state,
602 bool data_reduction_proxy_was_used,
603 bool came_from_websearch,
604 int websearch_chrome_joint_experiment_id,
605 bool is_preview,
606 URLPattern::SchemeMasks scheme_type) {
607 // If we've already dumped, do nothing.
608 // This simple bool works because we only dump for the main frame.
609 if (document_state->load_histograms_recorded())
610 return;
611
612 // Abort if any of these is missing.
613 Time start = document_state->start_load_time();
614 Time commit = document_state->commit_load_time();
615 Time navigation_start =
616 Time::FromDoubleT(performance.navigationStart());
617 if (start.is_null() || commit.is_null() || navigation_start.is_null())
618 return;
619
620 // We properly handle null values for the next 3 variables.
621 Time request = document_state->request_time();
622 Time first_paint = document_state->first_paint_time();
623 Time first_paint_after_load = document_state->first_paint_after_load_time();
624 Time finish_doc = document_state->finish_document_load_time();
625 Time finish_all_loads = document_state->finish_load_time();
626
627 // Handle case where user hits "stop" or "back" before loading completely.
628 // Note that this makes abandoned page loads be recorded as if they were
629 // completed, polluting the metrics with artifically short completion times.
630 // We are not fixing this as these metrics are being dropped as deprecated.
631 if (finish_doc.is_null()) {
632 finish_doc = Time::Now();
633 document_state->set_finish_document_load_time(finish_doc);
634 }
635 if (finish_all_loads.is_null()) {
636 finish_all_loads = Time::Now();
637 document_state->set_finish_load_time(finish_all_loads);
638 }
639
640 document_state->set_load_histograms_recorded(true);
641
642 // Note: Client side redirects will have no request time.
643 Time begin = request.is_null() ? start : request;
644 TimeDelta begin_to_finish_doc = finish_doc - begin;
645 TimeDelta begin_to_finish_all_loads = finish_all_loads - begin;
646 TimeDelta start_to_finish_all_loads = finish_all_loads - start;
647 TimeDelta start_to_commit = commit - start;
648
649 DocumentState::LoadType load_type = document_state->load_type();
650
651 // The above code sanitized all values of times, in preparation for creating
652 // actual histograms. The remainder of this code could be run at destructor
653 // time for the document_state, since all data is intact.
654
655 // Aggregate PLT data across all link types.
656 UMA_HISTOGRAM_ENUMERATION("PLT.LoadType", load_type,
657 DocumentState::kLoadTypeMax);
658 PLT_HISTOGRAM("PLT.StartToCommit", start_to_commit);
659 PLT_HISTOGRAM("PLT.CommitToFinishDoc", finish_doc - commit);
660 PLT_HISTOGRAM("PLT.FinishDocToFinish", finish_all_loads - finish_doc);
661 PLT_HISTOGRAM("PLT.BeginToCommit", commit - begin);
662 PLT_HISTOGRAM("PLT.StartToFinish", start_to_finish_all_loads);
663 if (!request.is_null()) {
664 PLT_HISTOGRAM("PLT.RequestToStart", start - request);
665 PLT_HISTOGRAM("PLT.RequestToFinish", finish_all_loads - request);
666 }
667 PLT_HISTOGRAM("PLT.CommitToFinish", finish_all_loads - commit);
668
669 scoped_ptr<TimeDelta> begin_to_first_paint;
670 scoped_ptr<TimeDelta> commit_to_first_paint;
671 if (!first_paint.is_null()) {
672 // 'first_paint' can be before 'begin' for an unknown reason.
673 // See bug http://crbug.com/125273 for details.
674 if (begin <= first_paint) {
675 begin_to_first_paint.reset(new TimeDelta(first_paint - begin));
676 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFirstPaint",
677 *begin_to_first_paint,
678 came_from_websearch,
679 websearch_chrome_joint_experiment_id,
680 is_preview);
681 }
682
683 // Conditional was previously a DCHECK. Changed due to multiple bot
684 // failures, listed in crbug.com/383963
685 if (commit <= first_paint) {
686 commit_to_first_paint.reset(new TimeDelta(first_paint - commit));
687 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.CommitToFirstPaint",
688 *commit_to_first_paint,
689 came_from_websearch,
690 websearch_chrome_joint_experiment_id,
691 is_preview);
692 }
693 }
694 if (!first_paint_after_load.is_null()) {
695 // 'first_paint_after_load' can be before 'begin' for an unknown reason.
696 // See bug http://crbug.com/125273 for details.
697 if (begin <= first_paint_after_load) {
698 PLT_HISTOGRAM("PLT.BeginToFirstPaintAfterLoad",
699 first_paint_after_load - begin);
700 }
701 // Both following conditionals were previously DCHECKs. Changed due to
702 // multiple bot failures, listed in crbug.com/383963
703 if (commit <= first_paint_after_load) {
704 PLT_HISTOGRAM("PLT.CommitToFirstPaintAfterLoad",
705 first_paint_after_load - commit);
706 }
707 if (finish_all_loads <= first_paint_after_load) {
708 PLT_HISTOGRAM("PLT.FinishToFirstPaintAfterLoad",
709 first_paint_after_load - finish_all_loads);
710 }
711 }
712 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinishDoc", begin_to_finish_doc,
713 came_from_websearch,
714 websearch_chrome_joint_experiment_id,
715 is_preview);
716 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinish", begin_to_finish_all_loads,
717 came_from_websearch,
718 websearch_chrome_joint_experiment_id,
719 is_preview);
720
721 // Load type related histograms.
722 switch (load_type) {
723 case DocumentState::UNDEFINED_LOAD:
724 PLT_HISTOGRAM("PLT.BeginToFinishDoc_UndefLoad", begin_to_finish_doc);
725 PLT_HISTOGRAM("PLT.BeginToFinish_UndefLoad", begin_to_finish_all_loads);
726 break;
727 case DocumentState::RELOAD:
728 PLT_HISTOGRAM("PLT.BeginToFinishDoc_Reload", begin_to_finish_doc);
729 PLT_HISTOGRAM("PLT.BeginToFinish_Reload", begin_to_finish_all_loads);
730 break;
731 case DocumentState::HISTORY_LOAD:
732 PLT_HISTOGRAM("PLT.BeginToFinishDoc_HistoryLoad", begin_to_finish_doc);
733 PLT_HISTOGRAM("PLT.BeginToFinish_HistoryLoad", begin_to_finish_all_loads);
734 break;
735 case DocumentState::NORMAL_LOAD:
736 PLT_HISTOGRAM("PLT.BeginToFinishDoc_NormalLoad", begin_to_finish_doc);
737 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad", begin_to_finish_all_loads);
738 break;
739 case DocumentState::LINK_LOAD_NORMAL:
740 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadNormal",
741 begin_to_finish_doc);
742 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal",
743 begin_to_finish_all_loads);
744 break;
745 case DocumentState::LINK_LOAD_RELOAD:
746 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadReload",
747 begin_to_finish_doc);
748 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadReload",
749 begin_to_finish_all_loads);
750 break;
751 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
752 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadStaleOk",
753 begin_to_finish_doc);
754 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadStaleOk",
755 begin_to_finish_all_loads);
756 break;
757 case DocumentState::LINK_LOAD_CACHE_ONLY:
758 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadCacheOnly",
759 begin_to_finish_doc);
760 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadCacheOnly",
761 begin_to_finish_all_loads);
762 break;
763 default:
764 break;
765 }
766
767 if (data_reduction_proxy_was_used) {
768 PLT_HISTOGRAM("PLT.BeginToFinishDoc_SpdyProxy", begin_to_finish_doc);
769 PLT_HISTOGRAM("PLT.BeginToFinish_SpdyProxy", begin_to_finish_all_loads);
770 }
771
772 if (document_state->was_prefetcher()) {
773 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcher",
774 begin_to_finish_doc);
775 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcher",
776 begin_to_finish_all_loads);
777 }
778 if (document_state->was_referred_by_prefetcher()) {
779 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcherReferrer",
780 begin_to_finish_doc);
781 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcherReferrer",
782 begin_to_finish_all_loads);
783 }
784
785 const bool use_webrequest_histogram =
786 ChromeContentRendererClient::WasWebRequestUsedBySomeExtensions();
787 if (use_webrequest_histogram) {
788 switch (load_type) {
789 case DocumentState::NORMAL_LOAD:
790 PLT_HISTOGRAM(
791 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequest",
792 begin_to_finish_all_loads);
793 break;
794 case DocumentState::LINK_LOAD_NORMAL:
795 PLT_HISTOGRAM(
796 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequest",
797 begin_to_finish_all_loads);
798 break;
799 case DocumentState::LINK_LOAD_RELOAD:
800 PLT_HISTOGRAM(
801 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequest",
802 begin_to_finish_all_loads);
803 break;
804 case DocumentState::LINK_LOAD_CACHE_STALE_OK:
805 PLT_HISTOGRAM(
806 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequest",
807 begin_to_finish_all_loads);
808 break;
809 default:
810 break;
811 }
812 }
813 }
814
815 } // namespace
816
817 PageLoadHistograms::PageLoadHistograms(content::RenderView* render_view)
818 : content::RenderViewObserver(render_view) {
819 }
820
821 void PageLoadHistograms::Dump(WebFrame* frame) {
822 // We only dump histograms for main frames.
823 // In the future, it may be interesting to tag subframes and dump them too.
824 if (!frame || frame->parent())
825 return;
826
827 // If the main frame lives in a different process, don't do anything.
828 // Histogram data will be recorded by the real main frame.
829 if (frame->isWebRemoteFrame())
830 return;
831
832 // Only dump for supported schemes.
833 URLPattern::SchemeMasks scheme_type =
834 GetSupportedSchemeType(frame->document().url());
835 if (scheme_type == 0)
836 return;
837
838 // Ignore multipart requests.
839 if (frame->dataSource()->response().isMultipartPayload())
840 return;
841
842 DocumentState* document_state =
843 DocumentState::FromDataSource(frame->dataSource());
844
845 bool data_reduction_proxy_was_used = false;
846 data_reduction_proxy::LoFiStatus lofi_status =
847 data_reduction_proxy::LOFI_STATUS_TEMPORARILY_OFF;
848 if (!document_state->proxy_server().IsEmpty()) {
849 Send(new DataReductionProxyViewHostMsg_DataReductionProxyStatus(
850 document_state->proxy_server(), &data_reduction_proxy_was_used,
851 &lofi_status));
852 }
853
854 bool came_from_websearch =
855 IsFromGoogleSearchResult(frame->document().url(),
856 GURL(frame->document().referrer()));
857 int websearch_chrome_joint_experiment_id = kNoExperiment;
858 bool is_preview = false;
859 if (came_from_websearch) {
860 websearch_chrome_joint_experiment_id =
861 GetQueryStringBasedExperiment(GURL(frame->document().referrer()));
862 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview");
863 }
864
865 // Metrics based on the timing information recorded for the Navigation Timing
866 // API - http://www.w3.org/TR/navigation-timing/.
867 DumpHistograms(frame->performance(), document_state,
868 data_reduction_proxy_was_used, lofi_status,
869 came_from_websearch, websearch_chrome_joint_experiment_id,
870 is_preview, scheme_type);
871
872 // Old metrics based on the timing information stored in DocumentState. These
873 // are deprecated and should go away.
874 DumpDeprecatedHistograms(frame->performance(), document_state,
875 data_reduction_proxy_was_used,
876 came_from_websearch,
877 websearch_chrome_joint_experiment_id,
878 is_preview,
879 scheme_type);
880
881 // Log the PLT to the info log.
882 LogPageLoadTime(document_state, frame->dataSource());
883
884 // Since there are currently no guarantees that renderer histograms will be
885 // sent to the browser, we initiate a PostTask here to be sure that we send
886 // the histograms we generated. Without this call, pages that don't have an
887 // on-close-handler might generate data that is lost when the renderer is
888 // shutdown abruptly (perchance because the user closed the tab).
889 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it
890 // should post when the onload is complete, so that it doesn't interfere with
891 // the next load.
892 content::RenderThread::Get()->UpdateHistograms(
893 content::kHistogramSynchronizerReservedSequenceNumber);
894 }
895
896 void PageLoadHistograms::FrameWillClose(WebFrame* frame) {
897 Dump(frame);
898 }
899
900 void PageLoadHistograms::ClosePage() {
901 // TODO(davemoore) This code should be removed once willClose() gets
902 // called when a page is destroyed. page_load_histograms_.Dump() is safe
903 // to call multiple times for the same frame, but it will simplify things.
904 Dump(render_view()->GetWebView()->mainFrame());
905 }
906
907 void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state,
908 const WebDataSource* ds) const {
909 // Because this function gets called on every page load,
910 // take extra care to optimize it away if logging is turned off.
911 if (logging::LOG_INFO < logging::GetMinLogLevel())
912 return;
913
914 DCHECK(document_state);
915 DCHECK(ds);
916 GURL url(ds->request().url());
917 Time start = document_state->start_load_time();
918 Time finish = document_state->finish_load_time();
919 // TODO(mbelshe): should we log more stats?
920 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms "
921 << url.spec();
922 }