Add TRACE_EVENT macros to net.

content/browser/loader/resource_loader.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_loader.h"
 
 #include <utility>
 
 #include "base/command_line.h"
 #include "base/location.h"
 #include "base/metrics/histogram.h"
 #include "base/profiler/scoped_tracker.h"
 #include "base/single_thread_task_runner.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/time/time.h"
+#include "base/trace_event/trace_event.h"
 #include "content/browser/appcache/appcache_interceptor.h"
 #include "content/browser/child_process_security_policy_impl.h"
 #include "content/browser/loader/cross_site_resource_handler.h"
 #include "content/browser/loader/detachable_resource_handler.h"
 #include "content/browser/loader/resource_loader_delegate.h"
 #include "content/browser/loader/resource_request_info_impl.h"
 #include "content/browser/service_worker/service_worker_request_handler.h"
 #include "content/browser/ssl/ssl_client_auth_handler.h"
 #include "content/browser/ssl/ssl_manager.h"
 #include "content/browser/ssl/ssl_policy.h"
@@ skipping 212 matching lines @@
   return ResourceRequestInfoImpl::ForRequest(request_.get());
 }
 
 void ResourceLoader::ClearLoginDelegate() {
   login_delegate_ = NULL;
 }
 
 void ResourceLoader::OnReceivedRedirect(net::URLRequest* unused,
                                         const net::RedirectInfo& redirect_info,
                                         bool* defer) {
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("net"),
+               "ResourceLoader::OnReceivedRedirect");
   DCHECK_EQ(request_.get(), unused);
 
   DVLOG(1) << "OnReceivedRedirect: " << request_->url().spec();
   DCHECK(request_->status().is_success());
 
   ResourceRequestInfoImpl* info = GetRequestInfo();
 
   if (info->GetProcessType() != PROCESS_TYPE_PLUGIN &&
       !ChildProcessSecurityPolicyImpl::GetInstance()->
           CanRequestURL(info->GetChildID(), redirect_info.new_url)) {
@@ skipping 65 matching lines @@
                                            bool fatal) {
   ResourceRequestInfoImpl* info = GetRequestInfo();
 
   SSLManager::OnSSLCertificateError(
       weak_ptr_factory_.GetWeakPtr(), info->GetResourceType(), request_->url(),
       info->GetWebContentsGetterForRequest(), ssl_info, fatal);
 }
 
 void ResourceLoader::OnBeforeNetworkStart(net::URLRequest* unused,
                                           bool* defer) {
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("net"),
+               "ResourceLoader::OnBeforeNetworkStart");
   DCHECK_EQ(request_.get(), unused);
 
   // Give the handler a chance to delay the URLRequest from using the network.
   if (!handler_->OnBeforeNetworkStart(request_->url(), defer)) {
     Cancel();
     return;
   } else if (*defer) {
     deferred_stage_ = DEFERRED_NETWORK_START;
   }
 }
 
 void ResourceLoader::OnResponseStarted(net::URLRequest* unused) {
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("net"),
+               "ResourceLoader::OnResponseStarted");
   DCHECK_EQ(request_.get(), unused);
 
   DVLOG(1) << "OnResponseStarted: " << request_->url().spec();
 
   if (!request_->status().is_success()) {
     ResponseCompleted();
     return;
   }
 
   CompleteResponseStarted();
 
   if (is_deferred())
     return;
 
   if (request_->status().is_success())
     StartReading(false);  // Read the first chunk.
   else
     ResponseCompleted();
 }
 
 void ResourceLoader::OnReadCompleted(net::URLRequest* unused, int bytes_read) {
+  TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("net"),
+               "ResourceLoader::OnReadCompleted");
   DCHECK_EQ(request_.get(), unused);
   DVLOG(1) << "OnReadCompleted: \"" << request_->url().spec() << "\""
            << " bytes_read = " << bytes_read;
 
   // bytes_read == -1 always implies an error.
   if (bytes_read == -1 || !request_->status().is_success()) {
     ResponseCompleted();
     return;
   }
 
@@ skipping 83 matching lines @@
     case DEFERRED_REDIRECT:
       request_->FollowDeferredRedirect();
       break;
     case DEFERRED_READ:
       base::ThreadTaskRunnerHandle::Get()->PostTask(
           FROM_HERE, base::Bind(&ResourceLoader::ResumeReading,
                                 weak_ptr_factory_.GetWeakPtr()));
       break;
     case DEFERRED_RESPONSE_COMPLETE:
       base::ThreadTaskRunnerHandle::Get()->PostTask(
           FROM_HERE, base::Bind(&ResourceLoader::ResponseCompleted,

[mmenke, 2016/04/04 16:45:49]

Looks like you're missing ResponseComplete in the deferred case.  I'm not sure
how often this happens.  Could considering adding ResponseComplete directly, but
you catch most call paths that go through there already.

Looks like the other two PostTasks in this method may be missed as well.

[ssid, 2016/04/05 00:50:12]

The performance team has added few trace points in this file, which included
ResponseCompleted. I also changed category in this file to loading to keep
consistent with them.

                                 weak_ptr_factory_.GetWeakPtr()));
       break;
     case DEFERRED_FINISH:
       // Delay self-destruction since we don't know how we were reached.
       base::ThreadTaskRunnerHandle::Get()->PostTask(
           FROM_HERE, base::Bind(&ResourceLoader::CallDidFinishLoading,
                                 weak_ptr_factory_.GetWeakPtr()));
       break;
   }
 }
@@ skipping 121 matching lines @@
 
   // Make sure we track the buffer in at least one place.  This ensures it gets
   // deleted even in the case the request has already finished its job and
   // doesn't use the buffer.
   scoped_refptr<net::IOBuffer> buf;
   int buf_size;
   {
     // TODO(darin): Remove ScopedTracker below once crbug.com/475761 is fixed.
     tracked_objects::ScopedTracker tracking_profile2(
         FROM_HERE_WITH_EXPLICIT_FUNCTION("475761 OnWillRead()"));
+    TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("net"), "ResourceLoader::ReadMore");
 
     if (!handler_->OnWillRead(&buf, &buf_size, -1)) {
       Cancel();
       return;
     }
   }
 
   DCHECK(buf.get());
   DCHECK(buf_size > 0);
 
@@ skipping 95 matching lines @@
       case net::URLRequestStatus::FAILED:
         status = STATUS_UNDEFINED;
         break;
     }
 
     UMA_HISTOGRAM_ENUMERATION("Net.Prefetch.Pattern", status, STATUS_MAX);
   }
 }
 
 }  // namespace content