New issue
Advanced search Search tips

Issue 818683 link

Starred by 7 users

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 2
Type: Bug



Sign in to add a comment

Network panel shows huge Content Download time for 304 response

Reported by vojtech....@gmail.com, Mar 5 2018

Issue description

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

Steps to reproduce the problem:
1. Open incognito window with Dev tools and switch to Network panel
2. Open https://www.glami.fr/robes.html  - returns HTTP 200
3. Reload using CMD+R - returns HTTP 304
4. Look at the Content Download time for the main HTML - it's 300 msec in my browser.

What is the expected behavior?
When the server returns "304", the browser uses cached HTML response, so the Content Download shoud be always ZERO, because the 304 response contains no response body.

What went wrong?
The network panel is reporting 295 msec "Content Download" time when there's no response body from the server (HTTP 304 response).

Did this work before? N/A 

Chrome version: 64.0.3282.186  Channel: stable
OS Version: OS X 10.13.3
Flash Version: 

this might be connected with https://bugs.chromium.org/p/chromium/issues/detail?id=779528, but I'm not sure.
 
Screenshot 2018-03-05 16.49.59.png
609 KB View Download
The result of the same test in Firefox
Screenshot 2018-03-05 17.34.47.png
36.0 KB View Download

Comment 2 Deleted

Comment 3 by caseq@chromium.org, Mar 5 2018

Components: -Platform>DevTools Platform>DevTools>Network
Owner: caseq@chromium.org
Status: Assigned (was: assu)
Same result in canary: Version 67.0.3362.0 (Official Build) canary (64-bit)
Screenshot 2018-03-06 01.47.26.png
147 KB View Download
Owner: jarhar@chromium.org
Cc: paulir...@chromium.org
Thanks for reporting the bug, sorry for the late reply.

The large content download time relative to the short TTFB certainly does seem strange for a 304. I tried reproducing it, but https://www.glami.fr/robes.html now returns a 404. I found a similar page on the same site https://www.glami.fr/robes-femmes/ but I couldn't get it to give me a 304.

Firefox showing zero for receiving makes sense for a 304, and the reason Chrome never shows zero for "Content Download" is because it doesn't accurately represent the time it took for data to transfer over the wire and includes overhead from Chrome doing something else before telling DevTools that loading has "finished" for that request.

My guess for your example is that Chrome was particularly busy doing something before reporting that the request was "complete." It's also possible that a particularly slow disk cache access could be the culprit.

+paulirish Do you think we should change the label or documentation for "Content Download?"
@jarhar@chromium.org It took so long so we decided to remove that testing HTML file from our site. 
Anyway, we have put it back and I'm still able to reproduce that behaviour, please try it again now.
Thanks for putting it back up, I can reproduce the bug now in release 69.0.3497.100. However, in my development build (71.0.3576.0), I found that the Content Download time is significantly shorter and looks more like an average 304. Would you mind trying again in Canary? In the meantime I will try to track down the long Content Download time.
I'm just trying the same in Canary and I still see about 140 msec "Content Download" in average.

140 msec is huge for 140 byte 304 response - average ping to the webserver from my laptop is 15 msec.


	$ ping glami.fr
	PING glami.fr (88.86.120.16): 56 data bytes
	64 bytes from 88.86.120.16: icmp_seq=0 ttl=51 time=13.790 ms
	64 bytes from 88.86.120.16: icmp_seq=1 ttl=51 time=15.062 ms
	64 bytes from 88.86.120.16: icmp_seq=2 ttl=51 time=18.291 ms
	64 bytes from 88.86.120.16: icmp_seq=3 ttl=51 time=14.864 ms
	64 bytes from 88.86.120.16: icmp_seq=4 ttl=51 time=13.116 ms
	^C
	--- glami.fr ping statistics ---
	5 packets transmitted, 5 packets received, 0.0% packet loss
	round-trip min/avg/max/stddev = 13.116/15.025/18.291/1.781 ms


--

Version 71.0.3577.0 (Official Build) canary (64-bit)

See the screenshot attached.
Screenshot 2018-10-11 14.19.17.png
103 KB View Download
My colleague just tried the same in Canary on slower laptop (Macbook Air) and the average "Content Download" time was 220 msec. Which is 80 msec slower than on my Macbook Pro.

I think that time includes some CPU processing time of the CSS inlined in the HTML file, or something like that.

I understand this issue may seem unimportant. But when the frontend developer tells you "your server is responding slowly, just look at the Content Download", then it looks like a backend problem. And that makes improving of the FCP time much more difficult.
Another fact: When I use mobile device simulator in the Developer Tools, the "Content Download" time drops to 23 msec. Screen:


Screenshot 2018-10-11 15.21.17.png
223 KB View Download
You're correct, the Content Download time is definitely including some other time beyond downloading. It's not actually time spent _processing_ the file.  In this case, "Content Download" includes time spent reading from the cache. And here, reading the cache takes >100ms. Crazy yes but we've seen it before. A large response (~1mb) takes a while so reducing it would help. :)

Also we'll look into adding a "Reading from cache" time span in the timing details here. This will also clarify when network traffic is done vs when the cache interaction happens.

Hypothetically we could update the docs. "Content download" could say "this time could also include reading from the cache, which in some circumstances can take >100ms"
I still don't get it - why is "reading from the cache" 100 msec on Desktop and only about 10 msec on Mobile? The browser is the same. 
The HTML file is identical (it's a static HTML file saved on disk).

I would expect that "reading from the cache" always takes the same amount of time.

Sign in to add a comment