AdGuard Home v0.106.1 high CPU usage and slow DNS response #3064

N1ghtshad0w · 2021-05-03T22:31:00Z

Issue Details

Version of AdGuard Home server:
    AdGuard Home, version v0.106.1
How did you install AdGuard Home:
    Docker Image
How did you setup DNS configuration:
    System
If it's a router or IoT, please write device model:
    Raspberry Pi 3 Model B+
CPU architecture:
    arm
Operating system and version:
    Raspberry Pi OS Kernel version: 5.10.17

Expected Behavior
AGH should run with minimal CPU usage.

Actual Behavior
AGH runs with high CPU usage dragging the whole system down resulting in a slow DNS response.

Additional Information
AGH was running fine using v0.105.2.
Upgraded to v0.106.1 over the previous version without changing any settings.
Slow DNS responses noticed immediately.
Running DNS benchmark revealed that AGH was running slower than external DNS.
Further investigation revealed that AGH is using high CPU %.
Clean installed v0.106.1 and reconfigured from scratch and still problem exists (high CPU usage and slow DNS response).
Rolling back to v0.105.2 fixes the problem.

The text was updated successfully, but these errors were encountered:

ameshkov · 2021-05-07T07:47:55Z

We don't see anything like that on our side.

Probably, we'll need to see the pprof dumps from your RPi.

Here's how you can get them:

Stop AGH
Set debug_pprof to true in AdGuardHome.yaml
Start AGH
It'll start listening on localhost:6060

Now if you open http://localhost:6060/debug/pprof/profile?seconds=30, you'll download the CPU profile dump.
I'd like to see two of them - one for v0.105.2, the other one for v0.106.x.

Also, if you have go and graphwiz installed anywhere, you can take a look yourself: go tool pprof -http localhost:3434 path_to_dump will open a nice UI interface for exploring the dump.

N1ghtshad0w · 2021-05-07T09:33:25Z

We don't see anything like that on our side.

Probably, we'll need to see the pprof dumps from your RPi.

Here's how you can get them:
1. Stop AGH

2. Set `debug_pprof` to `true` in AdGuardHome.yaml

3. Start AGH

4. It'll start listening on `localhost:6060`
Now if you open http://localhost:6060/debug/pprof/profile?seconds=30, you'll download the CPU profile dump.
I'd like to see two of them - one for v0.105.2, the other one for v0.106.x.

Also, if you have go and graphwiz installed anywhere, you can take a look yourself: go tool pprof -http localhost:3434 path_to_dump will open a nice UI interface for exploring the dump.

Followed your steps to download the dump but it couldn't connect to http://adguardhome container ip:6060/debug/pprof/profile?seconds=30 most likely cause I am using macvlan schema.

I took 2 screenshots for htop one with v0.105.2 and one with v0.106.2
With v0.106.2 I see steady heavy CPU usage involving AdGuardHome.yaml
With v0.105.2 I don't see such usage.

v0.105.2

v0.106.2

DeuceCode · 2021-05-07T10:24:41Z

Can confirm was also experiencing this issue on v0.106.1 and v0.106.2 on a Raspberry Pi 4 4GB. Rolled back to v0.105.2 and this issue was no longer present.

I first noticed this issue when checking my Adguard Home Dashboard and noticed the average processing time for queries had jumped up from 20-30ms to several 100s of milliseconds. A quick look through the query logs showed a lot of Reverse DNS lookups taking on the order of 700-900ms to complete. My top queried domain had quickly become 1.0.28.172.in-addr.arpa the address of the adguard container with almost 5000 queries in a 24 hour period. Having reverted about 12 hours ago, queries to that address have already halved,

I've also followded your steps to download the dumps, but was also unable to connect. I'm not using macvlan so I'm sure its not that. I'll keep trying a few other configs and update if I get it working.

ameshkov · 2021-05-07T10:58:24Z

