ScopedTrackers to help pin down where IOThread::InitSystemRequestContextOnIOThread is janky

chrome/browser/io_thread.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 "chrome/browser/io_thread.h"
 
 #include <vector>
 
 #include "base/base64.h"
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/command_line.h"
 #include "base/compiler_specific.h"
 #include "base/debug/leak_tracker.h"
 #include "base/logging.h"
 #include "base/metrics/field_trial.h"
 #include "base/metrics/user_metrics.h"
 #include "base/prefs/pref_registry_simple.h"
 #include "base/prefs/pref_service.h"
+#include "base/profiler/scoped_tracker.h"
 #include "base/stl_util.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_piece.h"
 #include "base/strings/string_split.h"
 #include "base/strings/string_util.h"
 #include "base/threading/sequenced_worker_pool.h"
 #include "base/threading/thread.h"
 #include "base/threading/worker_pool.h"
 #include "base/time/time.h"
 #include "base/trace_event/trace_event.h"
@@ skipping 216 matching lines @@
       globals->http_user_agent_settings.get());
   // TODO(rtenneti): We should probably use HttpServerPropertiesManager for the
   // system URLRequestContext too. There's no reason this should be tied to a
   // profile.
   return context;
 }
 
 net::URLRequestContext*
 ConstructSystemRequestContext(IOThread::Globals* globals,
                               net::NetLog* net_log) {
+  // TODO(michaeln): Remove ScopedTracker below once crbug.com/454983 is fixed.
+  tracked_objects::ScopedTracker tracking_profile(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "454983 ConstructSystemRequestContext"));
   net::URLRequestContext* context = new SystemURLRequestContext;
   context->set_net_log(net_log);
   context->set_host_resolver(globals->host_resolver.get());
   context->set_cert_verifier(globals->cert_verifier.get());
   context->set_transport_security_state(
       globals->transport_security_state.get());
   context->set_cert_transparency_verifier(
       globals->cert_transparency_verifier.get());
   context->set_http_auth_handler_factory(
       globals->http_auth_handler_factory.get());
@@ skipping 709 matching lines @@
 void IOThread::ClearHostCache() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
 
   net::HostCache* host_cache = globals_->host_resolver->GetHostCache();
   if (host_cache)
     host_cache->clear();
 }
 
 void IOThread::InitializeNetworkSessionParams(
     net::HttpNetworkSession::Params* params) {
+  // TODO(michaeln): Remove ScopedTracker below once crbug.com/454983 is fixed.
+  tracked_objects::ScopedTracker tracking_profile(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION(
+          "454983 IOThread::InitializeNetworkSessionParams"));
   InitializeNetworkSessionParamsFromGlobals(*globals_, params);
 }
 
 // static
 void IOThread::InitializeNetworkSessionParamsFromGlobals(
     const IOThread::Globals& globals,
     net::HttpNetworkSession::Params* params) {
   params->host_resolver = globals.host_resolver.get();
   params->cert_verifier = globals.cert_verifier.get();
   params->cert_policy_enforcer = globals.cert_policy_enforcer.get();
@@ skipping 92 matching lines @@
       BrowserThread::IO,
       FROM_HERE,
       base::Bind(&IOThread::InitSystemRequestContextOnIOThread,
                  base::Unretained(this)));
 }
 
 void IOThread::InitSystemRequestContextOnIOThread() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   DCHECK(!globals_->system_proxy_service.get());
   DCHECK(system_proxy_config_service_.get());
 

[Peter Kasting, 2015/02/09 23:35:44]

Do you want a tracker here to measure the remaining time in this function
besides what you're instrumenting below and elsewhere?

In particular it seems like someone suggested ConstructSystemRequestContext()
below might be slow?  Didn't know if you wanted to also track that.

[michaeln, 2015/02/10 00:02:24]

No, i'm trying to distinguish between objs being constructed in
HttpNetworkSession's initializer list vs the body of that ctor.
 
ConstructSystemRequestContext is tracked sepereately (see line 258)

I'm wondering about CertDatabase, it's platform specific and the overall
InitSystemRequestContext slowness is specific to macs.

   const base::CommandLine& command_line =
       *base::CommandLine::ForCurrentProcess();
   globals_->system_proxy_service.reset(
       ProxyServiceFactory::CreateProxyService(
           net_log_,
           globals_->proxy_script_fetcher_context.get(),
           globals_->system_network_delegate.get(),
           system_proxy_config_service_.release(),
           command_line,
           quick_check_enabled_.GetValue()));
 
   net::HttpNetworkSession::Params system_params;
   InitializeNetworkSessionParams(&system_params);
   system_params.net_log = net_log_;
   system_params.proxy_service = globals_->system_proxy_service.get();
 
-  globals_->system_http_transaction_factory.reset(
-      new net::HttpNetworkLayer(
-          new net::HttpNetworkSession(system_params)));
+  {
+    // TODO(michaeln): Remove after crbug.com/454983 is fixed.
+    tracked_objects::ScopedTracker tracking_profile(
+        FROM_HERE_WITH_EXPLICIT_FUNCTION(
+            "454983 IOThread::InitSystemRequestContextOnIOThread"
+            ".HttpNetworkSession"));

[Peter Kasting, 2015/02/09 23:35:44]

Nit: Name seems slightly misleading since this is actually measuring the
HttpNetworkLayer/HttpTransactionFactory constructor costs, right?  (Since you've
instrumented HttpNetworkSession's constructor separately.)

+    globals_->system_http_transaction_factory.reset(
+        new net::HttpNetworkLayer(
+            new net::HttpNetworkSession(system_params)));
+  }
   globals_->system_url_request_job_factory.reset(
       new net::URLRequestJobFactoryImpl());
   globals_->system_request_context.reset(
       ConstructSystemRequestContext(globals_, net_log_));
   globals_->system_request_context->set_ssl_config_service(
       globals_->ssl_config_service.get());
   globals_->system_request_context->set_http_server_properties(
       globals_->http_server_properties->GetWeakPtr());
 }
 
@@ skipping 259 matching lines @@
   net::QuicVersionVector supported_versions = net::QuicSupportedVersions();
   for (size_t i = 0; i < supported_versions.size(); ++i) {
     net::QuicVersion version = supported_versions[i];
     if (net::QuicVersionToString(version) == quic_version) {
       return version;
     }
   }
 
   return net::QUIC_VERSION_UNSUPPORTED;
 }