Add UMA that periodically logs number of outstanding requests

content/browser/loader/resource_dispatcher_host_impl.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.
 
 // See http://dev.chromium.org/developers/design-documents/multi-process-resource-loading
 
 #include "content/browser/loader/resource_dispatcher_host_impl.h"
 
 #include <stddef.h>
 
@@ skipping 150 matching lines @@
 
 namespace content {
 
 namespace {
 
 static ResourceDispatcherHostImpl* g_resource_dispatcher_host;
 
 // The interval for calls to ResourceDispatcherHostImpl::UpdateLoadStates
 const int kUpdateLoadStatesIntervalMsec = 250;
 
+// The interval for calls to RecordOutstandingRequestsStats.
+const int kRecordOutstandingRequestsStatsIntervalMsec = 60000;
+
 // Maximum byte "cost" of all the outstanding requests for a renderer.
 // See declaration of |max_outstanding_requests_cost_per_process_| for details.
 // This bound is 25MB, which allows for around 6000 outstanding requests.
 const int kMaxOutstandingRequestsCostPerProcess = 26214400;
 
 // The number of milliseconds after noting a user gesture that we will
 // tag newly-created URLRequest objects with the
 // net::LOAD_MAYBE_USER_GESTURE load flag. This is a fairly arbitrary
 // guess at how long to expect direct impact from a user gesture, but
 // this should be OK as the load flag is a best-effort thing only,
@@ skipping 151 matching lines @@
     : request_id_(-1),
       is_shutdown_(false),
       num_in_flight_requests_(0),
       max_num_in_flight_requests_(base::SharedMemory::GetHandleLimit()),
       max_num_in_flight_requests_per_process_(static_cast<int>(
           max_num_in_flight_requests_ * kMaxRequestsPerProcessRatio)),
       max_outstanding_requests_cost_per_process_(
           kMaxOutstandingRequestsCostPerProcess),
       largest_outstanding_request_count_seen_(0),
       largest_outstanding_request_per_process_count_seen_(0),
+      peak_outstanding_request_count_(0),
+      peak_outstanding_request_count_multitab_(0),
       delegate_(nullptr),
       loader_delegate_(nullptr),
       allow_cross_origin_auth_prompt_(false),
       create_download_handler_intercept_(download_handler_intercept),
       main_thread_task_runner_(base::ThreadTaskRunnerHandle::Get()),
       io_thread_task_runner_(io_thread_runner),
       experimental_web_features_enabled_(
           base::CommandLine::ForCurrentProcess()->HasSwitch(
               switches::kEnableExperimentalWebPlatformFeatures)) {
   DCHECK(main_thread_task_runner_->BelongsToCurrentThread());
   DCHECK(!g_resource_dispatcher_host);
   g_resource_dispatcher_host = this;
 
   ANNOTATE_BENIGN_RACE(
       &last_user_gesture_time_,
       "We don't care about the precise value, see http://crbug.com/92889");
 
   io_thread_task_runner_->PostTask(
       FROM_HERE,
       base::Bind(&ResourceDispatcherHostImpl::OnInit, base::Unretained(this)));
 
   update_load_states_timer_.reset(new base::RepeatingTimer());
+  record_outstanding_requests_stats_timer_.reset(new base::RepeatingTimer());
 }
 
 // The default ctor is only used by unittests. It is reasonable to assume that
 // the main thread and the IO thread are the same for unittests.
 ResourceDispatcherHostImpl::ResourceDispatcherHostImpl()
     : ResourceDispatcherHostImpl(CreateDownloadHandlerIntercept(),
                                  base::ThreadTaskRunnerHandle::Get()) {}
 
 ResourceDispatcherHostImpl::~ResourceDispatcherHostImpl() {
   DCHECK(outstanding_requests_stats_map_.empty());
@@ skipping 208 matching lines @@
 
   const net::URLRequestJobFactory* job_factory =
       info->GetContext()->GetRequestContext()->job_factory();
   if (!url.is_valid() || job_factory->IsHandledProtocol(url.scheme()))
     return false;
 
   return delegate_->HandleExternalProtocol(url, info);
 }
 
 void ResourceDispatcherHostImpl::DidStartRequest(ResourceLoader* loader) {
-  // Make sure we have the load state monitor running.
+  // Make sure we have the load state monitors running.
   if (!update_load_states_timer_->IsRunning() &&
       scheduler_->HasLoadingClients()) {
     update_load_states_timer_->Start(
         FROM_HERE, TimeDelta::FromMilliseconds(kUpdateLoadStatesIntervalMsec),
         this, &ResourceDispatcherHostImpl::UpdateLoadInfo);
   }
+  if (!record_outstanding_requests_stats_timer_->IsRunning()) {
+    record_outstanding_requests_stats_timer_->Start(
+        FROM_HERE,
+        TimeDelta::FromMilliseconds(
+            kRecordOutstandingRequestsStatsIntervalMsec),
+        this, &ResourceDispatcherHostImpl::RecordOutstandingRequestsStats);
+  }
 }
 
 void ResourceDispatcherHostImpl::DidReceiveRedirect(
     ResourceLoader* loader,
     const GURL& new_url,
     ResourceResponse* response) {
   ResourceRequestInfoImpl* info = loader->GetRequestInfo();
   if (delegate_) {
     delegate_->OnRequestRedirected(
         new_url, loader->request(), info->GetContext(), response);
@@ skipping 168 matching lines @@
 void ResourceDispatcherHostImpl::OnInit() {
   scheduler_.reset(new ResourceScheduler);
 }
 
 void ResourceDispatcherHostImpl::OnShutdown() {
   DCHECK(io_thread_task_runner_->BelongsToCurrentThread());
 
   is_shutdown_ = true;
   pending_loaders_.clear();
 
-  // Make sure we shutdown the timer now, otherwise by the time our destructor
+  // Make sure we shutdown the timers now, otherwise by the time our destructor
   // runs if the timer is still running the Task is deleted twice (once by
   // the MessageLoop and the second time by RepeatingTimer).
   update_load_states_timer_.reset();
+  record_outstanding_requests_stats_timer_.reset();
 
   // Clear blocked requests if any left.
   // Note that we have to do this in 2 passes as we cannot call
   // CancelBlockedRequestsForRoute while iterating over
   // blocked_loaders_map_, as it modifies it.
   std::set<GlobalFrameRoutingId> ids;
   for (const auto& blocked_loaders : blocked_loaders_map_) {
     std::pair<std::set<GlobalFrameRoutingId>::iterator, bool> result =
         ids.insert(blocked_loaders.first);
     // We should not have duplicates.
@@ skipping 1161 matching lines @@
   }
 
   if (stats.num_requests >
       largest_outstanding_request_per_process_count_seen_) {
     largest_outstanding_request_per_process_count_seen_ = stats.num_requests;
     UMA_HISTOGRAM_COUNTS_1M(
         "Net.ResourceDispatcherHost.OutstandingRequests.PerProcess",
         largest_outstanding_request_per_process_count_seen_);
   }
 
+  if (num_in_flight_requests_ > peak_outstanding_request_count_) {
+    peak_outstanding_request_count_ = num_in_flight_requests_;
+  }
+
+  if (outstanding_requests_stats_map_.size() >= 2 &&

[Takashi Toyoshima, 2017/06/20 07:39:21]

This will report if there is one background tab that has a long-polling request,
and it will be a very common case. Probably, we want to check if each map entry
isn't in the "network quiet" state.

[Kunihiko Sakamoto, 2017/06/20 08:39:28]

Done.

+      num_in_flight_requests_ > peak_outstanding_request_count_multitab_) {
+    peak_outstanding_request_count_multitab_ = num_in_flight_requests_;
+  }
+
   return stats;
 }
 
 bool ResourceDispatcherHostImpl::HasSufficientResourcesForRequest(
     net::URLRequest* request) {
   ResourceRequestInfoImpl* info = ResourceRequestInfoImpl::ForRequest(request);
   OustandingRequestsStats stats = IncrementOutstandingRequestsCount(1, info);
 
   if (stats.num_requests > max_num_in_flight_requests_per_process_)
     return false;
@@ skipping 508 matching lines @@
   // We need to be able to compare all requests to find the most important one
   // per tab. Since some requests may be navigation requests and we don't have
   // their render frame routing IDs yet (which is what we have for subresource
   // requests), we must go to the UI thread and compare the requests using their
   // WebContents.
   main_thread_task_runner_->PostTask(
       FROM_HERE,
       base::Bind(UpdateLoadStateOnUI, loader_delegate_, base::Passed(&infos)));
 }
 
+void ResourceDispatcherHostImpl::RecordOutstandingRequestsStats() {
+  if (peak_outstanding_request_count_ != 0) {
+    UMA_HISTOGRAM_COUNTS_1M(
+        "Net.ResourceDispatcherHost.PeakOutstandingRequests",
+        peak_outstanding_request_count_);
+    peak_outstanding_request_count_ = 0;

[Takashi Toyoshima, 2017/06/20 07:39:21]

this will not report at the next time if there are no inc/dec events in the next
timer period.
we may want to keep the current outstanding value?

[Kunihiko Sakamoto, 2017/06/20 08:39:28]

Good catch, thanks!
Done.

+  }
+
+  if (peak_outstanding_request_count_multitab_ != 0) {
+    UMA_HISTOGRAM_COUNTS_1M(
+        "Net.ResourceDispatcherHost.PeakOutstandingRequests.MultiTabLoading",
+        peak_outstanding_request_count_multitab_);
+    peak_outstanding_request_count_multitab_ = 0;
+  }
+}
+
 void ResourceDispatcherHostImpl::BlockRequestsForRoute(
     const GlobalFrameRoutingId& global_routing_id) {
   DCHECK(io_thread_task_runner_->BelongsToCurrentThread());
   DCHECK(blocked_loaders_map_.find(global_routing_id) ==
          blocked_loaders_map_.end())
       << "BlockRequestsForRoute called  multiple time for the same RFH";
   blocked_loaders_map_[global_routing_id] =
       base::MakeUnique<BlockedLoadersList>();
 }
 
@@ skipping 190 matching lines @@
                                  &throttles);
     if (!throttles.empty()) {
       handler.reset(new ThrottlingResourceHandler(std::move(handler), request,
                                                   std::move(throttles)));
     }
   }
   return handler;
 }
 
 }  // namespace content