Followed your steps to download the dump but it couldn't connect to http://adguardhome container ip:6060/debug/pprof/profile?seconds=30 most likely cause I am using macvlan schema.

Hmm, I don't think this port is exposed from the container.

You need to run the container with --expose 6060/tcp and add port mapping.

ameshkov · 2021-05-07T10:59:24Z

@DeuceCode @N1ghtshad0w could you please record verbose-level log? Maybe we can figure something from it.

Configure AdGuard Home to write verbose-level log.
Reproduce the issue.
Post the log file here.

N1ghtshad0w · 2021-05-07T12:06:46Z

Followed your steps to download the dump but it couldn't connect to http://adguardhome container ip:6060/debug/pprof/profile?seconds=30 most likely cause I am using macvlan schema.

Hmm, I don't think this port is exposed from the container.

You need to run the container with --expose 6060/tcp and add port mapping.

You are right port 6060 is not exposed from the container.
Only these ports are

EXPOSE map[3000/tcp:{} 3001/tcp:{} 443/tcp:{} 443/udp:{} 53/tcp:{} 53/udp:{} 5443/tcp:{} 5443/udp:{} 67/udp:{} 68/udp:{} 784/udp:{} 80/tcp:{} 853/tcp:{}]

macvlan is an overlay network that assigns an IP address to your container, all declared expose ports are accessible on the assigned IP and nothing needs to be forwarded to the host.

Port 6060 need to be added to the dockerfile EXPOSE command, adding it to the docker run command doesn't do anything.

ameshkov · 2021-05-07T12:13:06Z

Well, the difference is rather huge, hopefully, we'll be able to figure it out from the verbose log.

CaesarRulezzz · 2021-05-07T18:08:27Z

I have this issue on v0.106.2 (and v0.106.1). As a temporary measure I have disabled almost all filtering lists. This has helped to reduce latency from 18k ms to 100 ms.

ameshkov · 2021-05-07T18:13:36Z

@CaesarRulezzz what's your config? Is it docker as well?

Could you please reproduce the issue and record the verbose-level logs #3064 (comment) ?

@ all - if you want to share logs privately, please send them to [email protected] and mention this issue.

CaesarRulezzz · 2021-05-07T18:24:28Z

@CaesarRulezzz what's your config? Is it docker as well?

Could you please reproduce the issue and record the verbose-level logs #3064 (comment) ?

@ all - if you want to share logs privately, please send them to [email protected] and mention this issue.

Yes, I use it in a docker container.

CaesarRulezzz · 2021-05-08T06:01:21Z

@CaesarRulezzz what's your config? Is it docker as well?

Could you please reproduce the issue and record the verbose-level logs #3064 (comment) ?

@ all - if you want to share logs privately, please send them to [email protected] and mention this issue.

I've sent logs to [email protected]

ameshkov · 2021-05-08T06:04:25Z

Received, thank you!

EugeneOne1 · 2021-05-11T17:57:20Z

Hello again, @N1ghtshad0w, @DeuceCode and @CaesarRulezzz! We've got some assumptions about the issue. Could you please find the max_goroutines setting in the dns section of AdGuardHome.yaml configuration file, set it to 0 and look if it fixes the issue?

N1ghtshad0w · 2021-05-12T01:38:26Z

Hello again, @N1ghtshad0w, @DeuceCode and @CaesarRulezzz! We've got some assumptions about the issue. Could you please find the max_goroutines setting in the dns section of AdGuardHome.yaml configuration file, set it to 0 and look if it fixes the issue?

Didn't work for me.
Changed max_goroutines setting from the default 300 to 0
In 5 min uptime 2000 rdns queries were made ranging from 500+ms to 900+ms for each query
after 10 min uptime rdns queries reached 4000+
failing to successfully resolve connected clients names

Back to v0.105.2 again for now.

ameshkov · 2021-05-12T08:08:20Z

This just means that your local DNS server is rather slow to respond to PTR queries, it does not mean that there's any performance issue with AdGuard Home.

