You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
Normal use of AdGuard Home as the primary resolver on LAN sporadically results in pauses and delays likely attributed to slow DNS resolution.
I have dns.upstream_mode set to parallel, and dns.upstream_timeout set to 5s.
(I previously had dns.upstream_timeout set to 2s, but this made the problem described below worse.)
My AdGuard Home container uses a macvlan interface for connectivity and is on a very beefy server. My config is simple: I only use one filter list. No client rules. No DoH. No encryption. Do DHCP server.
(Note that I added quite a few comments, and analysis of my querylog.json, to #6818 because I thought that might be the right place to discuss the bad average response times I'm seeing, but the findings I've documented here seem to be something different.)
Expected result
Fast, reliable DNS resolution.
Actual result
Unexpected, consistent delays from multiple independent upstreams.
Additional information and/or screenshots
For this analysis, I enabled log.verbose: true and then ran tcpdump on the Docker host to look for traffic to all three upstreams.
There are two queries, very close together, that I'm choosing to highlight for this analysis. First, here is the request setup as logged by AGH in thread/task 34888:
1 2025/02/10 20:50:09.288239 1#34888 [debug] dnsproxy: handling new udp packet raddr=192.168.9.118:54050
1 2025/02/10 20:50:09.288758 1#34888 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 48068"
1 2025/02/10 20:50:09.289195 1#34888 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0"
1 2025/02/10 20:50:09.289731 1#34888 [debug] dnsproxy: in line_num=3 line=""
1 2025/02/10 20:50:09.290217 1#34888 [debug] dnsproxy: in line_num=4 line=";; QUESTION SECTION:"
1 2025/02/10 20:50:09.290638 1#34888 [debug] dnsproxy: in line_num=5 line=";conf.config-security.com.\tIN\t HTTPS"
1 2025/02/10 20:50:09.291143 1#34888 [debug] dnsproxy: in line_num=6 line=""
1 2025/02/10 20:50:09.291639 1#34888 [debug] dnsforward: started processing initial
1 2025/02/10 20:50:09.291992 1#34888 [debug] applying filters: looking for client with ip 192.168.9.118 and clientid ""
1 2025/02/10 20:50:09.292436 1#34888 [debug] applying filters: no clients with ip 192.168.9.118 and clientid ""
1 2025/02/10 20:50:09.292734 1#34888 [debug] dnsforward: finished processing initial
1 2025/02/10 20:50:09.292924 1#34888 [debug] dnsforward: started processing ddr
1 2025/02/10 20:50:09.293214 1#34888 [debug] dnsforward: finished processing ddr
1 2025/02/10 20:50:09.293273 1#34888 [debug] dnsforward: started processing dhcp hosts
1 2025/02/10 20:50:09.293309 1#34888 [debug] dnsforward: finished processing dhcp hosts
1 2025/02/10 20:50:09.293339 1#34888 [debug] dnsforward: started processing dhcp addrs
1 2025/02/10 20:50:09.293399 1#34888 [debug] dnsforward: finished processing dhcp addrs
1 2025/02/10 20:50:09.293481 1#34888 [debug] dnsforward: started processing filtering before req
1 2025/02/10 20:50:09.293876 1#34888 [debug] filtering: unsupported qtype 65
1 2025/02/10 20:50:09.294423 1#34888 [debug] safe browsing: checking conf.config-security.com: 5b42.dcff.sb.dns.adguard.com.
1 2025/02/10 20:50:09.323430 1#34888 [debug] safe browsing: received hashes for conf.config-security.com: [ *SNIPPED* ]
1 2025/02/10 20:50:09.323497 1#34888 [debug] safe browsing: received answer for conf.config-security.com with 1 TXT count
1 2025/02/10 20:50:09.323561 1#34888 [debug] safe browsing: stored in cache: [91 66]
1 2025/02/10 20:50:09.323603 1#34888 [debug] safe browsing: stored in cache: [220 255]
1 2025/02/10 20:50:09.323647 1#34888 [debug] github.com/AdguardTeam/AdGuardHome/internal/filtering.(*DNSFilter).checkSafeBrowsing(): filtering: safebrowsing lookup for "conf.config-security.com"; Elapsed time: 29ms
1 2025/02/10 20:50:09.323674 1#34888 [debug] dnsforward: finished processing filtering before req
1 2025/02/10 20:50:09.323698 1#34888 [debug] dnsforward: started processing upstream
Next, AGH sends out the queries to each of the upstreams (remember, these are 3 independent organizations). I've labeled them QA, QB, QC ("Q" for "Query"). These are sent on the wire within a few milliseconds after logging started processing upstream:
Now a second request (for the same name and record type) is received less than a second later, and processed by thread/task 35798. Note that the "safe browsing" data for this request is found in the cache from the request above. Note also that the replies to QA, QB or QC have not yet been received:
2 2025/02/10 20:50:10.279667 1#35798 [debug] dnsproxy: handling new udp packet raddr=192.168.9.118:54050
2 2025/02/10 20:50:10.279794 1#35798 [debug] dnsproxy: in line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 48068"
2 2025/02/10 20:50:10.279862 1#35798 [debug] dnsproxy: in line_num=2 line=";; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0"
2 2025/02/10 20:50:10.279929 1#35798 [debug] dnsproxy: in line_num=3 line=""
2 2025/02/10 20:50:10.279992 1#35798 [debug] dnsproxy: in line_num=4 line=";; QUESTION SECTION:"
2 2025/02/10 20:50:10.280101 1#35798 [debug] dnsproxy: in line_num=5 line=";conf.config-security.com.\tIN\t HTTPS"
2 2025/02/10 20:50:10.280200 1#35798 [debug] dnsproxy: in line_num=6 line=""
2 2025/02/10 20:50:10.280321 1#35798 [debug] dnsforward: started processing initial
2 2025/02/10 20:50:10.280551 1#35798 [debug] applying filters: looking for client with ip 192.168.9.118 and clientid ""
2 2025/02/10 20:50:10.280624 1#35798 [debug] applying filters: no clients with ip 192.168.9.118 and clientid ""
2 2025/02/10 20:50:10.280814 1#35798 [debug] dnsforward: finished processing initial
2 2025/02/10 20:50:10.280946 1#35798 [debug] dnsforward: started processing ddr
2 2025/02/10 20:50:10.281165 1#35798 [debug] dnsforward: finished processing ddr
2 2025/02/10 20:50:10.281341 1#35798 [debug] dnsforward: started processing dhcp hosts
2 2025/02/10 20:50:10.281448 1#35798 [debug] dnsforward: finished processing dhcp hosts
2 2025/02/10 20:50:10.281539 1#35798 [debug] dnsforward: started processing dhcp addrs
2 2025/02/10 20:50:10.281618 1#35798 [debug] dnsforward: finished processing dhcp addrs
2 2025/02/10 20:50:10.281694 1#35798 [debug] dnsforward: started processing filtering before req
2 2025/02/10 20:50:10.281799 1#35798 [debug] filtering: unsupported qtype 65
2 2025/02/10 20:50:10.282097 1#35798 [debug] safe browsing: found "conf.config-security.com" in cache, blocked: false
2 2025/02/10 20:50:10.282399 1#35798 [debug] github.com/AdguardTeam/AdGuardHome/internal/filtering.(*DNSFilter).checkSafeBrowsing(): filtering: safebrowsing lookup for "conf.config-security.com"; Elapsed time: 0ms
2 2025/02/10 20:50:10.282722 1#35798 [debug] dnsforward: finished processing filtering before req
2 2025/02/10 20:50:10.282771 1#35798 [debug] dnsforward: started processing upstream
These queries also show up on the wire within a few milliseconds after AGH logs started processing upstream. These are QD, QE and QF:
The first response gets processed by thread/task 34888:
1 2025/02/10 20:50:10.641291 1#34888 [debug] dnsproxy: resolved src=upstream rtt=1.317465767s
1 2025/02/10 20:50:10.641382 1#34888 [debug] dnsforward: finished processing upstream
1 2025/02/10 20:50:10.641425 1#34888 [debug] dnsforward: started processing filtering after resp
1 2025/02/10 20:50:10.641555 1#34888 [debug] dnsforward: checked None for conf.config-security.com.
1 2025/02/10 20:50:10.641620 1#34888 [debug] dnsforward: finished processing filtering after resp
1 2025/02/10 20:50:10.641693 1#34888 [debug] ipset: started processing
1 2025/02/10 20:50:10.641759 1#34888 [debug] ipset: finished processing
1 2025/02/10 20:50:10.641798 1#34888 [debug] dnsforward: started processing querylog and stats
1 2025/02/10 20:50:10.641845 1#34888 [debug] dnsforward: client ip for stats and querylog: 192.168.9.118
1 2025/02/10 20:50:10.641955 1#34888 [debug] dnsforward: finished processing querylog and stats
1 2025/02/10 20:50:10.642067 1#34888 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 48068"
1 2025/02/10 20:50:10.642135 1#34888 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0"
1 2025/02/10 20:50:10.642198 1#34888 [debug] dnsproxy: out line_num=3 line=""
1 2025/02/10 20:50:10.642261 1#34888 [debug] dnsproxy: out line_num=4 line=";; QUESTION SECTION:"
1 2025/02/10 20:50:10.642324 1#34888 [debug] dnsproxy: out line_num=5 line=";conf.config-security.com.\tIN\t HTTPS"
1 2025/02/10 20:50:10.642384 1#34888 [debug] dnsproxy: out line_num=6 line=""
1 2025/02/10 20:50:10.642445 1#34888 [debug] dnsproxy: out line_num=7 line=";; ANSWER SECTION:"
1 2025/02/10 20:50:10.642515 1#34888 [debug] dnsproxy: out line_num=8 line="conf.config-security.com.\t300\tIN\tHTTPS\t1 . alpn=\"h2\" ipv4hint=\"104.26.14.69,104.26.15.69,172.67.72.191\" ipv6hint=\"2606:4700:20::681a:e45,2606:4700:20::681a:f45,2606:4700:20::ac43:48bf\""
1 2025/02/10 20:50:10.642598 1#34888 [debug] dnsproxy: out line_num=9 line=""
Over 5s (remember, I have dns.upstream_timeout: 5s) has elapsed since the second set of queries (QD, QE and QF) were sent but now AGH is sending out another set of queries! 🤔
Since AGH did not receive a response within 5s, the second AGH thread/task reports the query as SERVFAIL and logs i/o timeout:
2 2025/02/10 20:50:20.285057 1#35798 [debug] dnsproxy: resolving err src=upstream err="exchanging with 9.9.9.9:53 over udp: read udp 192.168.8.1:33134->9.9.9.9:53: i/o timeout\nexchanging with 8.8.8.8:53 over udp: read udp 192.168.8.1:37586->8.8.8.8:53: i/o timeout\nexchanging with 1.1.1.1:53 over udp: read udp 192.168.8.1:56730->1.1.1.1:53: i/o timeout"
2 2025/02/10 20:50:20.285130 1#35798 [debug] dnsforward: finished processing upstream
2 2025/02/10 20:50:20.285271 1#35798 [debug] dnsproxy: out line_num=1 line=";; opcode: QUERY, status: SERVFAIL, id: 48068"
2 2025/02/10 20:50:20.285377 1#35798 [debug] dnsproxy: out line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0"
2 2025/02/10 20:50:20.285497 1#35798 [debug] dnsproxy: out line_num=3 line=""
2 2025/02/10 20:50:20.285636 1#35798 [debug] dnsproxy: out line_num=4 line=";; QUESTION SECTION:"
2 2025/02/10 20:50:20.285764 1#35798 [debug] dnsproxy: out line_num=5 line=";conf.config-security.com.\tIN\t HTTPS"
2 2025/02/10 20:50:20.285948 1#35798 [debug] dnsproxy: out line_num=6 line=""
2 2025/02/10 20:50:20.286221 1#35798 [debug] dnsproxy: handling dns request proto=udp err="using request handler: exchanging with 9.9.9.9:53 over udp: read udp 192.168.8.1:33134->9.9.9.9:53: i/o timeout\nexchanging with 8.8.8.8:53 over udp: read udp 192.168.8.1:37586->8.8.8.8:53: i/o timeout\exchanging with 1.1.1.1:53 over udp: read udp 192.168.8.1:56730->1.1.1.1:53: i/o timeout"
Over 5s since the second set of queries (QD, QE, QF) were sent, replies now show up on the wire from all three upstreams, with 8.8.8 returning about 3s later than the other two:
and then 9s since the third set of queries (QG, QH, QI) were sent, replies show up on the wire _from all three upstreams, with 8.8.8.8 returning 1.5s later than the other two:
Finally, while this is going on, the AGH container is rejecting numerous responses from all three upstreams as "unreachable":
2025-02-10 20:49:59.727701 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 37782 unreachable, length 106
2025-02-10 20:50:01.990217 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 36672 unreachable, length 250
2025-02-10 20:50:05.310742 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 46996 unreachable, length 232
2025-02-10 20:50:05.311062 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 48190 unreachable, length 232
2025-02-10 20:50:05.313297 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 51169 unreachable, length 232
2025-02-10 20:50:05.344634 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 33963 unreachable, length 108
2025-02-10 20:50:05.346069 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 41604 unreachable, length 108
2025-02-10 20:50:05.357988 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 51448 unreachable, length 108
2025-02-10 20:50:06.205771 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 49794 unreachable, length 318
2025-02-10 20:50:06.206756 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 52064 unreachable, length 158
2025-02-10 20:50:06.207679 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 38373 unreachable, length 318
2025-02-10 20:50:06.209146 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 58465 unreachable, length 318
2025-02-10 20:50:06.209625 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 34783 unreachable, length 158
2025-02-10 20:50:06.211650 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 50580 unreachable, length 250
2025-02-10 20:50:06.212203 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 55587 unreachable, length 226
2025-02-10 20:50:06.212528 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 54953 unreachable, length 144
2025-02-10 20:50:06.212829 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 33193 unreachable, length 150
2025-02-10 20:50:06.213917 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 47700 unreachable, length 147
2025-02-10 20:50:06.221895 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 49101 unreachable, length 175
2025-02-10 20:50:07.285764 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 46290 unreachable, length 158
2025-02-10 20:50:23.104866 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 44174 unreachable, length 219
2025-02-10 20:50:23.107649 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 42138 unreachable, length 285
2025-02-10 20:50:23.108018 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 58905 unreachable, length 277
2025-02-10 20:50:23.108388 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 57138 unreachable, length 124
2025-02-10 20:50:23.108800 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 55230 unreachable, length 115
2025-02-10 20:50:23.108954 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 38031 unreachable, length 180
2025-02-10 20:50:23.109268 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 49853 unreachable, length 102
2025-02-10 20:50:23.109442 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 34670 unreachable, length 115
2025-02-10 20:50:23.110831 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 52800 unreachable, length 269
2025-02-10 20:50:23.111198 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 44834 unreachable, length 102
2025-02-10 20:50:23.111247 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 60096 unreachable, length 115
2025-02-10 20:50:23.111687 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 41856 unreachable, length 103
2025-02-10 20:50:23.112166 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 46099 unreachable, length 149
2025-02-10 20:50:23.112515 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 42906 unreachable, length 115
2025-02-10 20:50:23.112877 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 37854 unreachable, length 124
2025-02-10 20:50:23.114278 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 44925 unreachable, length 149
2025-02-10 20:50:23.115279 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 36230 unreachable, length 103
2025-02-10 20:50:23.115983 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 50749 unreachable, length 103
2025-02-10 20:50:24.803649 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 45815 unreachable, length 219
2025-02-10 20:50:24.818316 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 45539 unreachable, length 115
2025-02-10 20:50:24.822844 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 57081 unreachable, length 103
2025-02-10 20:50:26.286801 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 45770 unreachable, length 219
2025-02-10 20:50:26.288531 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 40939 unreachable, length 172
2025-02-10 20:50:26.290569 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 49949 unreachable, length 148
2025-02-10 20:50:26.291497 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 60958 unreachable, length 291
2025-02-10 20:50:26.293429 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 50301 unreachable, length 148
2025-02-10 20:50:26.294136 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 58343 unreachable, length 148
2025-02-10 20:50:28.012307 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 53738 unreachable, length 219
2025-02-10 20:50:29.787293 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 34553 unreachable, length 283
2025-02-10 20:50:29.787396 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 46721 unreachable, length 269
2025-02-10 20:50:29.787430 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 52930 unreachable, length 124
2025-02-10 20:50:29.787771 IP 192.168.8.1 > 1.1.1.1: ICMP 192.168.8.1 udp port 43898 unreachable, length 219
2025-02-10 20:50:29.788179 IP 192.168.8.1 > 8.8.8.8: ICMP 192.168.8.1 udp port 41868 unreachable, length 124
2025-02-10 20:50:29.791486 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 41346 unreachable, length 148
2025-02-10 20:50:29.791500 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 43018 unreachable, length 148
2025-02-10 20:50:29.791530 IP 192.168.8.1 > 9.9.9.9: ICMP 192.168.8.1 udp port 51450 unreachable, length 103
This behavior does not happen all the time, but happens in spurts.
(Note that there were many other queries being processed by AGH during the above timeframe, I only selected two queries to pull out of the logs and pcap to analyze and report on here.)
The text was updated successfully, but these errors were encountered:
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 or ask for help
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)
Linux, AMD64 (aka x86_64)
Installation
Docker
Setup
On one machine
AdGuard Home version
0.107.55
Action
Normal use of AdGuard Home as the primary resolver on LAN sporadically results in pauses and delays likely attributed to slow DNS resolution.
I have
dns.upstream_modeset toparallel, anddns.upstream_timeoutset to5s.(I previously had
dns.upstream_timeoutset to2s, but this made the problem described below worse.)My AdGuard Home container uses a macvlan interface for connectivity and is on a very beefy server. My config is simple: I only use one filter list. No client rules. No DoH. No encryption. Do DHCP server.
(Note that I added quite a few comments, and analysis of my
querylog.json, to #6818 because I thought that might be the right place to discuss the bad average response times I'm seeing, but the findings I've documented here seem to be something different.)Expected result
Fast, reliable DNS resolution.
Actual result
Unexpected, consistent delays from multiple independent upstreams.
Additional information and/or screenshots
For this analysis, I enabled
log.verbose: trueand then rantcpdumpon the Docker host to look for traffic to all three upstreams.There are two queries, very close together, that I'm choosing to highlight for this analysis. First, here is the request setup as logged by AGH in thread/task 34888:
Next, AGH sends out the queries to each of the upstreams (remember, these are 3 independent organizations). I've labeled them QA, QB, QC ("Q" for "Query"). These are sent on the wire within a few milliseconds after logging
started processing upstream:Now a second request (for the same name and record type) is received less than a second later, and processed by thread/task 35798. Note that the "safe browsing" data for this request is found in the cache from the request above. Note also that the replies to QA, QB or QC have not yet been received:
These queries also show up on the wire within a few milliseconds after AGH logs
started processing upstream. These are QD, QE and QF:The responses ("R") from the first set of queries now arrive from each upstream, about 1.3 seconds after being sent:
The first response gets processed by thread/task 34888:
Over 5s (remember, I have
dns.upstream_timeout: 5s) has elapsed since the second set of queries (QD, QE and QF) were sent but now AGH is sending out another set of queries! 🤔Since AGH did not receive a response within 5s, the second AGH thread/task reports the query as SERVFAIL and logs
i/o timeout:Over 5s since the second set of queries (QD, QE, QF) were sent, replies now show up on the wire from all three upstreams, with 8.8.8 returning about 3s later than the other two:
and then 9s since the third set of queries (QG, QH, QI) were sent, replies show up on the wire _from all three upstreams, with 8.8.8.8 returning 1.5s later than the other two:
Finally, while this is going on, the AGH container is rejecting numerous responses from all three upstreams as "unreachable":
This behavior does not happen all the time, but happens in spurts.
(Note that there were many other queries being processed by AGH during the above timeframe, I only selected two queries to pull out of the logs and pcap to analyze and report on here.)
The text was updated successfully, but these errors were encountered: