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..f53e679d4d05c7d5f95e61e2c7e26e24d922fee4 100644
--- a/content/browser/loader/resource_scheduler.cc
+++ b/content/browser/loader/resource_scheduler.cc
@@ -7,6 +7,7 @@
 #include "content/browser/loader/resource_scheduler.h"
 
 #include "base/metrics/field_trial.h"
+#include "base/metrics/histogram.h"
 #include "base/stl_util.h"
 #include "content/common/resource_messages.h"
 #include "content/browser/loader/resource_message_delegate.h"
@@ -129,7 +130,8 @@ class ResourceScheduler::ScheduledResourceRequest
         classification_(NORMAL_REQUEST),
         scheduler_(scheduler),
         priority_(priority),
-        fifo_ordering_(0) {
+        fifo_ordering_(0),
+        request_seen_(base::TimeTicks::Now()) {

[mmenke, 2014/10/30 15:14:19]

Should include base/time.h (Timer, included in the header, includes it, but
seems like we should be including it explicitly)

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

     TRACE_EVENT_ASYNC_BEGIN1("net", "URLRequest", request_,
                              "url", request->url().spec());
   }
@@ -143,6 +145,17 @@ class ResourceScheduler::ScheduledResourceRequest
       deferred_ = false;
       controller()->Resume();
     }
+    base::TimeDelta time_deferred = base::TimeTicks::Now() - request_seen_;

[mmenke, 2014/10/30 15:14:19]

This this the time we want?  We could measure time we actually delayed the
request actually paused instead (Time between when WillStartRequest() was
called, and we called controller()->Resume(), if we paused the request, or 0 if
we chose not to pause it).

It is a less direct measure than the time we *tried* to delay the request for,
but it is closed to our practical impact.

Not sure how much difference there'll be between the two histograms - probably
not much.

[aiolos (Not reviewing), 2014/10/30 16:58:47]

I can see value from both options. I'm guessing we probably don't need both,
although knowing how much impact we're actually having on requests wouldn't be a
bad thing. Would it make sense to have histograms for both for this experiment
just to see, and then take out whichever one we feel is less helpful afterward?

[mmenke, 2014/10/30 17:30:40]

I'm fine with adding both, and a TODO to remove one of them fairly promptly. 
Definitely agree we don't need/want both longer term.

Nice to know if there's any meaningful difference between the two.  If not, can
throw one away pretty quickly.  If not, can figure out if the difference is
relevant, and then get rid of the one we decide we care less about.

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+    std::string histogram_name = base::StringPrintf(
+        "ResourceScheduler.%sRequestTimeDeferred",

[Ilya Sherman, 2014/10/30 03:18:11]

Optional nit: I'd recommend having the Active vs. Background string appear as a
suffix, so that the related histograms are alphabetized to be right next to each
other.

[mmenke, 2014/10/30 15:14:19]

It also makes the histograms more searchable.

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+        scheduler_->IsClientActive(client_id_) ? "Active" : "Background");
+    base::HistogramBase* histogram_counter = base::Histogram::FactoryTimeGet(
+        histogram_name,
+        base::TimeDelta::FromMilliseconds(1),
+        base::TimeDelta::FromMinutes(5),
+        100,

[mmenke, 2014/10/30 15:14:19]

Do we really need 100 buckets?  Think 50 should be fine.  This is just about
reducing size of the histogram in memory.

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+        base::Histogram::kUmaTargetedHistogramFlag);
+    histogram_counter->AddTime(time_deferred);
   }
 
   void set_request_priority_params(const RequestPriorityParams& priority) {
@@ -194,6 +207,7 @@ class ResourceScheduler::ScheduledResourceRequest
   ResourceScheduler* scheduler_;
   RequestPriorityParams priority_;
   uint32 fifo_ordering_;
+  base::TimeTicks request_seen_;

[mmenke, 2014/10/30 15:14:19]

"request_seen_" makes me think "Did we see the request", not "when was this
request seen".

Suggest calling it time_seen_...  Or could just use request_->creation_time() 
(Throttles are created right after the URLRequest is scheduled, so that should
basically be the same thing).

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Acknowledged.

 
   DISALLOW_COPY_AND_ASSIGN(ScheduledResourceRequest);
 };
@@ -998,6 +1012,14 @@ void ResourceScheduler::LoadCoalescedRequests() {
   }
 }
 
+bool ResourceScheduler::IsClientActive(ClientId client_id) {
+    ClientMap::iterator client_it = client_map_.find(client_id);

[mmenke, 2014/10/30 15:14:19]

const_iterator

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+      if (client_it == client_map_.end()) {
+            return false;

[mmenke, 2014/10/30 15:14:19]

When there's no client, we just let requests through the scheduler, so this
seems the wrong bucket to put that case into.

Also, when a client goes away, are its requests typically deleted first, or the
client?

[aiolos (Not reviewing), 2014/10/31 23:33:27]

I made a separate histogram for those requests plus requests from clients that
have switched states since the request was issued. I'm debating changing this to
add a histogram that gets counts from all requests instead.

ie:

ResourceScheduler.RequestTimeDeferred_Active
ResourceScheduler.RequestTimeDeferred_Background
ResourceScheduler.RequestTimeDeferred_Other

vs 

ResourceScheduler.RequestTimeDeferred
ResourceScheduler.RequestTimeDeferred_Active
ResourceScheduler.RequestTimeDeferred_Background

Thoughts?

+              }

[mmenke, 2014/10/30 15:14:19]

don't use braces when both condition and body of an if take up one line.

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+        return client_it->second->is_active();

[mmenke, 2014/10/30 15:14:19]

Formatting here is off

[aiolos (Not reviewing), 2014/10/31 23:33:27]

Done.

+}
+
 void ResourceScheduler::ReprioritizeRequest(ScheduledResourceRequest* request,
                                             net::RequestPriority new_priority,
                                             int new_intra_priority_value) {