Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Some requests in the cache are slow #5248

Open
3 tasks done
Gandulf78 opened this issue Dec 9, 2022 · 5 comments
Open
3 tasks done

Some requests in the cache are slow #5248

Gandulf78 opened this issue Dec 9, 2022 · 5 comments
Labels
needs investigation Needs to be reproduced reliably.

Comments

@Gandulf78
Copy link

Gandulf78 commented Dec 9, 2022

Prerequisites

  • I have checked the Wiki and Discussions and found no answer

  • I have searched other issues and found no duplicates

  • I want to report a bug and not ask a question

Operating system type

Linux, Other (please mention the version in the description)

CPU architecture

ARMv7

Installation

Docker

Setup

On one machine

AdGuard Home version

v0.108.0-b.23

Description

What did you do?

I notice that sometimes DNS lookup in the cache are slow. Usually they take around 1-3ms but frequently they are around 30-40 ms and more rarely 100ms. There’s no way to analyze more in detail the behavior of the cache.

Expected result

DNS lookup in the cache are more constantly around a couple of ms.

Actual result

Screenshots (if applicable)

Additional information

AdguardHome is installed on a NAS via docker.

@ainar-g ainar-g added the needs investigation Needs to be reproduced reliably. label Dec 9, 2022
@ainar-g
Copy link
Contributor

ainar-g commented Dec 9, 2022

There isn't a lot of information here, unfortunately, but we'll take a look at things we can optimize in the cache.

adguard pushed a commit to AdguardTeam/dnsproxy that referenced this issue Dec 9, 2022
Updates AdguardTeam/AdGuardHome#5248.

Squashed commit of the following:

commit 46255f5
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri Dec 9 18:12:48 2022 +0300

    proxy: imp logs

commit 6bc8867
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri Dec 9 17:35:20 2022 +0300

    all: upd go; imp logs; typos

commit b3c8625
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri Dec 9 16:10:36 2022 +0300

    proxy: imp cache locking
@he-pennypacker
Copy link

I can add a bit more detail, I have come across the same issue and a search engine lead me here. Here's an example response, apparently 'served from cache' - I assume this means served from AGH cache? 46 ms is very slow from cache, I would expect 1-3ms from every cached response.

Is there anything else you need to investigate?

My details:

CPU architecture
ARMv7 Processor rev 5 (v7l) -

Installation
running on GL.inet Slate Plus router

Setup
?

AdGuard Home version
Version: v0.107.26

Status: Processed
DNS server: tls://1dot1dot1dot1.cloudflare-dns.com:853 (served from cache)
Elapsed: 46 ms
Response code: NOERROR
Response: A: 74.125.200.92 (ttl=10)

And another sluggish cached response, this time 70 ms

Status: Processed
DNS server: tls://1dot1dot1dot1.cloudflare-dns.com:853 (served from cache)
Elapsed: 70 ms
Response code: NOERROR
Response:
CNAME: nytimes.map.fastly.net. (ttl=10)
A: 151.101.1.164 (ttl=10)
A: 151.101.65.164 (ttl=10)
A: 151.101.129.164 (ttl=10)
A: 151.101.193.164 (ttl=10)

@he-pennypacker
Copy link

Another thought. The helper text under the 'Optimistic caching' checkbox states:

Make AdGuard Home respond from the cache even when the entries are expired and also try to refresh them.

Re: the 70ms response time in my second example above...Is this a) the response time from cache (what I would expect), or b) the response time from upstream when refreshing?

Given the log states 70ms which seems awfully high for a cached response, I suspect the log is showing the response time from upstream when refreshing, which is not the expected behaviour?

@mshish
Copy link

mshish commented Dec 6, 2023

Do you all have "Use AdGuard parental control web service" and/or "Use AdGuard browsing security web service" enabled? Turning both off seemed to solve this for me (which makes sense that the API would take 10+ msec roundtrip). I switched to using CloudFlare's for Families (1.1.1.3) upstream, which gives less control/visibility but maintains performance.

@he-pennypacker
Copy link

I had the AdGuard browsing security service turned on (but not the parental control). I turned this off, cleared my log and stats, and that has indeed significantly improved my average processing time which went from 34ms to 6ms. Many thanks for the tip 😄

This raises an interesting question. What is the "TTL" for a cached AdGuard Security Service response (safe or not safe)? Does AGH cache these answers, or is it checked each and every time?

There are still some lengthy cached responses, e.g.

Status: Processed
DNS server: tls://dns.nextdns.io:853 (served from cache)
Elapsed: 19 ms
Response code: NOERROR
Response:
CNAME: prod1.naturallanguageeditorservice.osi.office.net.akadns.net. (ttl=10)
CNAME: prod-all.naturallanguageeditorservice.osi.office.net.akadns.net. (ttl=10)
A: 52.111.224.24 (ttl=10)
A: 52.111.224.23 (ttl=10)
A: 52.111.224.21 (ttl=10)
A: 52.111.224.22 (ttl=10)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs investigation Needs to be reproduced reliably.
Projects
None yet
Development

No branches or pull requests

4 participants