AdguardTeam/dnsproxy

dig ID mismatch

ZeroClover opened this issue · 4 comments

ZeroClover commented

I use dnsproxy on my internal network as a simple DNS forwarder to help devices that do not support Encrypted DNS use my private Encrypted DNS server.

However, I found that in certain cases, the query is very slow, and using the 'dig' command produces the following output:

time dig @10.1.62.33 apple.com
;; Warning: ID mismatch: expected ID 53731, got 0

; <<>> DiG 9.10.6 <<>> @10.1.62.33 apple.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 53731
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4096
;; QUESTION SECTION:
;apple.com.			IN	A

;; ANSWER SECTION:
apple.com.		476	IN	A	17.253.144.10

;; Query time: 0 msec
;; SERVER: 10.1.62.33#53(10.1.62.33)
;; WHEN: Tue Jul 16 16:56:28 HKT 2024
;; MSG SIZE  rcvd: 54

dig @10.1.62.33 apple.com  0.00s user 0.01s system 0% cpu 5.019 total

dnsproxy verbose log:

Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025505 INFO server will refuse requests of type any prefix=dnsproxy
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025508 INFO upstream mode is set prefix=dnsproxy mode=fastest_addr
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025512 INFO cache enabled prefix=dnsproxy size=2147483648
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025515 INFO starting dns proxy server prefix=dnsproxy
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025521 INFO creating udp server socket prefix=dnsproxy addr=0.0.0.0:53
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025574 INFO listening to udp prefix=dnsproxy addr=[::]:53
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025578 INFO creating tcp server socket prefix=dnsproxy addr=0.0.0.0:53
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025613 INFO listening to tcp prefix=dnsproxy addr=[::]:53
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025651 INFO entering udp listener loop prefix=dnsproxy addr=[::]:53
Jul 16 16:56:17 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:17.025675 INFO entering listener loop prefix=dnsproxy proto=tcp addr=[::]:53
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408884 DEBUG handling new udp packet prefix=dnsproxy raddr=10.1.62.123:61303
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408941 DEBUG in prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 53731"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408945 DEBUG in prefix=dnsproxy line_num=2 line=";; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408947 DEBUG in prefix=dnsproxy line_num=3 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408950 DEBUG in prefix=dnsproxy line_num=4 line=";; OPT PSEUDOSECTION:"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408953 DEBUG in prefix=dnsproxy line_num=5 line="; EDNS: version 0; flags:; udp: 4096"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408955 DEBUG in prefix=dnsproxy line_num=6 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408958 DEBUG in prefix=dnsproxy line_num=7 line=";; QUESTION SECTION:"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408961 DEBUG in prefix=dnsproxy line_num=8 line=";apple.com.\tIN\t A"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408963 DEBUG in prefix=dnsproxy line_num=9 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.408985 DEBUG creating a new http client
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409048 DEBUG sending request addr=1.2.4.8:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409058 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409094 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=32.935µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409125 DEBUG creating a new http client
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409143 DEBUG sending request addr=1.2.4.8:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409146 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409160 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=10.651µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409182 DEBUG sending request addr=121.4.4.1:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409185 DEBUG dialing prefix=bootstrap addr=121.4.4.1:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409197 DEBUG connection succeeded prefix=bootstrap addr=121.4.4.1:53 elapsed=9.338µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409216 DEBUG sending request addr=223.6.6.6:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409220 DEBUG dialing prefix=bootstrap addr=223.6.6.6:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409232 DEBUG connection succeeded prefix=bootstrap addr=223.6.6.6:53 elapsed=9.108µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409248 DEBUG sending request addr=1.2.4.8:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409251 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409263 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=9.329µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409281 DEBUG sending request addr=121.4.4.1:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409285 DEBUG dialing prefix=bootstrap addr=121.4.4.1:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409297 DEBUG connection succeeded prefix=bootstrap addr=121.4.4.1:53 elapsed=8.718µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409314 DEBUG sending request addr=223.6.6.6:53 proto=udp qtype=AAAA qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409318 DEBUG dialing prefix=bootstrap addr=223.6.6.6:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409332 DEBUG connection succeeded prefix=bootstrap addr=223.6.6.6:53 elapsed=11.442µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409347 DEBUG sending request addr=1.2.4.8:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409350 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409362 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=9.369µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409375 DEBUG sending request addr=121.4.4.1:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409379 DEBUG dialing prefix=bootstrap addr=121.4.4.1:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409391 DEBUG connection succeeded prefix=bootstrap addr=121.4.4.1:53 elapsed=9.219µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409405 DEBUG sending request addr=223.6.6.6:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409408 DEBUG dialing prefix=bootstrap addr=223.6.6.6:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409419 DEBUG connection succeeded prefix=bootstrap addr=223.6.6.6:53 elapsed=8.597µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409431 DEBUG sending request addr=121.4.4.1:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409434 DEBUG dialing prefix=bootstrap addr=121.4.4.1:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409447 DEBUG connection succeeded prefix=bootstrap addr=121.4.4.1:53 elapsed=8.417µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409461 DEBUG sending request addr=223.6.6.6:53 proto=udp qtype=A qname=<REDACTED DNS SERVER>.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409464 DEBUG dialing prefix=bootstrap addr=223.6.6.6:53 idx=1 total=1
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.409475 DEBUG connection succeeded prefix=bootstrap addr=223.6.6.6:53 elapsed=8.748µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414496 DEBUG response received addr=223.6.6.6:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414818 DEBUG response received addr=223.6.6.6:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414833 DEBUG response received addr=223.6.6.6:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414849 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414868 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=15.73µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.414884 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.418168 DEBUG response received addr=223.6.6.6:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.418184 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.418203 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=15.591µs
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.418217 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.424423 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=6.201356ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.427198 DEBUG response received addr=121.4.4.1:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.429874 DEBUG response received addr=121.4.4.1:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.438507 DEBUG response received addr=121.4.4.1:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.441374 DEBUG tls connection established elapsed=23.159897ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.441435 DEBUG got error, switching to http/2 for this upstream err="TLS was faster than QUIC, prefer it"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.441472 DEBUG sending request addr=https://<REDACTED DNS SERVER>:443/dns-query proto=tcp qtype=A qname=apple.com.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.441540 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.441739 DEBUG quic connection established elapsed=23.497801ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.448297 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=6.731286ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.450866 DEBUG response received addr=1.2.4.8:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.458623 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=43.732903ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.461098 DEBUG response received addr=1.2.4.8:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.461219 DEBUG response received addr=121.4.4.1:53 proto=udp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.466444 DEBUG response received addr=https://<REDACTED DNS SERVER>:443/dns-query proto=tcp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.505469 DEBUG tls connection established elapsed=90.584253ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.505492 DEBUG got error, switching to http/2 for this upstream err="TLS was faster than QUIC, prefer it"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.505505 DEBUG sending request addr=https://<REDACTED DNS SERVER>:443/dns-query proto=tcp qtype=A qname=apple.com.
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.505543 DEBUG dialing prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 idx=1 total=2
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.518818 DEBUG quic connection established elapsed=103.898505ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.548750 DEBUG connection succeeded prefix=bootstrap addr=<REDACTED DNS SERVER IP>:443 elapsed=43.193462ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640714 DEBUG response received addr=https://<REDACTED DNS SERVER>:443/dns-query proto=tcp status=ok
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640740 DEBUG resolved prefix=dnsproxy src=upstream rtt=231.765806ms
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640764 DEBUG out prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 0"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640767 DEBUG out prefix=dnsproxy line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640770 DEBUG out prefix=dnsproxy line_num=3 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640772 DEBUG out prefix=dnsproxy line_num=4 line=";; OPT PSEUDOSECTION:"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640775 DEBUG out prefix=dnsproxy line_num=5 line="; EDNS: version 0; flags:; udp: 4096"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640778 DEBUG out prefix=dnsproxy line_num=6 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640780 DEBUG out prefix=dnsproxy line_num=7 line=";; QUESTION SECTION:"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640783 DEBUG out prefix=dnsproxy line_num=8 line=";apple.com.\tIN\t A"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640785 DEBUG out prefix=dnsproxy line_num=9 line=""
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640788 DEBUG out prefix=dnsproxy line_num=10 line=";; ANSWER SECTION:"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640791 DEBUG out prefix=dnsproxy line_num=11 line="apple.com.\t481\tIN\tA\t17.253.144.10"
Jul 16 16:56:23 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:23.640807 DEBUG out prefix=dnsproxy line_num=12 line=""
Jul 16 16:56:25 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:25.409829 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:25 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:25.410280 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=40.94µs
Jul 16 16:56:25 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:25.409829 DEBUG dialing prefix=bootstrap addr=1.2.4.8:53 idx=1 total=1
Jul 16 16:56:25 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:25.410383 DEBUG connection succeeded prefix=bootstrap addr=1.2.4.8:53 elapsed=33.666µs
Jul 16 16:56:25 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:25.465451 DEBUG response received addr=1.2.4.8:53 proto=udp status=ok
Jul 16 16:56:27 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:27.410912 ERROR response received addr=1.2.4.8:53 proto=udp status="exchanging with 1.2.4.8:53 over udp: read udp 10.1.62.33:30282->1.2.4.8:53: i/o timeout"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.413952 DEBUG handling new udp packet prefix=dnsproxy raddr=10.1.62.123:61303
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414004 DEBUG in prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 53731"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414010 DEBUG in prefix=dnsproxy line_num=2 line=";; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414014 DEBUG in prefix=dnsproxy line_num=3 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414018 DEBUG in prefix=dnsproxy line_num=4 line=";; OPT PSEUDOSECTION:"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414023 DEBUG in prefix=dnsproxy line_num=5 line="; EDNS: version 0; flags:; udp: 4096"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414027 DEBUG in prefix=dnsproxy line_num=6 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414031 DEBUG in prefix=dnsproxy line_num=7 line=";; QUESTION SECTION:"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414035 DEBUG in prefix=dnsproxy line_num=8 line=";apple.com.\tIN\t A"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414039 DEBUG in prefix=dnsproxy line_num=9 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414058 DEBUG replying from cache prefix=dnsproxy prefix=cache source="general cache" ecs_enabled=true
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414069 DEBUG out prefix=dnsproxy line_num=1 line=";; opcode: QUERY, status: NOERROR, id: 53731"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414073 DEBUG out prefix=dnsproxy line_num=2 line=";; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414076 DEBUG out prefix=dnsproxy line_num=3 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414080 DEBUG out prefix=dnsproxy line_num=4 line=";; OPT PSEUDOSECTION:"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414083 DEBUG out prefix=dnsproxy line_num=5 line="; EDNS: version 0; flags:; udp: 4096"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414086 DEBUG out prefix=dnsproxy line_num=6 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414088 DEBUG out prefix=dnsproxy line_num=7 line=";; QUESTION SECTION:"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414091 DEBUG out prefix=dnsproxy line_num=8 line=";apple.com.\tIN\t A"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414094 DEBUG out prefix=dnsproxy line_num=9 line=""
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414097 DEBUG out prefix=dnsproxy line_num=10 line=";; ANSWER SECTION:"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414101 DEBUG out prefix=dnsproxy line_num=11 line="apple.com.\t476\tIN\tA\t17.253.144.10"
Jul 16 16:56:28 DNS-Forwarder dnsproxy[8775]: 2024/07/16 16:56:28.414104 DEBUG out prefix=dnsproxy line_num=12 line=""

