Open Bug 1626958 Opened 3 years ago Updated 8 months ago

DNS resolution takes a magnitude longer (over 100 ms) in Firefox than native OS DNS resolution

Categories

(Core :: Networking: DNS, defect, P3)

74 Branch
defect

Tracking

()

UNCONFIRMED

People

(Reporter: iphone4004, Unassigned)

References

Details

(Whiteboard: [necko-triaged])

Attachments

(1 file)

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Firefox/68.0

Steps to reproduce:

Summary: Firefox takes an exceedingly long time to perform DNS resolution. For example when I visit yahoo.com resolving s.yimg.com takes 133 ms. The expected DNS resolution time is about 20 ms, similar to native OS DNS resolution.

Steps to reproduce: Open Firefox. Open the Network tab in Web Developer tools.
Visit any web site that is not previously cached. Observer DNS Resolution times under Timings. Notice that each non-cached entry takes over 100 ms to resolve.

Environment: A freshly installed copy of Firefox without any additions except the Gecko Profiler. Gecko Profiler installed as per instructions here: https://old.reddit.com/r/firefox/comments/fsa57a/dns_resolution_takes_over_100_ms_in_firefox_how/fm0ns79/

Firefox was installed as follows:
$ sudo apt-get install firefox
firefox is already the newest version (74.0~mozillabinaries-1mx19+1).

Nothing else was installed, apart from the above mentioned Gecko Profiler.

I run dnsmasq locally as a DNS cache and forwarder. The upstream DNS server is 1.1.1.1.

Typical DNS resolution latencies:
$ dig | grep "Query time"
;; Query time: 18 msec

Likewise when directly querying 1.1.1.1:
$ dig @1.1.1.1| grep "Query time"
;; Query time: 18 msec

I do not run DNS over HTTP. I am in Europe, where DoH is not automatically enabled. I can see Firefox performing DNS queries by viewing the logs on localhost:

$ sudo less /var/log/dnsmasq.log

Apr 2 17:10:25 dnsmasq[579536]: query[A] s.yimg.com from 127.0.0.1
Apr 2 17:10:25 dnsmasq[579536]: forwarded s.yimg.com to 1.1.1.1
Apr 2 17:10:25 dnsmasq[579536]: reply s.yimg.com is <CNAME>
Apr 2 17:10:25 dnsmasq[579536]: reply edge.gycpi.b.yahoodns.net is 188.125.94.206
Apr 2 17:10:25 dnsmasq[579536]: reply edge.gycpi.b.yahoodns.net is 188.125.94.204

I've already tried toggling DNS prefetch on and off and disabling and enabling IPv6 DNS. These settings have no effect on DNS resolution times in Firefox.

I have also tried using 1.1.1.1 as a DNS server directly in /etc/resolv.conf and bypassing dnsmasq. It makes no difference to Firefox DNS resolution times.

I have tried removing and reinstalling Firefox. I have tried different DNS servers. I have rebooted the laptop and all other equipment. No difference.

The laptop is directly connected to the Internet. There is no proxy or middleboxen. I have requested new DHCP leases. I have chosen No proxy in Firefox settings. No difference whatsoever.

System information:
Application Basics
Name Firefox
Version 74.0
Build ID 20200309095159
Update Directory
/opt/firefox
Update History
Update Channel release
User Agent Mozilla/5.0 (X11; Linux x86_64; rv:74.0) Gecko/20100101 Firefox/74.0
OS Linux 4.9.200-antix.1-amd64-smp
Application Binary /opt/firefox/firefox-bin

No crash reports

Actual results:

Whenever a web site that is not cached is visited DNS resolution takes a magnitude longer (over 100 ms) in Firefox than native OS DNS resolution.

As can be seen in the below captured Gecko profile, when visiting yahoo.com DNS resolution in Firefox takes 160 ms. This is far too long, when it should take about 20 ms.

https://perfht.ml/2UA5K72

For reference, these are the DNS names that are resolved when visiting yahoo.com:
yahoo.com
www.yahoo.com
consent.yahoo.com
s.yimg.com
csp.yahoo.com

These are the results when resolving the above DNS names locally on the OS level after having cleared caches:

$ dig$ dig yahoo.com | grep "Query time"
;; Query time: 18 msec

www.yahoo.com | grep "Query time"
;; Query time: 18 msec

$ dig s.yimg.com | grep "Query time"
;; Query time: 18 msec

$ dig csp.yahoo.com | grep "Query time"
;; Query time: 18 msec

$ dig consent.yahoo.com | grep "Query time"
;; Query time: 18 msec

Likewise, here are the query times when querying 1.1.1.1 directly:

$ dig$ dig yahoo.com @1.1.1.1 | grep "Query time"
;; Query time: 18 msec

www.yahoo.com @1.1.1.1 | grep "Query time"
;; Query time: 18 msec

$ dig s.yimg.com @1.1.1.1 | grep "Query time"
;; Query time: 18 msec

$ dig csp.yahoo.com @1.1.1.1 | grep "Query time"
;; Query time: 18 msec

$ dig consent.yahoo.com @1.1.1.1| grep "Query time"
;; Query time: 18 msec

I tryly hope there is something I have done wrong that I can change to fix this. However, so far my testing points to an issue with Firefox. I pray it can be fixed somehow.

Expected results:

DNS resolution in Firefox should take approximately as long as native OS DNS resolution (about 20 ms).

Bugbug thinks this bug should belong to this component, but please revert this change in case of error.

Component: Untriaged → Networking: DNS
Product: Firefox → Core

Firefox without Doh uses Os resolver. It has a couple of threads that are only used for DNS resolution.

Is it also slow without profiler? Profiler adds logging that will slow things down.

Can you make a http log:
https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging

Flags: needinfo?(iphone4004)

As reqested, here is a log file from downloading yahoo.com and loggin the results using about:networking. Average DNS resolution times in Firefox were shown to be 100 ms, when the OS DNS resolution times average under 20 ms.

Flags: needinfo?(iphone4004)

Yes, DNS resolution in Firefox is slow also without the profiler. I started debugging this with the Web Developer tools only. I only installed the profiler after being told so at r/Firefox ( https://old.reddit.com/r/firefox/comments/fsa57a/dns_resolution_takes_over_100_ms_in_firefox_how/ ).

Attached is the log from me reloading yahoo.com. Average DNS resolution was 100 ms according to the Web Developer tools.

By looking at the profile,
during the DNS lookup, we have main threading jank for the first 83ms, and later comes the Graphic's RefreshDriverTick for another ~50ms.

2020-04-03 17:11:57.301305 UTC - [Parent 597655: Socket Thread]: D/nsHostResolver   Host [consent.yahoo.com] is being resolved. Appending callback [0x7f4482bbeb30].
2020-04-03 17:11:57.400646 UTC - [Parent 597655: DNS Resolver #456]: E/nsHostResolver DNS lookup thread - lookup completed for host [consent.yahoo.com]: success.

Looks like the host is already resolved, the waiting time is pretty much to wait for a event dispatched.

Priority: -- → P3
Whiteboard: [necko-triaged]

Because this bug's Severity has not been changed from the default since it was filed, and it's Priority is P3 (Backlog,) indicating it has been triaged, the bug's Severity is being updated to S3 (normal.)

Severity: normal → S3
See Also: → 1761528
Depends on: 1761528
See Also: 17615281583298
You need to log in before you can comment on or make changes to this bug.