Repository navigation
Print a message if getaddrinfo is slow on startup #4600
Description
On server startup, we call get_local_ips which in turn calls getaddrinfo for a few host names.
Under some circumstances, this step can take a while. It is done before we print any messages to the log or console, so this can be confusing. @deontologician ran into a case where the server was taking 15-30 seconds to come up, and we didn't know what was going on at first.
It would be nice if we could detect that the process is taking a while, and print a message about what's going on in that case.
This probably doesn't come up much in normal configurations.
In our case it happened because the OS X machine just had its hostname changed. After a reboot things were fine again. Hence pretty low priority...
Activity
rmg commentedon Aug 29, 2015
This also comes up when offline, as I discovered during a power outage. My laptop still runs, but WiFi is down, so my rethink docker container went from 2s startup to 24s startup. Fun to debug with access to the Internet only through a 3g tablet. But I did manage to come to the same conclusion as this issue through code inspection on github before landing here!
pdonorio commentedon Sep 6, 2016
I can confirm the problem offline, around ~30s (kinda frozen) if wifi is off or unreachable. Would it be possible to add an option on the command line to skip the operation?
danielmewes commentedon Sep 6, 2016
@pdonorio That sounds reasonable I think. I'm not 100% sure what we currently do the address lookup for. It might be important somehow, but most likely we can do without it.
pdonorio commentedon Sep 6, 2016
Ah great! Thanks!
Make sure that is really nothing important, but if you want my guess
it probably checks rethinkdb installed binary version against your website to tell the user when he should upgrade.
danielmewes commentedon Sep 6, 2016
@pdonorio I don't think the version check is the issue. The version check runs in the background and will not block a RethinkDB server from starting up (you can start with
--no-version-checkto verify this). Thegetaddrinfothat's blocking is one that's related to figuring out the interfaces to bind on I think.pdonorio commentedon Sep 6, 2016
I can confirm that with wifi disabled and
rethinkdb --no-update-checkthe issue is still there.Now that I recall, I had a similar app hanging with
socket.gethostbyaddrin python, of course when offline. Since there were no options to use a shorter timeout it ended up with skipping the call when you know you are disconnected.nenuko commentedon Nov 28, 2016
Hi! I've removed Google Public DNS of my Network preferences (OSX) and it worked
irae commentedon Dec 9, 2016
Thanks @nenuko! Based on your finding, although I was not using Google DNS, it got me trying stuff. Finally, this is what I did to solve it:
Reboot, and the issue is gone.
sorccu commentedon Feb 6, 2017
This has been happening with a docker setup we have, albeit not on all hosts. They're all Linux machines.
One one host, we're seeing a ~16s delay. Here's what I've found:
strace rethinkdb --cache-size 192 --no-update-checkf7b84f15e3d3d) 4 times. The hostname is configured in /etc/hosts, so it's not quite clear why it's attempting to look it up anyway.dig f7b84f15e3d3d @192.168.1.1(where 192.168.1.1 is the nameserver in/etc/resolv.conf) showed that it was taking about 4100ms to respond to each request, obviously finding nothing. Since according to strace it did this 4 times, it corresponds quite well with the 16 second total delay. Other non-existing host names have the same delay, too.Indeed it seems that the issue, at least in this case, is caused by a badly configured DNS server. However, it also feels like there are a few things that could be done to prevent this from being as much of an issue. First, it's not clear why the DNS lookup is done 4 times. Second, it's not clear why the dns lookup is being done at all - after all it was present in
/etc/hosts(and strace confirms that before each dns lookup,/etc/hostswas indeed read as well). Finally, it feels like specifying the server name manually with-nshould help with this issue but it doesn't seem to change anything.sorccu commentedon Feb 13, 2017
FWIW, the following does not reduce the ~16s delay in any way:
Seems like it might be doing DNS queries for the default binds (which include the hostname) even if a custom bind is provided.
Add the startup flag --no-dns-resolution to fix issue rethinkdb#4600.
Don't use DNS resolution when finding local ip addresses.
Don't use DNS resolution when finding local ip addresses.
srh commentedon Jan 8, 2018
It turns out that using
getaddrinfoon the hostname was the wrong thing to do. And the best of it is, we didn't even use the result ofgetaddrinfothanks to the loopback filtering logic mixing up a boolean -- instead of filtering out loopback addresses, it filtered out non-loopback addresses.sholladay commentedon Jan 22, 2018
@srh nice detective work. Your fix has me pretty excited. This has affected me for as long as I've been using RethinkDB and it's been a real pain.
What kind of startup time should I expect from a typical dev laptop (e.g. 2.3Ghz 2012 Macbook Pro)?
srh commentedon Jan 22, 2018
On my 2.7Ghz 2012 MBP it's 0.57 seconds with me manually recording it on a stopwatch.
With old binaries you can use the instructions at #6047 (comment) to mitigate this on macOS.
Don't use DNS resolution when finding local ip addresses.
Don't use DNS resolution when finding local ip addresses.