Background: Chrome has a requests queue. It will queue delayable requests under some circumstances. But I found it hard to determine which requests are causing the requests queuing.
My question is: do we have a way to dive into the root cause of the queuing issue ?
For HTTP/2 queuing has a different meaning and analysis. Read this great article on Head of Line Blocking (HOLB).
Here's my analysis of TTFB timings using Wireshark which could be a complement for the debug job.
HOLB may have 2 causes: HTTP and TCP. Request blocking can still happen (perhaps over TCP reasons).
Having a HAR file for the page/site, find entries with .blocked > 50 over timings (please, read HTTP/1.1 analysis below)
"timings": {
"blocked": 286,
"dns": 0,
"connect": 0,
"ssl": 0,
"send": 0,
"wait": 605,
"receive": 163
}
jq -r '.log.entries | to_entries[] | select(.value.response.httpVersion == "HTTP/2" and .value.timings.blocked > 0) | [.key, .value.request.url, .value.timings.blocked]' stackoverflow.com.har
Result
[12,"https://www.gravatar.com/avatar/05b09a797fd0c59d1627b30fb4cdba01?s=32&d=identicon&r=PG&f=1",140]
[19,"https://i.stack.imgur.com/jHqqo.jpg?s=32&g=1",319]
[22,"https://lh3.googleusercontent.com/a/AItbvmmvptZFLppl8vyYo83v1QOQJwt-90sdRzBnyw9Z=k-s32",7]
[23,"https://lh3.googleusercontent.com/a/AATXAJwXX0y4AkD3eL_6KvrwRXLmBviBVEXEb7X6U1WA=k-s32",6]
[27,"https://i.stack.imgur.com/kdIyT.jpg?s=32&g=1",314]
[48,"https://i.stack.imgur.com/65UsL.jpg?s=32&g=1",297]
[61,"https://i.stack.imgur.com/KLQJy.jpg?s=32&g=1",286]
There are several reasons why Chrome could be queuing a request (as any other browser)
Queueing. The browser queues requests when:
- There are higher priority requests.
- There are already six TCP connections open for this origin, which is the limit. Applies to HTTP/1.0 and HTTP/1.1 only.
- The browser is briefly allocating space in the disk cache
From the developer's tools Network tab, save the requests with Save all as HAR with content and analyze the timings object of each request
"timings": {
"blocked": 2.0329999979403803,
"dns": -1,
"ssl": -1,
"connect": -1,
"send": 0.397,
"wait": 189.6199999998943,
"receive": 296.10200000024633,
"_blocked_queueing": 1.1759999979403801
}
HAR could be filtered with jq, e.g. find entries with _blocked_queueing > 50
jq -r '.log.entries | to_entries[] | if(.value.timings._blocked_queueing > 50) then [.key, .value.request.url, .value.timings._blocked_queueing,.value.timings.blocked ] else empty end' stackoverflow.com.har
Result:
[
21,
"https://graph.facebook.com/4191055284264423/picture?type=large",
160.28299999743467,
160.66799999743466
]
[
66,
"https://fonts.gstatic.com/s/robotoslab/v13/BngbUXZYTXPIvIBgJJSb6s3BzlRRfKOFbvjojISmb2Rm.ttf",
55.99899999651825,
109.53999999651825
]
[
67,
"https://fonts.gstatic.com/s/robotoslab/v13/BngbUXZYTXPIvIBgJJSb6s3BzlRRfKOFbvjoa4Omb2Rm.ttf",
56.85599999560509,
56.85599999560509
]
Then we could inspect 6 preceding entries of one of those requests
jq -r --argjson idx 67 '.log.entries[($idx - 6):($idx + 1)] | .[] | [.request.url, .time, .timings]' stackoverflow.com.har
Or get the highest dns
jq -r '.log.entries | sort_by(.timings.dns|floor)[-1] | .timings.dns, .request.url' stackoverflow.com.har
438.551
https://example.com
Google offers an online HAR Analyzer that could be used similar to Dev tools Network pane.
Hovering over a request on the Waterfall column, the details of a request can be seen. As a first approach, long queuing requests could be preceded by one or several requests with high values on any of the items.
Using the command line below to get a csv and then make a chart with
jq -r '.log.entries | to_entries[] | [.value.startedDateTime, .value.serverIPAddress, .key, ((.value.startedDateTime[0:19] + "Z"|fromdateiso8601)*1000 + (.value.startedDateTime[20:23]|tonumber)), .value.time, .value.timings._blocked_queueing ] | @csv' stackoverflow.com.har | tee stackoverflow.com.har.csv
