Some cached records take a long time to resolve #3078

Open
opened 2026-03-04 02:57:14 -05:00 by deekerman · 5 comments
Owner

Originally created by @timkgh on GitHub (Sep 26, 2021).

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?

  • Version of AdGuard Home server:
    • v0.107.0-b.11
Originally created by @timkgh on GitHub (Sep 26, 2021). ### 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? * **Version of AdGuard Home server:** * v0.107.0-b.11
Author
Owner

@timkgh commented on GitHub (Sep 26, 2021):

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 on GitHub (Sep 26, 2021): 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.
Author
Owner

@timkgh commented on GitHub (Sep 26, 2021):

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

@timkgh commented on GitHub (Sep 26, 2021): > 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
Author
Owner

@ameshkov commented on GitHub (Sep 27, 2021):

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

@ameshkov commented on GitHub (Sep 27, 2021): Yeah, safe browsing & parental control are basically another DNS query with an independent cache.
Author
Owner

@timkgh commented on GitHub (Sep 27, 2021):

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 on GitHub (Sep 27, 2021): > 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.
Author
Owner

@timkgh commented on GitHub (Sep 27, 2021):

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

@timkgh commented on GitHub (Sep 27, 2021): > 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`
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/AdGuardHome#3078
No description provided.