1583298 - Determine if we are indeed spending up to 3x as long in DNS resolution as Chrome on some sites

Status: RESOLVED WORKSFORME

(Core :: Performance, task, P1)

Description

[Andrew Creskey [:acreskey]]

While looking at profiles generated as part of Bug 1582820, Bas and I noticed that we may be spending considerably more time in DNS resolution than Chrome.

This is captured in browsertime and so I collected it here.
Note the row for imdb and booking.com in particular and how we may be spending over 3x as long:
Also note that not all early navigation metrics are reported by both browsers, so this data is incomplete.

This may a problem in this profile, as we see numerous requests with 100ms on After DNS request, which should correspond to domain lookup end
https://perfht.ml/2l2AnmD

Comment 1

[Andrew Creskey [:acreskey]]

This profile includes DNS resolver threads:
https://perfht.ml/2l7YRuL

Comment 2

[Andrew Creskey [:acreskey]]

I've spent a bit of time going over the results from my browsertime live runs and also the results from a long-running test that :denispal ran in July.

You can find a plain-text summary of my live site data here (fenix_none is Fenix with tracking protection disabled)
https://paste.rs/LbS

And Denis' results (subset of sites that overlapped with tp6p1)
https://paste.rs/pEb

One area where the datasets agree is that on the last early navigation-metric time point, responseEnd.
They both sow Fenix being significantly faster than Chrome. Median of 411ms for Fenix and 563.5ms for Chrome in my dataset (368.5ms to 481ms in favor of Fenix in Denis' data).

The performance difference varies between sites:

Comment 3

[Andrew Creskey [:acreskey]]

Attachment: ResponseEnd timing by site

Comment 4

[Andrew Creskey [:acreskey]]

Denis' results show generally matching site-to-site performance differences, with a couple of exceptions.

In both datasets, Chrome and Fenix are roughly equal at responseStart time.
However Chrome reports being significantly slower by responseEnd.

Looking at the sum of the early metrics in my run, you can see Chrome's longer serverResponseTime (responseEnd - requestStart in browsertime caused by the longer delivery time:

Comment 5

[Andrew Creskey [:acreskey]]

Attachment: Sum of early metrics for the set of pages

Comment 6

[Andrew Creskey [:acreskey]]

Attachment: Early metrics by site

This is an overall view of our early metrics performance on these pages.
The sites with the long fetchStarts include a redirection.

Comment 7

[Andrew Creskey [:acreskey]]

So, going back to the bug as logged, are we spending more time doing DNS resolution?
Other than perhaps fetchStart, this may be the only metric we can improve on.
My dataset says yes, Denis' says no.
So I think I'll collect results from a third party.

Comment 8

[Andrew Creskey [:acreskey]]

Attachment: Domain lookup time by site

Site by site domain lookup time from my results.

Comment 9

[Andrew Creskey [:acreskey]]

Attachment: motoG5 live site domainLookuptime

As another datapoint, these are the results from :nalexander's live site tests in April 2019.
(These particular ones are from the Moto G5)
https://paste.rs/RlO

Here Fenix is faster for the median result, but slower for the mean (due to slow outliers which you can see in the attached graph).

Again, fenix is faster than Chrome in overall early navigation metrics (up to responseEnd).

Comment 10

[Andrew Creskey [:acreskey]]

My own view is that these browser-reported early navigation metrics should be taken with a grain of salt.

I think more profiling would be valuable to get a better idea of how many requests spend a large amount of time waiting for DNS resolution.

Just collecting some ideas if we want to experiment with this:
• I see that we do DNS prefetching in certain cases -- perhaps this could be expanded on or tuned?

• One of the reasons that Chrome dropped the OS's getaddrinfo() in favor of their own resolver was so they could "failover to different servers based on RTT or other signals". This could be worth trying.
With our own resolver, we could also race DNS requests, also discussed here
https://groups.google.com/forum/#!topic/mozilla.dev.tech.network/D8UmrLZZh5k

• The Resolver thread pool size could be experimented with. We saw a lot of requests that were blocked on what looked like DNS. Maybe hi-core count CPUs would do better with more threads.

• With DNS-over-https coming online soon, maybe that's what I should be looking at?

Comment 11

[Andrew Creskey [:acreskey]]

We were looking at telemetry for DNS_LOOKUP_TIME and, at least on desktop, with a median of 30ms this doesn't look like a problem to me.

https://telemetry.mozilla.org/new-pipeline/dist.html#!cumulative=0&end_date=2019-09-30&include_spill=0&keys=__none__!__none__!__none__&max_channel_version=nightly%252F71&measure=DNS_LOOKUP_TIME&min_channel_version=null&processType=*&product=Firefox&sanitize=1&sort_by_value=0&sort_keys=submissions&start_date=2019-09-02&table=0&trim=1&use_submission_date=0

I'm trying to see if I can get this Android.

Comment 12

[Andrew Creskey [:acreskey]]

I ran some tests where I increased the size of the resolver thread pool, hoping to coax some performance out of devices like the Octa-Core Pixel 3.
But it looks like increasing the pool sizes on Pixel 3 doesn't improve any meaningful metrics:
https://docs.google.com/spreadsheets/d/1bhdXkziUFBE5f4PbOiKN561TVAGAG6A8zrT--Uxq5Bw/edit#gid=1015141094
Mean backend time may be improved, but nothing user-facing.

Comment 13

[Stephen Donner [:stephend] Not actively reading bugmail]

Mass-removing myself from cc; search for 12b9dfe4-ece3-40dc-8d23-60e179f64ac1 or any reasonable part thereof, to mass-delete these notifications (and sorry!)

Comment 14

[Andrew Creskey [:acreskey]]

From this comment, it looks like we are misreporting our dns resolution times (they end up exaggerated)
https://bugzilla.mozilla.org/show_bug.cgi?id=1596935#c21

Comment 15

[Julien Wajsberg [:julienw]]

hey Andrew, is there anything more to do here? Dragana mentioned bug 1626958 to fix the misreporting, but that bug doesn't seem explicit about this...

Thanks!

Comment 16

[Andrew Creskey [:acreskey]]

To me this still seems important, so I logged Bug 1761528 to see if the reporting is indeed incorrect and to see if we can fix it.

Comment 17

[Donal Meehan [:dmeehan]]

99 is about to ship, not tracking for this release.

Comment 18

[Andrew Creskey [:acreskey]]

One thing to note, these measurements were all made with OS-based dns lookup, not DoH.

Comment 19

[Andrew Creskey [:acreskey]]

I'm going to see if this Chrome to Firefox discrepancy still reproduces.

Comment 20

[Andrew Creskey [:acreskey]]

Using the live site capabilities of our performance infrastructure, I'm not seeing a significant difference in DNS resolution times between Chrome and Firefox (Desktop and Pixel 2).
https://docs.google.com/spreadsheets/d/1iUuMtNZAIWMOO9SmBS_70RmIKnLK0DA_zj9MSOnD-eE/edit#gid=490683402

But note that the reported DNS times (domainLookupEnd - domainLookupStart) in the desktop tests are just a few milliseconds on both Firefox and Chrome.

So I'll do a small test locally as a sanity check.

Comment 21

[Andrew Creskey [:acreskey]]

Locally, on Desktop I'm seeing that we start the DNS lookup later than Chrome, but ultimately we complete the request in a similar amount of time.
https://docs.google.com/spreadsheets/d/1iUuMtNZAIWMOO9SmBS_70RmIKnLK0DA_zj9MSOnD-eE/edit#gid=490683402&range=65:75x

This bug was opened 3 years ago, but at the moment, I don't see any evidence that supports keeping it open.

Comment 22

[Andrew Creskey [:acreskey]]

In Bug 1761528 we verified that DNS resolution times are now accurate.
With the accuracy verified and because I'm no longer reproducing a performance difference between Chrome and Firefox, I'm going to close this bug.

Comment 23

[Michael Comella (:mcomella) [NI reported issues only: ex-Mozilla]]

With this being closed, do you know if bug 1702025 or bug 1664492, which are other fenix DNS issues, can be closed?

Comment 24

[Andrew Creskey [:acreskey]]

Michael, I think the first thing would be to verify the current state of DNS over HTTPS on Fenix.

To my understanding, both bug 1702025 and bug 1664492 occurred when we used the legacy native DNS resolution.

Since I think it's fair to say that we won't be investing in improving that workflow, if these bugs can't be reproduced with DoH, then I think it's fair to at least lower their priority.