First request on page load is always blocked for a long time
Categories
(Core :: Networking, defect)
Tracking
()
People
(Reporter: arash, Unassigned)
Details
(Keywords: regression, regressionwindow-wanted)
Attachments
(1 file)
|
608.90 KB,
image/png
|
Details |
2021-06-18_21-21.png
User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0
Steps to reproduce:
Visit a website (unique host) that has not been visited since I opened Firefox. This started happening in the Nightly release that I received this morning (Pacific Time). It often happens even if I have visited the host since Firefox was opened, but not as consistently. It was also reproducible in troubleshooting mode.
Firefox Version: 91.0a1 (2021-06-18) (64-bit)
OS: Ubuntu 20.04
Actual results:
The initial GET request to the site page is 'Blocked' for a long (varying duration) time (at least 800 ms up to 48.19 seconds). See attached screenshot for an example.
Expected results:
The request to the site should not have been blocked. There are no other connections to the server in question.
|
||
Comment 1•5 years ago
|
||
The Bugbug bot thinks this bug should belong to the 'Core::Widget: Gtk' component, and is moving the bug to that component. Please revert this change in case you think the bot is wrong.
As an additional data point, Chrome and the stable version of Firefox that comes with Ubuntu work just fine on the very same system.
|
||
Comment 3•5 years ago
|
||
Is there any chance you could pip install --user mozregression, then mozregression --good 89 to see what broke it for you?
I just installed mozregression and ran mozregression --good 89 and I was unable to reproduce it, though I did notice that the blocked time was always 80ms-200ms.
Clearly it's something in my nightly profile, so I created a new test profile, and my blocked times go back to 80m-200ms. Though 80ms-200ms is still quite high. I don't know what the exact equivalent is in Chrome, but the 'Queuing' time is always < 5ms and the 'Stalled' time is always < 1ms there.
By comparison, the 'Blocked' time on another older desktop next to this one that also runs Ubuntu 20.04 is always 0ms.
I'm happy to run any other tests to help diagnose this.
I narrowed down the problem. It's DNS over HTTPS. If I disable it, 'Blocked' is always 0ms. I turn it back on, and the 'Blocked' value is all over the place again.
I always use my personal NextDNS subscription as the DoH provider in my settings, but I just tried using the Firefox default (cloudflare), and I still had long 'Blocked' times.
In the meantime, I can turn off DoH in Firefox and just rely on the NextDNS daemon installed on my computer to protect DNS lookups, but it would be nice to understand the underlying problem.
|
|
||
Comment 6•5 years ago
|
||
Thank you! Valentin do you know why this might happen?
|
||
Comment 7•5 years ago
|
||
This might be a regression from bug 1713796.
@Arash, could you try to use mozregression with the DNS over HTTPS settings?
You should be able to set them from the command line like this: mozregression --good [build_or_date] --pref network.trr.mode:2 --pref network.trr.uri:"https://uri"
|
||
Comment 8•5 years ago
|
||
This could be also a dup of bug 1717253. I've provided some links for the test build in that bug. Please give it a try.
You could also try to capture an http log. Thanks!
@valentin, I ran mozregression (what an incredible tool!) as described, and I couldn't reproduce the original problem documented in this bug (20-50 second 'Blocked' times). I did some testing and @kershaw is correct that this seems to be a duplicate of bug 1717253. I'll capture an http log and report more in the other bug.
That said, the 60-200ms 'Blocked' times on first connect to a host happened in every build I used with mozregression, regardless of whether DoH was enabled or not. The only way I can get 'Blocked' to be 0ms is with my regular Firefox Nightly installation+profile and DoH disabled. Could we leave this bug open so I can continue to provide feedback here? I'll also work on providing feedback for bug 1717253.
|
||
Updated•5 years ago
|
|
|
||
Comment 10•5 years ago
|
||
It seems that 60-200ms delay is another problem than bug 1717253.
Anyway, we need a log to diagnose where the delay comes from, so I'd like to keep the needinfo flag. Please clear it until the log is provided.
Thanks.
|
||
Comment 11•5 years ago
|
||
Was about to try to reproduce this but I can't on the latest Firefox Nightly 91.0a1 (2021-06-21) on Windows 10 nor MacOS, this is a build that does not contain the potential fix from Bug 1717253.
Hey Arash, could you please confirm here as well if the test build from Bug 1717253 fixed this issue as well?
|
Reporter | |
Comment 12•5 years ago
|
||
Just got around to generating more logs. All logs were generated with a new profile.
Firefox 89 (via mozregression): https://ara.sh/private/firefox-bugzilla/log-nytimes-89.txt-main.4086117.zip (42 MB)
Firefox 91 (via mozregression): https://ara.sh/private/firefox-bugzilla/log-nytimes-91.txt-main.4086611.zip (25 MB)
Build from bug 1717253: https://ara.sh/private/firefox-bugzilla/log-nytimes-specialbuild.txt-main.4087394.zip (12 MB)
Every build exhibited the non-zero 'Blocked' time when I generated the log. I'm not sure if this covers all the logs that are needed, so I'll let someone else clear needinfo. Let me know if you need anything else. :)
|
|
||
Comment 14•5 years ago
|
||
I just checked the logs and I can't find anything wrong.
I also checked how Blocked time is calculated. Seeing the code here, Blocked time could be the time between a transaction is created and a DNS lookup started. It could be also the time from the creation of a transaction to first byte sent. A lot of things could happen during this time, so I think 60-200ms is a reasonable delay. I can also see around 80ms Blocked time locally.
I think we can close this bug, since the long delay was fixed in bug 1717253.
Description
•