However, I don't understand where this high load comes from.

@N1ghtshad0w could you please collect verbose logs for us? I doubt we can figure out what's causing this without your logs.

N1ghtshad0w · 2021-05-12T10:07:09Z

This just means that your local DNS server is rather slow to respond to PTR queries, it does not mean that there's any performance issue with AdGuard Home.

I don't think so, going back to v0.105.2 I don't have that issue anymore.
After 8 hours uptime using v0.105.2 rdns have a total of 103 queries, not 4000+ in 10 min like with v0.106.2

@N1ghtshad0w could you please collect verbose logs for us? I doubt we can figure out what's causing this without your logs.

The problem is that I can't keep v0.106.2 running cause it cripples all the other services and eventually drag the whole server down, that's why I keep going back to v0.105.2 to keep the server running.

ameshkov · 2021-05-12T10:09:14Z

The problem is that I can't keep v0.106.2 running cause it cripples all the other services and eventually drag the whole server down, that's why I keep going back to v0.105.2 to keep the server running.

Well, we only need logs for a short period of time, 5 minutes would be enough.

N1ghtshad0w · 2021-05-12T12:07:00Z

The problem is that I can't keep v0.106.2 running cause it cripples all the other services and eventually drag the whole server down, that's why I keep going back to v0.105.2 to keep the server running.

Well, we only need logs for a short period of time, 5 minutes would be enough.

N1ghtshad0w · 2021-05-12T12:12:11Z

@N1ghtshad0w could you please collect verbose logs for us? I doubt we can figure out what's causing this without your logs.

I ran it for like 20min with verbose logging on and it generated insane amount of logs around 600+ MBs in log files

I checked some of the files it goes on and on like this

2021/05/12 13:45:57 1#417897 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56307->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417921 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:46529->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417898 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55881->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417916 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39232->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417913 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:41442->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417872 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59952->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417917 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42424->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417899 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47150->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417940 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:36466->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417938 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44924->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417941 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49398->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417943 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56729->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417920 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44480->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417919 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:54557->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417954 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44799->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417942 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43245->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417937 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51523->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417939 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51021->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417947 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:37523->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417888 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:60779->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417922 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44087->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417953 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:45567->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417956 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59557->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417955 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:50800->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417958 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:58882->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417923 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:57305->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417901 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55572->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417918 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:57280->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417924 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56939->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417927 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55101->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417946 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42615->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417929 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:50029->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417925 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44749->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417945 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:53805->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417926 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51800->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417900 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47607->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417930 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:35195->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417960 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:58451->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417931 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:54693->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417948 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:37041->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417903 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:48040->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417957 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:37989->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417959 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:35803->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417951 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:37379->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417944 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39900->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417904 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:60813->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417950 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44324->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417962 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43157->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417961 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33298->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417949 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:54687->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417902 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56284->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417969 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51182->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417970 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55723->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417952 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:57562->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417972 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:60878->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417928 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44990->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417932 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:36446->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417987 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47296->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417985 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47205->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417986 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43414->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417971 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:52147->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417988 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42004->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417973 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42482->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417990 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40133->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417976 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51210->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417991 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:54577->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417979 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:45660->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417978 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43480->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417980 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:38340->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417977 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:35487->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417981 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:53750->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417993 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:38502->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417989 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49742->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417974 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56154->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417992 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59460->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417935 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49826->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417982 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59697->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417995 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:50842->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417975 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47659->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417933 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:34097->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417994 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:57223->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417996 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56033->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417934 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39425->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418004 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39515->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417983 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39829->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417984 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:58878->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418003 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:35147->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418018 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49609->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417963 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55955->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418019 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:50711->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418017 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43159->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417964 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:37257->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418005 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47977->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417965 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56007->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418021 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42452->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418022 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44904->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418002 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:46903->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418020 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55350->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417936 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40662->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418001 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33016->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418023 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:60844->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417966 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:54048->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418006 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56074->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417998 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47575->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418025 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:32774->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418007 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:58316->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417997 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:58537->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418028 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:57279->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418008 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:39982->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418026 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43494->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417999 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42963->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418027 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40026->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418009 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:45498->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418024 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33485->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418000 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:41556->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418033 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:53091->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417967 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59421->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417968 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:34373->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418029 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:55200->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418049 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33773->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418035 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:41802->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418034 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40388->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418010 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:38904->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418050 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:32991->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418036 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:53969->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418037 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:51263->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418011 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47127->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418012 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40687->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418013 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:53361->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418051 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:56788->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418052 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:43865->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418014 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49363->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418015 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:47637->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418030 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:60791->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418031 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33109->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418016 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:35212->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418032 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:33242->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418065 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:49890->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418081 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:44343->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418082 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:32867->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418084 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:42278->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418083 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:59430->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#418053 [debug] 127.0.0.11:53: response: read udp 127.0.0.1:40579->127.0.0.11:53: i/o timeout
2021/05/12 13:45:57 1#417914 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).Resolve(): RTT: 1310 ms
2021/05/12 13:45:57 1#417884 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).Resolve(): RTT: 1279 ms

