Add histograms to gather ResourceScheduler information.

content/browser/loader/resource_scheduler.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 <set>
 
 #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"
 #include "content/public/browser/resource_request_info.h"
 #include "content/public/browser/resource_throttle.h"
 #include "ipc/ipc_message_macros.h"
 #include "net/base/host_port_pair.h"
 #include "net/base/load_flags.h"
 #include "net/base/request_priority.h"
 #include "net/http/http_server_properties.h"
 #include "net/url_request/url_request.h"
 #include "net/url_request/url_request_context.h"
 
 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);
+  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

[mmenke, 2014/11/03 19:01:19]

nit:  Blank line before end of namespace.

[aiolos (Not reviewing), 2014/11/03 20:16:01]

Done.

+
 static const size_t kCoalescedTimerPeriod = 5000;
 static const size_t kMaxNumDelayableRequestsPerClient = 10;
 static const size_t kMaxNumDelayableRequestsPerHost = 6;
 static const size_t kMaxNumThrottledRequestsPerClient = 1;

[mmenke, 2014/11/03 19:01:20]

Optional nit:  When there's an anonymous namespace, the preference seems to be
to not use static before variable declarations, and instead move them into the
anonymous namespace.

 
 struct ResourceScheduler::RequestPriorityParams {
   RequestPriorityParams()
     : priority(net::DEFAULT_PRIORITY),
       intra_priority(0) {
   }
 
   RequestPriorityParams(net::RequestPriority priority, int intra_priority)
     : priority(priority),
       intra_priority(intra_priority) {
@@ skipping 85 matching lines @@
         client_id_(client_id),
         request_(request),
         ready_(false),
         deferred_(false),
         classification_(NORMAL_REQUEST),
         scheduler_(scheduler),
         priority_(priority),
         fifo_ordering_(0) {
     TRACE_EVENT_ASYNC_BEGIN1("net", "URLRequest", request_,
                              "url", request->url().spec());
+    client_state_on_creation_ = scheduler_->GetClientState(client_id_);

[mmenke, 2014/11/03 19:01:19]

optional nit:  I think it's preferred to have
"client_state_on_creation_(scheduler->GetClientState(client_id)," in the
initializer list, and make client_state_on_creation_ const.

If you really prefer this, though, that's fine.

[aiolos (Not reviewing), 2014/11/03 20:16:02]

Done.

   }
 
   ~ScheduledResourceRequest() override { scheduler_->RemoveRequest(this); }
 
   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_);
+    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";

[mmenke, 2014/11/03 19:01:20]

nit:  Use braces on all blocks of an if statements when any component of it
takes more than one lines (ie, this should be "if () {...} else if () {...}",
modulo linebreaks)

[aiolos (Not reviewing), 2014/11/03 20:16:01]

Done.

+
+    if (deferred_) {
       deferred_ = false;
       controller()->Resume();
-    }
+      PostHistogram("RequestTimeDeferred", client_state, time - time_deferred_);
+    } else
+      PostHistogram("RequestTimeDeferred",
+                    client_state,
+                    base::TimeDelta::FromMicroseconds(0));

[mmenke, 2014/11/03 19:01:19]

nit:  Per above comment, should use braces here.

[aiolos (Not reviewing), 2014/11/03 20:16:01]

Done.

+    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) {
     priority_ = priority;
   }
   const RequestPriorityParams& get_request_priority_params() const {
     return priority_;
   }
   const ClientId& client_id() const { return client_id_; }
   net::URLRequest* url_request() { return request_; }
@@ skipping 14 matching lines @@
   bool OnMessageReceived(const IPC::Message& message) override {
     bool handled = true;
     IPC_BEGIN_MESSAGE_MAP(ScheduledResourceRequest, message)
       IPC_MESSAGE_HANDLER(ResourceHostMsg_DidChangePriority, DidChangePriority)
       IPC_MESSAGE_UNHANDLED(handled = false)
     IPC_END_MESSAGE_MAP()
     return handled;
   }
 
   // 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"; }
 
   void DidChangePriority(int request_id, net::RequestPriority new_priority,
                          int intra_priority_value) {
     scheduler_->ReprioritizeRequest(this, new_priority, intra_priority_value);
   }
 
   ClientId client_id_;
+  ResourceScheduler::ClientState client_state_on_creation_;
   net::URLRequest* request_;

[mmenke, 2014/11/03 19:01:19]

While you're here, can client_id_ and request_ be const?

[aiolos (Not reviewing), 2014/11/03 20:16:01]

request_ can't be const because of the usage of url_request's SetPriority, but I
changed client_id_.

   bool ready_;
   bool deferred_;
   RequestClassification classification_;
   ResourceScheduler* scheduler_;
   RequestPriorityParams priority_;
   uint32 fifo_ordering_;
+  base::TimeTicks time_deferred_;
 
   DISALLOW_COPY_AND_ASSIGN(ScheduledResourceRequest);
 };
 
 bool ResourceScheduler::ScheduledResourceSorter::operator()(
     const ScheduledResourceRequest* a,
     const ScheduledResourceRequest* b) const {
   // Want the set to be ordered first by decreasing priority, then by
   // decreasing intra_priority.
   // ie. with (priority, intra_priority)
@@ skipping 540 matching lines @@
   DCHECK(client);
   return client->throttle_state();
 }
 
 scoped_ptr<ResourceThrottle> ResourceScheduler::ScheduleRequest(
     int child_id,
     int route_id,
     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()) {
     // There are several ways this could happen:
     // 1. <a ping> requests don't have a route_id.
     // 2. Most unittests don't send the IPCs needed to register Clients.
     // 3. The tab is closed while a RequestResource IPC is in flight.
     unowned_requests_.insert(request.get());
     request->Start();
     return request.Pass();
@@ skipping 221 matching lines @@
 void ResourceScheduler::LoadCoalescedRequests() {
   DCHECK(should_coalesce_);
   ClientMap::iterator client_it = client_map_.begin();
   while (client_it != client_map_.end()) {
     Client* client = client_it->second;
     client->LoadCoalescedRequests();
     ++client_it;
   }
 }
 
+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) {
   if (request->url_request()->load_flags() & net::LOAD_IGNORE_LIMITS) {
     // We should not be re-prioritizing requests with the
     // IGNORE_LIMITS flag.
     NOTREACHED();
     return;
   }
   RequestPriorityParams new_priority_params(new_priority,
@@ skipping 16 matching lines @@
 
   Client *client = client_it->second;
   client->ReprioritizeRequest(
       request, old_priority_params, new_priority_params);
 }
 
 ResourceScheduler::ClientId ResourceScheduler::MakeClientId(
     int child_id, int route_id) {
   return (static_cast<ResourceScheduler::ClientId>(child_id) << 32) | route_id;
 }
-
 }  // namespace content

[mmenke, 2014/11/03 19:01:19]

nit:  Blank line before end of namespace.

[aiolos (Not reviewing), 2014/11/03 20:16:01]

Done.