Record resource scheduler UMA

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 "content/browser/loader/resource_scheduler.h"
 
 #include <stdint.h>
 
 #include <set>
 #include <string>
@@ skipping 209 matching lines @@
                            bool is_async)
       : client_id_(client_id),
         request_(request),
         ready_(false),
         deferred_(false),
         is_async_(is_async),
         attributes_(kAttributeNone),
         scheduler_(scheduler),
         priority_(priority),
         fifo_ordering_(0),
+        delayable_requests_in_flight_(0u),
         host_port_pair_(net::HostPortPair::FromURL(request->url())),
         weak_ptr_factory_(this) {
     DCHECK(!request_->GetUserData(kUserDataKey));
     request_->SetUserData(kUserDataKey, base::MakeUnique<UnownedPointer>(this));
   }
 
   ~ScheduledResourceRequest() override {
+    if ((attributes_ & kAttributeLayoutBlocking) == kAttributeLayoutBlocking) {
+      UMA_HISTOGRAM_COUNTS_100(
+          "ResourceScheduler.PeakDelayableRequestsInFlight.LayoutBlocking",
+          delayable_requests_in_flight_);
+    }
+    if (!((attributes_ & kAttributeDelayable) == kAttributeDelayable)) {
+      UMA_HISTOGRAM_COUNTS_100(
+          "ResourceScheduler.PeakDelayableRequestsInFlight.NonDelayable",
+          delayable_requests_in_flight_);
+    }
     request_->RemoveUserData(kUserDataKey);
     scheduler_->RemoveRequest(this);
   }
 
   static ScheduledResourceRequest* ForRequest(net::URLRequest* request) {
     UnownedPointer* pointer =
         static_cast<UnownedPointer*>(request->GetUserData(kUserDataKey));
     return pointer ? pointer->get() : nullptr;
   }
 
@@ skipping 20 matching lines @@
                        START_SYNC));
         return;
       }
       deferred_ = false;
       Resume();
     }
 
     ready_ = true;
   }
 
+  void UpdateDelayableRequestsInFlight(size_t delayable_requests_in_flight) {
+    delayable_requests_in_flight_ =
+        std::max(delayable_requests_in_flight_, delayable_requests_in_flight);
+  }
+
   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_; }
   const net::URLRequest* url_request() const { return request_; }
   bool is_async() const { return is_async_; }
@@ skipping 34 matching lines @@
 
   const ClientId client_id_;
   net::URLRequest* request_;
   bool ready_;
   bool deferred_;
   bool is_async_;
   RequestAttributes attributes_;
   ResourceScheduler* scheduler_;
   RequestPriorityParams priority_;
   uint32_t fifo_ordering_;
+
+  // True if a delayable request was in-flight at the same when |this| was
+  // in-flight.

[Randy Smith (Not in Mondays), 2017/05/21 21:43:56]

I think the comment's out of date?  Sounds like it's talking about a boolean.

[tbansal1, 2017/05/25 01:07:46]

Thanks. Fixed.

+  size_t delayable_requests_in_flight_;
   // Cached to excessive recomputation in ShouldKeepSearching.
   const net::HostPortPair host_port_pair_;
 
   base::WeakPtrFactory<ResourceScheduler::ScheduledResourceRequest>
       weak_ptr_factory_;
 
   DISALLOW_COPY_AND_ASSIGN(ScheduledResourceRequest);
 };
 
 const void* const ResourceScheduler::ScheduledResourceRequest::kUserDataKey =
@@ skipping 146 matching lines @@
   }
 
  private:
   enum ShouldStartReqResult {
     DO_NOT_START_REQUEST_AND_STOP_SEARCHING,
     DO_NOT_START_REQUEST_AND_KEEP_SEARCHING,
     START_REQUEST,
     YIELD_SCHEDULER
   };
 
