RDH: Add some more instrumentation to figure out jank in RDH.

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 <algorithm>
 #include <set>
@@ skipping 2166 matching lines @@
     net::URLRequest* request = loader.second->request();
     net::UploadProgress upload_progress;
     {
       // TODO(pkasting): Remove ScopedTracker below once crbug.com/455952 is
       // fixed.
       tracked_objects::ScopedTracker tracking_profile2(
           FROM_HERE_WITH_EXPLICIT_FUNCTION(
               "455952 ResourceDispatcherHostImpl::GetLoadInfoForAllRoutes2"));
       upload_progress = request->GetUploadProgress();
     }
+
+    tracked_objects::ScopedTracker tracking_profile4(

[eroman, 2015/02/27 21:25:52]

I would suggest measuring TimeTicks manually for these sections, and accumulate
it over the entire pending_loaders_ before reporting it to the profiler.

The reason I suggest that is it might be more of the multiplicative effect that
leads to the jank than any individual one.

Either way, LGTM

[mmenke, 2015/02/27 21:50:22]

Good point.  For now, I think I'll just do this and look at aggregate CPU usage
(Which, admittedly, is much different from "jank").  Could end up improving the
average case but not the worst/janky case, but this method is up there when it
comes to total runtime on the IOThread, too, so I don't think that would be a
waste of time.

Admittedly, being one of the largest aggregate consumers of CPU time on the IO
thread doesn't exactly mean it consumes a huge amount of CPU time in an absolute
sense, but it really shouldn't be up there.

+        FROM_HERE_WITH_EXPLICIT_FUNCTION(
+            "455952 ResourceDispatcherHostImpl::GetLoadInfoForAllRoutes4"));
+
     LoadInfo load_info;
     load_info.url = request->url();
     {
       // TODO(pkasting): Remove ScopedTracker below once crbug.com/455952 is
       // fixed.
       tracked_objects::ScopedTracker tracking_profile3(
           FROM_HERE_WITH_EXPLICIT_FUNCTION(
               "455952 ResourceDispatcherHostImpl::GetLoadInfoForAllRoutes3"));
       load_info.load_state = request->GetLoadState();
     }
     load_info.upload_size = upload_progress.size();
     load_info.upload_position = upload_progress.position();
 
+    tracked_objects::ScopedTracker tracking_profile5(
+        FROM_HERE_WITH_EXPLICIT_FUNCTION(
+            "455952 ResourceDispatcherHostImpl::GetLoadInfoForAllRoutes5"));
+
     GlobalRoutingID id(loader.second->GetRequestInfo()->GetGlobalRoutingID());
     LoadInfoMap::iterator existing = info_map->find(id);
+
+    tracked_objects::ScopedTracker tracking_profile6(
+        FROM_HERE_WITH_EXPLICIT_FUNCTION(
+            "455952 ResourceDispatcherHostImpl::GetLoadInfoForAllRoutes6"));
+
     if (existing == info_map->end() ||
         LoadInfoIsMoreInteresting(load_info, existing->second)) {
       (*info_map)[id] = load_info;
     }
   }
   return info_map.Pass();
 }
 
 void ResourceDispatcherHostImpl::UpdateLoadInfo() {
   // TODO(pkasting): Remove ScopedTracker below once crbug.com/455952 is
@@ skipping 169 matching lines @@
 
   // Add a flag to selectively bypass the data reduction proxy if the resource
   // type is not an image.
   if (request_data.resource_type != RESOURCE_TYPE_IMAGE)
     load_flags |= net::LOAD_BYPASS_DATA_REDUCTION_PROXY;
 
   return load_flags;
 }
 
 }  // namespace content