Closed AnthonyBe closed 4 years ago
Do you still have this issue if you enable any of these modules?
Looks like a connectivity issue, what happens if you try opening https://dns.adguard.com/info.txt
?
I get
dns-vultr-sn-1
But it took at least 5-6 sec to respond.
So it's Sidney, but something is very wrong with connectivity
Yep! 😢
Is it close to you geographically?
It'd help if you show the output of traceroute 176.103.130.130
So, yes, I am in Sydney.
The tracert isn't pretty reading..
C:\WINDOWS\system32>tracert 176.103.130.130
Tracing route to 176-103-130-130.dns.adguard.com [176.103.130.130]
over a maximum of 30 hops:
1 <1 ms <1 ms <1 ms ARCHER_VR1600V [192.168.0.1]
2 13 ms 12 ms 14 ms 10.20.23.229
3 110 ms 111 ms 111 ms syd-apt-ros-wgw1-be-10.tpgi.com.au [203.29.134.7]
4 111 ms 108 ms 107 ms be300.sglebbrdr11.aapt.net.au [203.219.107.198]
5 85 ms 92 ms 91 ms 202.10.14.202
6 83 ms 85 ms 84 ms 202.10.14.207
7 276 ms 275 ms 274 ms aapt.s1.nsw.au.coloau.net.au [210.8.163.98]
8 270 ms 278 ms 224 ms 45.112.247.83
9 * * * Request timed out.
10 * * * Request timed out.
11 * * * Request timed out.
12 9 ms 9 ms 11 ms 176-103-130-130.dns.adguard.com [176.103.130.130]
Trace complete.
as a comparison
C:\WINDOWS\system32>tracert 1.1.1.1
Tracing route to one.one.one.one [1.1.1.1]
over a maximum of 30 hops:
1 <1 ms <1 ms <1 ms ARCHER_VR1600V [192.168.0.1]
2 15 ms 15 ms 10 ms 10.20.23.229
3 16 ms 16 ms 13 ms syd-apt-ros-wgw1-be-20.tpgi.com.au [203.29.134.71]
4 15 ms 13 ms 15 ms be300.sglebbrdr11.aapt.net.au [203.219.107.198]
5 18 ms 13 ms 14 ms Bundle-Ether100.ken-edge903.sydney.telstra.net [139.130.93.21]
6 15 ms 21 ms 17 ms clo3040883.lnk.telstra.net [203.54.132.242]
7 14 ms 16 ms 13 ms one.one.one.one [1.1.1.1]
Trace complete.
I've disabled everything in AGH that relates to using any of the AG web services and am only using filters and hosts files. Over the last 24 hours, my average processing time has now gone up to 1170ms.
Hm, the route is not ideal, but still, I don't understand where the 5sec delay comes from.
Could you please use WinMTR and collect a report using it? https://sourceforge.net/projects/winmtr/files/Latest/
I've disabled everything in AGH that relates to using any of the AG web services and am only using filters and hosts files. Over the last 24 hours, my average processing time has now gone up to 1170ms.
Well, this just might be some problematic domain that takes long time to resolve.
|------------------------------------------------------------------------------------------|
| WinMTR statistics |
| Host - % | Sent | Recv | Best | Avrg | Wrst | Last |
|------------------------------------------------|------|------|------|------|------|------|
| ARCHER_VR1600V - 0 | 101 | 101 | 0 | 0 | 1 | 0 |
| 10.20.22.119 - 0 | 101 | 101 | 10 | 18 | 44 | 17 |
| syd-apt-ros-wgw1-be-20.tpgi.com.au - 0 | 101 | 101 | 11 | 20 | 46 | 19 |
| be300.sglebbrdr11.aapt.net.au - 0 | 101 | 101 | 12 | 20 | 46 | 18 |
| 202.10.14.202 - 0 | 101 | 101 | 12 | 21 | 47 | 18 |
| 202.10.14.207 - 0 | 101 | 101 | 10 | 21 | 47 | 20 |
| aapt.s1.nsw.au.coloau.net.au - 0 | 101 | 101 | 12 | 21 | 46 | 18 |
| 45.112.247.83 - 2 | 97 | 96 | 10 | 22 | 70 | 20 |
| No response from host - 100 | 21 | 0 | 0 | 0 | 0 | 0 |
| No response from host - 100 | 21 | 0 | 0 | 0 | 0 | 0 |
| No response from host - 100 | 21 | 0 | 0 | 0 | 0 | 0 |
| 176-103-130-130.dns.adguard.com - 0 | 101 | 101 | 11 | 20 | 45 | 19 |
|________________________________________________|______|______|______|______|______|______|
Any value in me running it for longer to capture more or is the above sufficient?
Hmmm, I don't understand what's going on then, I see no packets loss:(
What values does ping dns.adguard.com
show?
Just in case, could you please check if you still have these errors in the log when you enable browsing security?
C:\WINDOWS\system32>ping dns.adguard.com -t
Pinging dns.adguard.com [176.103.130.130] with 32 bytes of data:
Reply from 176.103.130.130: bytes=32 time=13ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=15ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=11ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=12ms TTL=52
Reply from 176.103.130.130: bytes=32 time=8ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=12ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=9ms TTL=52
Reply from 176.103.130.130: bytes=32 time=11ms TTL=52
Reply from 176.103.130.130: bytes=32 time=13ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=13ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Reply from 176.103.130.130: bytes=32 time=46ms TTL=52
Reply from 176.103.130.130: bytes=32 time=10ms TTL=52
Ping statistics for 176.103.130.130:
Packets: Sent = 27, Received = 27, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 8ms, Maximum = 46ms, Average = 11ms
Re-enabled Use AdGuard browsing security web service at 21:10. Subsequent logs:
2020/03/04 21:10:57 [info] SafeBrowsing: failed: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=r6QBAAABAAAAAAAACDM2NjdhMDM4CGUzMDA0MzA1CGMzYTFjOWE2CGUxMGM4NWVhCGZiOWU3YTIyAnNiA2RucwdhZGd1YXJkA2NvbQAAEAAB: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:00 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=-y4BAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:00 [info] SafeBrowsing: failed: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=SyoBAAABAAAAAAAACDM2NjdhMDM4CGUzMDA0MzA1CGMzYTFjOWE2CGUxMGM4NWVhCGZiOWU3YTIyAnNiA2RucwdhZGd1YXJkA2NvbQAAEAAB: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:00 [info] SafeBrowsing: failed: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=tzYBAAABAAAAAAAACDM2NjdhMDM4CGUzMDA0MzA1CGMzYTFjOWE2CGUxMGM4NWVhCGZiOWU3YTIyAnNiA2RucwdhZGd1YXJkA2NvbQAAEAAB: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:04 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=jj4BAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:07 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=ZAsBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:10 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=-ZsBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:10 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 5496 ms
2020/03/04 21:11:10 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 5492 ms
2020/03/04 21:11:10 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 3567 ms
2020/03/04 21:11:10 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 3421 ms
2020/03/04 21:11:13 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=-MYBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:13 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 4419 ms
2020/03/04 21:11:13 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 3380 ms
2020/03/04 21:11:16 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=MOUBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:16 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 4423 ms
2020/03/04 21:11:19 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=W6sBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:19 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 5418 ms
2020/03/04 21:11:22 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=yi0BAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:22 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 3370 ms
2020/03/04 21:11:25 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=l3QBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:30 [info] SafeBrowsing: failed: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=ju8BAAABAAAAAAAACDQ0NTIyN2U3CDM4OTQyN2Y2AnNiA2RucwdhZGd1YXJkA2NvbQAAEAAB: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
2020/03/04 21:11:38 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: couldn't do a POST request to 'https://dns-family.adguard.com:443/dns-query', cause: Get https://dns-family.adguard.com:443/dns-query?dns=XfYBAAABAAAAAAAACGlwdjRvbmx5BGFycGEAAAEAAQ: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
Hmm, I don't get it :(
Could you please enable verbose log in AdGuard? Maybe it is using IPv6
Hmm, I see that there are many errors even with Cloudflare:
2020/03/04 21:27:00 6436#1938 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.0.0.1:853, in 10000 milliseconds, cause: dial tcp 1.0.0.1:853: i/o timeout
2020/03/04 21:27:00 6436#1939 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.0.0.1:853, in 10000 milliseconds, cause: dial tcp 1.0.0.1:853: i/o timeout
2020/03/04 21:27:00 6436#1942 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.0.0.1:853, in 10000 milliseconds, cause: dial tcp 1.0.0.1:853: i/o timeout
2020/03/04 21:27:00 6436#1947 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.0.0.1:853, in 10000 milliseconds, cause: dial tcp 1.0.0.1:853: i/o timeout
2020/03/04 21:27:00 6436#1946 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.0.0.1:853, in 10000 milliseconds, cause: dial tcp 1.0.0.1:853: i/o timeout
2020/03/04 21:27:01 6436#1828 [debug] github.com/AdguardTeam/dnsproxy/upstream.createDialContext.func1(): dialer failed to initialize connection to 1.1.1.1:853, in 10000 milliseconds, cause: dial tcp 1.1.1.1:853: i/o timeout
It looks like some connections are dropped randomly
Moreover, this may be triggering the other issue with dns-family.adguard.com
Yeah, I'm starting to suspect either a networking issue at my ISP or an issue with my NTU.
Thanks for the help, I'll chase things up at my end for now.
As far as I understand, you're using tls://1.1.1.1
as a bootstrap resolver?
Try replacing it with some plain DNS instead just in case, 8.8.8.8
for instance
No, Bootstrap resolver is 8.8.8.8:53
Upstream DNSs is
tls://1dot1dot1dot1.cloudflare-dns.com
tls://one.one.one.one
https://cloudflare-dns.com/dns-query
with parallel queries enabled
Well, so it seems there are not too many issues with bootstrap, but CF upstreams are failing from time to time:(
As well as AG DNS
Out of curiosity, I went back and checked an old AGH.log I had kept.
Looks like I started getting this issue 6 Jan 2020. That's when I started getting clumps of the
SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 5307 ms
errors. So this might not actually be related to the weird random connection drops I'm seeing currently..
@AnthonyBe You can check family protection DOH using any other tool temporally or ask from ISP technical team(not customer support) to check https://dns-family.adguard.com/dns-query
Interestingly this is the last instance of the error in my log:
2020/03/06 07:18:53 [info] SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded: 3235 ms
4 days and the only entries in my logs are filter updates. My AGH average processing time is also back down to 28ms.
This looks like a trunking issue or routing issue with my ISP or further upstream.
Yeah, looks like this is it
I have the same problem with v0.101.0. I switched on parental control for one client and Safebrowsing for all. And some times I see that sites do not loading. In this case AdGuardHome consume 100% cpu my Raspberry Pi. Restart service fix problem till next time.
AdGuardHome consume 100% cpu
@maxtar Can you show verbose logs while this is happening?
Also, what is the output of ps
?
@szolin It's happen not regulars. I think log file in verbose mode will very large while this issue happen. Maybe do rolling file by size or time or something else as in log4j?
Yeah, rolling log files makes sense. @maxtar would you mind creating a feature request for that?
@ameshkov Ok. :) Will write.
Expected Behavior
Clean-ish logs
Actual Behavior
My AGH logs are filled with 10's of the following every minute:
SafeBrowsing: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded
andParental: failed: couldn't initialize HTTP client or transport, cause: timeout exceeded
For example
Additional Information
I had defined a Client that contained the IP addresses of 3 devices. The client configuration did include having Use Adguard parental control web service enabled. I have disabled it for now to see what effect it has on AGH performance and log file cleanliness. AGH.zip AdGuardHome.yaml.txt