New issue
Advanced search Search tips

Issue 760059 link

Starred by 4 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 2
Type: Bug



Sign in to add a comment

Resource Timing (DNS) inaccurate when using HTTP/2

Reported by saja...@gmail.com, Aug 29 2017

Issue description

UserAgent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.101 Safari/537.36

Steps to reproduce the problem:
1. Ensure host DNS cache is flushed and start fresh browser session
2. Navigate to https://db.sajalkayan.com/res.html

What is the expected behavior?
The DNS timings for each request hitting *.tbrum7.com should be > 0, since this is the first time ever browser is accessing a randomized hostname.

What went wrong?
This issue appears to happen only when accessing resources over HTTP/2 and connection re-use is involved. Chrome makes DNS queries for each subdomain (verified using wireshark), but (domainLookupEnd - domainLookupStart) is 0.

The Network tab of developer tools also shows DNS time as 0 and tags what should have been the actual DNS time as "Stalled".

Did this work before? N/A 

Does this work in other browsers? Yes

Chrome version: 60.0.3112.101  Channel: stable
OS Version: 
Flash Version: 

PS: The reproduce example might not be available or working as intended in the future. I can't figure out how to make a static example for this issue.
 

Comment 1 by mmenke@chromium.org, Aug 29 2017

Components: Internals>Network>HTTP2
Interesting that you're only seeing this with HTTP/2.  If you were also seeing it with HTTP, I'd say this was preconnect.  We start preconnecting before the renderer is spun up, so DNS resolution may complete before a request is actually started.  We're too cowardly to give times that aren't in the expected order, so in that case, it looks like no time was taken by DNS resolution.

However, if you're not seeing it with HTTPS + HTTP/1.x to the same server, something else may be going on.  My guess is it's still pre-connect related, and it's due to only reporting DNS resolution time to the first consumer of the H2 session, and some weirdness in the logic there.

Comment 2 by mmenke@chromium.org, Aug 29 2017

Could you provide us an about:net-export log of this happening?  It may better illuminate just what the issue is.  Instructions:  https://dev.chromium.org/for-testers/providing-network-details

Comment 3 by mmenke@chromium.org, Aug 29 2017

Labels: Needs-Feedback

Comment 4 by saja...@gmail.com, Aug 29 2017

For us we know it's not pre-connect related since for each test we generate randomized hostname. There is no way for the browser to predict the hostname.

We do not see it on HTTPS + HTTP/1.x. Only when experimenting with HTTP/2.

I reproduced this on a fresh profile. 

Attached:
chrome-net-export-log.json.gz : Output of about:net-export (gzipped)
restiming.json : JSON.stringify( window.performance.getEntriesByType("resource"))
restiming.txt : The debug output shown on screen

The 3 requests for *.tbrum7.com in restiming.json have domainLookupStart = domainLookupEnd.
chrome-net-export-log.json.gz
863 KB Download
restiming.json
2.2 KB View Download
restiming.txt
529 bytes View Download
Project Member

Comment 5 by sheriffbot@chromium.org, Aug 29 2017

Cc: mmenke@chromium.org
Labels: -Needs-Feedback
Thank you for providing more feedback. Adding requester "mmenke@chromium.org" to the cc list and removing "Needs-Feedback" label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Comment 6 by mmenke@chromium.org, Aug 29 2017

Thanks for the log!  Looks like we pooled all the requests for *.tbrum7.com onto a single H2 session, which was created for h2-1.tbrum5.com.  The session for h2-1.tbrum5.com was not preconnected (Nor was the one for db.sajalkayan.com).  Did the request for those two URLs (https://db.sajalkayan.com/res.html and https://h2-1.tbrum5.com/?0.3078734305934181) have DNS timing information, but not the others?  It may be related to session reuse.

If we do a DNS lookup, but then reuse an H2 session that was already connected, it may be the case that we don't include DNS timing information.

Comment 7 by saja...@gmail.com, Aug 29 2017

Ah!
So I didn't have the right words to express this, but this missing DNS timing information only happens during H2 session reuse.

I do get timing information for fresh connections.

> If we do a DNS lookup, but then reuse an H2 session that was already connected, it may be the case that we don't include DNS timing information.

That's the summary of my issue.

To add. I can reproduce the issue in :-
1. Chrome unstable : Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/62.0.3192.0 Safari/537.36_
2. Chrome stable few months ago, unknown version

Comment 8 by mmenke@chromium.org, Aug 29 2017

Cc: pmeenan@chromium.org
Thanks for the confirmation.  I'll defer to the HTTP2 and performance API people the prioritization of this / whether it is worth fixing.

If you read the W3C resource timing doc, the domainLookupStart section says "If a persistent connection [RFC 2616] is used or the resource is retrieved from relevant application caches or local resources, this attribute must return the same value as fetchStart."  So it looks like we are in compliance with the letter of the spec, though this is likely an oversight in the spec itself, not realizing that in some cases we may do a DNS lookup before reusing a connection.

Comment 9 Deleted

Comment 10 by saja...@gmail.com, Aug 30 2017

I think the spec is somewhat ambiguous about it since "persistent connection [RFC 2616]" might only be specific to http/1.1.
Labels: Needs-Triage-M60 TE-NeedsTriageHelp
Unable to triage this issue from TE-End, hence adding "TE-NeedsTriageHelp" for further triage.
Components: -Blink>PerformanceAPIs Blink>PerformanceAPIs>ResourceTiming

Comment 13 by ricea@chromium.org, Oct 19 2017

#10 Do you have any comment on the impact? Is it interfering with your work to a significant degree?
Labels: Needs-Feedback

Comment 15 by saja...@gmail.com, Nov 24 2017

It does have significant impact for us. We rely on resource timing API to determine the DNS latency, but now the timing measurements are incorrect due to H2 session reuse. In the real-world DNS query was required prior to making the request, but the timing API does not reflect that.

In this case enabling H2 on our server caused Resource Timing to not reflect real-world behaviour.
Project Member

Comment 16 by sheriffbot@chromium.org, Nov 24 2017

Cc: yhirano@chromium.org
Labels: -Needs-Feedback
Thank you for providing more feedback. Adding requester "yhirano@chromium.org" to the cc list and removing "Needs-Feedback" label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Status: Available (was: Unconfirmed)
mmenke@, would you be a reasonable owner for this?
I don't have the time to work on this, unfortunately.
Any thoughts on who an alternative owner would be?
Filed https://github.com/w3c/resource-timing/issues/160 to ask for spec clarification.
Cc: -pmeenan@chromium.org
Still looking for an appropriate owner, mmenke@, do you have any thought?

Sign in to add a comment