My dnsproxy config:

[Unit]
Description=Simple DNS proxy with DoH, DoT, DoQ and DNSCrypt support
After=syslog.target
After=network.target

[Service]
Restart=always
RestartSec=2s
Type=simple
WorkingDirectory=/opt/dns

ExecStart=/usr/local/bin/dnsproxy \
    --listen 0.0.0.0 -p 53 \
    --upstream /opt/dns/upstream.conf \
    --fallback /opt/dns/fallback.conf \
    --bootstrap=121.4.4.1:53 \
    --bootstrap=223.6.6.6:53 \
    --bootstrap=1.2.4.8:53 \
    --cache --cache-size=2147483648 \
    --cache-optimistic \
    --http3 \
    --upstream-mode=fastest_addr \
    --use-private-rdns \
    --private-rdns-upstream=10.1.62.1 \
    --edns \
    -v \
    --refuse-any
ExecStop=/bin/kill -SIGINT $MAINPID

CapabilityBoundingSet=CAP_NET_BIND_SERVICE
AmbientCapabilities=CAP_NET_BIND_SERVICE

LimitCPU=infinity
LimitFSIZE=infinity
LimitDATA=infinity
LimitSTACK=infinity
LimitCORE=infinity
LimitRSS=infinity
LimitNOFILE=infinity
LimitAS=infinity
LimitNPROC=infinity
LimitMEMLOCK=infinity
LimitLOCKS=infinity
LimitSIGPENDING=infinity
LimitMSGQUEUE=infinity
LimitRTPRIO=infinity
LimitRTTIME=infinity

[Install]
WantedBy=multi-user.target

My private upstream Encrypted DNS server is located in the same city as me and I have not encountered any performance issues when using the dnslookup tool to query it.

ZeroClover commented

I found that setting the upstream-mode to load_balance will not cause this issue. This issue only occurs when the upstream-mode is set to parallel or fastest_addr.

EugeneOne1 commented

@ZeroClover, hello! Thank you for your thorough report. We've pushed the fix for this issue, so the dnsproxy built from master should now set IDs properly. Could you please check it out?

ZeroClover commented

@EugeneOne1 After building dnsproxy from the current master branch, I have confirmed that this issue has been resolved.

  • 👍1
EugeneOne1 commented

@ZeroClover, thank you for testing it. We'll close it for now and will include this into the upcoming release.