AdguardTeam / AdGuardHome

Network-wide ads & trackers blocking DNS server
https://adguard.com/adguard-home.html
GNU General Public License v3.0
25.11k stars 1.8k forks source link

Some cached records take a long time to resolve #3656

Open timkgh opened 3 years ago

timkgh commented 3 years ago

Issue Details

An example of a cached query that takes 42ms. I assume it's cached because it doesn't have an Upstream field.

{"IP":"<redacted>","T":"2021-09-25T22:40:42.958377923-07:00","QH":"play.googleapis.com","QT":"A","QC":"IN","CP":"","Answer":"<redacted>","Result":{},"Elapsed":42544389}

I see multiple of these in the log file, various domains, while most cached queries return in <1ms.

Is this normal? Is there some lock contention? GC? Or is it the optimistic cache that actually ends up going to an upstream but doesn't get logged correctly?

timkgh commented 3 years ago

There is something going on here. Lots of queries in the log for local domain names that get forwarded to a dnsmasq instance running on the same router and that take over 40ms. But the dnsmasq server itself is very fast to respond, under 1ms. Not sure whether these local names get checked for safe browsing and parental control.

timkgh commented 3 years ago

Not sure whether these local names get checked for safe browsing and parental control.

It appears that having safe browsing and parental control enabled adds >40ms of overhead. Related: #2857

ameshkov commented 3 years ago

Yeah, safe browsing & parental control are basically another DNS query with an independent cache.

timkgh commented 3 years ago

Yeah, safe browsing & parental control are basically another DNS query with an independent cache.

Can you please make it clear in the UI settings and document it? My initial impression was that partial hashes were checked locally and only if there's a local match a request was going to be sent to your servers.

timkgh commented 3 years ago

Yeah, safe browsing & parental control are basically another DNS query with an independent cache.

Is it 1 request or 2 if I have both safe browsing and parental control enabled? Empirical evidence shows that if I only have 1 enabled it adds about 20ms, with both enabled it adds about 40ms, so I'm thinking it makes 2 extra requests? ~20ms per request is consistent with I see if I dig google.com @94.140.14.15