+  // Records the metrics related to number of requests in flight.
+  void RecordRequestCountMetrics() const {
+    UMA_HISTOGRAM_COUNTS_100("ResourceScheduler.RequestsCount.All",
+                             in_flight_requests_.size());
+    UMA_HISTOGRAM_COUNTS_100("ResourceScheduler.RequestsCount.Delayable",
+                             in_flight_delayable_count_);
+
+    size_t non_delayable_in_flight_count =
+        in_flight_requests_.size() - in_flight_delayable_count_;
+
+    UMA_HISTOGRAM_COUNTS_100("ResourceScheduler.RequestsCount.NonDelayable",
+                             non_delayable_in_flight_count);

[Randy Smith (Not in Mondays), 2017/05/21 21:43:56]

I don't have strong objections, but histograms do cost (memory, bandwidth).  Do
you need a histogram that duplicates the information available in other
histograms?  Why?

[tbansal1, 2017/05/25 01:07:46]

I am not sure if this is duplicate of some other histogram. This is recording
the difference between two values, however it is not possible to compute this
from the data from the other 2 histograms.

[Randy Smith (Not in Mondays), 2017/05/25 17:40:12]

Good point, though it's possible with some serious dremeling.  

Ok, I'll just push back a little bit more than yield: Could you confirm for
yourself that you'll actually use all three of these histograms, rather just
needing the data you can get from two of them in the third context (e.g. average
for the distribution)?  If so, I'm good with them.

[tbansal1, 2017/05/31 06:31:21]

Yes, for now I think it is useful to record the difference separately so that it
can be analyzed as a function different network qualities.

+    UMA_HISTOGRAM_COUNTS_100(
+        "ResourceScheduler.RequestsCount.TotalLayoutBlocking",
+        total_layout_blocking_count_);
+
+    if (total_layout_blocking_count_ > 0) {
+      UMA_HISTOGRAM_COUNTS_100(
+          "ResourceScheduler.RequestsCount.DelayableWhenLayoutBlocking",
+          in_flight_delayable_count_);
+    }
+
+    if (non_delayable_in_flight_count > 0) {
+      UMA_HISTOGRAM_COUNTS_100(
+          "ResourceScheduler.RequestsCount.DelayableWhenNonDelayable",
+          in_flight_delayable_count_);
+    }
+  }
+
   void InsertInFlightRequest(ScheduledResourceRequest* request) {
     in_flight_requests_.insert(request);
     SetRequestAttributes(request, DetermineRequestAttributes(request));
+    RecordRequestCountMetrics();

[Randy Smith (Not in Mondays), 2017/05/21 21:43:56]

I remain uncertain that you're going to get good statistics from this.  I'm
willing to defer to the histograms.xml owner if you'd like (if you specifically
raise the issue with them) but to me, this means that you're going to way
overcount situations in the above histograms when you've got a lot of requests,
and undercount when you have fewer.  I'd instead suggest that you have
RecordRequestCountMetrics on a timer that goes off ever n ms while requests are
in-flight and records these metrics at those points.  Alternatively, you could
do something that integrates the values of the various above metrics over times
in between insertions of in flight requests (though you'll need something that
captures when the last in flight request completes).  But recording histograms
on what is, as best I can tell, the statistically arbitrary point of when a new
request gets inserted still strikes me as wrong.

[tbansal1, 2017/05/25 01:07:46]

I agree with the spirit of this concern. The goal of these metrics is to compare
different resource scheduling algorithms, and see how frequently different
algorithms allow a certain number of requests to go in flight. 

One problem with using time-based sampling is that different algorithms may
record different number of samples (if we restrict taking the sample to only
when there are at least 1 request in-flight). This would make it difficult to
compare different algorithms. Recording at request insertion/deletion has the
nice property that changing the scheduling algorithm does not change the number
of samples.

I would agree that this metric has problems (e.g., it is oblivious of the
duration of different states). A more comprehensive way (but with more histogram
bloat) of recording this might be to use histograms of the format:
ResourceScheduler.Count.{All|Delayable|NonDelayble|TotalLayoutBlocking|DelayableWhenLayoutBlocking|DelayableWhenNonDelayable}.{1..N}.
This would require ~6*N histograms.

