Adding histograms showing fraction of page load times

chrome/browser/net/cache_stats.cc

+// Copyright (c) 2012 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "chrome/browser/net/cache_stats.h"
+
+#include <vector>
+
+#include "base/hash_tables.h"
+#include "base/metrics/histogram.h"
+#include "base/stl_util.h"
+#include "base/string_number_conversions.h"
+#include "base/timer.h"
+#include "chrome/browser/browser_process.h"
+#include "chrome/browser/io_thread.h"
+#include "chrome/browser/profiles/profile.h"
+#include "chrome/browser/ui/tab_contents/tab_contents.h"
+#include "content/public/browser/browser_thread.h"
+#include "content/public/browser/render_process_host.h"
+#include "content/public/browser/render_view_host.h"
+#include "content/public/browser/resource_request_info.h"
+#include "content/public/browser/web_contents.h"
+#include "net/url_request/url_request.h"
+
+using content::BrowserThread;
+using content::ResourceRequestInfo;
+using content::RenderViewHost;
+
+#if defined(COMPILER_GCC)
+
+namespace BASE_HASH_NAMESPACE {
+template <>
+struct hash<const net::URLRequest*> {
+  std::size_t operator()(const net::URLRequest* value) const {
+    return reinterpret_cast<std::size_t>(value);
+  }
+};
+}
+
+#endif
+
+namespace chrome_browser_net {
+
+namespace {

[rvargas (doing something else), 2012/07/26 02:13:43]

nit: Do you mind moving this namespace out of the file namespace?

[tburkard, 2012/07/26 02:50:54]

Done.

+
+bool GetRenderView(const net::URLRequest& request,
+                   int* process_id, int* route_id) {
+  const ResourceRequestInfo* info = ResourceRequestInfo::ForRequest(&request);
+  if (!info)
+    return false;
+
+  return info->GetAssociatedRenderView(process_id, route_id);
+}
+
+void CallCacheStatsTabEventOnIOThread(std::pair<int, int> render_view_id,
+                                      CacheStats::TabEvent event,
+                                      IOThread* io_thread) {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+  static CacheStats* cache_stats = io_thread->globals()->cache_stats.get();
+  cache_stats->OnTabEvent(render_view_id, event);
+}
+
+// Times after a load has started at which stats are collected.
+const int kStatsCollectionTimesMs[] = {
+  500,
+  1000,
+  2000,
+  3000,
+  4000,
+  5000,
+  7500,
+  10000,
+  15000,
+  20000
+};
+
+static int kTabLoadStatsAutoCleanupTimeoutSeconds = 30;
+
+}  // namespace
+
+// Helper struct keeping stats about the page load progress & cache usage
+// stats during the pageload so far for a given RenderView, identified
+// by a pair of process id and route id.
+struct CacheStats::TabLoadStats {
+  TabLoadStats(std::pair<int, int> render_view_id, CacheStats* owner)
+      : render_view_id(render_view_id),
+        num_active(0),
+        spinner_started(false),
+        timer(false, false) {
+    // Initialize the timer to do an automatic cleanup.  If a pageload is
+    // started for the TabLoadStats within that timeframe, CacheStats
+    // will start using the timer, thereby cancelling the cleanup.
+    // Once CacheStats starts the timer, the object is guaranteed to be
+    // destroyed eventually, so there is no more need for automatic cleanup at
+    // that point.
+    timer.Start(FROM_HERE,
+                base::TimeDelta::FromSeconds(
+                    kTabLoadStatsAutoCleanupTimeoutSeconds),
+                base::Bind(&CacheStats::RemoveTabLoadStats,
+                           base::Unretained(owner),
+                           render_view_id));
+  }
+
+  std::pair<int, int> render_view_id;
+  int num_active;
+  bool spinner_started;
+  base::TimeTicks load_start_time;
+  base::TimeTicks cache_start_time;
+  base::TimeDelta cache_total_time;
+  base::Timer timer;
+  typedef base::hash_map<const net::URLRequest*, int> PerRequestNumActiveMap;
+  PerRequestNumActiveMap per_request_num_active;
+};
+
+CacheStatsTabHelper::CacheStatsTabHelper(TabContents* tab)
+    : content::WebContentsObserver(tab->web_contents()),
+      cache_stats_(NULL) {
+  is_profile_otr_ = tab->profile()->IsOffTheRecord();
+}
+
+void CacheStatsTabHelper::DidStartProvisionalLoadForFrame(
+    int64 frame_id,
+    bool is_main_frame,
+    const GURL& validated_url,
+    bool is_error_page,
+    content::RenderViewHost* render_view_host) {
+  if (!is_main_frame)
+    return;
+  if (!validated_url.SchemeIs("http"))

[rvargas (doing something else), 2012/07/26 02:13:43]

no https?

[tburkard, 2012/07/26 02:50:54]

Wanted to focus on http first, since a lot of sites don't permit caching for
https.  Can add this later.

On 2012/07/26 02:13:43, rvargas wrote:

[rvargas (doing something else), 2012/07/26 18:56:12]

Note that https goes through exactly the same logic though... and we won't be
able to compare the results with other data that aggregates the two protocols.
Not that there would be a lot to compare.

[tburkard, 2012/07/26 19:12:49]

I am aware of that.  I may add separate histograms for http and https, along
with the other histograms that we discussed that I will add soon once this
change is landed.

On 2012/07/26 18:56:12, rvargas wrote:

+    return;
+  NotifyCacheStats(CacheStats::SPINNER_START, render_view_host);
+}
+
+void CacheStatsTabHelper::DidStopLoading(RenderViewHost* render_view_host) {
+  NotifyCacheStats(CacheStats::SPINNER_STOP, render_view_host);
+}
+
+CacheStatsTabHelper::~CacheStatsTabHelper() {
+}
+
+void CacheStatsTabHelper::NotifyCacheStats(
+    CacheStats::TabEvent event,
+    RenderViewHost* render_view_host) {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
+  if (is_profile_otr_)
+    return;
+  int process_id = render_view_host->GetProcess()->GetID();
+  int route_id = render_view_host->GetRoutingID();
+  BrowserThread::PostTask(
+      BrowserThread::IO, FROM_HERE,
+      base::Bind(&CallCacheStatsTabEventOnIOThread,
+                 std::pair<int, int>(process_id, route_id),
+                 event,
+                 base::Unretained(g_browser_process->io_thread())));
+}
+
+CacheStats::CacheStats() {
+  for (int i = 0;
+       i < static_cast<int>(arraysize(kStatsCollectionTimesMs));
+       i++) {
+    final_histograms_.push_back(
+        base::LinearHistogram::FactoryGet(
+            "CacheStats.FractionCacheUseFinalPLT_" +
+            base::IntToString(kStatsCollectionTimesMs[i]),
+            0, 101, 102, base::Histogram::kUmaTargetedHistogramFlag));
+    intermediate_histograms_.push_back(
+        base::LinearHistogram::FactoryGet(
+            "DiskCache.FractionCacheUseIntermediatePLT_" +
+            base::IntToString(kStatsCollectionTimesMs[i]),
+            0, 101, 102, base::Histogram::kNoFlags));
+  }
+  DCHECK_EQ(final_histograms_.size(), arraysize(kStatsCollectionTimesMs));
+  DCHECK_EQ(intermediate_histograms_.size(),
+            arraysize(kStatsCollectionTimesMs));
+}
+
+CacheStats::~CacheStats() {
+  STLDeleteValues(&tab_load_stats_);
+}
+
+CacheStats::TabLoadStats* CacheStats::GetTabLoadStats(
+    std::pair<int, int> render_view_id) {
+  if (tab_load_stats_.count(render_view_id) < 1)
+    tab_load_stats_[render_view_id] = new TabLoadStats(render_view_id, this);
+  return tab_load_stats_[render_view_id];
+}
+
+void CacheStats::RemoveTabLoadStats(std::pair<int, int> render_view_id) {
+  TabLoadStatsMap::iterator it = tab_load_stats_.find(render_view_id);
+  if (it != tab_load_stats_.end()) {
+    delete it->second;
+    tab_load_stats_.erase(it);
+  }
+}
+
+void CacheStats::OnCacheWaitStateChange(
+    const net::URLRequest& request,
+    net::NetworkDelegate::CacheWaitState state) {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+  int process_id, route_id;
+  if (!GetRenderView(request, &process_id, &route_id))
+    return;
+  TabLoadStats* stats =
+      GetTabLoadStats(std::pair<int, int>(process_id, route_id));
+  if (main_request_contexts_.count(request.context()) < 1)
+    return;
+  bool newly_started = false;
+  bool newly_finished = false;
+  std::pair<TabLoadStats::PerRequestNumActiveMap::iterator, bool> insert_ret =
+      stats->per_request_num_active.insert(
+          std::pair<const net::URLRequest*, int>(&request, 0));
+  TabLoadStats::PerRequestNumActiveMap::iterator entry = insert_ret.first;
+  DCHECK_GE(entry->second, 0);
+  switch (state) {
+    case net::NetworkDelegate::CACHE_WAIT_STATE_START:
+      DCHECK(entry->second == 0);
+      if (entry->second == 0)
+        newly_started = true;
+      entry->second++;
+      break;
+    case net::NetworkDelegate::CACHE_WAIT_STATE_FINISH:
+      if (entry->second > 0) {
+        entry->second--;
+        if (entry->second == 0)
+          newly_finished = true;
+      }
+      break;
+    case net::NetworkDelegate::CACHE_WAIT_STATE_RESET:
+      if (entry->second > 0) {
+        entry->second = 0;
+        newly_finished = true;
+      }
+      break;
+  }
+  DCHECK_GE(entry->second, 0);
+  if (newly_started) {
+    DCHECK(!newly_finished);
+    if (stats->num_active == 0) {
+      stats->cache_start_time = base::TimeTicks::Now();
+    }
+    stats->num_active++;
+  }
+  if (newly_finished) {
+    DCHECK(!newly_started);
+    if (stats->num_active == 1) {
+      stats->cache_total_time +=
+          base::TimeTicks::Now() - stats->cache_start_time;
+    }
+    stats->num_active--;
+  }
+}
+
+void CacheStats::OnTabEvent(std::pair<int, int> render_view_id,
+                            TabEvent event) {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+  TabLoadStats* stats = GetTabLoadStats(render_view_id);
+  if (event == SPINNER_START) {
+    stats->spinner_started = true;
+    stats->cache_total_time = base::TimeDelta();
+    stats->cache_start_time = base::TimeTicks::Now();
+    stats->load_start_time = base::TimeTicks::Now();
+    ScheduleTimer(stats, 0);
+  } else {
+    DCHECK_EQ(event, SPINNER_STOP);
+    if (stats->spinner_started) {
+      stats->spinner_started = false;
+      base::TimeDelta load_time =
+          base::TimeTicks::Now() - stats->load_start_time;
+      if (stats->num_active > 1)
+        stats->cache_total_time +=
+            base::TimeTicks::Now() - stats->cache_start_time;
+      RecordCacheFractionHistogram(load_time, stats->cache_total_time, true);
+    }
+    RemoveTabLoadStats(render_view_id);
+  }
+}
+
+void CacheStats::ScheduleTimer(TabLoadStats* stats, int timer_index) {
+  DCHECK(timer_index >= 0 &&
+         timer_index < static_cast<int>(arraysize(kStatsCollectionTimesMs)));
+  base::TimeDelta delta =
+      base::TimeDelta::FromMilliseconds(kStatsCollectionTimesMs[timer_index]);
+  delta -= base::TimeTicks::Now() - stats->load_start_time;
+  stats->timer.Start(FROM_HERE,
+                     delta,
+                     base::Bind(&CacheStats::TimerCb,
+                                base::Unretained(this),
+                                base::Unretained(stats),
+                                timer_index));
+}
+
+void CacheStats::TimerCb(TabLoadStats* stats, int timer_index) {
+  DCHECK(stats->spinner_started);
+  base::TimeDelta load_time = base::TimeTicks::Now() - stats->load_start_time;
+  base::TimeDelta cache_time = stats->cache_total_time;
+  if (stats->num_active > 1)
+    cache_time += base::TimeTicks::Now() - stats->cache_start_time;
+  RecordCacheFractionHistogram(load_time, cache_time, false);
+  timer_index++;
+  if (timer_index < static_cast<int>(arraysize(kStatsCollectionTimesMs)))
+    ScheduleTimer(stats, timer_index);
+  else
+    RemoveTabLoadStats(stats->render_view_id);
+}
+
+void CacheStats::RecordCacheFractionHistogram(base::TimeDelta elapsed,
+                                              base::TimeDelta cache_time,
+                                              bool is_load_done) {
+  if (elapsed.InMilliseconds() <= 0)
+    return;
+
+  int64 cache_fraction_percentage =
+      100 * cache_time.InMilliseconds() / elapsed.InMilliseconds();
+
+  DCHECK(cache_fraction_percentage >= 0 && cache_fraction_percentage < 100);
+
+  int index = 0;
+  while (index + 1 < static_cast<int>(arraysize(kStatsCollectionTimesMs)) &&
+         base::TimeDelta::FromMilliseconds(kStatsCollectionTimesMs[index + 1]) <
+         elapsed) {
+    index++;
+  }
+
+  if (is_load_done) {
+    final_histograms_[index]->Add(cache_fraction_percentage);
+  } else {
+    intermediate_histograms_[index]->Add(cache_fraction_percentage);
+  }
+}
+
+void CacheStats::RegisterMainURLRequestContext(
+    const net::URLRequestContext* context) {
+  main_request_contexts_.insert(context);
+}
+
+void CacheStats::UnregisterMainURLRequestContext(
+    const net::URLRequestContext* context) {
+  main_request_contexts_.erase(context);
+}
+
+}  // namespace chrome_browser_net