Update chrome.loadTimes() to use timings from WebPerformance.

chrome/renderer/loadtimes_extension_bindings.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/renderer/loadtimes_extension_bindings.h"
 
 #include <math.h>
 
 #include "base/time/time.h"
 #include "content/public/renderer/document_state.h"
 #include "net/http/http_response_info.h"
 #include "third_party/WebKit/public/web/WebLocalFrame.h"
+#include "third_party/WebKit/public/web/WebPerformance.h"
 #include "v8/include/v8.h"
 
 using blink::WebDataSource;
 using blink::WebLocalFrame;
 using blink::WebNavigationType;
+using blink::WebPerformance;
 using content::DocumentState;
 
 // Values for CSI "tran" property
 const int kTransitionLink = 0;
 const int kTransitionForwardBack = 6;
 const int kTransitionOther = 15;
 const int kTransitionReload = 16;
 
 namespace extensions_v8 {
 
 static const char* const kLoadTimesExtensionName = "v8/LoadTimes";
 
 class LoadTimesExtensionWrapper : public v8::Extension {
  public:
-  // Creates an extension which adds a new function, chromium.GetLoadTimes()
+  // Creates an extension which adds a new function, chrome.loadTimes()
   // This function returns an object containing the following members:
   // requestTime: The time the request to load the page was received
   // loadTime: The time the renderer started the load process
   // finishDocumentLoadTime: The time the document itself was loaded
   //                         (this is before the onload() method is fired)
   // finishLoadTime: The time all loading is done, after the onload()
   //                 method and all resources
   // navigationType: A string describing what user action initiated the load
+  //
+  // Note that chrome.loadTimes() is deprecated in favor of performance.timing.
+  // Many of the timings reported via chrome.loadTimes() match timings available
+  // in performance.timing. Timing data will be removed from chrome.loadTimes()
+  // in a future release. No new timings or other information should be exposed
+  // via these APIs.
   LoadTimesExtensionWrapper() :
     v8::Extension(kLoadTimesExtensionName,
       "var chrome;"
       "if (!chrome)"
       "  chrome = {};"
       "chrome.loadTimes = function() {"
       "  native function GetLoadTimes();"
       "  return GetLoadTimes();"
       "};"
       "chrome.csi = function() {"
@@ skipping 53 matching lines @@
       return;
     }
     WebDataSource* data_source = frame->dataSource();
     if (!data_source) {
       return;
     }
     DocumentState* document_state = DocumentState::FromDataSource(data_source);
     if (!document_state) {
       return;
     }
-    double request_time = document_state->request_time().ToDoubleT();
-    double start_load_time = document_state->start_load_time().ToDoubleT();
+    WebPerformance web_performance = frame->performance();
+    // Though request time now tends to be used to describe the time that the
+    // request for the main resource was issued, when chrome.loadTimes() was
+    // added, it was used to describe 'The time the request to load the page was
+    // received', which is the time now known as navigation start. For backward
+    // compatibility, we continue to provide request_time, setting its value to
+    // navigation start.
+    double request_time = web_performance.navigationStart();
+    // Developers often use start_load_time as the time the navigation was
+    // started, so we return navigationStart for this value as well. See
+    // https://gist.github.com/search?utf8=%E2%9C%93&q=startLoadTime.
+    // Note that, historically, start_load_time reported the time that a
+    // provisional load was first processed in the render process. For
+    // browser-initiated navigations, this is some time after navigation start,
+    // which means that developers who used this value as a way to track the
+    // start of a navigation were misusing this timestamp and getting the wrong
+    // value - they should be using navigationStart intead. Additionally,
+    // once plznavigate ships, provisional loads will not be processed by the
+    // render process for browser-initiated navigations, so reporting the time a
+    // provisional load was processed in the render process will no longer make
+    // sense. Thus, we now report the time for navigationStart, which is a value
+    // more consistent with what developers currently use start_load_time for.
+    double start_load_time = web_performance.navigationStart();
+    // TODO(bmcquade): Remove this. 'commit' time is a concept internal to
+    // chrome that shouldn't be exposed to the web platform.
     double commit_load_time = document_state->commit_load_time().ToDoubleT();

[Pat Meenan, 2016/06/27 16:23:39]

Maybe use web_performance.responseStart() since that's functionally what it is
and would keep everything consistent and tied to the monotonic clock.

[Bryan McQuade, 2016/06/27 20:35:14]

Agree. Done.

     double finish_document_load_time =
-        document_state->finish_document_load_time().ToDoubleT();
-    double finish_load_time = document_state->finish_load_time().ToDoubleT();
-    double first_paint_time = document_state->first_paint_time().ToDoubleT();
+        web_performance.domContentLoadedEventEnd();

[Pat Meenan, 2016/06/27 16:23:39]

Sanity check and make sure this should be the end and not the start (i.e.
includes the duration of script execution).  Looking at the implementation of
finish_document_load_time() it looks like the time was set before the
notifications are passed to the observers.

[Bryan McQuade, 2016/06/27 20:35:13]

Yes, good suggestion - I had eyeballed which of start or end was closer in the
timings but hadn't actually traced the calls to see which was right. Here's what
I found:

The existing code sets finish_document_load_time in
RenderFrameImpl::didFinishDocumentLoad:
https://cs.chromium.org/chromium/src/content/renderer/render_frame_impl.cc?dr...

didFinishDocumentLoad is called via FrameLoader::finishedParsing which is called
from Document::finishedParsing:
https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/dom/Docum...
This is slightly after m_documentTiming.markDomContentLoadedEventEnd(); is
called, earlier in Document::finishedParsing, so using domContentLoadedEventEnd
seems right here.

+    double finish_load_time = web_performance.loadEventEnd();

[Pat Meenan, 2016/06/27 16:23:39]

Same as with DCL, I think this needs to be tied to the start instead of the end
to match existing behavior.

[Bryan McQuade, 2016/06/27 20:35:14]

Here's the trace for this one:
finish_load_time is set in RenderFrameImpl::didFinishLoad, which gets called via
FrameLoader::checkCompleted:
https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/loader/Fr...

This call is shortly after the load event gets fired, above, at the call to
m_frame->document()->implicitClose(), which eventually fires both load event
start and end, via
this->domWindow()->documentWasClosed()
LocalDOMWindow::dispatchWindowLoadEvent()
LocalDOMWindow::dispatchLoadEvent():
https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/frame/Loc...

So it looks like loadEventEnd is a better match than loadEventStart.

+    double first_paint_time = web_performance.firstContentfulPaint();

[Pat Meenan, 2016/06/27 16:23:39]

Shouldn't this be firstPaint() to keep it consistent with existing behavior
(understanding that we may be trying to push sites to look at contentful paint
instead, not sure we want to switch it out from under them).

[Bryan McQuade, 2016/06/27 20:35:14]

Yep, agree. Updated to firstPaint().

+    // TODO(bmcquade): remove this. It's misleading to track the first paint
+    // after the load event, since many pages perform their meaningful paints
+    // long before the load event fires.
     double first_paint_after_load_time =
         document_state->first_paint_after_load_time().ToDoubleT();

[Pat Meenan, 2016/06/27 16:23:39]

Can we just zero this out instead (or remove it)?  The clock used by
first_paint_after_load_time() is Time::now() and not the same monotonic clock as
the rest of the timers.

[Bryan McQuade, 2016/06/27 20:35:13]

Sure, I decided to zero it out for now. Any code that looks this value up will
continue to at least get a sane numeric value. Longer term, we'll remove
chrome.loadTimes() timings entirely, but that's a more involved change.

     std::string navigation_type =
         GetNavigationType(data_source->navigationType());
     bool was_fetched_via_spdy = document_state->was_fetched_via_spdy();
     bool was_npn_negotiated = document_state->was_npn_negotiated();
     std::string npn_negotiated_protocol =
         document_state->npn_negotiated_protocol();
     bool was_alternate_protocol_available =
         document_state->was_alternate_protocol_available();
     std::string connection_info = net::HttpResponseInfo::ConnectionInfoToString(
         document_state->connection_info());
@@ skipping 179 matching lines @@
     }
     args.GetReturnValue().Set(csi);
   }
 };
 
 v8::Extension* LoadTimesExtension::Get() {
   return new LoadTimesExtensionWrapper();
 }
 
 }  // namespace extensions_v8