ameshkov · 2021-05-12T13:07:51Z

What's hosted on 127.0.0.11:53?

ainar-g · 2021-05-12T14:55:52Z

@N1ghtshad0w, can you please try to enter the address of your network's router into the “DNS settings” → “Private DNS servers”? Or uncheck the “Enable reverse resolving of clients' IP addresses” check mark?

N1ghtshad0w · 2021-05-12T16:01:49Z

What's hosted on 127.0.0.11:53?

@ameshkov, 127.0.0.11 is the internal docker DNS address, which normally forwards to the host’s DNS.

N1ghtshad0w · 2021-05-12T16:47:06Z

@N1ghtshad0w, can you please try to enter the address of your network's router into the “DNS settings” → “Private DNS servers”? Or uncheck the “Enable reverse resolving of clients' IP addresses” check mark?

@ainar-g, that did it I think. So far so good.
I didn't notice the new “DNS settings” → “Private DNS servers” upgrading from v0.105.2 and since I had my “Private DNS servers” declared in the "Upstream DNS servers" → "[/x.x.in-addr.arpa/]x.x.x.x" everything should have been okay.
Thanks for your help.

CaesarRulezzz · 2021-05-12T19:00:00Z

Hello again, @N1ghtshad0w, @DeuceCode and @CaesarRulezzz! We've got some assumptions about the issue. Could you please find the max_goroutines setting in the dns section of AdGuardHome.yaml configuration file, set it to 0 and look if it fixes the issue?

It looks like the fix is working for me...

N1ghtshad0w · 2021-05-12T20:27:25Z

Hello again, @N1ghtshad0w, @DeuceCode and @CaesarRulezzz! We've got some assumptions about the issue. Could you please find the max_goroutines setting in the dns section of AdGuardHome.yaml configuration file, set it to 0 and look if it fixes the issue?

It looks like the fix is working for me...

Issue is fixed for me without changing anything in the configuration file.

@CaesarRulezzz, did you enter the address of your network's router into the “DNS settings” → “Private DNS servers”?

Updates #3064. Squashed commit of the following: commit 2cfeb83 Author: Ainar Garipov <[email protected]> Date: Thu May 13 14:02:08 2021 +0300 all: imp code, expose pprof port commit a22656a Author: Ainar Garipov <[email protected]> Date: Thu May 13 13:34:05 2021 +0300 all: imp code, dockerfile commit 35e2145 Author: Ainar Garipov <[email protected]> Date: Thu May 13 12:34:09 2021 +0300 dnsforward: exclude docker dns

ainar-g · 2021-05-13T11:54:01Z

@N1ghtshad0w, @CaesarRulezzz, @DeuceCode, we've pushed a possible fix to the edge channel in revision 1b789b5. Could you please check if the solution works for you?

