I've been trying to troubleshoot an issue where using a curl lookup command takes a long time (sometimes) and is quick some other time.
TL;DR
Question: how do i troubleshoot further.
Connecting directly to an ip-address has no issues.
I've tried two different locations, multiple machines (RPi, debian vm, Windows10).
I've tried to set nameservers to both 1.1.1.1 and to 8.8.8.8 with the same result
i've changed the /etc/resolv.conf so that it contains (and yes. i've writeprotected it)
options timeout:1
So now it nolongertakes 5 seconds before it succeeds in dns_resolution.. but 1.00xx seconds (sometimes) and sometimes 0.00xxx seconds.
For me it first looked like a firewall dropping packets issue or a ipv6-try issue. however i've disabled ipv6 on the machines, with no luck.
I've used this command to do the lookups:
while :; do curl --max-time 10 -w "time_namelookup: %{time_namelookup}, time_connect: %{time_connect}, time_appconnect: %{time_appconnect}, time_pretransfer: %{time_pretransfer}, time_redirect: %{time_redirect}, time_starttransfer: %{time_starttransfer}, time_total: %{time_total}\n" -o /dev/null -s "https://www.google.com"; sleep 1; done
and here is some sample result:
time_namelookup: 1.059151, time_connect: 1.083971, time_appconnect: 1.129219, time_pretransfer: 1.129803, time_redirect: 0.000000, time_starttransfer: 1.191138, time_total: 1.198772
time_namelookup: 1.058956, time_connect: 1.084363, time_appconnect: 1.130112, time_pretransfer: 1.131392, time_redirect: 0.000000, time_starttransfer: 1.291702, time_total: 1.300107
time_namelookup: 1.057719, time_connect: 1.083355, time_appconnect: 1.128083, time_pretransfer: 1.128726, time_redirect: 0.000000, time_starttransfer: 1.190859, time_total: 1.198635
time_namelookup: 0.018382, time_connect: 0.043042, time_appconnect: 0.077228, time_pretransfer: 0.077517, time_redirect: 0.000000, time_starttransfer: 0.142618, time_total: 0.150624
time_namelookup: 1.058276, time_connect: 1.082821, time_appconnect: 1.127496, time_pretransfer: 1.128083, time_redirect: 0.000000, time_starttransfer: 1.188930, time_total: 1.197614
time_namelookup: 0.023630, time_connect: 0.047877, time_appconnect: 0.079810, time_pretransfer: 0.080053, time_redirect: 0.000000, time_starttransfer: 0.136007, time_total: 0.141614
time_namelookup: 0.018607, time_connect: 0.043160, time_appconnect: 0.079620, time_pretransfer: 0.079966, time_redirect: 0.000000, time_starttransfer: 0.139617, time_total: 0.145728
time_namelookup: 1.059191, time_connect: 1.084436, time_appconnect: 1.127247, time_pretransfer: 1.127825, time_redirect: 0.000000, time_starttransfer: 1.189962, time_total: 1.199934
time_namelookup: 1.058040, time_connect: 1.083303, time_appconnect: 1.127172, time_pretransfer: 1.128314, time_redirect: 0.000000, time_starttransfer: 1.194481, time_total: 1.202276
time_namelookup: 0.018539, time_connect: 0.043664, time_appconnect: 0.079772, time_pretransfer: 0.080074, time_redirect: 0.000000, time_starttransfer: 0.141406, time_total: 0.147358
time_namelookup: 1.060180, time_connect: 1.084996, time_appconnect: 1.130302, time_pretransfer: 1.131054, time_redirect: 0.000000, time_starttransfer: 1.197778, time_total: 1.205363
time_namelookup: 0.031891, time_connect: 0.058458, time_appconnect: 0.097752, time_pretransfer: 0.098055, time_redirect: 0.000000, time_starttransfer: 0.157533, time_total: 0.188634
time_namelookup: 1.059059, time_connect: 1.083472, time_appconnect: 1.126565, time_pretransfer: 1.127196, time_redirect: 0.000000, time_starttransfer: 1.189149, time_total: 1.195730
time_namelookup: 0.023647, time_connect: 0.048197, time_appconnect: 0.082277, time_pretransfer: 0.082772, time_redirect: 0.000000, time_starttransfer: 0.143120, time_total: 0.149757
time_namelookup: 0.017073, time_connect: 0.041658, time_appconnect: 0.081927, time_pretransfer: 0.082310, time_redirect: 0.000000, time_starttransfer: 0.144873, time_total: 0.152739
time_namelookup: 0.017251, time_connect: 0.042056, time_appconnect: 0.079905, time_pretransfer: 0.080475, time_redirect: 0.000000, time_starttransfer: 0.141332, time_total: 0.147886
Doing a dig command however is VERY fast:
$ dig @dns.google google.com
; <<>> DiG 9.11.5-P4-5.1+deb10u8-Raspbian <<>> @dns.google google.com
; (2 servers found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 13497
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 512
;; QUESTION SECTION:
;google.com. IN A
;; ANSWER SECTION:
google.com. 221 IN A 172.217.19.78
;; Query time: 25 msec
;; SERVER: 8.8.4.4#53(8.8.4.4)
;; WHEN: Thu Feb 16 10:44:24 UTC 2023
;; MSG SIZE rcvd: 55
$ dig @1.1.1.1 google.com
; <<>> DiG 9.11.5-P4-5.1+deb10u8-Raspbian <<>> @1.1.1.1 google.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 54885
;; flags: qr rd ra; QUERY: 1, ANSWER: 6, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;google.com. IN A
;; ANSWER SECTION:
google.com. 65 IN A 142.250.147.101
google.com. 65 IN A 142.250.147.113
google.com. 65 IN A 142.250.147.138
google.com. 65 IN A 142.250.147.139
google.com. 65 IN A 142.250.147.100
google.com. 65 IN A 142.250.147.102
;; Query time: 13 msec
;; SERVER: 1.1.1.1#53(1.1.1.1)
;; WHEN: Thu Feb 16 10:44:33 UTC 2023
;; MSG SIZE rcvd: 135
This is similar across multiple internet connection outgoing originating from Denmark
I also had some findings where there was no issues at all. dns resolution was fast etc on one device while there was issues on a other device running though the same ASN-no but different sub ip-range.
MTR/traceroute shows no signs of issues. im just not sure why it goes to 100.x.x.x ip address, but there must be some kind of routing. This does not happen on the other connections
My traceroute [v0.92]
devicename (xx.x.x.xxx) 2023-02-16T11:50:47+0000
Keys: Help Display mode Restart statistics Order of fields quit
Packets Pings
Host Loss% Snt Last Avg Best Wrst StDev
1. xx.x.x.x 0.0% 211 3.0 2.2 1.4 8.3 0.8
2. 31.3.xx.xxx 0.0% 211 1.7 2.1 1.4 7.3 0.7
3. 100.64.x.xxx 0.0% 211 6.8 8.1 6.1 37.8 3.5
4. 94.127.48.17 1.4% 211 7.4 8.3 6.1 48.0 6.3
5. xe-2-1-0-311.alb2nqe10.d 0.0% 211 6.9 9.4 6.3 46.4 6.3
6. ae0-0.stkm2nqp7.se.ip.td 0.0% 211 15.7 16.4 14.8 35.1 2.8
7. 72.14.214.162 0.0% 211 17.4 17.1 15.3 33.4 2.7
8. 209.85.254.3 0.0% 211 16.1 17.0 15.4 48.7 3.8
9. 108.170.253.181 0.9% 211 18.4 17.8 15.2 60.1 6.2
10. 108.170.227.249 10.0% 211 20.6 17.8 15.4 41.2 4.2
209.85.246.61
11. 142.251.51.215 2.8% 211 26.7 26.4 24.0 54.7 4.6
209.85.248.7
12. 142.250.214.184 1.4% 210 44.6 25.9 23.7 48.6 4.1
142.251.239.219
13. 172.253.70.203 0.5% 210 25.1 24.8 23.9 28.2 0.6
142.250.46.23
14. ???
15. ???
16. ???
17. ???
18. ???
19. ???
20. ???
21. ???
22. ???
23. rd-in-f139.1e100.net 38.3% 210 24.8 25.0 24.1 30.7 0.7
Traceroute shows that it goes to one actual ip address and then to a bogus (100.x.x.x) ip adddress.
traceroute to google.com (142.250.147.102), 30 hops max, 60 byte packets
1 xx.x.x.x (xx.x.x.x) 2.436 ms 2.624 ms 2.510 ms
2 31.3.xx.xxx (31.3.xx.xxx) 2.392 ms 2.941 ms 2.834 ms
3 100.64.x.xxx (100.64.x.xxx) 6.451 ms 6.629 ms 6.519 ms
4 94.127.48.17 (94.127.48.17) 6.403 ms 6.600 ms 6.762 ms
5 xe-2-1-0-311.alb2nqe10.dk.ip.tdc.net (87.48.169.225) 6.653 ms 8.382 ms 8.074 ms
6 ae0-0.stkm2nqp7.se.ip.tdc.net (83.88.2.128) 16.956 ms 16.121 ms 15.401 ms
7 72.14.214.162 (72.14.214.162) 16.827 ms 16.741 ms 16.650 ms
8 * * *
9 108.170.254.33 (108.170.254.33) 17.564 ms 209.85.242.10 (209.85.242.10) 16.346 ms 108.170.253.161 (108.170.253.161) 17.412 ms
10 108.170.254.38 (108.170.254.38) 17.255 ms 108.170.253.182 (108.170.253.182) 17.105 ms 108.170.254.54 (108.170.254.54) 16.645 ms
11 209.85.246.61 (209.85.246.61) 16.484 ms 72.14.234.107 (72.14.234.107) 17.352 ms 142.250.235.228 (142.250.235.228) 17.045 ms
12 108.170.236.41 (108.170.236.41) 26.269 ms 26.088 ms 142.251.51.217 (142.251.51.217) 26.110 ms
13 142.251.239.219 (142.251.239.219) 24.352 ms 142.250.214.198 (142.250.214.198) 26.021 ms 142.250.214.178 (142.250.214.178) 26.295 ms
14 142.250.214.229 (142.250.214.229) 25.056 ms 142.250.215.9 (142.250.215.9) 25.494 ms 142.250.229.93 (142.250.229.93) 25.310 ms
15 * * *
16 * * *
17 * * *
18 * * *
19 * * *
20 * * *
21 * * *
22 * * *
23 * rd-in-f102.1e100.net (142.250.147.102) 25.956 ms *