Then every time a request is inserted or removed, we record for how long (=time
duration) there were X requests in flight. e.g., if there were 3 requests in
flight for 30 seconds, we record a 30 second sample in the histogram:
ResourceScheduler.Count.All.3.
Similarly, we record 5 more samples.

I am hesitant to go with that approach since it is not clear if we really need
to record the time dimension.

Thoughts?

[Randy Smith (Not in Mondays), 2017/05/25 17:40:12]

My problem is that I'm not a statistician, though I'm clearly trying to play one
on TV :-}.  If we take the goal as being only comparing scheduling algorithms, I
think a metric of "fewer at insertion of in flight request is better" is ok, and
this is a fine way to get that metric.  I'd recommending skipping the second
call on erasing in flights requests, though--I don't think we care much about
that value.  

An alternative metric to try and get would be "average number of in-flight
requests for the duration of any given request".  I'm inclined to think that's a
better metric than the value at insertion, as requests will be interfering with
each other for the full overlap of their lifetimes.  I'm happy to yield to your
preference.

If you'd prefer that metric, I don't think it would be hard to compute, and it
would only take one (per type being counted) histogram.  What you'd do is, for
each request, keep three variables: The amount of time the request has been
oustanding for, the average number of other requests active during that time,
and the last time the average was computed.  Whenever there was a change
(erasure or addition) of a request that wasn't the request in question, you
would recompute the average ((average * time outstanding + time since last
computed * other requests active since that time)/(time outstanding + time since
last compued)) and the time outstanding.  When the request completes, the
average gets entered into the histogram(s).

But I'm willing to accept what you currently have if you prefer it to that
(modulo removing the recording from the EraseInFlightRequest() method--if you
think that's a good idea you'll need to pitch it to me).

[tbansal1, 2017/05/31 06:31:21]

Done.  
Average is a fine metric but then I would argue for recording average of
different types of requests. For example, average of count of requests of type X
when a request of type Y is in flight.
where X,Y belong to {delayable, non-delayble, layout blocking};
This is because we do not want to lump metrics from different types of requests
in the same histogram.
Done.

+
+    if (RequestAttributesAreSet(request->attributes(), kAttributeDelayable)) {
+      // Notify all in-flight with the new count of in-flight delayable
+      // requests.
+      for (RequestSet::const_iterator it = in_flight_requests_.begin();
+           it != in_flight_requests_.end(); ++it) {
+        (*it)->UpdateDelayableRequestsInFlight(in_flight_delayable_count_);
+      }
+    }
+
+    if (RequestAttributesAreSet(request->attributes(),
+                                kAttributeLayoutBlocking) ||
+        !RequestAttributesAreSet(request->attributes(), kAttributeDelayable)) {
+      // |request| is either a layout blocking or a non-delayable request.
+      request->UpdateDelayableRequestsInFlight(in_flight_delayable_count_);
+    }
   }
 
   void EraseInFlightRequest(ScheduledResourceRequest* request) {
     size_t erased = in_flight_requests_.erase(request);
     DCHECK_EQ(1u, erased);
     // Clear any special state that we were tracking for this request.
     SetRequestAttributes(request, kAttributeNone);
+    RecordRequestCountMetrics();
   }
 
   void ClearInFlightRequests() {
     in_flight_requests_.clear();
     in_flight_delayable_count_ = 0;
     total_layout_blocking_count_ = 0;
+    RecordRequestCountMetrics();
   }
 
   size_t CountRequestsWithAttributes(
       const RequestAttributes attributes,
       ScheduledResourceRequest* current_request) {
     size_t matching_request_count = 0;
     for (RequestSet::const_iterator it = in_flight_requests_.begin();
          it != in_flight_requests_.end(); ++it) {
       if (RequestAttributesAreSet((*it)->attributes(), attributes))
         matching_request_count++;
@@ skipping 570 matching lines @@
   }
   ReprioritizeRequest(request, new_priority, current_intra_priority);
 }
 
 ResourceScheduler::ClientId ResourceScheduler::MakeClientId(
     int child_id, int route_id) {
   return (static_cast<ResourceScheduler::ClientId>(child_id) << 32) | route_id;
 }
 
 }  // namespace content