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_util.h"
15 #include "base/strings/stringprintf.h"
16 #include "base/strings/utf_string_conversions.h"
17 #include "base/time/time.h"
18 #include "chrome/common/chrome_switches.h"
19 #include "chrome/renderer/chrome_content_renderer_client.h"
20 #include "content/public/common/content_constants.h"
21 #include "content/public/renderer/document_state.h"
22 #include "content/public/renderer/render_thread.h"
23 #include "content/public/renderer/render_view.h"
24 #include "extensions/common/url_pattern.h"
25 #include "net/base/url_util.h"
26 #include "third_party/WebKit/public/platform/WebURLRequest.h"
27 #include "third_party/WebKit/public/platform/WebURLResponse.h"
28 #include "third_party/WebKit/public/web/WebDocument.h"
29 #include "third_party/WebKit/public/web/WebFrame.h"
30 #include "third_party/WebKit/public/web/WebPerformance.h"
31 #include "third_party/WebKit/public/web/WebView.h"
34 using blink::WebDataSource
;
35 using blink::WebFrame
;
36 using blink::WebPerformance
;
37 using blink::WebString
;
39 using base::TimeDelta
;
40 using content::DocumentState
;
42 const size_t kPLTCount
= 100;
46 // ID indicating that no GWS-Chrome joint experiment is active.
47 const int kNoExperiment
= 0;
49 // Max ID of GWS-Chrome joint experiment. If you change this value, please
50 // update PLT_HISTOGRAM_WITH_GWS_VARIANT accordingly.
51 const int kMaxExperimentID
= 20;
54 return TimeDelta::FromMilliseconds(10);
57 return TimeDelta::FromMinutes(10);
60 // This function corresponds to PLT_HISTOGRAM macro invocation without caching.
61 // Use this for PLT histograms with dynamically generated names, which
62 // otherwise can't use the caching PLT_HISTOGRAM macro without code duplication.
63 void PltHistogramWithNoMacroCaching(const std::string
& name
,
64 const TimeDelta
& sample
) {
65 // The parameters should exacly match the parameters in
66 // UMA_HISTOGRAM_CUSTOM_TIMES macro.
67 base::HistogramBase
* histogram_pointer
= base::Histogram::FactoryTimeGet(
68 name
, kPLTMin(), kPLTMax(), kPLTCount
,
69 base::HistogramBase::kUmaTargetedHistogramFlag
);
70 histogram_pointer
->AddTime(sample
);
73 // Various preview applicability states.
74 enum GwsPreviewState
{
76 // Instant search clicks [not] applied, data reduction proxy used,
79 // Instant search clicks applied, data reduction proxy [not] used,
82 // Instant search clicks applied, data reduction proxy used,
83 // [not] from web search
87 // This records UMA corresponding to the PLT_HISTOGRAM macro without caching.
88 void PltHistogramWithGwsPreview(const char* name
,
89 const TimeDelta
& sample
,
90 GwsPreviewState preview_state
,
91 int preview_experiment_id
) {
92 std::string preview_suffix
;
93 switch (preview_state
) {
94 case PREVIEW_WAS_SHOWN
:
95 preview_suffix
= "_WithPreview";
98 preview_suffix
= "_Preview";
100 case PREVIEW_NOT_USED
:
101 preview_suffix
= "_NoPreview";
106 PltHistogramWithNoMacroCaching(name
+ preview_suffix
, sample
);
108 if (preview_experiment_id
!= kNoExperiment
) {
109 std::string name_with_experiment_id
= base::StringPrintf(
110 "%s%s_Experiment%d", name
, preview_suffix
.c_str(),
111 preview_experiment_id
);
112 PltHistogramWithNoMacroCaching(name_with_experiment_id
, sample
);
116 #define PLT_HISTOGRAM(name, sample) \
117 UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, kPLTMin(), kPLTMax(), kPLTCount);
119 #define PLT_HISTOGRAM_WITH_GWS_VARIANT( \
120 name, sample, came_from_websearch, websearch_chrome_joint_experiment_id, \
121 preview_state, preview_experiment_id) { \
122 PLT_HISTOGRAM(name, sample); \
123 if (came_from_websearch) { \
124 PLT_HISTOGRAM(base::StringPrintf("%s_FromGWS", name), sample) \
125 if (websearch_chrome_joint_experiment_id != kNoExperiment) { \
126 std::string name_with_experiment_id = base::StringPrintf( \
127 "%s_FromGWS_Experiment%d", \
128 name, websearch_chrome_joint_experiment_id); \
129 PltHistogramWithNoMacroCaching(name_with_experiment_id, sample); \
132 PltHistogramWithGwsPreview(name, sample, preview_state, \
133 preview_experiment_id); \
136 // In addition to PLT_HISTOGRAM, add the *_DataReductionProxy variant
137 // conditionally. This macro runs only in one thread.
138 #define PLT_HISTOGRAM_DRP(name, sample, data_reduction_proxy_was_used) \
140 static base::HistogramBase* counter(NULL); \
141 static base::HistogramBase* drp_counter(NULL); \
143 DCHECK(drp_counter == NULL); \
144 counter = base::Histogram::FactoryTimeGet( \
145 name, kPLTMin(), kPLTMax(), kPLTCount, \
146 base::Histogram::kUmaTargetedHistogramFlag); \
148 counter->AddTime(sample); \
149 if (!data_reduction_proxy_was_used) break; \
150 if (!drp_counter) { \
151 drp_counter = base::Histogram::FactoryTimeGet( \
152 std::string(name) + "_DataReductionProxy", \
153 kPLTMin(), kPLTMax(), kPLTCount, \
154 base::Histogram::kUmaTargetedHistogramFlag); \
156 drp_counter->AddTime(sample); \
159 // Returns the scheme type of the given URL if its type is one for which we
160 // dump page load histograms. Otherwise returns NULL.
161 URLPattern::SchemeMasks
GetSupportedSchemeType(const GURL
& url
) {
162 if (url
.SchemeIs("http"))
163 return URLPattern::SCHEME_HTTP
;
164 else if (url
.SchemeIs("https"))
165 return URLPattern::SCHEME_HTTPS
;
166 return static_cast<URLPattern::SchemeMasks
>(0);
169 // Returns true if the data reduction proxy was used. Note, this function will
170 // produce a false positive if a page is fetched using SPDY and using a proxy,
171 // and |kDatReductionProxyViaValue| is added to the Via header.
172 // TODO(bengr): Plumb the hostname of the proxy from |HttpNetworkTransaction|
173 // and check if it matches |SPDY_PROXY_AUTH_ORIGIN|.
174 bool DataReductionProxyWasUsed(WebFrame
* frame
) {
175 #if defined(SPDY_PROXY_AUTH_ORIGIN)
176 const char kViaHeaderName
[] = "Via";
177 const char kDatReductionProxyViaValue
[] = "1.1 Chrome Compression Proxy";
179 DocumentState
* document_state
=
180 DocumentState::FromDataSource(frame
->dataSource());
181 if (!document_state
->was_fetched_via_proxy())
184 std::string
via_header(base::UTF16ToUTF8(
185 frame
->dataSource()->response().httpHeaderField(kViaHeaderName
)));
186 return via_header
.find(kDatReductionProxyViaValue
) != std::string::npos
;
191 // Returns true if the provided URL is a referrer string that came from
192 // a Google Web Search results page. This is a little non-deterministic
193 // because desktop and mobile websearch differ and sometimes just provide
194 // http://www.google.com/ as the referrer. In the case of /url we can be sure
195 // that it came from websearch but we will be generous and allow for cases
196 // where a non-Google URL was provided a bare Google URL as a referrer.
197 // The domain validation matches the code used by the prerenderer for similar
199 // TODO(pmeenan): Remove the fuzzy logic when the referrer is reliable
200 bool IsFromGoogleSearchResult(const GURL
& url
, const GURL
& referrer
) {
201 if (!StartsWithASCII(referrer
.host(), "www.google.", true))
203 if (StartsWithASCII(referrer
.path(), "/url", true))
205 bool is_possible_search_referrer
=
206 referrer
.path().empty() ||
207 referrer
.path() == "/" ||
208 StartsWithASCII(referrer
.path(), "/search", true) ||
209 StartsWithASCII(referrer
.path(), "/webhp", true);
210 if (is_possible_search_referrer
&&
211 !StartsWithASCII(url
.host(), "www.google", true))
216 // Extracts a Google Web Search and Chrome joint experiment ID from a referrer
217 // that came from a Google Web Search results page. An experiment ID is embedded
218 // in a query string as a "gcjeid=" parameter value.
219 int GetQueryStringBasedExperiment(const GURL
& referrer
) {
221 if (!net::GetValueForKeyInQuery(referrer
, "gcjeid", &value
))
222 return kNoExperiment
;
225 if (!base::StringToInt(value
, &experiment_id
))
226 return kNoExperiment
;
227 if (0 < experiment_id
&& experiment_id
<= kMaxExperimentID
)
228 return experiment_id
;
229 return kNoExperiment
;
232 // Appends "cerivrj_*" and "gcjeid" query parameters from preview_url to url.
233 // Returns true if "cerivrj_*" query is found.
234 // This will be used only for search results URLs.
235 bool AppendPreviewQueryFromURL(const GURL
& preview_url
, GURL
* url
) {
236 bool preview_query_found
= false;
237 for (net::QueryIterator
it(preview_url
); !it
.IsAtEnd(); it
.Advance()) {
238 const std::string param_name
= it
.GetKey();
239 bool is_preview
= StartsWithASCII(param_name
, "cerivrj_", true);
240 if (url
&& (is_preview
|| param_name
== "gcjeid"))
241 net::AppendQueryParameter(*url
, param_name
, it
.GetValue());
242 preview_query_found
= preview_query_found
|| is_preview
;
244 return preview_query_found
;
247 // Returns true if the provided referrer URL is the preview URL of the current
248 // URL. Preview URL differs from original only with "cerivrj_*", "gcjeid" query
250 bool IsReferrerPreviewOfURL(const GURL
& url
,
251 const base::string16
& referrer_str
) {
252 GURL
referrer(referrer_str
);
253 if (referrer
.is_valid()) {
254 GURL
generated_preview_url(url
);
255 // Now try to copy "cerivrj_*" and "gcjeid" paramters to url and check if
256 // they exactly match.
257 if (AppendPreviewQueryFromURL(referrer
, &generated_preview_url
))
258 return generated_preview_url
== referrer
;
263 // Returns preview state by looking at url and referer url.
264 void GetPreviewState(const GURL
& url
,
265 const base::string16
& referrer
,
266 bool came_from_websearch
,
267 bool data_reduction_proxy_was_used
,
268 GwsPreviewState
* preview_state
,
269 int* preview_experiment_id
) {
270 // Conditions for GWS preview are,
271 // 1. Data reduction proxy was used.
272 // 2. URL is loaded from web search.
273 // If the URL contains "cerivrj_*' query parameter record under
275 if (data_reduction_proxy_was_used
) {
276 if (came_from_websearch
) {
278 AppendPreviewQueryFromURL(url
, NULL
) ? PREVIEW
: PREVIEW_NOT_USED
;
279 } else if (IsReferrerPreviewOfURL(url
, referrer
)) {
280 *preview_state
= PREVIEW_WAS_SHOWN
;
281 *preview_experiment_id
= GetQueryStringBasedExperiment(GURL(referrer
));
286 void DumpPerformanceTiming(const WebPerformance
& performance
,
287 DocumentState
* document_state
,
288 bool data_reduction_proxy_was_used
,
289 bool came_from_websearch
,
290 int websearch_chrome_joint_experiment_id
,
291 GwsPreviewState preview_state
,
292 int preview_experiment_id
) {
293 Time request
= document_state
->request_time();
295 Time navigation_start
= Time::FromDoubleT(performance
.navigationStart());
296 Time redirect_start
= Time::FromDoubleT(performance
.redirectStart());
297 Time redirect_end
= Time::FromDoubleT(performance
.redirectEnd());
298 Time fetch_start
= Time::FromDoubleT(performance
.fetchStart());
299 Time domain_lookup_start
= Time::FromDoubleT(performance
.domainLookupStart());
300 Time domain_lookup_end
= Time::FromDoubleT(performance
.domainLookupEnd());
301 Time connect_start
= Time::FromDoubleT(performance
.connectStart());
302 Time connect_end
= Time::FromDoubleT(performance
.connectEnd());
303 Time request_start
= Time::FromDoubleT(performance
.requestStart());
304 Time response_start
= Time::FromDoubleT(performance
.responseStart());
305 Time response_end
= Time::FromDoubleT(performance
.responseEnd());
306 Time dom_loading
= Time::FromDoubleT(performance
.domLoading());
307 Time dom_interactive
= Time::FromDoubleT(performance
.domInteractive());
308 Time dom_content_loaded_start
=
309 Time::FromDoubleT(performance
.domContentLoadedEventStart());
310 Time dom_content_loaded_end
=
311 Time::FromDoubleT(performance
.domContentLoadedEventEnd());
312 Time load_event_start
= Time::FromDoubleT(performance
.loadEventStart());
313 Time load_event_end
= Time::FromDoubleT(performance
.loadEventEnd());
314 Time begin
= (request
.is_null() ? navigation_start
: request_start
);
316 DCHECK(!navigation_start
.is_null());
318 // It is possible for a document to have navigation_start time, but no
319 // request_start. An example is doing a window.open, which synchronously
320 // loads "about:blank", then using document.write add a meta http-equiv
321 // refresh tag, which causes a navigation. In such case, we will arrive at
322 // this function with no request/response timing data and identical load
323 // start/end values. Avoid logging this case, as it doesn't add any
324 // meaningful information to the histogram.
325 if (request_start
.is_null())
328 // TODO(dominich): Investigate conditions under which |load_event_start| and
329 // |load_event_end| may be NULL as in the non-PT_ case below. Examples in
330 // http://crbug.com/112006.
331 // DCHECK(!load_event_start.is_null());
332 // DCHECK(!load_event_end.is_null());
334 if (document_state
->web_timing_histograms_recorded())
336 document_state
->set_web_timing_histograms_recorded(true);
338 if (!redirect_start
.is_null() && !redirect_end
.is_null()) {
339 PLT_HISTOGRAM_DRP("PLT.NT_Redirect", redirect_end
- redirect_start
,
340 data_reduction_proxy_was_used
);
342 "PLT.NT_DelayBeforeFetchRedirect",
343 (fetch_start
- navigation_start
) - (redirect_end
- redirect_start
),
344 data_reduction_proxy_was_used
);
346 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeFetch",
347 fetch_start
- navigation_start
,
348 data_reduction_proxy_was_used
);
350 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomainLookup",
351 domain_lookup_start
- fetch_start
,
352 data_reduction_proxy_was_used
);
353 PLT_HISTOGRAM_DRP("PLT.NT_DomainLookup",
354 domain_lookup_end
- domain_lookup_start
,
355 data_reduction_proxy_was_used
);
356 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeConnect",
357 connect_start
- domain_lookup_end
,
358 data_reduction_proxy_was_used
);
359 PLT_HISTOGRAM_DRP("PLT.NT_Connect", connect_end
- connect_start
,
360 data_reduction_proxy_was_used
);
361 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeRequest",
362 request_start
- connect_end
,
363 data_reduction_proxy_was_used
);
364 PLT_HISTOGRAM_DRP("PLT.NT_Request", response_start
- request_start
,
365 data_reduction_proxy_was_used
);
366 PLT_HISTOGRAM_DRP("PLT.NT_Response", response_end
- response_start
,
367 data_reduction_proxy_was_used
);
369 if (!dom_loading
.is_null()) {
370 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomLoading",
371 dom_loading
- response_start
,
372 data_reduction_proxy_was_used
);
374 if (!dom_interactive
.is_null() && !dom_loading
.is_null()) {
375 PLT_HISTOGRAM_DRP("PLT.NT_DomLoading",
376 dom_interactive
- dom_loading
,
377 data_reduction_proxy_was_used
);
379 if (!dom_content_loaded_start
.is_null() && !dom_interactive
.is_null()) {
380 PLT_HISTOGRAM_DRP("PLT.NT_DomInteractive",
381 dom_content_loaded_start
- dom_interactive
,
382 data_reduction_proxy_was_used
);
384 if (!dom_content_loaded_start
.is_null() &&
385 !dom_content_loaded_end
.is_null() ) {
386 PLT_HISTOGRAM_DRP("PLT.NT_DomContentLoaded",
387 dom_content_loaded_end
- dom_content_loaded_start
,
388 data_reduction_proxy_was_used
);
390 if (!dom_content_loaded_end
.is_null() && !load_event_start
.is_null()) {
391 PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeLoadEvent",
392 load_event_start
- dom_content_loaded_end
,
393 data_reduction_proxy_was_used
);
396 // TODO(simonjam): There is no way to distinguish between abandonment and
397 // intentional Javascript navigation before the load event fires.
398 // TODO(dominich): Load type breakdown
399 if (!load_event_start
.is_null()) {
400 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinishDoc",
401 load_event_start
- begin
,
403 websearch_chrome_joint_experiment_id
,
404 preview_state
, preview_experiment_id
);
405 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinishDoc",
406 load_event_start
- response_start
,
408 websearch_chrome_joint_experiment_id
,
409 preview_state
, preview_experiment_id
);
410 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinishDoc",
411 load_event_start
- navigation_start
,
413 websearch_chrome_joint_experiment_id
,
414 preview_state
, preview_experiment_id
);
415 if (data_reduction_proxy_was_used
) {
416 PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_DataReductionProxy",
417 load_event_start
- begin
);
418 PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_DataReductionProxy",
419 load_event_start
- response_start
);
420 PLT_HISTOGRAM("PLT.PT_RequestToFinishDoc_DataReductionProxy",
421 load_event_start
- navigation_start
);
424 if (!load_event_end
.is_null()) {
425 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToFinish",
426 load_event_end
- begin
,
428 websearch_chrome_joint_experiment_id
,
429 preview_state
, preview_experiment_id
);
430 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_CommitToFinish",
431 load_event_end
- response_start
,
433 websearch_chrome_joint_experiment_id
,
434 preview_state
, preview_experiment_id
);
435 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToFinish",
436 load_event_end
- navigation_start
,
438 websearch_chrome_joint_experiment_id
,
439 preview_state
, preview_experiment_id
);
440 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToFinish",
441 load_event_end
- request_start
,
443 websearch_chrome_joint_experiment_id
,
444 preview_state
, preview_experiment_id
);
445 if (data_reduction_proxy_was_used
) {
446 PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy",
447 load_event_end
- begin
);
448 PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy",
449 load_event_end
- response_start
);
450 PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy",
451 load_event_end
- navigation_start
);
452 PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy",
453 load_event_end
- request_start
);
456 if (!load_event_start
.is_null() && !load_event_end
.is_null()) {
457 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish",
458 load_event_end
- load_event_start
);
459 PLT_HISTOGRAM_DRP("PLT.NT_LoadEvent",
460 load_event_end
- load_event_start
,
461 data_reduction_proxy_was_used
);
463 if (data_reduction_proxy_was_used
)
464 PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_DataReductionProxy",
465 load_event_end
- load_event_start
);
467 if (!dom_content_loaded_start
.is_null()) {
468 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToDomContentLoaded",
469 dom_content_loaded_start
- navigation_start
,
471 websearch_chrome_joint_experiment_id
,
472 preview_state
, preview_experiment_id
);
473 if (data_reduction_proxy_was_used
)
474 PLT_HISTOGRAM("PLT.PT_RequestToDomContentLoaded_DataReductionProxy",
475 dom_content_loaded_start
- navigation_start
);
477 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_BeginToCommit",
478 response_start
- begin
,
480 websearch_chrome_joint_experiment_id
,
481 preview_state
, preview_experiment_id
);
482 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToStart",
483 request_start
- navigation_start
,
485 websearch_chrome_joint_experiment_id
,
486 preview_state
, preview_experiment_id
);
487 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_StartToCommit",
488 response_start
- request_start
,
490 websearch_chrome_joint_experiment_id
,
491 preview_state
, preview_experiment_id
);
492 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.PT_RequestToCommit",
493 response_start
- navigation_start
,
495 websearch_chrome_joint_experiment_id
,
496 preview_state
, preview_experiment_id
);
497 if (data_reduction_proxy_was_used
) {
498 PLT_HISTOGRAM("PLT.PT_BeginToCommit_DataReductionProxy",
499 response_start
- begin
);
500 PLT_HISTOGRAM("PLT.PT_RequestToStart_DataReductionProxy",
501 request_start
- navigation_start
);
502 PLT_HISTOGRAM("PLT.PT_StartToCommit_DataReductionProxy",
503 response_start
- request_start
);
504 PLT_HISTOGRAM("PLT.PT_RequestToCommit_DataReductionProxy",
505 response_start
- navigation_start
);
509 enum MissingStartType
{
511 COMMIT_MISSING
= 0x2,
512 NAV_START_MISSING
= 0x4,
513 MISSING_START_TYPE_MAX
= 0x8
517 FINISH_DOC_MISSING
= 0x1,
518 FINISH_ALL_LOADS_MISSING
= 0x2,
519 LOAD_EVENT_START_MISSING
= 0x4,
520 LOAD_EVENT_END_MISSING
= 0x8,
521 ABANDON_TYPE_MAX
= 0x10
526 PageLoadHistograms::PageLoadHistograms(content::RenderView
* render_view
)
527 : content::RenderViewObserver(render_view
),
528 cross_origin_access_count_(0),
529 same_origin_access_count_(0) {
532 void PageLoadHistograms::Dump(WebFrame
* frame
) {
533 // We only dump histograms for main frames.
534 // In the future, it may be interesting to tag subframes and dump them too.
535 if (!frame
|| frame
->parent())
538 // Only dump for supported schemes.
539 URLPattern::SchemeMasks scheme_type
=
540 GetSupportedSchemeType(frame
->document().url());
541 if (scheme_type
== 0)
544 // Ignore multipart requests.
545 if (frame
->dataSource()->response().isMultipartPayload())
548 DocumentState
* document_state
=
549 DocumentState::FromDataSource(frame
->dataSource());
551 bool data_reduction_proxy_was_used
= DataReductionProxyWasUsed(frame
);
552 bool came_from_websearch
=
553 IsFromGoogleSearchResult(frame
->document().url(),
554 GURL(frame
->document().referrer()));
555 int websearch_chrome_joint_experiment_id
= kNoExperiment
;
556 if (came_from_websearch
) {
557 websearch_chrome_joint_experiment_id
=
558 GetQueryStringBasedExperiment(GURL(frame
->document().referrer()));
561 GwsPreviewState preview_state
= PREVIEW_NONE
;
562 int preview_experiment_id
= websearch_chrome_joint_experiment_id
;
563 GetPreviewState(frame
->document().url(), frame
->document().referrer(),
564 came_from_websearch
, data_reduction_proxy_was_used
,
565 &preview_state
, &preview_experiment_id
);
567 // Times based on the Web Timing metrics.
568 // http://www.w3.org/TR/navigation-timing/
569 // TODO(tonyg, jar): We are in the process of vetting these metrics against
570 // the existing ones. Once we understand any differences, we will standardize
571 // on a single set of metrics.
572 DumpPerformanceTiming(frame
->performance(), document_state
,
573 data_reduction_proxy_was_used
,
575 websearch_chrome_joint_experiment_id
,
576 preview_state
, preview_experiment_id
);
578 // If we've already dumped, do nothing.
579 // This simple bool works because we only dump for the main frame.
580 if (document_state
->load_histograms_recorded())
583 // Collect measurement times.
584 Time start
= document_state
->start_load_time();
585 Time commit
= document_state
->commit_load_time();
587 // TODO(tonyg, jar): Start can be missing after an in-document navigation and
588 // possibly other cases like a very premature abandonment of the page.
589 // The PLT.MissingStart histogram should help us troubleshoot and then we can
591 Time navigation_start
=
592 Time::FromDoubleT(frame
->performance().navigationStart());
593 int missing_start_type
= 0;
594 missing_start_type
|= start
.is_null() ? START_MISSING
: 0;
595 missing_start_type
|= commit
.is_null() ? COMMIT_MISSING
: 0;
596 missing_start_type
|= navigation_start
.is_null() ? NAV_START_MISSING
: 0;
597 UMA_HISTOGRAM_ENUMERATION("PLT.MissingStart", missing_start_type
,
598 MISSING_START_TYPE_MAX
);
599 if (missing_start_type
)
602 // We properly handle null values for the next 3 variables.
603 Time request
= document_state
->request_time();
604 Time first_paint
= document_state
->first_paint_time();
605 Time first_paint_after_load
= document_state
->first_paint_after_load_time();
606 Time finish_doc
= document_state
->finish_document_load_time();
607 Time finish_all_loads
= document_state
->finish_load_time();
609 // TODO(tonyg, jar): We suspect a bug in abandonment counting, this temporary
610 // histogram should help us to troubleshoot.
611 Time load_event_start
=
612 Time::FromDoubleT(frame
->performance().loadEventStart());
613 Time load_event_end
= Time::FromDoubleT(frame
->performance().loadEventEnd());
614 int abandon_type
= 0;
615 abandon_type
|= finish_doc
.is_null() ? FINISH_DOC_MISSING
: 0;
616 abandon_type
|= finish_all_loads
.is_null() ? FINISH_ALL_LOADS_MISSING
: 0;
617 abandon_type
|= load_event_start
.is_null() ? LOAD_EVENT_START_MISSING
: 0;
618 abandon_type
|= load_event_end
.is_null() ? LOAD_EVENT_END_MISSING
: 0;
619 UMA_HISTOGRAM_ENUMERATION("PLT.AbandonType", abandon_type
, ABANDON_TYPE_MAX
);
621 // Handle case where user hits "stop" or "back" before loading completely.
622 bool abandoned_page
= finish_doc
.is_null();
623 if (abandoned_page
) {
624 finish_doc
= Time::Now();
625 document_state
->set_finish_document_load_time(finish_doc
);
628 // TODO(jar): We should really discriminate the definition of "abandon" more
629 // finely. We should have:
630 // abandon_before_document_loaded
631 // abandon_before_onload_fired
633 if (finish_all_loads
.is_null()) {
634 finish_all_loads
= Time::Now();
635 document_state
->set_finish_load_time(finish_all_loads
);
637 DCHECK(!abandoned_page
); // How can the doc have finished but not the page?
639 return; // Don't try to record a stat which is broken.
642 document_state
->set_load_histograms_recorded(true);
644 // Note: Client side redirects will have no request time.
645 Time begin
= request
.is_null() ? start
: request
;
646 TimeDelta begin_to_finish_doc
= finish_doc
- begin
;
647 TimeDelta begin_to_finish_all_loads
= finish_all_loads
- begin
;
648 TimeDelta start_to_finish_all_loads
= finish_all_loads
- start
;
649 TimeDelta start_to_commit
= commit
- start
;
651 DocumentState::LoadType load_type
= document_state
->load_type();
653 // The above code sanitized all values of times, in preparation for creating
654 // actual histograms. The remainder of this code could be run at destructor
655 // time for the document_state, since all data is intact.
657 // Aggregate PLT data across all link types.
658 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned", abandoned_page
? 1 : 0, 2);
659 UMA_HISTOGRAM_ENUMERATION("PLT.LoadType", load_type
,
660 DocumentState::kLoadTypeMax
);
661 PLT_HISTOGRAM("PLT.StartToCommit", start_to_commit
);
662 PLT_HISTOGRAM("PLT.CommitToFinishDoc", finish_doc
- commit
);
663 PLT_HISTOGRAM("PLT.FinishDocToFinish", finish_all_loads
- finish_doc
);
664 PLT_HISTOGRAM("PLT.BeginToCommit", commit
- begin
);
665 PLT_HISTOGRAM("PLT.StartToFinish", start_to_finish_all_loads
);
666 if (!request
.is_null()) {
667 PLT_HISTOGRAM("PLT.RequestToStart", start
- request
);
668 PLT_HISTOGRAM("PLT.RequestToFinish", finish_all_loads
- request
);
670 PLT_HISTOGRAM("PLT.CommitToFinish", finish_all_loads
- commit
);
672 scoped_ptr
<TimeDelta
> begin_to_first_paint
;
673 scoped_ptr
<TimeDelta
> commit_to_first_paint
;
674 if (!first_paint
.is_null()) {
675 // 'first_paint' can be before 'begin' for an unknown reason.
676 // See bug http://crbug.com/125273 for details.
677 if (begin
<= first_paint
) {
678 begin_to_first_paint
.reset(new TimeDelta(first_paint
- begin
));
679 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFirstPaint",
680 *begin_to_first_paint
,
682 websearch_chrome_joint_experiment_id
,
683 preview_state
, preview_experiment_id
);
685 DCHECK(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
,
690 websearch_chrome_joint_experiment_id
,
691 preview_state
, preview_experiment_id
);
693 if (!first_paint_after_load
.is_null()) {
694 // 'first_paint_after_load' can be before 'begin' for an unknown reason.
695 // See bug http://crbug.com/125273 for details.
696 if (begin
<= first_paint_after_load
) {
697 PLT_HISTOGRAM("PLT.BeginToFirstPaintAfterLoad",
698 first_paint_after_load
- begin
);
700 DCHECK(commit
<= first_paint_after_load
);
701 PLT_HISTOGRAM("PLT.CommitToFirstPaintAfterLoad",
702 first_paint_after_load
- commit
);
703 DCHECK(finish_all_loads
<= first_paint_after_load
);
704 PLT_HISTOGRAM("PLT.FinishToFirstPaintAfterLoad",
705 first_paint_after_load
- finish_all_loads
);
707 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinishDoc", begin_to_finish_doc
,
709 websearch_chrome_joint_experiment_id
,
710 preview_state
, preview_experiment_id
);
711 PLT_HISTOGRAM_WITH_GWS_VARIANT("PLT.BeginToFinish", begin_to_finish_all_loads
,
713 websearch_chrome_joint_experiment_id
,
714 preview_state
, preview_experiment_id
);
716 // Load type related histograms.
718 case DocumentState::UNDEFINED_LOAD
:
719 PLT_HISTOGRAM("PLT.BeginToFinishDoc_UndefLoad", begin_to_finish_doc
);
720 PLT_HISTOGRAM("PLT.BeginToFinish_UndefLoad", begin_to_finish_all_loads
);
722 case DocumentState::RELOAD
:
723 PLT_HISTOGRAM("PLT.BeginToFinishDoc_Reload", begin_to_finish_doc
);
724 PLT_HISTOGRAM("PLT.BeginToFinish_Reload", begin_to_finish_all_loads
);
726 case DocumentState::HISTORY_LOAD
:
727 PLT_HISTOGRAM("PLT.BeginToFinishDoc_HistoryLoad", begin_to_finish_doc
);
728 PLT_HISTOGRAM("PLT.BeginToFinish_HistoryLoad", begin_to_finish_all_loads
);
730 case DocumentState::NORMAL_LOAD
:
731 PLT_HISTOGRAM("PLT.BeginToFinishDoc_NormalLoad", begin_to_finish_doc
);
732 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad", begin_to_finish_all_loads
);
734 case DocumentState::LINK_LOAD_NORMAL
:
735 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadNormal",
736 begin_to_finish_doc
);
737 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal",
738 begin_to_finish_all_loads
);
740 case DocumentState::LINK_LOAD_RELOAD
:
741 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadReload",
742 begin_to_finish_doc
);
743 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadReload",
744 begin_to_finish_all_loads
);
746 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
747 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadStaleOk",
748 begin_to_finish_doc
);
749 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadStaleOk",
750 begin_to_finish_all_loads
);
752 case DocumentState::LINK_LOAD_CACHE_ONLY
:
753 PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadCacheOnly",
754 begin_to_finish_doc
);
755 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadCacheOnly",
756 begin_to_finish_all_loads
);
762 if (data_reduction_proxy_was_used
) {
763 UMA_HISTOGRAM_ENUMERATION(
764 "PLT.Abandoned_SpdyProxy", abandoned_page
? 1 : 0, 2);
765 PLT_HISTOGRAM("PLT.BeginToFinishDoc_SpdyProxy", begin_to_finish_doc
);
766 PLT_HISTOGRAM("PLT.BeginToFinish_SpdyProxy", begin_to_finish_all_loads
);
769 if (document_state
->was_prefetcher()) {
770 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcher",
771 begin_to_finish_doc
);
772 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcher",
773 begin_to_finish_all_loads
);
775 if (document_state
->was_referred_by_prefetcher()) {
776 PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcherReferrer",
777 begin_to_finish_doc
);
778 PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcherReferrer",
779 begin_to_finish_all_loads
);
781 if (document_state
->was_after_preconnect_request()) {
782 PLT_HISTOGRAM("PLT.BeginToFinishDoc_AfterPreconnectRequest",
783 begin_to_finish_doc
);
784 PLT_HISTOGRAM("PLT.BeginToFinish_AfterPreconnectRequest",
785 begin_to_finish_all_loads
);
788 // TODO(mpcomplete): remove the extension-related histograms after we collect
789 // enough data. http://crbug.com/100411
790 const bool use_adblock_histogram
=
791 ChromeContentRendererClient::IsAdblockInstalled();
792 if (use_adblock_histogram
) {
793 UMA_HISTOGRAM_ENUMERATION(
794 "PLT.Abandoned_ExtensionAdblock",
795 abandoned_page
? 1 : 0, 2);
797 case DocumentState::NORMAL_LOAD
:
799 "PLT.BeginToFinish_NormalLoad_ExtensionAdblock",
800 begin_to_finish_all_loads
);
802 case DocumentState::LINK_LOAD_NORMAL
:
804 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblock",
805 begin_to_finish_all_loads
);
807 case DocumentState::LINK_LOAD_RELOAD
:
809 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblock",
810 begin_to_finish_all_loads
);
812 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
814 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblock",
815 begin_to_finish_all_loads
);
822 const bool use_adblockplus_histogram
=
823 ChromeContentRendererClient::IsAdblockPlusInstalled();
824 if (use_adblockplus_histogram
) {
825 UMA_HISTOGRAM_ENUMERATION(
826 "PLT.Abandoned_ExtensionAdblockPlus",
827 abandoned_page
? 1 : 0, 2);
829 case DocumentState::NORMAL_LOAD
:
831 "PLT.BeginToFinish_NormalLoad_ExtensionAdblockPlus",
832 begin_to_finish_all_loads
);
834 case DocumentState::LINK_LOAD_NORMAL
:
836 "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblockPlus",
837 begin_to_finish_all_loads
);
839 case DocumentState::LINK_LOAD_RELOAD
:
841 "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblockPlus",
842 begin_to_finish_all_loads
);
844 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
846 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblockPlus",
847 begin_to_finish_all_loads
);
854 const bool use_webrequest_adblock_histogram
=
855 ChromeContentRendererClient::IsAdblockWithWebRequestInstalled();
856 if (use_webrequest_adblock_histogram
) {
857 UMA_HISTOGRAM_ENUMERATION(
858 "PLT.Abandoned_ExtensionWebRequestAdblock",
859 abandoned_page
? 1 : 0, 2);
861 case DocumentState::NORMAL_LOAD
:
863 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblock",
864 begin_to_finish_all_loads
);
866 case DocumentState::LINK_LOAD_NORMAL
:
868 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblock",
869 begin_to_finish_all_loads
);
871 case DocumentState::LINK_LOAD_RELOAD
:
873 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblock",
874 begin_to_finish_all_loads
);
876 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
878 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblock",
879 begin_to_finish_all_loads
);
886 const bool use_webrequest_adblockplus_histogram
=
887 ChromeContentRendererClient::
888 IsAdblockPlusWithWebRequestInstalled();
889 if (use_webrequest_adblockplus_histogram
) {
890 UMA_HISTOGRAM_ENUMERATION(
891 "PLT.Abandoned_ExtensionWebRequestAdblockPlus",
892 abandoned_page
? 1 : 0, 2);
894 case DocumentState::NORMAL_LOAD
:
896 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblockPlus",
897 begin_to_finish_all_loads
);
899 case DocumentState::LINK_LOAD_NORMAL
:
901 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblockPlus",
902 begin_to_finish_all_loads
);
904 case DocumentState::LINK_LOAD_RELOAD
:
906 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblockPlus",
907 begin_to_finish_all_loads
);
909 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
911 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblockPlus",
912 begin_to_finish_all_loads
);
919 const bool use_webrequest_other_histogram
=
920 ChromeContentRendererClient::
921 IsOtherExtensionWithWebRequestInstalled();
922 if (use_webrequest_other_histogram
) {
923 UMA_HISTOGRAM_ENUMERATION(
924 "PLT.Abandoned_ExtensionWebRequestOther",
925 abandoned_page
? 1 : 0, 2);
927 case DocumentState::NORMAL_LOAD
:
929 "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestOther",
930 begin_to_finish_all_loads
);
932 case DocumentState::LINK_LOAD_NORMAL
:
934 "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestOther",
935 begin_to_finish_all_loads
);
937 case DocumentState::LINK_LOAD_RELOAD
:
939 "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestOther",
940 begin_to_finish_all_loads
);
942 case DocumentState::LINK_LOAD_CACHE_STALE_OK
:
944 "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestOther",
945 begin_to_finish_all_loads
);
952 // Record SpdyCwnd results.
953 if (document_state
->was_fetched_via_spdy()) {
955 case DocumentState::LINK_LOAD_NORMAL
:
956 PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal_cwndDynamic",
957 begin_to_finish_all_loads
);
958 PLT_HISTOGRAM("PLT.StartToFinish_LinkLoadNormal_cwndDynamic",
959 start_to_finish_all_loads
);
960 PLT_HISTOGRAM("PLT.StartToCommit_LinkLoadNormal_cwndDynamic",
963 case DocumentState::NORMAL_LOAD
:
964 PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad_cwndDynamic",
965 begin_to_finish_all_loads
);
966 PLT_HISTOGRAM("PLT.StartToFinish_NormalLoad_cwndDynamic",
967 start_to_finish_all_loads
);
968 PLT_HISTOGRAM("PLT.StartToCommit_NormalLoad_cwndDynamic",
976 // Record page load time and abandonment rates for proxy cases.
977 if (document_state
->was_fetched_via_proxy()) {
978 if (scheme_type
== URLPattern::SCHEME_HTTPS
) {
979 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.https", start_to_finish_all_loads
);
980 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.https",
981 abandoned_page
? 1 : 0, 2);
983 DCHECK(scheme_type
== URLPattern::SCHEME_HTTP
);
984 PLT_HISTOGRAM("PLT.StartToFinish.Proxy.http", start_to_finish_all_loads
);
985 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.http",
986 abandoned_page
? 1 : 0, 2);
989 if (scheme_type
== URLPattern::SCHEME_HTTPS
) {
990 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.https",
991 start_to_finish_all_loads
);
992 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.https",
993 abandoned_page
? 1 : 0, 2);
995 DCHECK(scheme_type
== URLPattern::SCHEME_HTTP
);
996 PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.http",
997 start_to_finish_all_loads
);
998 UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.http",
999 abandoned_page
? 1 : 0, 2);
1003 // Site isolation metrics.
1004 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithCrossSiteFrameAccess",
1005 cross_origin_access_count_
);
1006 UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithSameSiteFrameAccess",
1007 same_origin_access_count_
);
1009 // Log the PLT to the info log.
1010 LogPageLoadTime(document_state
, frame
->dataSource());
1012 // Since there are currently no guarantees that renderer histograms will be
1013 // sent to the browser, we initiate a PostTask here to be sure that we send
1014 // the histograms we generated. Without this call, pages that don't have an
1015 // on-close-handler might generate data that is lost when the renderer is
1016 // shutdown abruptly (perchance because the user closed the tab).
1017 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it
1018 // should post when the onload is complete, so that it doesn't interfere with
1020 content::RenderThread::Get()->UpdateHistograms(
1021 content::kHistogramSynchronizerReservedSequenceNumber
);
1024 void PageLoadHistograms::ResetCrossFramePropertyAccess() {
1025 cross_origin_access_count_
= 0;
1026 same_origin_access_count_
= 0;
1029 void PageLoadHistograms::FrameWillClose(WebFrame
* frame
) {
1033 void PageLoadHistograms::ClosePage() {
1034 // TODO(davemoore) This code should be removed once willClose() gets
1035 // called when a page is destroyed. page_load_histograms_.Dump() is safe
1036 // to call multiple times for the same frame, but it will simplify things.
1037 Dump(render_view()->GetWebView()->mainFrame());
1038 ResetCrossFramePropertyAccess();
1041 void PageLoadHistograms::LogPageLoadTime(const DocumentState
* document_state
,
1042 const WebDataSource
* ds
) const {
1043 // Because this function gets called on every page load,
1044 // take extra care to optimize it away if logging is turned off.
1045 if (logging::LOG_INFO
< logging::GetMinLogLevel())
1048 DCHECK(document_state
);
1050 GURL
url(ds
->request().url());
1051 Time start
= document_state
->start_load_time();
1052 Time finish
= document_state
->finish_load_time();
1053 // TODO(mbelshe): should we log more stats?
1054 VLOG(1) << "PLT: " << (finish
- start
).InMilliseconds() << "ms "