Very slow and increasing "Average upstream response time"

netizeni commented 4 months ago

Prerequisites

[X] I have checked the Wiki and Discussions and found no answer
[X] I have searched other issues and found no duplicates
[X] I want to report a bug and not ask a question or ask for help
[X] I have set up AdGuard Home correctly and configured clients to use it. (Use the Discussions for help with installing and configuring clients.)

Platform (OS and CPU architecture)

Custom (please mention in the description)

Installation

Other (please mention in the description)

Setup

On one machine

AdGuard Home version

v0.107.45

Action

I used to use DoH of various DNS services and recently noticed it takes quite a while to load websites, so I decided to switch to old regular DNS, hoping to speed it up, but it didn't happen. Once added, upstream DNS starts increasing the average response time for more than 10x.

On the same machine where AGH is installed, running dnsperftest script multiple times a day, returns more or less consistent results:

                     test1   test2   test3   test4   test5   test6   test7   test8   test9   test10  Average
76.76.2.41           35 ms   35 ms   35 ms   39 ms   35 ms   39 ms   39 ms   47 ms   39 ms   35 ms     37.80  //from resolv.conf
9.9.9.9              3 ms    3 ms    47 ms   3 ms    11 ms   3 ms    7 ms    3 ms    3 ms    11 ms     9.40  //from resolv.conf
quad9                3 ms    3 ms    7 ms    3 ms    3 ms    3 ms    3 ms    3 ms    7 ms    11 ms     4.60
google               11 ms   11 ms   27 ms   11 ms   7 ms    27 ms   15 ms   59 ms   11 ms   27 ms     20.60
norton               31 ms   27 ms   31 ms   27 ms   27 ms   27 ms   27 ms   27 ms   27 ms   23 ms     27.40
neustar              31 ms   35 ms   31 ms   31 ms   35 ms   35 ms   35 ms   31 ms   31 ms   35 ms     33.00
level3               27 ms   31 ms   31 ms   63 ms   31 ms   51 ms   31 ms   31 ms   27 ms   31 ms     35.40
cleanbrowsing        35 ms   35 ms   39 ms   35 ms   35 ms   39 ms   39 ms   39 ms   35 ms   43 ms     37.40
nextdns              39 ms   39 ms   39 ms   35 ms   35 ms   39 ms   35 ms   39 ms   39 ms   39 ms     37.80
opendns              35 ms   35 ms   39 ms   39 ms   39 ms   35 ms   35 ms   51 ms   35 ms   35 ms     37.80
comodo               39 ms   35 ms   39 ms   35 ms   39 ms   35 ms   43 ms   39 ms   39 ms   39 ms     38.20
freenom              35 ms   31 ms   63 ms   31 ms   75 ms   27 ms   31 ms   83 ms   35 ms   83 ms     49.40
yandex               71 ms   67 ms   71 ms   67 ms   71 ms   71 ms   71 ms   71 ms   71 ms   67 ms     69.80
adguard              155 ms  127 ms  139 ms  175 ms  119 ms  139 ms  123 ms  155 ms  131 ms  135 ms    139.80
cloudflare           1000 ms 1000 ms 1000 ms 1000 ms 1000 ms 1000 ms 1000 ms 1000 ms 1000 ms 1000 ms   1000.00

While the current "Average upstream response time" in AGH looks like this (and progressively increases more and more):

When I'm using VPN and its DNS, website are loading noticeably faster. Is there something to change in AdGuard Home DNS settings shown below which should hopefully speed up the response time?

dns:
  bind_hosts:
    - 0.0.0.0
  port: 53
  anonymize_client_ip: false
  ratelimit: 150
  ratelimit_subnet_len_ipv4: 24
  ratelimit_subnet_len_ipv6: 56
  ratelimit_whitelist: []
  refuse_any: true
  upstream_dns:
    - 76.76.2.41
    - 76.76.2.32
    - 193.110.81.0
    - 9.9.9.9
  upstream_dns_file: ""
  bootstrap_dns:
    - 76.76.10.32
    - 76.76.10.41
  fallback_dns:
    - 9.9.9.9
  upstream_mode: load_balance
  fastest_timeout: 1s
  allowed_clients: []
  disallowed_clients: []
  blocked_hosts:
    - version.bind
    - id.server
    - hostname.bind
  trusted_proxies:
    - 127.0.0.0/8
    - ::1/128
  cache_size: 134217728
  cache_ttl_min: 0
  cache_ttl_max: 0
  cache_optimistic: true
  bogus_nxdomain: []
  aaaa_disabled: false
  enable_dnssec: false
  edns_client_subnet:
    custom_ip: ""
    enabled: false
    use_custom: false
  max_goroutines: 300
  handle_ddr: true
  ipset: []
  ipset_file: ""
  bootstrap_prefer_ipv6: false
  upstream_timeout: 10s
  private_networks: []
  use_private_ptr_resolvers: true
  local_ptr_upstreams: []
  use_dns64: false
  dns64_prefixes: []
  serve_http3: false
  use_http3_upstreams: false
  serve_plain_dns: true

Expected result

Lower "Average upstream response time" over time and faster responses.

Actual result

"Average upstream response time" getting increased over time. Websites take quite a while to load.

Additional information and/or screenshots

AdGuard Home is installed on RPi 3B+ running DietPi (debian based).

bobloadmire commented 1 month ago

Loool I love the notion that downgrading and staying on an old version forever was a proposed "solution"

ingoratsdorf commented 1 month ago

Running v0.107.49 yesterday and had 3ms (forwards to unbound) to 11ms DNS response time. Updated today to v0.107.50 and the old bug is back with ridiculous response times.

202.27.158.40:53 - 10170 ms
208.67.222.222:53 - 10043 ms
210.55.111.1:53 - 10029 ms
202.27.156.72:53 - 7517 ms
1.1.1.1:53 - 388 ms
9.9.9.9:53 - 138 ms
192.168.1.1:5053 - 136 ms (unbound)
122.56.237.1:53 - 31 ms

Even unbound is not the 3ms any more that it was, it's now 136ms even though it was not touched, updated or restarted. Whatever happened in v0.107.50 f***d everything up :-(

cat querylog.json | jq -r '(.QH + ":" + (.Elapsed | tostring))' | sort -t: -nrk2 | head -20
api.flightproxy.teams.microsoft.com:30442836354
array803.prod.do.dsp.mp.microsoft.com:30059729536
api.flightproxy.teams.microsoft.com:30051697911
array803.prod.do.dsp.mp.microsoft.com:30043604843
api.flightproxy.teams.microsoft.com:30034833094
prod-southeastasia.access-point.cloudmessaging.edge.microsoft.com:30031838778
pub-ent-jpwe-07-t.trouter.teams.microsoft.com:30026066998
prod-southeastasia.access-point.cloudmessaging.edge.microsoft.com:30022012015
array803.prod.do.dsp.mp.microsoft.com:30019877227
prod-southeastasia.access-point.cloudmessaging.edge.microsoft.com:30019016008
nimbus.bitdefender.net:20267173577
array803.prod.do.dsp.mp.microsoft.com:20014837572
array519.prod.do.dsp.mp.microsoft.com:18992164171
cosmic-centralindia-ns-9f6fe5304d2e.trafficmanager.net:18913135751
firestore.googleapis.com:18616632547
firestore.googleapis.com:18614976471
pub-ent-jpwe-07-t.trouter.teams.microsoft.com:18072695579
prod-southeastasia.access-point.cloudmessaging.edge.microsoft.com:17975556061
pub-ent-jpwe-07-t.trouter.teams.microsoft.com:17961922263
pub-ent-jpwe-07-t.trouter.teams.microsoft.com:17961627842

