Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

Using wget (curl, httplib2) I always get a 5 second resolving timeout. This issue doesn't arrive when I do wget -4 or wget -6. Resolving also works using dig or host. Delay can be lowered using "options timeout:2" in /etc/resolv.conf

The strace output of this is:

15:19:09.908234 uname({sys="Linux", node="openkvk", ...}) = 0 
15:19:09.908413 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3 
15:19:09.908482 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, 16) = 0 
15:19:09.908569 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) 
15:19:09.908637 sendto(3, "F\347\1\0\0\1\0\0\0\0\0\0\10slashdot\3org\0\0\1\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30 
15:19:09.908735 poll([{fd=3, events=POLLIN|POLLOUT}], 1, 5000) = 1 ([{fd=3, revents=POLLOUT}])
15:19:09.908804 sendto(3, "F\331\1\0\0\1\0\0\0\0\0\0\10slashdot\3org\0\0\34\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30 
15:19:09.908884 poll([{fd=3, events=POLLIN}], 1, 4999) = 1 ([{fd=3, revents=POLLIN}]) 
15:19:09.911230 ioctl(3, FIONREAD, [46]) = 0 
15:19:09.911308 recvfrom(3, "F\347\201\200\0\1\0\1\0\0\0\0\10slashdot\3org\0\0\1\0\1\300\f"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 46 
15:19:09.911445 poll([{fd=3, events=POLLIN}], 1, 4997) = 0 (Timeout) 
15:19:14.909096 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) 
15:19:14.909189 sendto(3, "F\347\1\0\0\1\0\0\0\0\0\0\10slashdot\3org\0\0\1\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30 
15:19:14.909292 poll([{fd=3, events=POLLIN}], 1, 5000) = 1 ([{fd=3, revents=POLLIN}]) 
15:19:14.911569 ioctl(3, FIONREAD, [46]) = 0 
15:19:14.911644 recvfrom(3, "F\347\201\200\0\1\0\1\0\0\0\0\10slashdot\3org\0\0\1\0\1\300\f"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 46 
15:19:14.911772 poll([{fd=3, events=POLLOUT}], 1, 4997) = 1 ([{fd=3, revents=POLLOUT}]) 
15:19:14.911837 sendto(3, "F\331\1\0\0\1\0\0\0\0\0\0\10slashdot\3org\0\0\34\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30 
15:19:14.912051 poll([{fd=3, events=POLLIN}], 1, 4997) = 1 ([{fd=3, revents=POLLIN}]) 
15:19:14.914034 ioctl(3, FIONREAD, [106]) = 0

Tcpdump output:

tcpdump -vvv  port 53 
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes 
15:19:09.908687 IP (tos 0x0, ttl 64, id 37830, offset 0, flags [DF], proto UDP (17), length 58) 
    93.157.136.242.38551 > 212.83.206.202.domain: [bad udp cksum 3576!] 18151+ A? slashdot.org. (30) 
15:19:09.908852 IP (tos 0x0, ttl 64, id 37831, offset 0, flags [DF], proto UDP (17), length 58) 
    93.157.136.242.38551 > 212.83.206.202.domain: [bad udp cksum 2876!] 18137+ AAAA? slashdot.org. (30) 
15:19:09.911081 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 74) 
    212.83.206.202.domain > 93.157.136.242.38551: [udp sum ok] 18151 q: A? slashdot.org. 1/0/0 slashdot.org. [22m21s] A 216.34.181.45 (46) 
15:19:14.909246 IP (tos 0x0, ttl 64, id 37832, offset 0, flags [DF], proto UDP (17), length 58) 
    93.157.136.242.38551 > 212.83.206.202.domain: [bad udp cksum 3576!] 18151+ A? slashdot.org. (30) 
15:19:14.911442 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 74) 
    212.83.206.202.domain > 93.157.136.242.38551: [udp sum ok] 18151 q: A? slashdot.org. 1/0/0 slashdot.org. [22m16s] A 216.34.181.45 (46) 
15:19:14.911882 IP (tos 0x0, ttl 64, id 37833, offset 0, flags [DF], proto UDP (17), length 58) 
    93.157.136.242.38551 > 212.83.206.202.domain: [bad udp cksum 2876!] 18137+ AAAA? slashdot.org. (30) 
15:19:14.913906 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 134) 
    212.83.206.202.domain > 93.157.136.242.38551: [udp sum ok] 18137 q: AAAA? slashdot.org. 0/1/0 ns: slashdot.org. [3m39s] SOA ns-1.ch3.sourceforge.com. hostmaster.corp.sourceforge.com. 2011101300 14400 1800 604800 3600 (106) 

Tools like dig/host perform similar to using wget -4 or wget -6, instant, without any problem.

I have tried each of the following servers individually.

nameserver 2001:4018:3:12::202
nameserver 2001:4018:1:64::202
nameserver 212.83.206.202
nameserver 213.207.64.202
nameserver 8.8.8.8
nameserver 8.8.4.4

What could cause this delay?

Requested output: wget -4 (works)

23:41:10.428217 IP (tos 0x0, ttl 64, id 11790, offset 0, flags [DF], proto UDP (17), length 55)
    93.157.136.242.51379 > 212.83.206.202.domain: [bad udp cksum e070!] 65414+ A? vircon.nl. (27)
23:41:10.430442 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 71)
    212.83.206.202.domain > 93.157.136.242.51379: [udp sum ok] 65414 q: A? vircon.nl. 1/0/0 vircon.nl. [15h59m29s] A 31.193.104.52 (43)

23:41:10.427920 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3
23:41:10.427982 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, 16) = 0
23:41:10.428095 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
23:41:10.428166 sendto(3, "\377\206\1\0\0\1\0\0\0\0\0\0\6vircon\2nl\0\0\1\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
23:41:10.428262 poll([{fd=3, events=POLLIN}], 1, 5000) = 1 ([{fd=3, revents=POLLIN}])
23:41:10.430572 ioctl(3, FIONREAD, [43]) = 0
23:41:10.430651 recvfrom(3, "\377\206\201\200\0\1\0\1\0\0\0\0\6vircon\2nl\0\0\1\0\1\300\f\0\1\0"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 43
23:41:10.430774 close(3)  

wget (broken)

23:40:13.577621 IP (tos 0x0, ttl 64, id 20475, offset 0, flags [DF], proto UDP (17), length 55)
    93.157.136.242.55276 > 212.83.206.202.domain: [bad udp cksum 16c!] 62764+ A? vircon.nl. (27)
23:40:13.577786 IP (tos 0x0, ttl 64, id 20476, offset 0, flags [DF], proto UDP (17), length 55)
    93.157.136.242.55276 > 212.83.206.202.domain: [bad udp cksum 9654!] 61847+ AAAA? vircon.nl. (27)
23:40:13.579879 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 71)
    212.83.206.202.domain > 93.157.136.242.55276: [udp sum ok] 62764 q: A? vircon.nl. 1/0/0 vircon.nl. [22h20m8s] A 31.193.104.52 (43)
23:40:18.582490 IP (tos 0x0, ttl 64, id 20477, offset 0, flags [DF], proto UDP (17), length 55)
    93.157.136.242.55276 > 212.83.206.202.domain: [bad udp cksum 16c!] 62764+ A? vircon.nl. (27)
23:40:18.584709 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 71)
    212.83.206.202.domain > 93.157.136.242.55276: [udp sum ok] 62764 q: A? vircon.nl. 1/0/0 vircon.nl. [16h21s] A 31.193.104.52 (43)
