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"
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 "third_party/WebKit/public/platform/WebURLRequest.h"
28 #include "third_party/WebKit/public/platform/WebURLResponse.h"
29 #include "third_party/WebKit/public/web/WebDocument.h"
30 #include "third_party/WebKit/public/web/WebFrame.h"
31 #include "third_party/WebKit/public/web/WebPerformance.h"
32 #include "third_party/WebKit/public/web/WebView.h"
35 #if defined(SPDY_PROXY_AUTH_ORIGIN)
36 #include "net/http/http_response_headers.h"
39 using blink::WebDataSource
;
40 using blink::WebFrame
;
41 using blink::WebPerformance
;
42 using blink::WebString
;
44 using base::TimeDelta
;
45 using content::DocumentState
;
47 const size_t kPLTCount
= 100;
51 // ID indicating that no GWS-Chrome joint experiment is active.
52 const int kNoExperiment
= 0;
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;
59 return TimeDelta::FromMilliseconds(10);
62 return TimeDelta::FromMinutes(10);
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
);
78 // Various preview applicability states.
79 enum GwsPreviewState
{
81 // Instant search clicks [not] applied, data reduction proxy used,
84 // Instant search clicks applied, data reduction proxy [not] used,
87 // Instant search clicks applied, data reduction proxy used,
88 // [not] from web search
92 // This records UMA corresponding to the PLT_HISTOGRAM macro without caching.
93 void PltHistogramWithGwsPreview(const char* name
,
94 const TimeDelta
& sample
,
95 GwsPreviewState preview_state
,
96 int preview_experiment_id
) {
97 std::string preview_suffix
;
98 switch (preview_state
) {
99 case PREVIEW_WAS_SHOWN
:
100 preview_suffix
= "_WithPreview";
103 preview_suffix
= "_Preview";
105 case PREVIEW_NOT_USED
:
106 preview_suffix
= "_NoPreview";
111 PltHistogramWithNoMacroCaching(name
+ preview_suffix
, sample
);
113 if (preview_experiment_id
!= kNoExperiment
) {
114 std::string name_with_experiment_id
= base::StringPrintf(
115 "%s%s_Experiment%d", name
, preview_suffix
.c_str(),
116 preview_experiment_id
);
117 PltHistogramWithNoMacroCaching(name_with_experiment_id
, sample
);
121 #define PLT_HISTOGRAM(name, sample) \
122 UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, kPLTMin(), kPLTMax(), kPLTCount);
124 #define PLT_HISTOGRAM_WITH_GWS_VARIANT( \
125 name, sample, came_from_websearch, websearch_chrome_joint_experiment_id, \
126 preview_state, preview_experiment_id) { \
127 PLT_HISTOGRAM(name, sample); \
128 if (came_from_websearch) { \
129 PLT_HISTOGRAM(base::StringPrintf("%s_FromGWS", name), sample) \
130 if (websearch_chrome_joint_experiment_id != kNoExperiment) { \
131 std::string name_with_experiment_id = base::StringPrintf( \
132 "%s_FromGWS_Experiment%d", \
133 name, websearch_chrome_joint_experiment_id); \
134 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample); \
137 PltHistogramWithGwsPreview(name, sample, preview_state, \
138 preview_experiment_id); \
141 // In addition to PLT_HISTOGRAM, add the *_DataReductionProxy variant
142 // conditionally. This macro runs only in one thread.
143 #define PLT_HISTOGRAM_DRP(name, sample, data_reduction_proxy_was_used) \
145 static base::HistogramBase* counter(NULL); \
146 static base::HistogramBase* drp_counter(NULL); \
148 DCHECK(drp_counter == NULL); \
149 counter = base::Histogram::FactoryTimeGet( \
150 name, kPLTMin(), kPLTMax(), kPLTCount, \
151 base::Histogram::kUmaTargetedHistogramFlag); \
153 counter->AddTime(sample); \
154 if (!data_reduction_proxy_was_used) break; \
155 if (!drp_counter) { \
156 drp_counter = base::Histogram::FactoryTimeGet( \
157 std::string(name) + "_DataReductionProxy", \
158 kPLTMin(), kPLTMax(), kPLTCount, \
159 base::Histogram::kUmaTargetedHistogramFlag); \
161 drp_counter->AddTime(sample); \
164 // Returns the scheme type of the given URL if its type is one for which we
165 // dump page load histograms. Otherwise returns NULL.
166 URLPattern::SchemeMasks
GetSupportedSchemeType(const GURL
& url
) {
167 if (url
.SchemeIs("http"))
168 return URLPattern::SCHEME_HTTP
;
169 else if (url
.SchemeIs("https"))
170 return URLPattern::SCHEME_HTTPS
;
171 return static_cast<URLPattern::SchemeMasks
>(0);
174 // Helper function to check for string in 'via' header. Returns true if
175 // |via_value| is one of the values listed in the Via header and the response
176 // was fetched via a proxy.
177 bool ViaHeaderContains(WebFrame
* frame
, const std::string
& via_value
) {
178 const char kViaHeaderName
[] = "Via";
180 DocumentState
* document_state
=
181 DocumentState::FromDataSource(frame
->dataSource());
182 if (!document_state
->was_fetched_via_proxy())
185 std::vector
<std::string
> values
;
186 // Multiple via headers have already been coalesced and hence each value
187 // separated by a comma corresponds to a proxy. The value added by a proxy is
188 // not expected to contain any commas.
189 // Example., Via: 1.0 Compression proxy, 1.1 Google Instant Proxy Preview
191 frame
->dataSource()->response().httpHeaderField(kViaHeaderName
).utf8(),
193 return std::find(values
.begin(), values
.end(), via_value
) != values
.end();
196 // Returns true if the data reduction proxy was used. Note, this function will
197 // produce a false positive if a page is fetched using SPDY and using a proxy,
198 // and the data reduction proxy's via value is added to the Via header.
199 // TODO(bengr): Plumb the hostname of the proxy and check if it matches
200 // |SPDY_PROXY_AUTH_ORIGIN|.
201 bool DataReductionProxyWasUsed(WebFrame
* frame
) {
202 #if defined(SPDY_PROXY_AUTH_ORIGIN)
203 DocumentState
* document_state
=
204 DocumentState::FromDataSource(frame
->dataSource());
205 if (!document_state
->was_fetched_via_proxy())
208 std::string via_header
=
209 base::UTF16ToUTF8(frame
->dataSource()->response().httpHeaderField("Via"));
211 if (via_header
.empty())
213 std::string headers
= "HTTP/1.1 200 OK\nVia: " + via_header
+ "\n\n";
214 // Produce raw headers, expected by the |HttpResponseHeaders| constructor.
215 std::replace(headers
.begin(), headers
.end(), '\n', '\0');
216 scoped_refptr
<net::HttpResponseHeaders
> response_headers(
217 new net::HttpResponseHeaders(headers
));
218 return response_headers
->IsDataReductionProxyResponse();
224 // Returns true if the provided URL is a referrer string that came from
225 // a Google Web Search results page. This is a little non-deterministic
226 // because desktop and mobile websearch differ and sometimes just provide
227 // http://www.google.com/ as the referrer. In the case of /url we can be sure
228 // that it came from websearch but we will be generous and allow for cases
229 // where a non-Google URL was provided a bare Google URL as a referrer.
230 // The domain validation matches the code used by the prerenderer for similar
232 // TODO(pmeenan): Remove the fuzzy logic when the referrer is reliable
233 bool IsFromGoogleSearchResult(const GURL
& url
, const GURL
& referrer
) {
234 if (!StartsWithASCII(referrer
.host(), "www.google.", true))
236 if (StartsWithASCII(referrer
.path(), "/url", true))
238 bool is_possible_search_referrer
=
239 referrer
.path().empty() ||
240 referrer
.path() == "/" ||
241 StartsWithASCII(referrer
.path(), "/search", true) ||
242 StartsWithASCII(referrer
.path(), "/webhp", true);
243 if (is_possible_search_referrer
&&
244 !StartsWithASCII(url
.host(), "www.google", true))
249 // Extracts a Google Web Search and Chrome joint experiment ID from a referrer
250 // that came from a Google Web Search results page. An experiment ID is embedded
251 // in a query string as a "gcjeid=" parameter value.
252 int GetQueryStringBasedExperiment(const GURL
& referrer
) {
254 if (!net::GetValueForKeyInQuery(referrer
, "gcjeid", &value
))
255 return kNoExperiment
;
258 if (!base::StringToInt(value
, &experiment_id
))
259 return kNoExperiment
;
260 if (0 < experiment_id
&& experiment_id
<= kMaxExperimentID
)
261 return experiment_id
;
262 return kNoExperiment
;
265 // Returns preview state by looking at url and referer url.
266 void GetPreviewState(WebFrame
* frame
,
267 bool came_from_websearch
,
268 bool data_reduction_proxy_was_used
,
269 GwsPreviewState
* preview_state
,
270 int* preview_experiment_id
) {
271 // Conditions for GWS preview are,
272 // 1. Data reduction proxy was used.
273 // Determine the preview state (PREVIEW, PREVIEW_WAS_SHOWN, PREVIEW_NOT_USED)
274 // by inspecting the Via header.
275 if (data_reduction_proxy_was_used
) {
276 if (came_from_websearch
) {
277 *preview_state
= ViaHeaderContains(
279 "1.1 Google Instant Proxy Preview") ? PREVIEW
: PREVIEW_NOT_USED
;
280 } else if (ViaHeaderContains(frame
, "1.1 Google Instant Proxy")) {
281 *preview_state
= PREVIEW_WAS_SHOWN
;
282 *preview_experiment_id
= GetQueryStringBasedExperiment(
283 GURL(frame
->document().referrer()));
288 void DumpPerformanceTiming(const WebPerformance
& performance
,
289 DocumentState
* document_state
,
290 bool data_reduction_proxy_was_used
,
291 bool came_from_websearch
,
292 int websearch_chrome_joint_experiment_id
,
293 GwsPreviewState preview_state
,
294 int preview_experiment_id
) {
295 Time request
= document_state
->request_time();
297 Time navigation_start
= Time::FromDoubleT(performance
.navigationStart());
298 Time redirect_start
= Time::FromDoubleT(performance
.redirectStart());
299 Time redirect_end
= Time::FromDoubleT(performance
.redirectEnd());
300 Time fetch_start
= Time::FromDoubleT(performance
.fetchStart());
301 Time domain_lookup_start
= Time::FromDoubleT(performance
.domainLookupStart());
302 Time domain_lookup_end
= Time::FromDoubleT(performance
.domainLookupEnd());
303 Time connect_start
= Time::FromDoubleT(performance
.connectStart());
304 Time connect_end
= Time::FromDoubleT(performance
.connectEnd());
305 Time request_start
= Time::FromDoubleT(performance
.requestStart());
306 Time response_start
= Time::FromDoubleT(performance
.responseStart());
307 Time response_end
= Time::FromDoubleT(performance
.responseEnd());
308 Time dom_loading
= Time::FromDoubleT(performance
.domLoading());
309 Time dom_interactive
= Time::FromDoubleT(performance
.domInteractive());
310 Time dom_content_loaded_start
=
311 Time::FromDoubleT(performance
.domContentLoadedEventStart());
312 Time dom_content_loaded_end
=
313 Time::FromDoubleT(performance
.domContentLoadedEventEnd());
314 Time load_event_start
= Time::FromDoubleT(performance
.loadEventStart());
315 Time load_event_end
= Time::FromDoubleT(performance
.loadEventEnd());
316 Time begin
= (request
.is_null() ? navigation_start
: request_start
);
318 DCHECK(!navigation_start
.is_null());
320 // It is possible for a document to have navigation_start time, but no
321 // request_start. An example is doing a window.open, which synchronously
322 // loads "about:blank", then using document.write add a meta http-equiv
323 // refresh tag, which causes a navigation. In such case, we will arrive at
324 // this function with no request/response timing data and identical load
325 // start/end values. Avoid logging this case, as it doesn't add any
326 // meaningful information to the histogram.
327 if (request_start
.is_null())
330 // TODO(dominich): Investigate conditions under which |load_event_start| and
331 // |load_event_end| may be NULL as in the non-PT_ case below. Examples in
332 // http://crbug.com/112006.
333 // DCHECK(!load_event_start.is_null());
334 // DCHECK(!load_event_end.is_null());
336 if (document_state
->web_timing_histograms_recorded())
338 document_state
->set_web_timing_histograms_recorded(true);
340 if (!redirect_start
.is_null() && !redirect_end
.is_null()) {
341 PLT_HISTOGRAM_DRP("PLT.NT_Redirect", redirect_end
- redirect_start
,
342 data_reduction_proxy_was_used
);
344 "PLT.NT_DelayBeforeFetchRedirect",
345 (fetch_start
- navigation_start
) - (redirect_end
- redirect_start
),
346 data_reduction_proxy_was_used
);
348 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeFetch",
349 fetch_start
- navigation_start
,
350 data_reduction_proxy_was_used
);
352 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomainLookup",
353 domain_lookup_start
- fetch_start
,
354 data_reduction_proxy_was_used
);
355 PLT_HISTOGRAM_DRP("PLT.NT_DomainLookup",
356 domain_lookup_end
- domain_lookup_start
,
357 data_reduction_proxy_was_used
);
358 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeConnect",
359 connect_start
- domain_lookup_end
,
360 data_reduction_proxy_was_used
);
361 PLT_HISTOGRAM_DRP("PLT.NT_Connect", connect_end
- connect_start
,
362 data_reduction_proxy_was_used
);
363 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeRequest",
364 request_start
- connect_end
,
365 data_reduction_proxy_was_used
);
366 PLT_HISTOGRAM_DRP("PLT.NT_Request", response_start
- request_start
,
367 data_reduction_proxy_was_used
);
368 PLT_HISTOGRAM_DRP("PLT.NT_Response", response_end
- response_start
,
369 data_reduction_proxy_was_used
);
371 if (!dom_loading
.is_null()) {
372 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomLoading",
373 dom_loading
- response_start
,
374 data_reduction_proxy_was_used
);
376 if (!dom_interactive
.is_null() && !dom_loading
.is_null()) {
377 PLT_HISTOGRAM_DRP("PLT.NT_DomLoading",
378 dom_interactive
- dom_loading
,
379 data_reduction_proxy_was_used
);
381 if (!dom_content_loaded_start
.is_null() && !dom_interactive
.is_null()) {
382 PLT_HISTOGRAM_DRP("PLT.NT_DomInteractive",
383 dom_content_loaded_start
- dom_interactive
,
384 data_reduction_proxy_was_used
);
386 if (!dom_content_loaded_start
.is_null() &&
387 !dom_content_loaded_end
.is_null() ) {
388 PLT_HISTOGRAM_DRP("PLT.NT_DomContentLoaded",
389 dom_content_loaded_end
- dom_content_loaded_start
,
390 data_reduction_proxy_was_used
);
392 if (!dom_content_loaded_end
.is_null() && !load_event_start
.is_null()) {
393 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeLoadEvent",
394 load_event_start
- dom_content_loaded_end
,
395 data_reduction_proxy_was_used
);
398 // TODO(simonjam): There is no way to distinguish between abandonment and
399 // intentional Javascript navigation before the load event fires.
400 // TODO(dominich): Load type breakdown
401 if (!load_event_start
.is_null()) {
402 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinishDoc",
403 load_event_start
- begin
,
405 websearch_chrome_joint_experiment_id
,
406 preview_state
, preview_experiment_id
);
407 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinishDoc",
408 load_event_start
- response_start
,
410 websearch_chrome_joint_experiment_id
,
411 preview_state
, preview_experiment_id
);
412 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinishDoc",
413 load_event_start
- navigation_start
,
415 websearch_chrome_joint_experiment_id
,
416 preview_state
, preview_experiment_id
);
417 if (data_reduction_proxy_was_used
) {
418 PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_DataReductionProxy",
419 load_event_start
- begin
);
420 PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_DataReductionProxy",
421 load_event_start
- response_start
);
422 PLT_HISTOGRAM("PLT.PT_RequestToFinishDoc_DataReductionProxy",
423 load_event_start
- navigation_start
);
426 if (!load_event_end
.is_null()) {
427 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinish",
428 load_event_end
- begin
,
430 websearch_chrome_joint_experiment_id
,
431 preview_state
, preview_experiment_id
);
432 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinish",
433 load_event_end
- response_start
,
435 websearch_chrome_joint_experiment_id
,
436 preview_state
, preview_experiment_id
);
437 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinish",
438 load_event_end
- navigation_start
,
440 websearch_chrome_joint_experiment_id
,
441 preview_state
, preview_experiment_id
);
442 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToFinish",
443 load_event_end
- request_start
,
445 websearch_chrome_joint_experiment_id
,
446 preview_state
, preview_experiment_id
);
447 if (data_reduction_proxy_was_used
) {
448 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy",
449 load_event_end
- begin
);
450 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy",
451 load_event_end
- response_start
);
452 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy",
453 load_event_end
- navigation_start
);
454 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy",
455 load_event_end
- request_start
);
458 if (!load_event_start
.is_null() && !load_event_end
.is_null()) {
459 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish",
460 load_event_end
- load_event_start
);
461 PLT_HISTOGRAM_DRP("PLT.NT_LoadEvent",
462 load_event_end
- load_event_start
,
463 data_reduction_proxy_was_used
);
465 if (data_reduction_proxy_was_used
)
466 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_DataReductionProxy",
467 load_event_end
- load_event_start
);
469 if (!dom_content_loaded_start
.is_null()) {
470 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToDomContentLoaded",
471 dom_content_loaded_start
- navigation_start
,
473 websearch_chrome_joint_experiment_id
,
474 preview_state
, preview_experiment_id
);
475 if (data_reduction_proxy_was_used
)
476 PLT_HISTOGRAM("PLT.PT_RequestToDomContentLoaded_DataReductionProxy",
477 dom_content_loaded_start
- navigation_start
);
479 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToCommit",
480 response_start
- begin
,
482 websearch_chrome_joint_experiment_id
,
483 preview_state
, preview_experiment_id
);
484 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToStart",
485 request_start
- navigation_start
,
487 websearch_chrome_joint_experiment_id
,
488 preview_state
, preview_experiment_id
);
489 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToCommit",
490 response_start
- request_start
,
492 websearch_chrome_joint_experiment_id
,
493 preview_state
, preview_experiment_id
);
494 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToCommit",
495 response_start
- navigation_start
,
497 websearch_chrome_joint_experiment_id
,
498 preview_state
, preview_experiment_id
);
499 if (data_reduction_proxy_was_used
) {
500 PLT_HISTOGRAM("PLT.PT_BeginToCommit_DataReductionProxy",
501 response_start
- begin
);
502 PLT_HISTOGRAM("PLT.PT_RequestToStart_DataReductionProxy",
503 request_start
- navigation_start
);
504 PLT_HISTOGRAM("PLT.PT_StartToCommit_DataReductionProxy",
505 response_start
- request_start
);
506 PLT_HISTOGRAM("PLT.PT_RequestToCommit_DataReductionProxy",
507 response_start
- navigation_start
);
511 enum MissingStartType
{
513 COMMIT_MISSING
= 0x2,
514 NAV_START_MISSING
= 0x4,
515 MISSING_START_TYPE_MAX
= 0x8
519 FINISH_DOC_MISSING
= 0x1,
520 FINISH_ALL_LOADS_MISSING
= 0x2,
521 LOAD_EVENT_START_MISSING
= 0x4,
522 LOAD_EVENT_END_MISSING
= 0x8,
523 ABANDON_TYPE_MAX
= 0x10
528 PageLoadHistograms::PageLoadHistograms(content::RenderView
* render_view
)
529 : content::RenderViewObserver(render_view
),
530 cross_origin_access_count_(0),
531 same_origin_access_count_(0) {
534 void PageLoadHistograms::Dump(WebFrame
* frame
) {
535 // We only dump histograms for main frames.
536 // In the future, it may be interesting to tag subframes and dump them too.
537 if (!frame
|| frame
->parent())
540 // Only dump for supported schemes.
541 URLPattern::SchemeMasks scheme_type
=
542 GetSupportedSchemeType(frame
->document().url());
543 if (scheme_type
== 0)
546 // Ignore multipart requests.
547 if (frame
->dataSource()->response().isMultipartPayload())
550 DocumentState
* document_state
=
551 DocumentState::FromDataSource(frame
->dataSource());
553 bool data_reduction_proxy_was_used
= DataReductionProxyWasUsed(frame
);
554 bool came_from_websearch
=
555 IsFromGoogleSearchResult(frame
->document().url(),
556 GURL(frame
->document().referrer()));
557 int websearch_chrome_joint_experiment_id
= kNoExperiment
;
558 if (came_from_websearch
) {
559 websearch_chrome_joint_experiment_id
=
560 GetQueryStringBasedExperiment(GURL(frame
->document().referrer()));
563 GwsPreviewState preview_state
= PREVIEW_NONE
;
564 int preview_experiment_id
= websearch_chrome_joint_experiment_id
;
565 GetPreviewState(frame
, came_from_websearch
, data_reduction_proxy_was_used
,
566 &preview_state
, &preview_experiment_id
);
568 // Times based on the Web Timing metrics.
569 // http://www.w3.org/TR/navigation-timing/
570 // TODO(tonyg, jar): We are in the process of vetting these metrics against
571 // the existing ones. Once we understand any differences, we will standardize
572 // on a single set of metrics.
573 DumpPerformanceTiming(frame
->performance(), document_state
,
574 data_reduction_proxy_was_used
,
576 websearch_chrome_joint_experiment_id
,
577 preview_state
, preview_experiment_id
);
579 // If we've already dumped, do nothing.
580 // This simple bool works because we only dump for the main frame.
581 if (document_state
->load_histograms_recorded())
584 // Collect measurement times.
585 Time start
= document_state
->start_load_time();
586 Time commit
= document_state
->commit_load_time();
588 // TODO(tonyg, jar): Start can be missing after an in-document navigation and
589 // possibly other cases like a very premature abandonment of the page.
590 // The PLT.MissingStart histogram should help us troubleshoot and then we can
592 Time navigation_start
=
593 Time::FromDoubleT(frame
->performance().navigationStart());
594 int missing_start_type
= 0;
595 missing_start_type
|= start
.is_null() ? START_MISSING
: 0;
596 missing_start_type
|= commit
.is_null() ? COMMIT_MISSING
: 0;
597 missing_start_type
|= navigation_start
.is_null() ? NAV_START_MISSING
: 0;
598 UMA_HISTOGRAM_ENUMERATION("PLT.MissingStart", missing_start_type
,
599 MISSING_START_TYPE_MAX
);
600 if (missing_start_type
)
603 // We properly handle null values for the next 3 variables.
604 Time request
= document_state
->request_time();
605 Time first_paint
= document_state
->first_paint_time();
606 Time first_paint_after_load
= document_state
->first_paint_after_load_time();
607 Time finish_doc
= document_state
->finish_document_load_time();
608 Time finish_all_loads
= document_state
->finish_load_time();
610 // TODO(tonyg, jar): We suspect a bug in abandonment counting, this temporary
611 // histogram should help us to troubleshoot.
612 Time load_event_start
=
613 Time::FromDoubleT(frame
->performance().loadEventStart());
614 Time load_event_end
= Time::FromDoubleT(frame
->performance().loadEventEnd());
615 int abandon_type
= 0;
616 abandon_type
|= finish_doc
.is_null() ? FINISH_DOC_MISSING
: 0;
617 abandon_type
|= finish_all_loads
.is_null() ? FINISH_ALL_LOADS_MISSING
: 0;
618 abandon_type
|= load_event_start
.is_null() ? LOAD_EVENT_START_MISSING
: 0;
619 abandon_type
|= load_event_end
.is_null() ? LOAD_EVENT_END_MISSING
: 0;
620 UMA_HISTOGRAM_ENUMERATION("PLT.AbandonType", abandon_type
, ABANDON_TYPE_MAX
);
622 // Handle case where user hits "stop" or "back" before loading completely.
623 bool abandoned_page
= finish_doc
.is_null();
624 if (abandoned_page
) {
625 finish_doc
= Time::Now();
626 document_state
->set_finish_document_load_time(finish_doc
);
629 // TODO(jar): We should really discriminate the definition of "abandon" more
630 // finely. We should have:
631 // abandon_before_document_loaded
632 // abandon_before_onload_fired
634 if (finish_all_loads
.is_null()) {
635 finish_all_loads
= Time::Now();
636 document_state
->set_finish_load_time(finish_all_loads
);
638 DCHECK(!abandoned_page
); // How can the doc have finished but not the page?
640 return; // Don't try to record a stat which is broken.
643 document_state
->set_load_histograms_recorded(true);
645 // Note: Client side redirects will have no request time.
646 Time begin
= request
.is_null() ? start
: request
;
647 TimeDelta begin_to_finish_doc
= finish_doc
- begin
;
648 TimeDelta begin_to_finish_all_loads
= finish_all_loads
- begin
;
649 TimeDelta start_to_finish_all_loads
= finish_all_loads
- start
;
650 TimeDelta start_to_commit
= commit
- start
;
652 DocumentState::LoadType load_type
= document_state
->load_type();
654 // The above code sanitized all values of times, in preparation for creating
655 // actual histograms. The remainder of this code could be run at destructor
656 // time for the document_state, since all data is intact.
658 // Aggregate PLT data across all link types.
659 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned", abandoned_page
? 1 : 0, 2);
660 UMA_HISTOGRAM_ENUMERATION("PLT.LoadType", load_type
,
661 DocumentState::kLoadTypeMax
);
662 PLT_HISTOGRAM("PLT.StartToCommit", start_to_commit
);
663 PLT_HISTOGRAM("PLT.CommitToFinishDoc", finish_doc
- commit
);
664 PLT_HISTOGRAM("PLT.FinishDocToFinish", finish_all_loads
- finish_doc
);
665 PLT_HISTOGRAM("PLT.BeginToCommit", commit
- begin
);
666 PLT_HISTOGRAM("PLT.StartToFinish", start_to_finish_all_loads
);
667 if (!request
.is_null()) {
668 PLT_HISTOGRAM("PLT.RequestToStart", start
- request
);
669 PLT_HISTOGRAM("PLT.RequestToFinish", finish_all_loads
- request
);
671 PLT_HISTOGRAM("PLT.CommitToFinish", finish_all_loads
- commit
);
673 scoped_ptr
<TimeDelta
> begin_to_first_paint
;
674 scoped_ptr
<TimeDelta
> commit_to_first_paint
;
675 if (!first_paint
.is_null()) {
676 // 'first_paint' can be before 'begin' for an unknown reason.
677 // See bug http://crbug.com/125273 for details.
678 if (begin
<= first_paint
) {
679 begin_to_first_paint
.reset(new TimeDelta(first_paint
- begin
));
680 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFirstPaint",
681 *begin_to_first_paint
,
683 websearch_chrome_joint_experiment_id
,
684 preview_state
, preview_experiment_id
);
686 DCHECK(commit
<= first_paint
);
687 commit_to_first_paint
.reset(new TimeDelta(first_paint
- commit
));
688 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.CommitToFirstPaint",
689 *commit_to_first_paint
,
691 websearch_chrome_joint_experiment_id
,
692 preview_state
, preview_experiment_id
);
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
);
701 DCHECK(commit
<= first_paint_after_load
);
702 PLT_HISTOGRAM("PLT.CommitToFirstPaintAfterLoad",
703 first_paint_after_load
- commit
);
704 DCHECK(finish_all_loads
<= first_paint_after_load
);
705 PLT_HISTOGRAM("PLT.FinishToFirstPaintAfterLoad",
706 first_paint_after_load
- finish_all_loads
);
708 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinishDoc", begin_to_finish_doc
,
710 websearch_chrome_joint_experiment_id
,
711 preview_state
, preview_experiment_id
);
712 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinish", begin_to_finish_all_loads
,
714 websearch_chrome_joint_experiment_id
,
715 preview_state
, preview_experiment_id
);
717 // Load type related histograms.
719 case DocumentState::UNDEFINED_LOAD
:
720 PLT_HISTOGRAM("PLT.BeginToFinishDoc_UndefLoad", begin_to_finish_doc
);
721 PLT_HISTOGRAM("PLT.BeginToFinish_UndefLoad", begin_to_finish_all_loads
);
723 case DocumentState::RELOAD
:
724 PLT_HISTOGRAM("PLT.BeginToFinishDoc_Reload", begin_to_finish_doc
);
725 PLT_HISTOGRAM("PLT.BeginToFinish_Reload", begin_to_finish_all_loads
);
727 case DocumentState::HISTORY_LOAD
:
728 PLT_HISTOGRAM("PLT.BeginToFinishDoc_HistoryLoad", begin_to_finish_doc
);
729 PLT_HISTOGRAM("PLT.BeginToFinish_HistoryLoad", begin_to_finish_all_loads
);
731 case DocumentState::NORMAL_LOAD
:
732 PLT_HISTOGRAM("PLT.BeginToFinishDoc_NormalLoad", begin_to_finish_doc
);
733 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad", begin_to_finish_all_loads
);
735 case DocumentState::LINK_LOAD_NORMAL
:
736 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadNormal",
737 begin_to_finish_doc
);
738 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal",
739 begin_to_finish_all_loads
);
741 case DocumentState::LINK_LOAD_RELOAD
:
742 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadReload",
743 begin_to_finish_doc
);
744 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadReload",
745 begin_to_finish_all_loads
);
747 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
748 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadStaleOk",
749 begin_to_finish_doc
);
750 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadStaleOk",
751 begin_to_finish_all_loads
);
753 case DocumentState::LINK_LOAD_CACHE_ONLY
:
754 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadCacheOnly",
755 begin_to_finish_doc
);
756 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadCacheOnly",
757 begin_to_finish_all_loads
);
763 if (data_reduction_proxy_was_used
) {
764 UMA_HISTOGRAM_ENUMERATION(
765 "PLT.Abandoned_SpdyProxy", abandoned_page
? 1 : 0, 2);
766 PLT_HISTOGRAM("PLT.BeginToFinishDoc_SpdyProxy", begin_to_finish_doc
);
767 PLT_HISTOGRAM("PLT.BeginToFinish_SpdyProxy", begin_to_finish_all_loads
);
770 if (document_state
->was_prefetcher()) {
771 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcher",
772 begin_to_finish_doc
);
773 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcher",
774 begin_to_finish_all_loads
);
776 if (document_state
->was_referred_by_prefetcher()) {
777 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcherReferrer",
778 begin_to_finish_doc
);
779 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcherReferrer",
780 begin_to_finish_all_loads
);
782 if (document_state
->was_after_preconnect_request()) {
783 PLT_HISTOGRAM("PLT.BeginToFinishDoc_AfterPreconnectRequest",
784 begin_to_finish_doc
);
785 PLT_HISTOGRAM("PLT.BeginToFinish_AfterPreconnectRequest",
786 begin_to_finish_all_loads
);
789 // TODO(mpcomplete): remove the extension-related histograms after we collect
790 // enough data. http://crbug.com/100411
791 const bool use_adblock_histogram
=
792 ChromeContentRendererClient::IsAdblockInstalled();
793 if (use_adblock_histogram
) {
794 UMA_HISTOGRAM_ENUMERATION(
795 "PLT.Abandoned_ExtensionAdblock",
796 abandoned_page
? 1 : 0, 2);
798 case DocumentState::NORMAL_LOAD
:
800 "PLT.BeginToFinish_NormalLoad_ExtensionAdblock",
801 begin_to_finish_all_loads
);
803 case DocumentState::LINK_LOAD_NORMAL
:
805 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblock",
806 begin_to_finish_all_loads
);
808 case DocumentState::LINK_LOAD_RELOAD
:
810 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblock",
811 begin_to_finish_all_loads
);
813 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
815 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblock",
816 begin_to_finish_all_loads
);
823 const bool use_adblockplus_histogram
=
824 ChromeContentRendererClient::IsAdblockPlusInstalled();
825 if (use_adblockplus_histogram
) {
826 UMA_HISTOGRAM_ENUMERATION(
827 "PLT.Abandoned_ExtensionAdblockPlus",
828 abandoned_page
? 1 : 0, 2);
830 case DocumentState::NORMAL_LOAD
:
832 "PLT.BeginToFinish_NormalLoad_ExtensionAdblockPlus",
833 begin_to_finish_all_loads
);
835 case DocumentState::LINK_LOAD_NORMAL
:
837 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblockPlus",
838 begin_to_finish_all_loads
);
840 case DocumentState::LINK_LOAD_RELOAD
:
842 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblockPlus",
843 begin_to_finish_all_loads
);
845 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
847 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblockPlus",
848 begin_to_finish_all_loads
);
855 const bool use_webrequest_adblock_histogram
=
856 ChromeContentRendererClient::IsAdblockWithWebRequestInstalled();
857 if (use_webrequest_adblock_histogram
) {
858 UMA_HISTOGRAM_ENUMERATION(
859 "PLT.Abandoned_ExtensionWebRequestAdblock",
860 abandoned_page
? 1 : 0, 2);
862 case DocumentState::NORMAL_LOAD
:
864 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblock",
865 begin_to_finish_all_loads
);
867 case DocumentState::LINK_LOAD_NORMAL
:
869 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblock",
870 begin_to_finish_all_loads
);
872 case DocumentState::LINK_LOAD_RELOAD
:
874 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblock",
875 begin_to_finish_all_loads
);
877 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
879 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblock",
880 begin_to_finish_all_loads
);
887 const bool use_webrequest_adblockplus_histogram
=
888 ChromeContentRendererClient::
889 IsAdblockPlusWithWebRequestInstalled();
890 if (use_webrequest_adblockplus_histogram
) {
891 UMA_HISTOGRAM_ENUMERATION(
892 "PLT.Abandoned_ExtensionWebRequestAdblockPlus",
893 abandoned_page
? 1 : 0, 2);
895 case DocumentState::NORMAL_LOAD
:
897 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblockPlus",
898 begin_to_finish_all_loads
);
900 case DocumentState::LINK_LOAD_NORMAL
:
902 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblockPlus",
903 begin_to_finish_all_loads
);
905 case DocumentState::LINK_LOAD_RELOAD
:
907 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblockPlus",
908 begin_to_finish_all_loads
);
910 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
912 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblockPlus",
913 begin_to_finish_all_loads
);
920 const bool use_webrequest_other_histogram
=
921 ChromeContentRendererClient::
922 IsOtherExtensionWithWebRequestInstalled();
923 if (use_webrequest_other_histogram
) {
924 UMA_HISTOGRAM_ENUMERATION(
925 "PLT.Abandoned_ExtensionWebRequestOther",
926 abandoned_page
? 1 : 0, 2);
928 case DocumentState::NORMAL_LOAD
:
930 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestOther",
931 begin_to_finish_all_loads
);
933 case DocumentState::LINK_LOAD_NORMAL
:
935 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestOther",
936 begin_to_finish_all_loads
);
938 case DocumentState::LINK_LOAD_RELOAD
:
940 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestOther",
941 begin_to_finish_all_loads
);
943 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
945 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestOther",
946 begin_to_finish_all_loads
);
953 // Record SpdyCwnd results.
954 if (document_state
->was_fetched_via_spdy()) {
956 case DocumentState::LINK_LOAD_NORMAL
:
957 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal_cwndDynamic",
958 begin_to_finish_all_loads
);
959 PLT_HISTOGRAM("PLT.StartToFinish_LinkLoadNormal_cwndDynamic",
960 start_to_finish_all_loads
);
961 PLT_HISTOGRAM("PLT.StartToCommit_LinkLoadNormal_cwndDynamic",
964 case DocumentState::NORMAL_LOAD
:
965 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad_cwndDynamic",
966 begin_to_finish_all_loads
);
967 PLT_HISTOGRAM("PLT.StartToFinish_NormalLoad_cwndDynamic",
968 start_to_finish_all_loads
);
969 PLT_HISTOGRAM("PLT.StartToCommit_NormalLoad_cwndDynamic",
977 // Record page load time and abandonment rates for proxy cases.
978 if (document_state
->was_fetched_via_proxy()) {
979 if (scheme_type
== URLPattern::SCHEME_HTTPS
) {
980 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.https", start_to_finish_all_loads
);
981 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.https",
982 abandoned_page
? 1 : 0, 2);
984 DCHECK(scheme_type
== URLPattern::SCHEME_HTTP
);
985 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.http", start_to_finish_all_loads
);
986 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.http",
987 abandoned_page
? 1 : 0, 2);
990 if (scheme_type
== URLPattern::SCHEME_HTTPS
) {
991 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.https",
992 start_to_finish_all_loads
);
993 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.https",
994 abandoned_page
? 1 : 0, 2);
996 DCHECK(scheme_type
== URLPattern::SCHEME_HTTP
);
997 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.http",
998 start_to_finish_all_loads
);
999 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.http",
1000 abandoned_page
? 1 : 0, 2);
1004 // Site isolation metrics.
1005 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithCrossSiteFrameAccess",
1006 cross_origin_access_count_
);
1007 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithSameSiteFrameAccess",
1008 same_origin_access_count_
);
1010 // Log the PLT to the info log.
1011 LogPageLoadTime(document_state
, frame
->dataSource());
1013 // Since there are currently no guarantees that renderer histograms will be
1014 // sent to the browser, we initiate a PostTask here to be sure that we send
1015 // the histograms we generated. Without this call, pages that don't have an
1016 // on-close-handler might generate data that is lost when the renderer is
1017 // shutdown abruptly (perchance because the user closed the tab).
1018 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it
1019 // should post when the onload is complete, so that it doesn't interfere with
1021 content::RenderThread::Get()->UpdateHistograms(
1022 content::kHistogramSynchronizerReservedSequenceNumber
);
1025 void PageLoadHistograms::ResetCrossFramePropertyAccess() {
1026 cross_origin_access_count_
= 0;
1027 same_origin_access_count_
= 0;
1030 void PageLoadHistograms::FrameWillClose(WebFrame
* frame
) {
1034 void PageLoadHistograms::ClosePage() {
1035 // TODO(davemoore) This code should be removed once willClose() gets
1036 // called when a page is destroyed. page_load_histograms_.Dump() is safe
1037 // to call multiple times for the same frame, but it will simplify things.
1038 Dump(render_view()->GetWebView()->mainFrame());
1039 ResetCrossFramePropertyAccess();
1042 void PageLoadHistograms::LogPageLoadTime(const DocumentState
* document_state
,
1043 const WebDataSource
* ds
) const {
1044 // Because this function gets called on every page load,
1045 // take extra care to optimize it away if logging is turned off.
1046 if (logging::LOG_INFO
< logging::GetMinLogLevel())
1049 DCHECK(document_state
);
1051 GURL
url(ds
->request().url());
1052 Time start
= document_state
->start_load_time();
1053 Time finish
= document_state
->finish_load_time();
1054 // TODO(mbelshe): should we log more stats?
1055 VLOG(1) << "PLT: " << (finish
- start
).InMilliseconds() << "ms "