Investigating slow DNS resolution in container
Some time ago, I had a curious case of very slow DNS resolution in a container on OpenShift. The symptoms were as follows:
- In the PHP application in the container, DNS resolution was very slow with a 5 second delay before the lookup was resolved
- In the container itself, DNS resolution for
curl
was very slow, with a 5 second timeout before the lookup was resolved - However, using
dig
in the container itself, DNS resolution was instant - Also, on the worker node, the DNS resolution was instant (using both
dig
andcurl
)
TL;DR: Since glibc 2.10, glibc performs IPv4 and IPv6 lookups in parallel. When IPv6 fails, there is a 5 second timeout in many cases before the lookup is returned. Disable IPv6 DNS lookups by setting “single-request” in “resolv.conf” or disable the IPv6 stack completely.
To debug the issue, I started curl
in the container and used the --write-out
option to show me where time was lost:
curl -vvv --header --write-out '\nlookup: %{time_namelookup}\nconnect: %{time_connect}\nappconnect: %{time_appconnect}\npretransfer: %{time_pretransfer}\nredirect: %{time_redirect}\nstarttransfer: %{time_starttransfer}\ntotal: %{time_total}\n' https://myapp.something.ch/something
[..]
lookup: 5.517
connect: 5.522
appconnect: 5.869
pretransfer: 5.873
redirect: 0.000
starttransfer: 7.187
total: 7.193
So clearly, the DNS lookup is taking too much time. Seeing that the lookup always takes around 5 seconds, we quickly suspected some kind of timeout. However, dig
in the container was always instant in looking up DNS. That was strange. So we started to actually strace
the process to see what happens:
strace -e trace=network -r -f curl -vvv --write-out '\nlookup: %{time_namelookup}\nconnect: %{time_connect}\nappconnect: %{time_appconnect}\npretransfer: %{time_pretransfer}\nredirect: %{time_redirect}\nstarttransfer: %{time_starttransfer}\ntotal: %{time_total}\n' https://myapp.something.ch/something
[..]
0.000000 socket(AF_INET6, SOCK_DGRAM, IPPROTO_IP) = 3
strace: Process 45 attached
[pid 45] 0.001007 socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
[pid 45] 0.000153 connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
[pid 45] 0.000804 socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
[pid 45] 0.000156 connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
[pid 45] 0.006068 socket(AF_INET, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP) = 3
[pid 45] 0.000143 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.140.10.217")}, 16) = 0
[pid 45] 0.000252 sendmmsg(3, {{{msg_name(0)=NULL, msg_iov(1)=[{"~\352\1\0\0\1\0\0\0\0\0\0\10myapp\tsomething\2"..., 63}], msg_controllen=0, msg_flags=MSG_OOB|MSG_DONTROUTE}, 63}, {{msg_name(0)=NULL, msg_iov(1)=[{"\0022\1\0\0\1\0\0\0\0\0\0\10myapp\tsomething\2"..., 63}], msg_controllen=0, msg_flags=0}, 63}}, 2, MSG_NOSIGNAL) = 2
[pid 45] 0.001548 recvfrom(3, "\0022\201\203\0\1\0\0\0\1\0\0\10myapp\tsomething\2"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.140.10.217")}, [16]) = 156
[pid 45] 5.003512 sendto(3, "~\352\1\0\0\1\0\0\0\0\0\0\10myapp\tsomething\2"..., 63, MSG_NOSIGNAL, NULL, 0) = 63
[pid 45] 0.001415 recvfrom(3, "~\352\201\203\0\1\0\0\0\1\0\0\10myapp\tsomething\2"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.140.10.217")}, [16]) = 156
[pid 45] 0.000486 sendto(3, "\0022\1\0\0\1\0\0\0\0\0\0\10myapp\tsomething\2"..., 63, MSG_NOSIGNAL, NULL, 0) = 63
[..]
So it looks like our DNS was responding pretty quickly, but our client would not continue until the 5 seconds have passed. Our containers were not using IPv6, so when I saw AF_INET6
in the log above, we quickly suspected something was going on with IPv6.
In the resolv.conf
man page, we just CTRL-F’d for “timeout” and quickly came across the section mentioning:
By default, glibc performs IPv4 and IPv6 lookups in parallel since version 2.9. Some appliance DNS servers cannot handle these queries properly and make the requests time out. This option disables the behavior and makes glibc perform the IPv6 and IPv4 requests sequentially (at the cost of some slowdown of the resolving process).
So it turns out that our worker node had an older version of “glibc” installed and was therefore not affected by this change. However, our container had a current version of “glibc”, which is why it showed the behaviour above. Also, as far as I can tell, dig
is not using “glibc” to resolve addresses, which is why we did not see the behaviour there.
So by setting single-request
in our resolv.conf
, we were able to resolve the issue of DNS resolution timeouts.