ingoratsdorf commented 1 month ago

Also since the update from v49 to v50 this morning:

netizeni commented 1 month ago

@overwatch3560 would you mind unlocking this issue, as it's obviously not solved?

ingoratsdorf commented 1 month ago

After the continuously high processing times, I downgraded to .49 version again and watched the processing times instantaneously going down to normal. I then upgraded again to .50 and the system normalised as well. I note that at no times unbound was restarted or any of the AdGuardHome config files were changed. (The one big spike was a power outage, all systems down and the server shut down and restarted with all services)

mwahyd commented 1 month ago

I am also facing the same issue. Currently on Version: v0.107.50

Upstream DNS servers that I am subscribed to:

#CloudflareDNS
h3://dns.cloudflare.com/dns-query
tls://one.one.one.one
#Quad9DNS
tls://dns.quad9.net
tls://dns9.quad9.net
https://dns.quad9.net/dns-query
https://dns9.quad9.net/dns-query

Response times:

tls://dns9.quad9.net:853   16562 ms
tls://dns.quad9.net:853   15897 ms
tls://one.one.one.one:853   6864 ms
https://dns.quad9.net:443/dns-query   2744 ms
https://dns.cloudflare.com:443/dns-query   2137 ms
https://dns9.quad9.net:443/dns-query   353 ms
192.168.0.1:53   124 ms

netizeni commented 1 month ago

@mwahyd seems like there's no point in reporting that issue obviously exist, when @overwatch3560 decided that a perfect solution is to downgrade the version, stay on it and problem solved.

He is even doubling down by ignoring all the messages asking to reopen this issue.

@ainar-g @EugeneOne1 Sorry for the tag, but can you please reopen this issue?

Cebeerre commented 1 month ago

Hi @netizeni, I'll reopen the issue ... Let me say though, that this is a very tricky thing to reproduce ...

I've been running myself 0.107.48 and went straight to 0.107.50. Always with just Unbound in recursive mode as upstream (supposed to be the slowest of the options) and my Average Response Time is always around 2-3 ms with an average response time from Unbound around 110-120 ms.

ainar-g commented 1 month ago

@netizeni, as others have mentioned, comparing AGH's timings with those of just requesting the upstreams isn't really saying much, since AGH performs multiple kinds of filtering. It's not the RTT, it includes the entire processing time. Both on requests and responses.

Some things that could shed more light:

Enable verbose logging to see what's going on whenever the queries are processed.
Try disabling the protection completely, including safe browsing and adult blocking filters.
Which filters are you using and how many rules in total are there right now? Does reducing the number of filtering-rule lists also reduce the processing time?

netizeni commented 1 month ago

@Cebeerre thank you! Yeah, I understand it's tricky, hence why this long thread is going on for 3 months.

@ainar-g reducing filter list does not affect it, I tested that in the past. I'm on a vacation, so can't check with verbose logging right now. Maybe some other people from here with the same problem can add more info.

straussmarkus commented 1 month ago

Same problem here with 0.107.51. I already have all of my upstreams above 10 seconds. This is ridiculous - seeing how long this thread already is. Downgrade beeing suggested as solution - LoL.

kolumdium commented 2 weeks ago

I came across this as well. Was running Adguard with relativly slow load times which I thought were normal. Then I installed Unbound and had longer responsetimes as well as timeouts <10s when requesting locally. I googled and came across this issue. Downgrading my Docker to use 0.107.49 resolved the Issue as well. Loadtimes are <70ms instead of 700ms and the local resolve is not on average <15ms instad of 2s. I changed nothing else. Unbound wasn't restarted. Adguard lists and config is the exact same. Adguard and Unbound are running on custom docker network in their own containers on different static IPs. If I can help debugging somehow let me know.

nmhung1985 commented 1 day ago

Haven't updated my AGH for about... 9 months. And since I upgraded it last week, this issue has occurred to me too.

AdguardTeam / AdGuardHome