New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 778722 link

Starred by 43 users

Issue metadata

Status: WontFix
Owner: ----
Closed: Jun 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 1
Type: Bug-Regression



Sign in to add a comment

TCP and SSL timing falsely reported as 0ms

Reported by rpelle...@gmail.com, Oct 26 2017

Issue description

UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/61.0.3163.100 Safari/537.36

Steps to reproduce the problem:
1. Open and run net-internals
2. Open a tab with dev tools open
3. Navigate to https://www.catchpoint.com/navtiming/ 

What is the expected behavior?
TCP and SSL should show non-zero values when net-internals shows activity for TCP and SSL. 

What went wrong?
The page illustrates that both navigation timing and developer tools in the latest Chrome version reports 0ms for TCP and SSL while net-internals correctly shows the time taken for both.

Please see the attached images comparing TCP and SSL timing from nav timing to net-internals.  

Did this work before? Yes 53 to my knowledge but it could have worked in later versions 

Chrome version: 61.0.3163.100  Channel: stable
OS Version: 10
Flash Version:
 
nav timing.png
80.3 KB View Download
net internals.png
520 KB View Download
This is working as intended. Navigation Timing Level 2 [0] shipped in Chrome 57.

--

10. Let domainLookupStart, domainLookupEnd, connectStart and connectEnd be the same value as fetchStart.

[..]

13. If no domain lookup is required, go to connect-start-step. Otherwise, immediately before a user agent starts the domain name lookup, record the time as domainLookupStart.

--

(Aside: I do hope you'll send a correction for the newsletter[0] just delivered to all Catchpoint customers regarding this.. "Due to a recently discovered defect in Google Chrome [..]".)

[1] http://us1.forward-to-friend.com/forward/preview?u=3d574c72a2e1d1cc21ed8c3aa&id=8d3f6ff506
[0] https://www.w3.org/TR/navigation-timing-2/#processing-model
The specification also has step 15 and 16 which is what this defect is about. In the testing we did the browser did establish a TCP connection, and ssl handshake. Additionally it impacts not just Nav Timing api, but also developer tools network tab.

Excerpt from spec:

connect-start-step] If a persistent transport connection is used to fetch the resource, let connectStart and connectEnd be the same value of domainLookupEnd. Otherwise, record the time as connectStart immediately before initiating the connection to the server and record the time as connectEnd immediately after the connection to the server or the proxy is established. A user agent MAY need multiple retries before this time. Once connection is established set the value of nextHopProtocol to the ALPN ID used by the connection. If a connection can not be established, abort the rest of the steps. 
A user agent MUST also set the secureConnectionStart attribute as follows: 
When a secure transport is used, the user agent MUST record the time as secureConnectionStart immediately before the handshake process to secure the connection.
When a secure transport is not used, the user agent MUST set the value of secureConnectionStart to 0.
I'm still not able to reproduce this in any case except where I'm able to confirm (in net-internals) that there was a socket available for reuse. When this is the case, your excerpt from the connect-start-step would apply:

"If a persistent transport connection is used to fetch the resource, let connectStart and connectEnd be the same value of domainLookupEnd."

Since there was a reusable connection available, there's (generally) no name lookup to be done. Therefore domainLookupEnd would still be set to fetchStart from step 10.
Quick update:

Here is a better test URL:
HTTP1.1: https://www.catchpoint.com/wp-content/uploads/2017/10/navtimings.html
HTTP2: https://www2.catchpoint.com/wp-content/uploads/2017/10/navtimings.html

Here is an example from Webpagetest with screenshots:
https://www.webpagetest.org/result/171028_P3_0cf9daf1e58df14c10aadc0c0a784efa/

You can see in the screenshot the SSLStart is not present. However, webpagetest shows there was SSL timings at the network level.

We also have confirmed when we reproduced locally on the chrome, the page is actually coming from cache (although dev tools says disable cache) - net-internals shows SSL handshake before it pulls the page from cache. This seems to be driven by preconnect.

However, in the webpagetest example before the URL was not in cache, was first view. Yet Navtimings does not have the SSL start.
Owner: allada@chromium.org
Status: Assigned (was: Unconfirmed)
Owner: eostroukhov@chromium.org
Components: -Platform>DevTools Blink>Network
Owner: ----
Status: Unconfirmed (was: Assigned)
chrome://network-internals is not a part of DevTools
"chrome://network-internals" is displaying the correct numbers as to what is happening in the network stack - it does not have problems.

Devtools, and Nav Timing API is displaying 0ms when the browser uses pre-connect on the main page URL.

Comment 9 by ricea@chromium.org, Jan 12 2018

Components: -Blink>Network Platform>DevTools Blink>PerformanceAPIs>NavigationTiming

Comment 10 by kozy@chromium.org, Jan 17 2018

Owner: eostroukhov@chromium.org
Status: Assigned (was: Unconfirmed)
Cc: eostroukhov@chromium.org
Components: -Platform>DevTools
Owner: ----
Status: Available (was: Assigned)
Labels: -Pri-2 Pri-1
We don't have anyone lined up to work on this yet, but with 43 stars, I'd say this should probably be P1.
Cc: y...@yoav.ws
Yoav, do you have any context here?

Comment 14 by npm@chromium.org, Jun 25 2018

Labels: Needs-Bisect
Since this worked before, would a bisect be useful here? It's a gigantic bisect range but might be worth pursuing since no one seems to want to take on this bug :P
Cc: phanindra.mandapaka@chromium.org
Labels: Triaged-ET Needs-Feedback
Unable to reproduce the issue on latest chrome stable 67.0.3396.99, Beta version 68.0.3440.33 latest chrome 69.0.3472.3. Attaching screen-cast for reference.
Steps
------
1. Launched chrome
2. Opened a tab with dev tools and navigated to Network tab
3. Navigated to given URL's in the comment #4
HTTP1.1: https://www.catchpoint.com/wp-content/uploads/2017/10/navtimings.html
HTTP2: https://www2.catchpoint.com/wp-content/uploads/2017/10/navtimings.html
As we are able to see the SSL values.

@Reporter: Could you please upgrade to latest chrome stable 67.0.3396.99, you can download latest chrome builds here:""https://www.chromium.org/getting-involved/dev-channel"". Let us know whether issue still persists.If possible provide screen-cast for better triaging this.
Thanks.!
778722.mp4
5.1 MB View Download

Comment 16 by y...@yoav.ws, Jun 26 2018

Just seeing this, sorry. No past context beyond what's in the issue.

Comment 17 by y...@yoav.ws, Jun 26 2018

I also can't reproduce this in M67. 
npm@ - I tend to close this as non-reproducible, but willing to give bisecting a shot, out of pure curiosity...
Status: WontFix (was: Available)
Closing SGTM.

Comment 19 by y...@yoav.ws, Jun 26 2018

FWIW, Bisect lead to https://chromium.googlesource.com/chromium/src/+log/95b827c4f05395c048567567fad603fecde01388..f1400a36711fe2f8d473a13121fb7498dec412b0 which has no immediate suspect. Whatever this was, it's no longer an issue

Sign in to add a comment