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