Add time-to-network histogram considering browser side navigation

content/browser/frame_host/navigator_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/navigator_impl.h"
 
 #include "base/command_line.h"
+#include "base/metrics/histogram.h"
 #include "base/time/time.h"
 #include "content/browser/frame_host/frame_tree.h"
 #include "content/browser/frame_host/frame_tree_node.h"
 #include "content/browser/frame_host/navigation_before_commit_info.h"
 #include "content/browser/frame_host/navigation_controller_impl.h"
 #include "content/browser/frame_host/navigation_entry_impl.h"
 #include "content/browser/frame_host/navigator_delegate.h"
 #include "content/browser/frame_host/render_frame_host_impl.h"
 #include "content/browser/renderer_host/render_view_host_impl.h"
 #include "content/browser/site_instance_impl.h"
@@ skipping 316 matching lines @@
     LOG(WARNING) << "Refusing to load URL as it exceeds " << GetMaxURLChars()
                  << " characters.";
     return false;
   }
 
   // This will be used to set the Navigation Timing API navigationStart
   // parameter for browser navigations in new tabs (intents, tabs opened through
   // "Open link in new tab"). We need to keep it above RFHM::Navigate() call to
   // capture the time needed for the RenderFrameHost initialization.
   base::TimeTicks navigation_start = base::TimeTicks::Now();
-

[clamy, 2014/09/19 14:56:03]

Did you remove the line on purpose? I think it is better to keep it there, since
it underlines that the comment is only about the previous line (and not the
following two).

[carlosk, 2014/09/23 17:02:56]

Done. It was not on purpose: I did changes in this line previously and than not
fully reverted them.

   FrameMsg_Navigate_Params navigate_params;
   RenderFrameHostManager* manager =
       render_frame_host->frame_tree_node()->render_manager();
 
   // PlzNavigate: the RenderFrameHosts are no longer asked to navigate. Instead
   // the RenderFrameHostManager handles the navigation requests for that frame
   // node.
   if (CommandLine::ForCurrentProcess()->HasSwitch(
       switches::kEnableBrowserSideNavigation)) {
+    navigation_start_time_ = navigation_start;
+    navigation_start_url_ = entry.GetURL();
     // Create the navigation parameters.
     MakeNavigateParams(
         entry, *controller_, reload_type, navigation_start, &navigate_params);
     return manager->RequestNavigation(entry, navigate_params);
   }
 
   RenderFrameHostImpl* dest_render_frame_host = manager->Navigate(entry);
   if (!dest_render_frame_host)
     return false;  // Unable to create the desired RenderFrameHost.
 
@@ skipping 17 matching lines @@
 
   // Navigate in the desired RenderFrameHost.
   // We can skip this step in the rare case that this is a transfer navigation
   // which began in the chosen RenderFrameHost, since the request has already
   // been issued.  In that case, simply resume the response.
   bool is_transfer_to_same =
       navigate_params.transferred_request_child_id != -1 &&
       navigate_params.transferred_request_child_id ==
           dest_render_frame_host->GetProcess()->GetID();
   if (!is_transfer_to_same) {
+    navigation_start_time_ = navigation_start;
+    navigation_start_url_ = entry.GetURL();
     dest_render_frame_host->Navigate(navigate_params);
   } else {
     // No need to navigate again.  Just resume the deferred request.
     dest_render_frame_host->GetProcess()->ResumeDeferredNavigation(
         GlobalRequestID(navigate_params.transferred_request_child_id,
                         navigate_params.transferred_request_request_id));
   }
 
   // Make sure no code called via RFH::Navigate clears the pending entry.
   CHECK_EQ(controller_->GetPendingEntry(), &entry);
@@ skipping 258 matching lines @@
 
 void NavigatorImpl::CommitNavigation(
     RenderFrameHostImpl* render_frame_host,
     const NavigationBeforeCommitInfo& info) {
   CheckWebUIRendererDoesNotDisplayNormalURL(
       render_frame_host, info.navigation_url);
   // TODO(clamy): the render_frame_host should now send a commit IPC to the
   // renderer.
 }
 
+void NavigatorImpl::LogResourceRequestTime(
+    base::TimeTicks timestamp, GURL url) {
+  if (navigation_start_url_ == url) {

[davidben, 2014/09/19 21:52:45]

This is slightly racy, but there's not really much we can do about it (that this
is awkward is something PlzNavigate is going to fix since we can tie everything
to a NavigationRequest). Just making a note of it: we're correlating events out
of flow without any IDs, so if we navigate twice in a row to the same URL (say
first a GET then a POST), the GET request starting (and being canceled shortly)
may get associated with the navigation_start_time_ of the POST.

[carlosk, 2014/09/23 17:02:57]

Yes! I was from the start looking for a "request_id" that would be consistent
throughout a navigation to more easily match this!

But as this doesn't yet exist I'll have to play with the URL for now. I also
added a TODO (to the navigatior.h method) stating this should be updated once we
have something more consistent.

Also if ppi@ suggestion of moving this histogram collection into a
WebContentsObserver works, this tracking shouldn't be required at all.

+    base::TimeDelta time_to_network = timestamp - navigation_start_time_;
+    LOCAL_HISTOGRAM_TIMES("PlzNavigate.TimeToNetworkRequest", time_to_network);

[clamy, 2014/09/19 14:56:03]

You want a UMA_HISTOGRAM_TIMES, otherwise we will not get values reported from
the field.

Additionally, I think it would be good to reset the navigation_start_time_ and
navigation_start_url_ here. Also add a condition to only execute this part of
the code if navigation_start_time_ and navigation_start_url_ are not null.

You also need to subtract the time executing the beforeunload event from this
value, as we discussed.

[carlosk, 2014/09/23 17:02:56]

Done! My bad!
Done! A reset here was indeed the right thing as it was the only histogram that
required it. But I just added the time-to-having-navigated histogram so the
reset moved there.

As these values are not pointers I can't sent them to null. So I'm  setting
navigation_start_time_ = TimeTicks() (equivalent of "0") and using that as a
flag.

It's not required to also reset the URL so I'm not doing it; let me know if I
should for some reason.
Oh! I haven't previously understood that the beforeunload should also be
discounted from this measurement! I thought it was only required for the
time-to-commit!

But as discussed yesterday I am for now dropping the need to subtract it.

+  }
+}
+
 void NavigatorImpl::CheckWebUIRendererDoesNotDisplayNormalURL(
     RenderFrameHostImpl* render_frame_host,
     const GURL& url) {
   int enabled_bindings =
       render_frame_host->render_view_host()->GetEnabledBindings();
   bool is_allowed_in_web_ui_renderer =
       WebUIControllerFactoryRegistry::GetInstance()->IsURLAcceptableForWebUI(
           controller_->GetBrowserContext(), url);
   if ((enabled_bindings & BINDINGS_POLICY_WEB_UI) &&
       !is_allowed_in_web_ui_renderer) {
     // Log the URL to help us diagnose any future failures of this CHECK.
     GetContentClient()->SetActiveURL(url);
     CHECK(0);
   }
 }
 
 }  // namespace content