Add histograms to gather ResourceScheduler information.

content/browser/loader/resource_scheduler.cc

Index: content/browser/loader/resource_scheduler.cc
diff --git a/content/browser/loader/resource_scheduler.cc b/content/browser/loader/resource_scheduler.cc
index 6cc902ea561895a7c7216103c6146b5b7107ff68..a149f3629881a2337b9a023c3c50d118bc91558e 100644
--- a/content/browser/loader/resource_scheduler.cc
+++ b/content/browser/loader/resource_scheduler.cc
@@ -7,7 +7,9 @@
 #include "content/browser/loader/resource_scheduler.h"
 
 #include "base/metrics/field_trial.h"
+#include "base/metrics/histogram.h"
 #include "base/stl_util.h"
+#include "base/time/time.h"
 #include "content/common/resource_messages.h"
 #include "content/browser/loader/resource_message_delegate.h"
 #include "content/public/browser/resource_controller.h"
@@ -23,6 +25,24 @@
 
 namespace content {
 
+namespace {
+
+void PostHistogram(const char* base_name,
+                   const char* suffix,
+                   base::TimeDelta time) {
+  std::string histogram_name =
+      base::StringPrintf("ResourceScheduler.%s_%s", base_name, suffix);

[Ilya Sherman, 2014/11/03 23:03:45]

Optional nit: Out of curiousity, why are you using an underscore rather than a
dot for the second separator?

[aiolos (Not reviewing), 2014/11/04 00:15:31]

It's the form I saw used with the only other histograms I've messed with
(SessionRestore.AllTabsLoaded_1, etc). I have no preference I was just trying to
be consistent with what I knew. After looking at other histograms, the dot does
seem to be used more often. Changing.

+  base::HistogramBase* histogram_counter = base::Histogram::FactoryTimeGet(
+      histogram_name,
+      base::TimeDelta::FromMilliseconds(1),
+      base::TimeDelta::FromMinutes(5),
+      50,
+      base::Histogram::kUmaTargetedHistogramFlag);
+  histogram_counter->AddTime(time);
+}
+
+}  // namespace
+
 static const size_t kCoalescedTimerPeriod = 5000;
 static const size_t kMaxNumDelayableRequestsPerClient = 10;
 static const size_t kMaxNumDelayableRequestsPerHost = 6;
@@ -123,6 +143,7 @@ class ResourceScheduler::ScheduledResourceRequest
                            const RequestPriorityParams& priority)
       : ResourceMessageDelegate(request),
         client_id_(client_id),
+        client_state_on_creation_(scheduler->GetClientState(client_id_)),
         request_(request),
         ready_(false),
         deferred_(false),
@@ -139,10 +160,36 @@ class ResourceScheduler::ScheduledResourceRequest
   void Start() {
     TRACE_EVENT_ASYNC_STEP_PAST0("net", "URLRequest", request_, "Queued");
     ready_ = true;
-    if (deferred_ && request_->status().is_success()) {
+    if (!request_->status().is_success())
+      return;
+    base::TimeTicks time = base::TimeTicks::Now();
+    ClientState current_state = scheduler_->GetClientState(client_id_);
+    // Note: the client state isn't perfectly accurate since it won't capture
+    // tabs which have switched between active and background multiple times.
+    // Ex: A tab with the following transitions Active -> Background -> Active
+    // will be recorded as Active.
+    const char* client_state = "Other";
+    if (current_state == client_state_on_creation_ && current_state == ACTIVE) {
+      client_state = "Active";
+    } else if (current_state == client_state_on_creation_ &&
+               current_state == BACKGROUND) {
+      client_state = "Background";
+    }
+
+    if (deferred_) {
       deferred_ = false;
       controller()->Resume();
+      PostHistogram("RequestTimeDeferred", client_state, time - time_deferred_);
+    } else {
+      PostHistogram("RequestTimeDeferred",

[Ilya Sherman, 2014/11/03 23:03:45]

In general, it's nice not to have to repeat histogram names, to reduce the risk
of typos sneaking in to just one of the code paths.  I'll defer to your
judgement here, but something to think about.

[aiolos (Not reviewing), 2014/11/04 00:15:31]

Done.

+                    client_state,
+                    base::TimeDelta::FromMicroseconds(0));
     }
+    PostHistogram(
+        "RequestTimeThrottled", client_state, time - request_->creation_time());
+    // TODO(aiolos): Remove one of the above sets of histograms after gaining an
+    // understanding of the difference between them and which one is more
+    // interesting.
   }
 
   void set_request_priority_params(const RequestPriorityParams& priority) {
@@ -177,7 +224,10 @@ class ResourceScheduler::ScheduledResourceRequest
   }
 
   // ResourceThrottle interface:
-  void WillStartRequest(bool* defer) override { deferred_ = *defer = !ready_; }
+  void WillStartRequest(bool* defer) override {
+    deferred_ = *defer = !ready_;
+    time_deferred_ = base::TimeTicks::Now();
+  }
 
   const char* GetNameForLogging() const override { return "ResourceScheduler"; }
 
@@ -186,7 +236,8 @@ class ResourceScheduler::ScheduledResourceRequest
     scheduler_->ReprioritizeRequest(this, new_priority, intra_priority_value);
   }
 
-  ClientId client_id_;
+  const ClientId client_id_;
+  const ResourceScheduler::ClientState client_state_on_creation_;
   net::URLRequest* request_;
   bool ready_;
   bool deferred_;
@@ -194,6 +245,7 @@ class ResourceScheduler::ScheduledResourceRequest
   ResourceScheduler* scheduler_;
   RequestPriorityParams priority_;
   uint32 fifo_ordering_;
+  base::TimeTicks time_deferred_;
 
   DISALLOW_COPY_AND_ASSIGN(ScheduledResourceRequest);
 };
@@ -754,9 +806,11 @@ scoped_ptr<ResourceThrottle> ResourceScheduler::ScheduleRequest(
     net::URLRequest* url_request) {
   DCHECK(CalledOnValidThread());
   ClientId client_id = MakeClientId(child_id, route_id);
-  scoped_ptr<ScheduledResourceRequest> request(
-      new ScheduledResourceRequest(client_id, url_request, this,
-          RequestPriorityParams(url_request->priority(), 0)));
+  scoped_ptr<ScheduledResourceRequest> request(new ScheduledResourceRequest(
+      client_id,
+      url_request,
+      this,
+      RequestPriorityParams(url_request->priority(), 0)));
 
   ClientMap::iterator it = client_map_.find(client_id);
   if (it == client_map_.end()) {
@@ -998,6 +1052,14 @@ void ResourceScheduler::LoadCoalescedRequests() {
   }
 }
 
+ResourceScheduler::ClientState ResourceScheduler::GetClientState(
+    ClientId client_id) const {
+  ClientMap::const_iterator client_it = client_map_.find(client_id);
+  if (client_it == client_map_.end())
+    return UNKNOWN;
+  return client_it->second->is_active() ? ACTIVE : BACKGROUND;
+}
+
 void ResourceScheduler::ReprioritizeRequest(ScheduledResourceRequest* request,
                                             net::RequestPriority new_priority,
                                             int new_intra_priority_value) {