Add/improve tracing in navigation.

content/browser/frame_host/render_frame_host_impl.cc

 // Copyright 2013 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/frame_host/render_frame_host_impl.h"
 
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/containers/hash_tables.h"
 #include "base/lazy_instance.h"
@@ skipping 446 matching lines @@
 gfx::NativeViewAccessible
     RenderFrameHostImpl::AccessibilityGetNativeViewAccessible() {
   RenderWidgetHostViewBase* view = static_cast<RenderWidgetHostViewBase*>(
       render_view_host_->GetView());
   if (view)
     return view->AccessibilityGetNativeViewAccessible();
   return NULL;
 }
 
 bool RenderFrameHostImpl::CreateRenderFrame(int parent_routing_id) {
-  TRACE_EVENT0("frame_host", "RenderFrameHostImpl::CreateRenderFrame");
+  TRACE_EVENT0("navigation", "RenderFrameHostImpl::CreateRenderFrame");
   DCHECK(!IsRenderFrameLive()) << "Creating frame twice";
 
   // The process may (if we're sharing a process with another host that already
   // initialized it) or may not (we have our own process or the old process
   // crashed) have been initialized. Calling Init multiple times will be
   // ignored, so this is safe.
   if (!GetProcess()->Init())
     return false;
 
   DCHECK(GetProcess()->HasConnection());
@@ skipping 44 matching lines @@
 
 void RenderFrameHostImpl::OnFrameFocused() {
   frame_tree_->SetFocusedFrame(frame_tree_node_);
 }
 
 void RenderFrameHostImpl::OnOpenURL(
     const FrameHostMsg_OpenURL_Params& params) {
   GURL validated_url(params.url);
   GetProcess()->FilterURL(false, &validated_url);
 
+  TRACE_EVENT1("navigation", "RenderFrameHostImpl::OnOpenURL",
+               "url", validated_url.possibly_invalid_spec());
   frame_tree_node_->navigator()->RequestOpenURL(
       this, validated_url, params.referrer, params.disposition,
       params.should_replace_current_entry, params.user_gesture);
 }
 
 void RenderFrameHostImpl::OnDocumentOnLoadCompleted() {
   // This message is only sent for top-level frames. TODO(avi): when frame tree
   // mirroring works correctly, add a check here to enforce it.
   delegate_->DocumentOnLoadCompleted(this);
 }
@@ skipping 38 matching lines @@
 // get a new page_id because we need to create a new navigation entry for that
 // action.
 void RenderFrameHostImpl::OnNavigate(const IPC::Message& msg) {
   // Read the parameters out of the IPC message directly to avoid making another
   // copy when we filter the URLs.
   PickleIterator iter(msg);
   FrameHostMsg_DidCommitProvisionalLoad_Params validated_params;
   if (!IPC::ParamTraits<FrameHostMsg_DidCommitProvisionalLoad_Params>::
       Read(&msg, &iter, &validated_params))
     return;
+  TRACE_EVENT1("navigation", "RenderFrameHostImpl::OnNavigate",
+               "url", validated_params.url.possibly_invalid_spec());
 
   // If we're waiting for a cross-site beforeunload ack from this renderer and
   // we receive a Navigate message from the main frame, then the renderer was
   // navigating already and sent it before hearing the FrameMsg_Stop message.
   // We do not want to cancel the pending navigation in this case, since the
   // old page will soon be stopped.  Instead, treat this as a beforeunload ack
   // to allow the pending navigation to continue.
   if (render_view_host_->is_waiting_for_beforeunload_ack_ &&
       render_view_host_->unload_ack_is_for_cross_site_transition_ &&
       PageTransitionIsMainFrame(validated_params.transition)) {
@@ skipping 76 matching lines @@
   frame_tree_node_->render_manager()->OnDeferredAfterResponseStarted(
       global_request_id, this);
 
   if (GetParent() || !delegate_->WillHandleDeferAfterResponseStarted())
     frame_tree_node_->render_manager()->ResumeResponseDeferredAtStart();
   else
     delegate_->DidDeferAfterResponseStarted(transition_data);
 }
 
 void RenderFrameHostImpl::SwapOut(RenderFrameProxyHost* proxy) {
+  // The end of this event is in OnSwapOutACK when the RenderFrame has completed
+  // the operation and sends back an IPC message.
+  // The trace event may not end properly if the ACK times out.  We expect this
+  // to be fixed when RenderViewHostImpl::OnSwapOut moves to RenderFrameHost.
+  TRACE_EVENT_ASYNC_BEGIN0("navigation", "RenderFrameHostImpl::SwapOut", this);
+
   // TODO(creis): Move swapped out state to RFH.  Until then, only update it
   // when swapping out the main frame.
   if (!GetParent()) {
     // If this RenderViewHost is not in the default state, it must have already
     // gone through this, therefore just return.
     if (render_view_host_->rvh_state_ != RenderViewHostImpl::STATE_DEFAULT)
       return;
 
     render_view_host_->SetState(
         RenderViewHostImpl::STATE_PENDING_SWAP_OUT);
@@ skipping 10 matching lines @@
   if (!GetParent())
     delegate_->SwappedOut(this);
   else
     set_swapped_out(true);
 }
 
 void RenderFrameHostImpl::OnBeforeUnloadACK(
     bool proceed,
     const base::TimeTicks& renderer_before_unload_start_time,
     const base::TimeTicks& renderer_before_unload_end_time) {
+  TRACE_EVENT_ASYNC_END0(
+      "navigation", "RenderFrameHostImpl::BeforeUnload", this);
   // TODO(creis): Support properly beforeunload on subframes. For now just
   // pretend that the handler ran and allowed the navigation to proceed.
   if (GetParent()) {
     render_view_host_->is_waiting_for_beforeunload_ack_ = false;
     frame_tree_node_->render_manager()->OnBeforeUnloadACK(
         render_view_host_->unload_ack_is_for_cross_site_transition_, proceed,
         renderer_before_unload_end_time);
     return;
   }
 
@@ skipping 52 matching lines @@
       render_view_host_->unload_ack_is_for_cross_site_transition_, proceed,
       before_unload_end_time);
 
   // If canceled, notify the delegate to cancel its pending navigation entry.
   if (!proceed)
     render_view_host_->GetDelegate()->DidCancelLoading();
 }
 
 void RenderFrameHostImpl::OnSwapOutACK() {
   OnSwappedOut(false);
+  TRACE_EVENT_ASYNC_END0("navigation", "RenderFrameHostImpl::SwapOut", this);
 }
 
 void RenderFrameHostImpl::OnSwappedOut(bool timed_out) {
   // For now, we only need to update the RVH state machine for top-level swaps.
   if (!GetParent())
     render_view_host_->OnSwappedOut(timed_out);
 }
 
 void RenderFrameHostImpl::OnContextMenu(const ContextMenuParams& params) {
   // Validate the URLs in |params|.  If the renderer can't request the URLs
@@ skipping 242 matching lines @@
 bool RenderFrameHostImpl::CanCommitURL(const GURL& url) {
   // TODO(creis): We should also check for WebUI pages here.  Also, when the
   // out-of-process iframes implementation is ready, we should check for
   // cross-site URLs that are not allowed to commit in this process.
 
   // Give the client a chance to disallow URLs from committing.
   return GetContentClient()->browser()->CanCommitURL(GetProcess(), url);
 }
 
 void RenderFrameHostImpl::Navigate(const FrameMsg_Navigate_Params& params) {
-  TRACE_EVENT0("frame_host", "RenderFrameHostImpl::Navigate");
+  TRACE_EVENT0("navigation", "RenderFrameHostImpl::Navigate");
   // Browser plugin guests are not allowed to navigate outside web-safe schemes,
   // so do not grant them the ability to request additional URLs.
   if (!GetProcess()->IsIsolatedGuest()) {
     ChildProcessSecurityPolicyImpl::GetInstance()->GrantRequestURL(
         GetProcess()->GetID(), params.url);
     if (params.url.SchemeIs(url::kDataScheme) &&
         params.base_url_for_data_url.SchemeIs(url::kFileScheme)) {
       // If 'data:' is used, and we have a 'file:' base url, grant access to
       // local files.
       ChildProcessSecurityPolicyImpl::GetInstance()->GrantRequestURL(
@@ skipping 44 matching lines @@
   params.navigation_type = FrameMsg_Navigate_Type::NORMAL;
   params.browser_navigation_start = base::TimeTicks::Now();
   Navigate(params);
 }
 
 void RenderFrameHostImpl::Stop() {
   Send(new FrameMsg_Stop(routing_id_));
 }
 
 void RenderFrameHostImpl::DispatchBeforeUnload(bool for_cross_site_transition) {
+  TRACE_EVENT_ASYNC_BEGIN0(
+      "navigation", "RenderFrameHostImpl::BeforeUnload", this);
   // TODO(creis): Support subframes.
   if (!render_view_host_->IsRenderViewLive() || GetParent()) {
     // We don't have a live renderer, so just skip running beforeunload.
     render_view_host_->is_waiting_for_beforeunload_ack_ = true;
     render_view_host_->unload_ack_is_for_cross_site_transition_ =
         for_cross_site_transition;
     base::TimeTicks now = base::TimeTicks::Now();
     OnBeforeUnloadACK(true, now, now);
     return;
   }
@@ skipping 157 matching lines @@
           routing_id_));
 }
 
 void RenderFrameHostImpl::SetNavigationsSuspended(
     bool suspend,
     const base::TimeTicks& proceed_time) {
   // This should only be called to toggle the state.
   DCHECK(navigations_suspended_ != suspend);
 
   navigations_suspended_ = suspend;
+  if (navigations_suspended_) {
+    TRACE_EVENT_ASYNC_BEGIN0("navigation",
+                             "RenderFrameHostImpl navigation suspended", this);
+  } else {
+    TRACE_EVENT_ASYNC_END0("navigation",
+                           "RenderFrameHostImpl navigation suspended", this);
+  }
+
   if (!suspend && suspended_nav_params_) {
     // There's navigation message params waiting to be sent. Now that we're not
     // suspended anymore, resume navigation by sending them. If we were swapped
     // out, we should also stop filtering out the IPC messages now.
     render_view_host_->SetState(RenderViewHostImpl::STATE_DEFAULT);
 
     DCHECK(!proceed_time.is_null());
     suspended_nav_params_->browser_navigation_start = proceed_time;
     Send(new FrameMsg_Navigate(routing_id_, *suspended_nav_params_));
     suspended_nav_params_.reset();
   }
 }
 
 void RenderFrameHostImpl::CancelSuspendedNavigations() {
   // Clear any state if a pending navigation is canceled or preempted.
   if (suspended_nav_params_)
     suspended_nav_params_.reset();
+
+  TRACE_EVENT_ASYNC_END0("navigation",
+                         "RenderFrameHostImpl navigation suspended", this);
   navigations_suspended_ = false;
 }
 
 }  // namespace content