Re: [Bug-wget] Slow DNS resolve (5 seconds)

[Adrian Grajdeanu]

Oooh, the miracles of open source. Been digging through the wget code 
and found me an answer. I should use -4 switch.
The issue was that even though ipv6 is disabled on the machine, wget is 
still trying to use it. Some might argue that this should not happen (as 
in that's a bug!), but based on its impact it may be too low a priority 
to warrant much fixing effort.

Adrian Grajdeanu wrote:
> Hi,
> I've noticed that wget 1.11.4 is very slow resolving hostnames via DNS. 
> Here is what I mean:
>  >time wget www.google.com
> --2008-11-30 09:27:07--  http://www.google.com/
> Resolving www.google.com... 64.233.169.103, 64.233.169.104, 
> 64.233.169.147, ...
> Connecting to www.google.com|64.233.169.103|:80... connected.
> HTTP request sent, awaiting response... 200 OK
> Length: unspecified [text/html]
> Saving to: `index.html.6'
>
>     [ <=>
>                ] 5,848       --.-K/s   in 0.01s
>
> 2008-11-30 09:27:12 (399 KB/s) - `index.html.6' saved [5848]
>
>
> real    0m5.047s
> user    0m0.002s
> sys     0m0.002s
>
> Notice realtime is 5 seconds and change. Five seconds are spent at the 
> Resolving www.google.com...
> line before answers are provided.
>
> Similar request using curl is 5 seconds faster:
>
>  >time curl www.google.com >index.html
>   % Total    % Received % Xferd  Average Speed   Time    Time     Time 
>  Current
>                                  Dload  Upload   Total   Spent    Left 
>  Speed
> 100  5848    0  5848    0     0  83808      0 --:--:-- --:--:-- --:--:-- 
>  311k
>
> real    0m0.073s
> user    0m0.001s
> sys     0m0.002s
>  >
>
> I've gone and strace the wget and found out a weird thing. Here are the 
> calls relevant to DNS request:
>
> socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
> connect(3, {sa_family=AF_INET, sin_port=htons(53), 
> sin_addr=inet_addr("68.105.28.12")}, 28) = 0
> fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
> fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
> poll([{fd=3, events=POLLOUT}], 1, 0)    = 1 ([{fd=3, revents=POLLOUT}])
> sendto(3, "\374\346\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\1\0\1"..., 
> 32, MSG_NOSIGNAL, NULL, 0) = 32
> poll([{fd=3, events=POLLIN|POLLOUT}], 1, 5000) = 1 ([{fd=3, 
> revents=POLLOUT}])
> sendto(3, "\37\347\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\34\0\1"..., 
> 32, MSG_NOSIGNAL, NULL, 0) = 32
> poll([{fd=3, events=POLLIN}], 1, 4999)  = 1 ([{fd=3, revents=POLLIN}])
> ioctl(3, FIONREAD, [340])               = 0
> recvfrom(3, 
> "\374\346\201\200\0\1\0\5\0\7\0\7\3www\6google\3com\0\0\1\0\1\300"..., 
> 2048, 0, {sa_family=AF_INET, sin_port=htons(53), 
> sin_addr=inet_addr("68.105.28.12")}, [16]) = 340
> poll([{fd=3, events=POLLIN}], 1, 4990)  = 0 (Timeout)
> close(3)                                = 0
>
> 68.105.28.12 is my DNS server. Notice two sendto calls, then one answer 
> (recvfrom) and then, just before close(3) the poll call that waits 5 
> seconds before timing out.
>
> A similar trace from wget 1.11.1 (no speed problem there) shows a 
> different picture:
>
> socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
> connect(3, {sa_family=AF_INET, sin_port=htons(53), 
> sin_addr=inet_addr("68.100.16.25")}, 28) = 0
> fcntl64(3, F_GETFL)                     = 0x2 (flags O_RDWR)
> fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
> gettimeofday({1228055607, 339121}, NULL) = 0
> poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
> send(3, "3\343\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\34\0\1", 32, 
> MSG_NOSIGNAL) = 32
> poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
> ioctl(3, FIONREAD, [100])               = 0
> recvfrom(3, 
> "3\343\201\200\0\1\0\1\0\1\0\0\3www\6google\3com\0\0\34\0\1"..., 1024, 
> 0, {sa_family=AF_INET, sin_port=htons(53), 
> sin_addr=inet_addr("68.100.16.25")}, [16]) = 100
> close(3)                                = 0
>
> This time there's only one send call, one answer (recvfrom) and that's 
> all, no timeout.
>
> My wget 1.11.4 is wget-1.11.4-1.fc10.x86_64 on a Fedora 10 machine 
> (x86_64). My wget 1.11.1 is wget-1.11.1-1.fc8 on a Fedora 8 32 bits 
> machine. Both machines have ipv6 disabled (lsmod | grep ipv6 returns 
> nothing, /sbin/ifconfig eth0 shows no ip6 addy).
>
> Any other information needed to pinpoint this issue?
>
>
> Cheers,
> Adrian