N1ghtshad0w · 2021-05-13T16:42:53Z

@N1ghtshad0w, @CaesarRulezzz, @DeuceCode, we've pushed a possible fix to the edge channel in revision 1b789b5. Could you please check if the solution works for you?

@ainar-g, using edge Version: v0.107.0-a.23+c890f5c1. Everything seems as expected so far.

CaesarRulezzz · 2021-05-13T18:47:56Z

@N1ghtshad0w, @CaesarRulezzz, @DeuceCode, we've pushed a possible fix to the edge channel in revision 1b789b5. Could you please check if the solution works for you?

I'm using Edge version v0.107.0-a.23+c890f5c1 (docker container). So far so good

DeuceCode · 2021-05-16T21:43:54Z

Apologies for not being able to get back to you.
I've also updated to adguard/adguardhome:edge v0.107.0-a.23+c890f5c1 and so far so good for me too.

ainar-g · 2021-05-17T11:05:21Z

It seems like the Docker fix worked for most people. We're going to release it with v0.106.3 in the nearest days.

Updates #3064. Squashed commit of the following: commit 2cfeb83 Author: Ainar Garipov <[email protected]> Date: Thu May 13 14:02:08 2021 +0300 all: imp code, expose pprof port commit a22656a Author: Ainar Garipov <[email protected]> Date: Thu May 13 13:34:05 2021 +0300 all: imp code, dockerfile commit 35e2145 Author: Ainar Garipov <[email protected]> Date: Thu May 13 12:34:09 2021 +0300 dnsforward: exclude docker dns

N1ghtshad0w · 2021-05-20T07:06:04Z

I upgraded to v0.106.3 the initial issue is solved, but still why does it send PTR requests to all my clients though my router is listed under “Private DNS servers” and "Upstream DNS servers" → "[/x.x.in-addr.arpa/]x.x.x.x"?

below is an image of the top queried domains over a period of 29 hours:

My router is setup to forward DNS requests to AGH and AGH is setup to use my router for PTR queries.
So shouldn't the normal behavior for AGH is to send PTR queries to the router only and once resolved it should be cached locally for further use without querying the router about it again to minimize unnecessary traffic?

GyokuroT · 2021-05-24T08:37:06Z

The bug isn't fixed for me. My log is still spammed with thousands of PTR requests. I don't use docker by the way.

ameshkov · 2021-05-24T08:42:57Z

So shouldn't the normal behavior for AGH is to send PTR queries to the router only and once resolved it should be cached locally for further use without querying the router about it again to minimize unnecessary traffic?

It is cached, but the TTL is just 10 minutes. We might need to increase it.

GyokuroT · 2021-05-24T08:47:04Z

So shouldn't the normal behavior for AGH is to send PTR queries to the router only and once resolved it should be cached locally for further use without querying the router about it again to minimize unnecessary traffic?

It is cached, but the TTL is just 10 minutes. We might need to increase it.

I disabled "Enable of reverse resolving of clients IP addresses". It's still spamming those requests. I use Adguard Home since the first release and never had this issue before. I started to experience this issue 1 or 2 releases ago on both of my Raspberry Pi's.

ameshkov · 2021-05-24T08:48:38Z

@GyokuroT mind collecting log for us? See here.

GyokuroT · 2021-05-24T09:49:08Z

log.zip

GyokuroT · 2021-05-24T11:22:37Z

@GyokuroT mind collecting log for us? See here.

is my provided log enough info or do you need more?

N1ghtshad0w · 2021-05-24T16:25:25Z

So shouldn't the normal behavior for AGH is to send PTR queries to the router only and once resolved it should be cached locally for further use without querying the router about it again to minimize unnecessary traffic?

It is cached, but the TTL is just 10 minutes. We might need to increase it.

@ameshkov, I have been setting "Override minimum TTL" → "3600" and "Override maximum TTL" → "68400" since I started using AGH. Unless there is an internal setting for rDNS TTL that I am not aware of.

