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..c8d1c08f4f2332184de7fd8ba14a5dca4e7bf58b 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"
@@ -118,11 +120,13 @@ class ResourceScheduler::ScheduledResourceRequest
       public ResourceThrottle {
  public:
   ScheduledResourceRequest(const ClientId& client_id,
+                           ResourceScheduler::ClientState client_state,

[mmenke, 2014/11/03 16:05:55]

Optional nit:  Suggest not taking this as an argument, but instead calling
scheduler->GetClientState here - think that, as implemented, when the request
wants the client state and what it does with it is more a feature of the request
than something the scheduler should care about.

[aiolos (Not reviewing), 2014/11/03 17:50:25]

Done.

                            net::URLRequest* request,
                            ResourceScheduler* scheduler,
                            const RequestPriorityParams& priority)
       : ResourceMessageDelegate(request),
         client_id_(client_id),
+        client_state_on_creation_(client_state),
         request_(request),
         ready_(false),
         deferred_(false),
@@ -139,9 +143,25 @@ class ResourceScheduler::ScheduledResourceRequest
   void Start() {
     TRACE_EVENT_ASYNC_STEP_PAST0("net", "URLRequest", request_, "Queued");
     ready_ = true;
-    if (deferred_ && request_->status().is_success()) {
-      deferred_ = false;
-      controller()->Resume();
+    if (request_->status().is_success()) {

[mmenke, 2014/11/03 16:05:55]

nit:  Suggest making this an early return - early returns are generally
preferred, particularly when there's a bunch of code below them, making
indentation a little harder to follow.

[aiolos (Not reviewing), 2014/11/03 17:50:26]

Done.

+      base::TimeTicks time = base::TimeTicks::Now();
+      ClientState current_state = scheduler_->GetClientState(client_id_);
+      const char* client_state =
+          current_state == UNKNOWN || current_state != client_state_on_creation_
+              ? "Other"
+              : current_state == ACTIVE ? "Active" : "Background";

[mmenke, 2014/11/03 16:05:54]

Suggest a method or function for this, or splitting this into multiple
statements.  As-is, it's pretty hard to follow.

[aiolos (Not reviewing), 2014/11/03 17:50:25]

Done.

+      if (deferred_) {
+        deferred_ = false;
+        controller()->Resume();
+        scheduler_->PostHistogram(
+            "RequestTimeDeferred", client_state, time - time_deferred_);

[mmenke, 2014/11/03 16:05:55]

If !deferred_, we should be recording a 0, I believe.

[aiolos (Not reviewing), 2014/11/03 17:50:25]

Done.

+      }
+      // TODO(aiolos): Remove one of these histograms after gaining an
+      // understanding of the difference between them and which one is more
+      // interesting.
+      scheduler_->PostHistogram("RequestTimeThrottled",
+                                client_state,
+                                time - request_->creation_time());
     }
   }
 
@@ -177,7 +197,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"; }
 
@@ -187,6 +210,7 @@ class ResourceScheduler::ScheduledResourceRequest
   }
 
   ClientId client_id_;
+  ResourceScheduler::ClientState client_state_on_creation_;
   net::URLRequest* request_;
   bool ready_;
   bool deferred_;
@@ -194,6 +218,7 @@ class ResourceScheduler::ScheduledResourceRequest
   ResourceScheduler* scheduler_;
   RequestPriorityParams priority_;
   uint32 fifo_ordering_;
+  base::TimeTicks time_deferred_;
 
   DISALLOW_COPY_AND_ASSIGN(ScheduledResourceRequest);
 };
@@ -754,9 +779,12 @@ 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,
+      GetClientState(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 +1026,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) {
@@ -1035,4 +1071,17 @@ ResourceScheduler::ClientId ResourceScheduler::MakeClientId(
   return (static_cast<ResourceScheduler::ClientId>(child_id) << 32) | route_id;
 }
 
+void ResourceScheduler::PostHistogram(const char* base_name,

[mmenke, 2014/11/03 16:05:55]

This should be in an anonymous namespace up top.

[aiolos (Not reviewing), 2014/11/03 17:50:26]

Done.

+                                      const char* suffix,
+                                      base::TimeDelta time) {
+  std::string histogram_name =
+      base::StringPrintf("ResourceScheduler.%s_%s", base_name, suffix);
+  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 content