23:40:18.585163 IP (tos 0x0, ttl 64, id 20478, offset 0, flags [DF], proto UDP (17), length 55)
    93.157.136.242.55276 > 212.83.206.202.domain: [bad udp cksum 9654!] 61847+ AAAA? vircon.nl. (27)
23:40:18.587212 IP (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto UDP (17), length 106)
    212.83.206.202.domain > 93.157.136.242.55276: [udp sum ok] 61847 q: AAAA? vircon.nl. 0/1/0 ns: vircon.nl. [56m25s] SOA ns1.vircon.nl. hostmaster.vircon.nl. 2011120602 10800 3600 604800 86400 (78)

23:40:13.577353 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3
23:40:13.577417 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, 16) = 0
23:40:13.577502 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
23:40:13.577572 sendto(3, "\365,\1\0\0\1\0\0\0\0\0\0\6vircon\2nl\0\0\1\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
23:40:13.577667 poll([{fd=3, events=POLLIN|POLLOUT}], 1, 5000) = 1 ([{fd=3, revents=POLLOUT}])
23:40:13.577737 sendto(3, "\361\227\1\0\0\1\0\0\0\0\0\0\6vircon\2nl\0\0\34\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
23:40:13.577892 poll([{fd=3, events=POLLIN}], 1, 4999) = 1 ([{fd=3, revents=POLLIN}])
23:40:13.580007 ioctl(3, FIONREAD, [43]) = 0
23:40:13.580105 recvfrom(3, "\365,\201\200\0\1\0\1\0\0\0\0\6vircon\2nl\0\0\1\0\1\300\f\0\1\0"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 43
23:40:13.580229 poll([{fd=3, events=POLLIN}], 1, 4997) = 0 (Timeout)
23:40:18.582338 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
23:40:18.582433 sendto(3, "\365,\1\0\0\1\0\0\0\0\0\0\6vircon\2nl\0\0\1\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
23:40:18.582535 poll([{fd=3, events=POLLIN}], 1, 5000) = 1 ([{fd=3, revents=POLLIN}])
23:40:18.584835 ioctl(3, FIONREAD, [43]) = 0
23:40:18.584912 recvfrom(3, "\365,\201\200\0\1\0\1\0\0\0\0\6vircon\2nl\0\0\1\0\1\300\f\0\1\0"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 43
23:40:18.585048 poll([{fd=3, events=POLLOUT}], 1, 4997) = 1 ([{fd=3, revents=POLLOUT}])
23:40:18.585117 sendto(3, "\361\227\1\0\0\1\0\0\0\0\0\0\6vircon\2nl\0\0\34\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
23:40:18.585300 poll([{fd=3, events=POLLIN}], 1, 4997) = 1 ([{fd=3, revents=POLLIN}])
23:40:18.587325 ioctl(3, FIONREAD, [78]) = 0
23:40:18.587394 recvfrom(3, "\361\227\201\200\0\1\0\0\0\1\0\0\6vircon\2nl\0\0\34\0\1\300\f\0\6\0"..., 2005, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("212.83.206.202")}, [16]) = 78
23:40:18.587513 close(3) 
share|improve this question
    
So what is the question? Beside having a really really bad DNS setup. –  mailq Dec 10 '11 at 22:16
    
Can you experiment with different nameservers to see if it only occurs with a particular nameserver? –  growse Dec 10 '11 at 22:17
    
I have already tried 6 dns servers. Given that there is an instant reply on wget -4, wget -6, dig, host. I doubt it is DNS. It is the resolver itself. (Or something that the resolver executes...) –  Stefan de Konink Dec 10 '11 at 22:25
1  
Can you compare and contrast the strace / tcpdump output between the wget that's causing issues and a more successful wget -4 or dig? –  growse Dec 10 '11 at 22:32
1  
I must admit I'm not sure what's going on here. The only insight I can offer is that wget is making both A and AAAA requests and could be waiting for both to return before returning the resolution result. Specifying -4 narrows it down to a single request which goes through instantly. Why this happens, don't know :( –  growse Dec 10 '11 at 22:59

1 Answer 1

up vote 6 down vote accepted

Your problem is described on http://udrepper.livejournal.com/20948.html, and is caused by a parallel lookup on both IPv4 and IPv6 which doesn't work together with some DNS servers and firewalls.

It can be fixed by adding "single-request" to the options in /etc/resolv.conf as the link above mentions.

share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.