Duetro · 2021-09-21T10:16:56Z

htshad0w, can you please try to enter the address of your network's router into the “DNS settings” → “Private DNS servers”? Or uncheck the “Enable reverse resolving of clients' IP addresses” check mark?

Worked for me, thanks! (Using v0.106.3)

Updates AdguardTeam#3064. Squashed commit of the following: commit 2cfeb83 Author: Ainar Garipov <[email protected]> Date: Thu May 13 14:02:08 2021 +0300 all: imp code, expose pprof port commit a22656a Author: Ainar Garipov <[email protected]> Date: Thu May 13 13:34:05 2021 +0300 all: imp code, dockerfile commit 35e2145 Author: Ainar Garipov <[email protected]> Date: Thu May 13 12:34:09 2021 +0300 dnsforward: exclude docker dns

ainar-g added needs investigation Needs to be reproduced reliably. performance Issues about performance and resource consumption labels May 5, 2021

ameshkov added this to the v0.106.3 milestone May 7, 2021

ainar-g self-assigned this May 11, 2021

N1ghtshad0w closed this as completed May 12, 2021

N1ghtshad0w reopened this May 12, 2021

ainar-g added bug docker Docker-related issues and removed needs investigation Needs to be reproduced reliably. labels May 12, 2021

ainar-g added the P2: High label May 12, 2021

ainar-g closed this as completed May 17, 2021

N1ghtshad0w mentioned this issue May 20, 2021

AdGuard Home sending out excessive PTR requests in its CIDR range #3157

Closed

AdGuard Home v0.106.1 high CPU usage and slow DNS response #3064

AdGuard Home v0.106.1 high CPU usage and slow DNS response #3064

Comments

N1ghtshad0w commented May 3, 2021

ameshkov commented May 7, 2021 • edited Loading

N1ghtshad0w commented May 7, 2021 • edited Loading

DeuceCode commented May 7, 2021

ameshkov commented May 7, 2021

ameshkov commented May 7, 2021

N1ghtshad0w commented May 7, 2021

ameshkov commented May 7, 2021

CaesarRulezzz commented May 7, 2021

ameshkov commented May 7, 2021

CaesarRulezzz commented May 7, 2021

CaesarRulezzz commented May 8, 2021

ameshkov commented May 8, 2021

EugeneOne1 commented May 11, 2021

N1ghtshad0w commented May 12, 2021

ameshkov commented May 12, 2021 • edited Loading

N1ghtshad0w commented May 12, 2021

ameshkov commented May 12, 2021

N1ghtshad0w commented May 12, 2021

N1ghtshad0w commented May 12, 2021 • edited by ameshkov Loading

ameshkov commented May 12, 2021

ainar-g commented May 12, 2021

N1ghtshad0w commented May 12, 2021

N1ghtshad0w commented May 12, 2021

CaesarRulezzz commented May 12, 2021

N1ghtshad0w commented May 12, 2021

ainar-g commented May 13, 2021

N1ghtshad0w commented May 13, 2021

CaesarRulezzz commented May 13, 2021

DeuceCode commented May 16, 2021

ainar-g commented May 17, 2021

N1ghtshad0w commented May 20, 2021

GyokuroT commented May 24, 2021 • edited Loading

ameshkov commented May 24, 2021

GyokuroT commented May 24, 2021

ameshkov commented May 24, 2021

GyokuroT commented May 24, 2021

GyokuroT commented May 24, 2021

N1ghtshad0w commented May 24, 2021

Duetro commented Sep 21, 2021

ameshkov commented May 7, 2021 •

edited

Loading

N1ghtshad0w commented May 7, 2021 •

edited

Loading

ameshkov commented May 12, 2021 •

edited

Loading

N1ghtshad0w commented May 12, 2021 •

edited by ameshkov

Loading

GyokuroT commented May 24, 2021 •

edited

Loading