1// Copyright (c) 2012 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include "chrome/renderer/page_load_histograms.h"
6
7#include <string>
8
9#include "base/command_line.h"
10#include "base/logging.h"
11#include "base/metrics/field_trial.h"
12#include "base/metrics/histogram.h"
13#include "base/strings/utf_string_conversions.h"
14#include "base/time/time.h"
15#include "chrome/common/chrome_switches.h"
16#include "chrome/renderer/chrome_content_renderer_client.h"
17#include "content/public/common/content_constants.h"
18#include "content/public/renderer/document_state.h"
19#include "content/public/renderer/render_thread.h"
20#include "content/public/renderer/render_view.h"
21#include "extensions/common/url_pattern.h"
22#include "third_party/WebKit/public/platform/WebURLRequest.h"
23#include "third_party/WebKit/public/platform/WebURLResponse.h"
24#include "third_party/WebKit/public/web/WebDocument.h"
25#include "third_party/WebKit/public/web/WebFrame.h"
26#include "third_party/WebKit/public/web/WebPerformance.h"
27#include "third_party/WebKit/public/web/WebView.h"
28#include "url/gurl.h"
29
30using WebKit::WebDataSource;
31using WebKit::WebFrame;
32using WebKit::WebPerformance;
33using WebKit::WebString;
34using base::Time;
35using base::TimeDelta;
36using content::DocumentState;
37
38const size_t kPLTCount = 100;
39
40namespace {
41
42TimeDelta kPLTMin() {
43  return TimeDelta::FromMilliseconds(10);
44}
45TimeDelta kPLTMax() {
46  return TimeDelta::FromMinutes(10);
47}
48
49#define PLT_HISTOGRAM(name, sample) \
50    UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, kPLTMin(), kPLTMax(), kPLTCount);
51
52// In addition to PLT_HISTOGRAM, add the *_DataReductionProxy variant
53// conditionally. This macro runs only in one thread.
54#define PLT_HISTOGRAM_DRP(name, sample, data_reduction_proxy_was_used) \
55  do {                                                                  \
56    static base::HistogramBase* counter(NULL);                          \
57    static base::HistogramBase* drp_counter(NULL);                      \
58    if (!counter) {                                                     \
59      DCHECK(drp_counter == NULL);                                      \
60      counter = base::Histogram::FactoryTimeGet(                        \
61          name, kPLTMin(), kPLTMax(), kPLTCount,                        \
62          base::Histogram::kUmaTargetedHistogramFlag);                  \
63    }                                                                   \
64    counter->AddTime(sample);                                           \
65    if (!data_reduction_proxy_was_used) break;                          \
66    if (!drp_counter) {                                                 \
67      drp_counter = base::Histogram::FactoryTimeGet(                    \
68          std::string(name) + "_DataReductionProxy",                    \
69          kPLTMin(), kPLTMax(), kPLTCount,                              \
70          base::Histogram::kUmaTargetedHistogramFlag);                  \
71    }                                                                   \
72    drp_counter->AddTime(sample);                                       \
73  } while (0)
74
75// Returns the scheme type of the given URL if its type is one for which we
76// dump page load histograms. Otherwise returns NULL.
77URLPattern::SchemeMasks GetSupportedSchemeType(const GURL& url) {
78  if (url.SchemeIs("http"))
79    return URLPattern::SCHEME_HTTP;
80  else if (url.SchemeIs("https"))
81    return URLPattern::SCHEME_HTTPS;
82  return static_cast<URLPattern::SchemeMasks>(0);
83}
84
85// Returns true if the data reduction proxy was used. Note, this function will
86// produce a false positive if a page is fetched using SPDY and using a proxy,
87// and |kDatReductionProxyViaValue| is added to the Via header.
88// TODO(bengr): Plumb the hostname of the proxy from |HttpNetworkTransaction|
89// and check if it matches |SPDY_PROXY_AUTH_ORIGIN|.
90bool DataReductionProxyWasUsed(WebFrame* frame) {
91#if defined(SPDY_PROXY_AUTH_ORIGIN)
92  const char kViaHeaderName[] = "Via";
93  const char kDatReductionProxyViaValue[] = "1.1 Chrome Compression Proxy";
94
95  DocumentState* document_state =
96      DocumentState::FromDataSource(frame->dataSource());
97  if (!document_state->was_fetched_via_proxy())
98    return false;
99
100  std::string via_header(UTF16ToUTF8(
101      frame->dataSource()->response().httpHeaderField(kViaHeaderName)));
102  return via_header.find(kDatReductionProxyViaValue) != std::string::npos;
103#endif
104  return false;
105}
106
107void DumpPerformanceTiming(const WebPerformance& performance,
108                           DocumentState* document_state,
109                           bool data_reduction_proxy_was_used) {
110  Time request = document_state->request_time();
111
112  Time navigation_start = Time::FromDoubleT(performance.navigationStart());
113  Time redirect_start = Time::FromDoubleT(performance.redirectStart());
114  Time redirect_end = Time::FromDoubleT(performance.redirectEnd());
115  Time fetch_start = Time::FromDoubleT(performance.fetchStart());
116  Time domain_lookup_start = Time::FromDoubleT(performance.domainLookupStart());
117  Time domain_lookup_end = Time::FromDoubleT(performance.domainLookupEnd());
118  Time connect_start = Time::FromDoubleT(performance.connectStart());
119  Time connect_end = Time::FromDoubleT(performance.connectEnd());
120  Time request_start = Time::FromDoubleT(performance.requestStart());
121  Time response_start = Time::FromDoubleT(performance.responseStart());
122  Time response_end = Time::FromDoubleT(performance.responseEnd());
123  Time dom_loading = Time::FromDoubleT(performance.domLoading());
124  Time dom_interactive = Time::FromDoubleT(performance.domInteractive());
125  Time dom_content_loaded_start =
126      Time::FromDoubleT(performance.domContentLoadedEventStart());
127  Time dom_content_loaded_end =
128      Time::FromDoubleT(performance.domContentLoadedEventEnd());
129  Time load_event_start = Time::FromDoubleT(performance.loadEventStart());
130  Time load_event_end = Time::FromDoubleT(performance.loadEventEnd());
131  Time begin = (request.is_null() ? navigation_start : request_start);
132
133  DCHECK(!navigation_start.is_null());
134
135  // It is possible for a document to have navigation_start time, but no
136  // request_start. An example is doing a window.open, which synchronously
137  // loads "about:blank", then using document.write add a meta http-equiv
138  // refresh tag, which causes a navigation. In such case, we will arrive at
139  // this function with no request/response timing data and identical load
140  // start/end values. Avoid logging this case, as it doesn't add any
141  // meaningful information to the histogram.
142  if (request_start.is_null())
143    return;
144
145  // TODO(dominich): Investigate conditions under which |load_event_start| and
146  // |load_event_end| may be NULL as in the non-PT_ case below. Examples in
147  // http://crbug.com/112006.
148  // DCHECK(!load_event_start.is_null());
149  // DCHECK(!load_event_end.is_null());
150
151  if (document_state->web_timing_histograms_recorded())
152    return;
153  document_state->set_web_timing_histograms_recorded(true);
154
155  if (!redirect_start.is_null() && !redirect_end.is_null()) {
156    PLT_HISTOGRAM_DRP("PLT.NT_Redirect", redirect_end - redirect_start,
157                      data_reduction_proxy_was_used);
158    PLT_HISTOGRAM_DRP(
159        "PLT.NT_DelayBeforeFetchRedirect",
160        (fetch_start - navigation_start) - (redirect_end - redirect_start),
161        data_reduction_proxy_was_used);
162  } else {
163    PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeFetch",
164                      fetch_start - navigation_start,
165                      data_reduction_proxy_was_used);
166  }
167  PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomainLookup",
168                    domain_lookup_start - fetch_start,
169                    data_reduction_proxy_was_used);
170  PLT_HISTOGRAM_DRP("PLT.NT_DomainLookup",
171                    domain_lookup_end - domain_lookup_start,
172                    data_reduction_proxy_was_used);
173  PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeConnect",
174                    connect_start - domain_lookup_end,
175                    data_reduction_proxy_was_used);
176  PLT_HISTOGRAM_DRP("PLT.NT_Connect", connect_end - connect_start,
177                    data_reduction_proxy_was_used);
178  PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeRequest",
179                    request_start - connect_end,
180                    data_reduction_proxy_was_used);
181  PLT_HISTOGRAM_DRP("PLT.NT_Request", response_start - request_start,
182                    data_reduction_proxy_was_used);
183  PLT_HISTOGRAM_DRP("PLT.NT_Response", response_end - response_start,
184                    data_reduction_proxy_was_used);
185
186  if (!dom_loading.is_null()) {
187    PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeDomLoading",
188                      dom_loading - response_start,
189                      data_reduction_proxy_was_used);
190  }
191  if (!dom_interactive.is_null() && !dom_loading.is_null()) {
192    PLT_HISTOGRAM_DRP("PLT.NT_DomLoading",
193                      dom_interactive - dom_loading,
194                      data_reduction_proxy_was_used);
195  }
196  if (!dom_content_loaded_start.is_null() && !dom_interactive.is_null()) {
197    PLT_HISTOGRAM_DRP("PLT.NT_DomInteractive",
198                      dom_content_loaded_start - dom_interactive,
199                      data_reduction_proxy_was_used);
200  }
201  if (!dom_content_loaded_start.is_null() &&
202      !dom_content_loaded_end.is_null() ) {
203    PLT_HISTOGRAM_DRP("PLT.NT_DomContentLoaded",
204                      dom_content_loaded_end - dom_content_loaded_start,
205                      data_reduction_proxy_was_used);
206  }
207  if (!dom_content_loaded_end.is_null() && !load_event_start.is_null()) {
208    PLT_HISTOGRAM_DRP("PLT.NT_DelayBeforeLoadEvent",
209                      load_event_start - dom_content_loaded_end,
210                      data_reduction_proxy_was_used);
211  }
212
213  // TODO(simonjam): There is no way to distinguish between abandonment and
214  // intentional Javascript navigation before the load event fires.
215  // TODO(dominich): Load type breakdown
216  if (!load_event_start.is_null()) {
217    PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc", load_event_start - begin);
218    PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc",
219                  load_event_start - response_start);
220    if (data_reduction_proxy_was_used) {
221      PLT_HISTOGRAM("PLT.PT_BeginToFinishDoc_DataReductionProxy",
222                    load_event_start - begin);
223      PLT_HISTOGRAM("PLT.PT_CommitToFinishDoc_DataReductionProxy",
224                    load_event_start - response_start);
225    }
226  }
227  if (!load_event_end.is_null()) {
228    PLT_HISTOGRAM("PLT.PT_BeginToFinish", load_event_end - begin);
229    PLT_HISTOGRAM("PLT.PT_CommitToFinish", load_event_end - response_start);
230    PLT_HISTOGRAM("PLT.PT_RequestToFinish", load_event_end - navigation_start);
231    PLT_HISTOGRAM("PLT.PT_StartToFinish", load_event_end - request_start);
232    if (data_reduction_proxy_was_used) {
233      PLT_HISTOGRAM("PLT.PT_BeginToFinish_DataReductionProxy",
234                    load_event_end - begin);
235      PLT_HISTOGRAM("PLT.PT_CommitToFinish_DataReductionProxy",
236                    load_event_end - response_start);
237      PLT_HISTOGRAM("PLT.PT_RequestToFinish_DataReductionProxy",
238                    load_event_end - navigation_start);
239      PLT_HISTOGRAM("PLT.PT_StartToFinish_DataReductionProxy",
240                    load_event_end - request_start);
241    }
242  }
243  if (!load_event_start.is_null() && !load_event_end.is_null()) {
244    PLT_HISTOGRAM("PLT.PT_FinishDocToFinish",
245                  load_event_end - load_event_start);
246    PLT_HISTOGRAM_DRP("PLT.NT_LoadEvent",
247                      load_event_end - load_event_start,
248                      data_reduction_proxy_was_used);
249
250    if (data_reduction_proxy_was_used) {
251      PLT_HISTOGRAM("PLT.PT_FinishDocToFinish_DataReductionProxy",
252                    load_event_end - load_event_start);
253    }
254  }
255  PLT_HISTOGRAM("PLT.PT_BeginToCommit", response_start - begin);
256  PLT_HISTOGRAM("PLT.PT_RequestToStart", request_start - navigation_start);
257  PLT_HISTOGRAM("PLT.PT_StartToCommit", response_start - request_start);
258  if (data_reduction_proxy_was_used) {
259    PLT_HISTOGRAM("PLT.PT_BeginToCommit_DataReductionProxy",
260                  response_start - begin);
261    PLT_HISTOGRAM("PLT.PT_RequestToStart_DataReductionProxy",
262                  request_start - navigation_start);
263    PLT_HISTOGRAM("PLT.PT_StartToCommit_DataReductionProxy",
264                  response_start - request_start);
265  }
266}
267
268enum MissingStartType {
269  START_MISSING = 0x1,
270  COMMIT_MISSING = 0x2,
271  NAV_START_MISSING = 0x4,
272  MISSING_START_TYPE_MAX = 0x8
273};
274
275enum AbandonType {
276  FINISH_DOC_MISSING = 0x1,
277  FINISH_ALL_LOADS_MISSING = 0x2,
278  LOAD_EVENT_START_MISSING = 0x4,
279  LOAD_EVENT_END_MISSING = 0x8,
280  ABANDON_TYPE_MAX = 0x10
281};
282
283}  // namespace
284
285PageLoadHistograms::PageLoadHistograms(content::RenderView* render_view)
286    : content::RenderViewObserver(render_view),
287      cross_origin_access_count_(0),
288      same_origin_access_count_(0) {
289}
290
291void PageLoadHistograms::Dump(WebFrame* frame) {
292  // We only dump histograms for main frames.
293  // In the future, it may be interesting to tag subframes and dump them too.
294  if (!frame || frame->parent())
295    return;
296
297  // Only dump for supported schemes.
298  URLPattern::SchemeMasks scheme_type =
299      GetSupportedSchemeType(frame->document().url());
300  if (scheme_type == 0)
301    return;
302
303  // Ignore multipart requests.
304  if (frame->dataSource()->response().isMultipartPayload())
305    return;
306
307  DocumentState* document_state =
308      DocumentState::FromDataSource(frame->dataSource());
309
310  bool data_reduction_proxy_was_used = DataReductionProxyWasUsed(frame);
311
312  // Times based on the Web Timing metrics.
313  // http://www.w3.org/TR/navigation-timing/
314  // TODO(tonyg, jar): We are in the process of vetting these metrics against
315  // the existing ones. Once we understand any differences, we will standardize
316  // on a single set of metrics.
317  DumpPerformanceTiming(frame->performance(), document_state,
318                        data_reduction_proxy_was_used);
319
320  // If we've already dumped, do nothing.
321  // This simple bool works because we only dump for the main frame.
322  if (document_state->load_histograms_recorded())
323    return;
324
325  // Collect measurement times.
326  Time start = document_state->start_load_time();
327  Time commit = document_state->commit_load_time();
328
329  // TODO(tonyg, jar): Start can be missing after an in-document navigation and
330  // possibly other cases like a very premature abandonment of the page.
331  // The PLT.MissingStart histogram should help us troubleshoot and then we can
332  // remove this.
333  Time navigation_start =
334      Time::FromDoubleT(frame->performance().navigationStart());
335  int missing_start_type = 0;
336  missing_start_type |= start.is_null() ? START_MISSING : 0;
337  missing_start_type |= commit.is_null() ? COMMIT_MISSING : 0;
338  missing_start_type |= navigation_start.is_null() ? NAV_START_MISSING : 0;
339  UMA_HISTOGRAM_ENUMERATION("PLT.MissingStart", missing_start_type,
340                            MISSING_START_TYPE_MAX);
341  if (missing_start_type)
342    return;
343
344  // We properly handle null values for the next 3 variables.
345  Time request = document_state->request_time();
346  Time first_paint = document_state->first_paint_time();
347  Time first_paint_after_load = document_state->first_paint_after_load_time();
348  Time finish_doc = document_state->finish_document_load_time();
349  Time finish_all_loads = document_state->finish_load_time();
350
351  // TODO(tonyg, jar): We suspect a bug in abandonment counting, this temporary
352  // histogram should help us to troubleshoot.
353  Time load_event_start =
354      Time::FromDoubleT(frame->performance().loadEventStart());
355  Time load_event_end = Time::FromDoubleT(frame->performance().loadEventEnd());
356  int abandon_type = 0;
357  abandon_type |= finish_doc.is_null() ? FINISH_DOC_MISSING : 0;
358  abandon_type |= finish_all_loads.is_null() ? FINISH_ALL_LOADS_MISSING : 0;
359  abandon_type |= load_event_start.is_null() ? LOAD_EVENT_START_MISSING : 0;
360  abandon_type |= load_event_end.is_null() ? LOAD_EVENT_END_MISSING : 0;
361  UMA_HISTOGRAM_ENUMERATION("PLT.AbandonType", abandon_type, ABANDON_TYPE_MAX);
362
363  // Handle case where user hits "stop" or "back" before loading completely.
364  bool abandoned_page = finish_doc.is_null();
365  if (abandoned_page) {
366    finish_doc = Time::Now();
367    document_state->set_finish_document_load_time(finish_doc);
368  }
369
370  // TODO(jar): We should really discriminate the definition of "abandon" more
371  // finely.  We should have:
372  // abandon_before_document_loaded
373  // abandon_before_onload_fired
374
375  if (finish_all_loads.is_null()) {
376    finish_all_loads = Time::Now();
377    document_state->set_finish_load_time(finish_all_loads);
378  } else {
379    DCHECK(!abandoned_page);  // How can the doc have finished but not the page?
380    if (abandoned_page)
381      return;  // Don't try to record a stat which is broken.
382  }
383
384  document_state->set_load_histograms_recorded(true);
385
386  // Note: Client side redirects will have no request time.
387  Time begin = request.is_null() ? start : request;
388  TimeDelta begin_to_finish_doc = finish_doc - begin;
389  TimeDelta begin_to_finish_all_loads = finish_all_loads - begin;
390  TimeDelta start_to_finish_all_loads = finish_all_loads - start;
391  TimeDelta start_to_commit = commit - start;
392
393  DocumentState::LoadType load_type = document_state->load_type();
394
395  // The above code sanitized all values of times, in preparation for creating
396  // actual histograms.  The remainder of this code could be run at destructor
397  // time for the document_state, since all data is intact.
398
399  // Aggregate PLT data across all link types.
400  UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned", abandoned_page ? 1 : 0, 2);
401  UMA_HISTOGRAM_ENUMERATION("PLT.LoadType", load_type,
402      DocumentState::kLoadTypeMax);
403  PLT_HISTOGRAM("PLT.StartToCommit", start_to_commit);
404  PLT_HISTOGRAM("PLT.CommitToFinishDoc", finish_doc - commit);
405  PLT_HISTOGRAM("PLT.FinishDocToFinish", finish_all_loads - finish_doc);
406  PLT_HISTOGRAM("PLT.BeginToCommit", commit - begin);
407  PLT_HISTOGRAM("PLT.StartToFinish", start_to_finish_all_loads);
408  if (!request.is_null()) {
409    PLT_HISTOGRAM("PLT.RequestToStart", start - request);
410    PLT_HISTOGRAM("PLT.RequestToFinish", finish_all_loads - request);
411  }
412  PLT_HISTOGRAM("PLT.CommitToFinish", finish_all_loads - commit);
413
414  scoped_ptr<TimeDelta> begin_to_first_paint;
415  scoped_ptr<TimeDelta> commit_to_first_paint;
416  if (!first_paint.is_null()) {
417    // 'first_paint' can be before 'begin' for an unknown reason.
418    // See bug http://crbug.com/125273 for details.
419    if (begin <= first_paint) {
420      begin_to_first_paint.reset(new TimeDelta(first_paint - begin));
421      PLT_HISTOGRAM("PLT.BeginToFirstPaint", *begin_to_first_paint);
422    }
423    DCHECK(commit <= first_paint);
424    commit_to_first_paint.reset(new TimeDelta(first_paint - commit));
425    PLT_HISTOGRAM("PLT.CommitToFirstPaint", *commit_to_first_paint);
426  }
427  if (!first_paint_after_load.is_null()) {
428    // 'first_paint_after_load' can be before 'begin' for an unknown reason.
429    // See bug http://crbug.com/125273 for details.
430    if (begin <= first_paint_after_load) {
431      PLT_HISTOGRAM("PLT.BeginToFirstPaintAfterLoad",
432          first_paint_after_load - begin);
433    }
434    DCHECK(commit <= first_paint_after_load);
435    PLT_HISTOGRAM("PLT.CommitToFirstPaintAfterLoad",
436        first_paint_after_load - commit);
437    DCHECK(finish_all_loads <= first_paint_after_load);
438    PLT_HISTOGRAM("PLT.FinishToFirstPaintAfterLoad",
439        first_paint_after_load - finish_all_loads);
440  }
441  PLT_HISTOGRAM("PLT.BeginToFinishDoc", begin_to_finish_doc);
442  PLT_HISTOGRAM("PLT.BeginToFinish", begin_to_finish_all_loads);
443
444  // Load type related histograms.
445  switch (load_type) {
446    case DocumentState::UNDEFINED_LOAD:
447      PLT_HISTOGRAM("PLT.BeginToFinishDoc_UndefLoad", begin_to_finish_doc);
448      PLT_HISTOGRAM("PLT.BeginToFinish_UndefLoad", begin_to_finish_all_loads);
449      break;
450    case DocumentState::RELOAD:
451      PLT_HISTOGRAM("PLT.BeginToFinishDoc_Reload", begin_to_finish_doc);
452      PLT_HISTOGRAM("PLT.BeginToFinish_Reload", begin_to_finish_all_loads);
453      break;
454    case DocumentState::HISTORY_LOAD:
455      PLT_HISTOGRAM("PLT.BeginToFinishDoc_HistoryLoad", begin_to_finish_doc);
456      PLT_HISTOGRAM("PLT.BeginToFinish_HistoryLoad", begin_to_finish_all_loads);
457      break;
458    case DocumentState::NORMAL_LOAD:
459      PLT_HISTOGRAM("PLT.BeginToFinishDoc_NormalLoad", begin_to_finish_doc);
460      PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad", begin_to_finish_all_loads);
461      break;
462    case DocumentState::LINK_LOAD_NORMAL:
463      PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadNormal",
464          begin_to_finish_doc);
465      PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal",
466                    begin_to_finish_all_loads);
467      break;
468    case DocumentState::LINK_LOAD_RELOAD:
469      PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadReload",
470           begin_to_finish_doc);
471      PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadReload",
472                    begin_to_finish_all_loads);
473      break;
474    case DocumentState::LINK_LOAD_CACHE_STALE_OK:
475      PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadStaleOk",
476           begin_to_finish_doc);
477      PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadStaleOk",
478                    begin_to_finish_all_loads);
479      break;
480    case DocumentState::LINK_LOAD_CACHE_ONLY:
481      PLT_HISTOGRAM("PLT.BeginToFinishDoc_LinkLoadCacheOnly",
482           begin_to_finish_doc);
483      PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadCacheOnly",
484                    begin_to_finish_all_loads);
485      break;
486    default:
487      break;
488  }
489
490  if (data_reduction_proxy_was_used) {
491    UMA_HISTOGRAM_ENUMERATION(
492        "PLT.Abandoned_SpdyProxy", abandoned_page ? 1 : 0, 2);
493    PLT_HISTOGRAM("PLT.BeginToFinishDoc_SpdyProxy", begin_to_finish_doc);
494    PLT_HISTOGRAM("PLT.BeginToFinish_SpdyProxy", begin_to_finish_all_loads);
495  }
496
497  if (document_state->was_prefetcher()) {
498    PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcher",
499                  begin_to_finish_doc);
500    PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcher",
501                  begin_to_finish_all_loads);
502  }
503  if (document_state->was_referred_by_prefetcher()) {
504    PLT_HISTOGRAM("PLT.BeginToFinishDoc_ContentPrefetcherReferrer",
505                  begin_to_finish_doc);
506    PLT_HISTOGRAM("PLT.BeginToFinish_ContentPrefetcherReferrer",
507                  begin_to_finish_all_loads);
508  }
509  if (document_state->was_after_preconnect_request()) {
510    PLT_HISTOGRAM("PLT.BeginToFinishDoc_AfterPreconnectRequest",
511                  begin_to_finish_doc);
512    PLT_HISTOGRAM("PLT.BeginToFinish_AfterPreconnectRequest",
513                  begin_to_finish_all_loads);
514  }
515
516  // TODO(mpcomplete): remove the extension-related histograms after we collect
517  // enough data. http://crbug.com/100411
518  const bool use_adblock_histogram =
519      chrome::ChromeContentRendererClient::IsAdblockInstalled();
520  if (use_adblock_histogram) {
521    UMA_HISTOGRAM_ENUMERATION(
522        "PLT.Abandoned_ExtensionAdblock",
523        abandoned_page ? 1 : 0, 2);
524    switch (load_type) {
525      case DocumentState::NORMAL_LOAD:
526        PLT_HISTOGRAM(
527            "PLT.BeginToFinish_NormalLoad_ExtensionAdblock",
528            begin_to_finish_all_loads);
529        break;
530      case DocumentState::LINK_LOAD_NORMAL:
531        PLT_HISTOGRAM(
532            "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblock",
533            begin_to_finish_all_loads);
534        break;
535      case DocumentState::LINK_LOAD_RELOAD:
536        PLT_HISTOGRAM(
537            "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblock",
538            begin_to_finish_all_loads);
539        break;
540      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
541        PLT_HISTOGRAM(
542            "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblock",
543            begin_to_finish_all_loads);
544        break;
545      default:
546        break;
547    }
548  }
549
550  const bool use_adblockplus_histogram =
551      chrome::ChromeContentRendererClient::IsAdblockPlusInstalled();
552  if (use_adblockplus_histogram) {
553    UMA_HISTOGRAM_ENUMERATION(
554        "PLT.Abandoned_ExtensionAdblockPlus",
555        abandoned_page ? 1 : 0, 2);
556    switch (load_type) {
557      case DocumentState::NORMAL_LOAD:
558        PLT_HISTOGRAM(
559            "PLT.BeginToFinish_NormalLoad_ExtensionAdblockPlus",
560            begin_to_finish_all_loads);
561        break;
562      case DocumentState::LINK_LOAD_NORMAL:
563        PLT_HISTOGRAM(
564            "PLT.BeginToFinish_LinkLoadNormal_ExtensionAdblockPlus",
565            begin_to_finish_all_loads);
566        break;
567      case DocumentState::LINK_LOAD_RELOAD:
568        PLT_HISTOGRAM(
569            "PLT.BeginToFinish_LinkLoadReload_ExtensionAdblockPlus",
570            begin_to_finish_all_loads);
571        break;
572      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
573        PLT_HISTOGRAM(
574            "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionAdblockPlus",
575            begin_to_finish_all_loads);
576        break;
577      default:
578        break;
579    }
580  }
581
582  const bool use_webrequest_adblock_histogram =
583      chrome::ChromeContentRendererClient::IsAdblockWithWebRequestInstalled();
584  if (use_webrequest_adblock_histogram) {
585    UMA_HISTOGRAM_ENUMERATION(
586        "PLT.Abandoned_ExtensionWebRequestAdblock",
587        abandoned_page ? 1 : 0, 2);
588    switch (load_type) {
589      case DocumentState::NORMAL_LOAD:
590        PLT_HISTOGRAM(
591            "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblock",
592            begin_to_finish_all_loads);
593        break;
594      case DocumentState::LINK_LOAD_NORMAL:
595        PLT_HISTOGRAM(
596            "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblock",
597            begin_to_finish_all_loads);
598        break;
599      case DocumentState::LINK_LOAD_RELOAD:
600        PLT_HISTOGRAM(
601            "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblock",
602            begin_to_finish_all_loads);
603        break;
604      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
605        PLT_HISTOGRAM(
606            "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblock",
607            begin_to_finish_all_loads);
608        break;
609      default:
610        break;
611    }
612  }
613
614  const bool use_webrequest_adblockplus_histogram =
615      chrome::ChromeContentRendererClient::
616          IsAdblockPlusWithWebRequestInstalled();
617  if (use_webrequest_adblockplus_histogram) {
618    UMA_HISTOGRAM_ENUMERATION(
619        "PLT.Abandoned_ExtensionWebRequestAdblockPlus",
620        abandoned_page ? 1 : 0, 2);
621    switch (load_type) {
622      case DocumentState::NORMAL_LOAD:
623        PLT_HISTOGRAM(
624            "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestAdblockPlus",
625            begin_to_finish_all_loads);
626        break;
627      case DocumentState::LINK_LOAD_NORMAL:
628        PLT_HISTOGRAM(
629            "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestAdblockPlus",
630            begin_to_finish_all_loads);
631        break;
632      case DocumentState::LINK_LOAD_RELOAD:
633        PLT_HISTOGRAM(
634            "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestAdblockPlus",
635            begin_to_finish_all_loads);
636        break;
637      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
638        PLT_HISTOGRAM(
639            "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestAdblockPlus",
640            begin_to_finish_all_loads);
641        break;
642      default:
643        break;
644    }
645  }
646
647  const bool use_webrequest_other_histogram =
648      chrome::ChromeContentRendererClient::
649          IsOtherExtensionWithWebRequestInstalled();
650  if (use_webrequest_other_histogram) {
651    UMA_HISTOGRAM_ENUMERATION(
652        "PLT.Abandoned_ExtensionWebRequestOther",
653        abandoned_page ? 1 : 0, 2);
654    switch (load_type) {
655      case DocumentState::NORMAL_LOAD:
656        PLT_HISTOGRAM(
657            "PLT.BeginToFinish_NormalLoad_ExtensionWebRequestOther",
658            begin_to_finish_all_loads);
659        break;
660      case DocumentState::LINK_LOAD_NORMAL:
661        PLT_HISTOGRAM(
662            "PLT.BeginToFinish_LinkLoadNormal_ExtensionWebRequestOther",
663            begin_to_finish_all_loads);
664        break;
665      case DocumentState::LINK_LOAD_RELOAD:
666        PLT_HISTOGRAM(
667            "PLT.BeginToFinish_LinkLoadReload_ExtensionWebRequestOther",
668            begin_to_finish_all_loads);
669        break;
670      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
671        PLT_HISTOGRAM(
672            "PLT.BeginToFinish_LinkLoadStaleOk_ExtensionWebRequestOther",
673            begin_to_finish_all_loads);
674        break;
675      default:
676        break;
677    }
678  }
679
680  // Record SpdyCwnd results.
681  if (document_state->was_fetched_via_spdy()) {
682    switch (load_type) {
683      case DocumentState::LINK_LOAD_NORMAL:
684        PLT_HISTOGRAM("PLT.BeginToFinish_LinkLoadNormal_cwndDynamic",
685                      begin_to_finish_all_loads);
686        PLT_HISTOGRAM("PLT.StartToFinish_LinkLoadNormal_cwndDynamic",
687                      start_to_finish_all_loads);
688        PLT_HISTOGRAM("PLT.StartToCommit_LinkLoadNormal_cwndDynamic",
689                      start_to_commit);
690        break;
691      case DocumentState::NORMAL_LOAD:
692        PLT_HISTOGRAM("PLT.BeginToFinish_NormalLoad_cwndDynamic",
693                      begin_to_finish_all_loads);
694        PLT_HISTOGRAM("PLT.StartToFinish_NormalLoad_cwndDynamic",
695                      start_to_finish_all_loads);
696        PLT_HISTOGRAM("PLT.StartToCommit_NormalLoad_cwndDynamic",
697                      start_to_commit);
698        break;
699      default:
700        break;
701    }
702  }
703
704  // Record page load time and abandonment rates for proxy cases.
705  if (document_state->was_fetched_via_proxy()) {
706    if (scheme_type == URLPattern::SCHEME_HTTPS) {
707      PLT_HISTOGRAM("PLT.StartToFinish.Proxy.https", start_to_finish_all_loads);
708      UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.https",
709                                abandoned_page ? 1 : 0, 2);
710    } else {
711      DCHECK(scheme_type == URLPattern::SCHEME_HTTP);
712      PLT_HISTOGRAM("PLT.StartToFinish.Proxy.http", start_to_finish_all_loads);
713      UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.Proxy.http",
714                                abandoned_page ? 1 : 0, 2);
715    }
716  } else {
717    if (scheme_type == URLPattern::SCHEME_HTTPS) {
718      PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.https",
719                    start_to_finish_all_loads);
720      UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.https",
721                                abandoned_page ? 1 : 0, 2);
722    } else {
723      DCHECK(scheme_type == URLPattern::SCHEME_HTTP);
724      PLT_HISTOGRAM("PLT.StartToFinish.NoProxy.http",
725                    start_to_finish_all_loads);
726      UMA_HISTOGRAM_ENUMERATION("PLT.Abandoned.NoProxy.http",
727                                abandoned_page ? 1 : 0, 2);
728    }
729  }
730
731  // Histograms to determine if disabling overlapped TCP reads
732  // has an impact on PLT.
733  static const bool use_overlapped_read_histogram =
734      base::FieldTrialList::TrialExists("OverlappedReadImpact");
735  if (use_overlapped_read_histogram) {
736    UMA_HISTOGRAM_ENUMERATION(
737        base::FieldTrial::MakeName("PLT.Abandoned", "OverlappedReadImpact"),
738        abandoned_page ? 1 : 0, 2);
739    UMA_HISTOGRAM_ENUMERATION(
740        base::FieldTrial::MakeName("PLT.LoadType", "OverlappedReadImpact"),
741        load_type, DocumentState::kLoadTypeMax);
742    switch (load_type) {
743      case DocumentState::NORMAL_LOAD:
744        PLT_HISTOGRAM(base::FieldTrial::MakeName(
745            "PLT.BeginToFinish_NormalLoad", "OverlappedReadImpact"),
746            begin_to_finish_all_loads);
747        break;
748      case DocumentState::LINK_LOAD_NORMAL:
749        PLT_HISTOGRAM(base::FieldTrial::MakeName(
750            "PLT.BeginToFinish_LinkLoadNormal", "OverlappedReadImpact"),
751            begin_to_finish_all_loads);
752        break;
753      case DocumentState::LINK_LOAD_RELOAD:
754        PLT_HISTOGRAM(base::FieldTrial::MakeName(
755            "PLT.BeginToFinish_LinkLoadReload", "OverlappedReadImpact"),
756            begin_to_finish_all_loads);
757        break;
758      case DocumentState::LINK_LOAD_CACHE_STALE_OK:
759        PLT_HISTOGRAM(base::FieldTrial::MakeName(
760            "PLT.BeginToFinish_LinkLoadStaleOk", "OverlappedReadImpact"),
761            begin_to_finish_all_loads);
762        break;
763      default:
764        break;
765    }
766  }
767
768  // Site isolation metrics.
769  UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithCrossSiteFrameAccess",
770                       cross_origin_access_count_);
771  UMA_HISTOGRAM_COUNTS("SiteIsolation.PageLoadsWithSameSiteFrameAccess",
772                       same_origin_access_count_);
773
774  // Log the PLT to the info log.
775  LogPageLoadTime(document_state, frame->dataSource());
776
777  // Since there are currently no guarantees that renderer histograms will be
778  // sent to the browser, we initiate a PostTask here to be sure that we send
779  // the histograms we generated.  Without this call, pages that don't have an
780  // on-close-handler might generate data that is lost when the renderer is
781  // shutdown abruptly (perchance because the user closed the tab).
782  // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it
783  // should post when the onload is complete, so that it doesn't interfere with
784  // the next load.
785  content::RenderThread::Get()->UpdateHistograms(
786      content::kHistogramSynchronizerReservedSequenceNumber);
787}
788
789void PageLoadHistograms::ResetCrossFramePropertyAccess() {
790  cross_origin_access_count_ = 0;
791  same_origin_access_count_ = 0;
792}
793
794void PageLoadHistograms::FrameWillClose(WebFrame* frame) {
795  Dump(frame);
796}
797
798void PageLoadHistograms::ClosePage() {
799  // TODO(davemoore) This code should be removed once willClose() gets
800  // called when a page is destroyed. page_load_histograms_.Dump() is safe
801  // to call multiple times for the same frame, but it will simplify things.
802  Dump(render_view()->GetWebView()->mainFrame());
803  ResetCrossFramePropertyAccess();
804}
805
806void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state,
807                                         const WebDataSource* ds) const {
808  // Because this function gets called on every page load,
809  // take extra care to optimize it away if logging is turned off.
810  if (logging::LOG_INFO < logging::GetMinLogLevel())
811    return;
812
813  DCHECK(document_state);
814  DCHECK(ds);
815  GURL url(ds->request().url());
816  Time start = document_state->start_load_time();
817  Time finish = document_state->finish_load_time();
818  // TODO(mbelshe): should we log more stats?
819  VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms "
820          << url.spec();
821}
822