Adding instrumentation to locate the source of jankiness.

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 959 matching lines @@
   }
 
   filter_ = NULL;
   return handled;
 }
 
 void ResourceDispatcherHostImpl::OnRequestResource(
     int routing_id,
     int request_id,
     const ResourceHostMsg_Request& request_data) {
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::OnRequestResource"));
   // When logging time-to-network only care about main frame and non-transfer
   // navigations.
   if (request_data.resource_type == RESOURCE_TYPE_MAIN_FRAME &&
       request_data.transferred_request_request_id == -1 &&
       !base::CommandLine::ForCurrentProcess()->HasSwitch(
           switches::kEnableBrowserSideNavigation)) {
     BrowserThread::PostTask(
         BrowserThread::UI,
         FROM_HERE,
         base::Bind(&LogResourceRequestTimeOnUI,
@@ skipping 95 matching lines @@
 
   // We should have a CrossSiteResourceHandler to finish the transfer.
   DCHECK(info->cross_site_handler());
 }
 
 void ResourceDispatcherHostImpl::BeginRequest(
     int request_id,
     const ResourceHostMsg_Request& request_data,
     IPC::Message* sync_result,  // only valid for sync
     int route_id) {
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile1(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest1"));
   int process_type = filter_->process_type();
   int child_id = filter_->child_id();
 
   // Reject invalid priority.
   if (request_data.priority < net::MINIMUM_PRIORITY ||
       request_data.priority > net::MAXIMUM_PRIORITY) {
     RecordAction(base::UserMetricsAction("BadMessageTerminate_RDH"));
     filter_->BadMessageReceived();
     return;
   }
 
   // If we crash here, figure out what URL the renderer was requesting.
   // http://crbug.com/91398
   char url_buf[128];
   base::strlcpy(url_buf, request_data.url.spec().c_str(), arraysize(url_buf));
   base::debug::Alias(url_buf);
 
   // If the request that's coming in is being transferred from another process,
   // we want to reuse and resume the old loader rather than start a new one.
   {
+    // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is
+    // fixed.
+    tracked_objects::ScopedTracker tracking_profile2(
+        FROM_HERE_WITH_EXPLICIT_FUNCTION(
+            "456331 ResourceDispatcherHostImpl::BeginRequest2"));
     LoaderMap::iterator it = pending_loaders_.find(
         GlobalRequestID(request_data.transferred_request_child_id,
                         request_data.transferred_request_request_id));
     if (it != pending_loaders_.end()) {
       // If the request is transferring to a new process, we can update our
       // state and let it resume with its existing ResourceHandlers.
       if (it->second->is_transferring()) {
         linked_ptr<ResourceLoader> deferred_loader = it->second;
         UpdateRequestForTransfer(child_id, route_id, request_id,
                                  request_data, deferred_loader);
 
         deferred_loader->CompleteTransfer();
       } else {
         RecordAction(base::UserMetricsAction("BadMessageTerminate_RDH"));
         filter_->BadMessageReceived();
       }
       return;
     }
   }
 
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile3(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest3"));
   ResourceContext* resource_context = NULL;
   net::URLRequestContext* request_context = NULL;
   filter_->GetContexts(request_data, &resource_context, &request_context);
   // http://crbug.com/90971
   CHECK(ContainsKey(active_resource_contexts_, resource_context));
 
   if (is_shutdown_ ||
       !ShouldServiceRequest(process_type, child_id, request_data,
                             filter_->file_system_context())) {
     AbortRequestBeforeItStarts(filter_, sync_result, request_id);
     return;
   }
 
   // Allow the observer to block/handle the request.
   if (delegate_ && !delegate_->ShouldBeginRequest(request_data.method,
                                                   request_data.url,
                                                   request_data.resource_type,
                                                   resource_context)) {
     AbortRequestBeforeItStarts(filter_, sync_result, request_id);
     return;
   }
 
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile4(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest4"));
   // Construct the request.
   net::CookieStore* cookie_store =
       GetContentClient()->browser()->OverrideCookieStoreForRenderProcess(
           child_id);
   scoped_ptr<net::URLRequest> new_request;
   new_request = request_context->CreateRequest(
       request_data.url, request_data.priority, NULL, cookie_store);
 
   new_request->set_method(request_data.method);
   new_request->set_first_party_for_cookies(
       request_data.first_party_for_cookies);
 
   // If the request is a MAIN_FRAME request, the first-party URL gets updated on
   // redirects.
   if (request_data.resource_type == RESOURCE_TYPE_MAIN_FRAME) {
     new_request->set_first_party_url_policy(
         net::URLRequest::UPDATE_FIRST_PARTY_URL_ON_REDIRECT);
   }
 
   const Referrer referrer(request_data.referrer, request_data.referrer_policy);
   SetReferrerForRequest(new_request.get(), referrer);
 
   net::HttpRequestHeaders headers;
   headers.AddHeadersFromString(request_data.headers);
   new_request->SetExtraRequestHeaders(headers);
 
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile5(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest5"));
   storage::BlobStorageContext* blob_context =
       GetBlobStorageContext(filter_->blob_storage_context());
   // Resolve elements from request_body and prepare upload data.
   if (request_data.request_body.get()) {
     // |blob_context| could be null when the request is from the plugins because
     // ResourceMessageFilters created in PluginProcessHost don't have the blob
     // context.
     if (blob_context) {
       // Attaches the BlobDataHandles to request_body not to free the blobs and
       // any attached shareable files until upload completion. These data will
       // be used in UploadDataStream and ServiceWorkerURLRequestJob.
       AttachRequestBodyBlobDataHandles(
           request_data.request_body.get(),
           blob_context);
     }
     new_request->set_upload(UploadDataStreamBuilder::Build(
         request_data.request_body.get(),
         blob_context,
         filter_->file_system_context(),
         BrowserThread::GetMessageLoopProxyForThread(BrowserThread::FILE)
             .get()));
   }
 
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile6(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest6"));
   bool allow_download = request_data.allow_download &&
       IsResourceTypeFrame(request_data.resource_type);
   bool do_not_prompt_for_login = request_data.do_not_prompt_for_login;
   bool is_sync_load = sync_result != NULL;
   int load_flags =
       BuildLoadFlagsForRequest(request_data, child_id, is_sync_load);
   if (request_data.resource_type == RESOURCE_TYPE_PREFETCH ||
       request_data.resource_type == RESOURCE_TYPE_FAVICON) {
     do_not_prompt_for_login = true;
   }
@@ skipping 55 matching lines @@
 
   if (new_request->url().SchemeIs(url::kBlobScheme)) {
     // Hang on to a reference to ensure the blob is not released prior
     // to the job being started.
     storage::BlobProtocolHandler::SetRequestedBlobDataHandle(
         new_request.get(),
         filter_->blob_storage_context()->context()->GetBlobDataFromPublicURL(
             new_request->url()));
   }
 
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile7(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequest7"));
   // Initialize the service worker handler for the request. We don't use
   // ServiceWorker for synchronous loads to avoid renderer deadlocks.
   ServiceWorkerRequestHandler::InitializeHandler(
       new_request.get(),
       filter_->service_worker_context(),
       blob_context,
       child_id,
       request_data.service_worker_provider_id,
       request_data.skip_service_worker || is_sync_load,
       request_data.fetch_request_mode,
@@ skipping 733 matching lines @@
                      request->method().size();
 
   // Note that this expression will typically be dominated by:
   // |kAvgBytesPerOutstandingRequest|.
   return kAvgBytesPerOutstandingRequest + strings_cost;
 }
 
 void ResourceDispatcherHostImpl::BeginRequestInternal(
     scoped_ptr<net::URLRequest> request,
     scoped_ptr<ResourceHandler> handler) {
+  // TODO(pkasting): Remove ScopedTracker below once crbug.com/456331 is fixed.
+  tracked_objects::ScopedTracker tracking_profile(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "456331 ResourceDispatcherHostImpl::BeginRequestInternal"));
   DCHECK(!request->is_pending());
   ResourceRequestInfoImpl* info =
       ResourceRequestInfoImpl::ForRequest(request.get());
 
   if ((TimeTicks::Now() - last_user_gesture_time_) <
       TimeDelta::FromMilliseconds(kUserGestureWindowMs)) {
     request->SetLoadFlags(
         request->load_flags() | net::LOAD_MAYBE_USER_GESTURE);
   }
 
@@ skipping 330 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