Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Startup takes over 40 seconds on macOS Sierra #6047

Closed
nodesocket opened this issue Aug 12, 2016 · 33 comments
Closed

Startup takes over 40 seconds on macOS Sierra #6047

nodesocket opened this issue Aug 12, 2016 · 33 comments
Milestone

Comments

@nodesocket
Copy link

nodesocket commented Aug 12, 2016

Starting up Rethinkdb 2.3.4 on the beta of macOS Sierra takes over 40 seconds even with no data. Any idea what could be happening? Installed RethinkDB via brew.

screen shot 2016-08-12 at 5 03 29 pm

Running rethinkdb 2.3.4 (CLANG 7.3.0 (clang-703.0.31))...
Running on Darwin 16.0.0 x86_64

Here is the configuration I am using:

directory=/Users/justin/Sites/my-project/rethinkdb/data
log-file=/Users/justin/Sites/my-project/rethinkdb/rethinkdb.log
bind=127.0.0.1
http-port=8000
cache-size=128
@nodesocket nodesocket changed the title Fresh startup takes over 40 seconds on macOS Sierra Startup takes over 40 seconds on macOS Sierra Aug 12, 2016
@danielmewes
Copy link
Member

That's odd.
If I remember correctly we've had a case where the start was delayed due to DNS lookups. I think we have a GitHub issue on that, but I can't find it right now.

Can you try adding the option no-default-bind to the configuration file and see if that changes anything?

After which console/log message (if any) is it taking the 40 seconds?

@danielmewes danielmewes added this to the 2.3.x milestone Aug 12, 2016
@nodesocket
Copy link
Author

no-default-bind did not help. Nothing is logged for maybe 40 seconds, then see:

2016-08-12T20:52:49.971142000 40.645290s notice: Running rethinkdb 2.3.4 (CLANG 7.3.0 (clang-703.0.31))...
2016-08-12T20:52:49.979863000 40.654007s notice: Running on Darwin 16.0.0 x86_64

@danielmewes
Copy link
Member

Nothing is logged for maybe 40 seconds, then see:

Ok if my memory serves me right, that's the same symptom which we've had the previous time. I'll try a bit more to find the other issue. GitHub search isn't too great...

@danielmewes
Copy link
Member

Found it: #4600

Can you try restarting your computer and see if the issue persists? (if you haven't done so already)

@larkost
Copy link
Collaborator

larkost commented Aug 12, 2016

I have setup one of the computers in our office on MacOS Sierra and am not able to reproduce this issue on either the current next or the v2.3.4 tag compiling directly. It is possible that there is some problem induced by using brew[1], but that is more of a guess rather than a well-reasoned argument.

[1] Side note: I am not a fan of brew generally, and in the case of RethinkDB you can use ./configure --fetch all to get a better result without any more work (but probably a bit more compile time). I have no evidence that this is responsible, or even involved, in this case.

@nodesocket
Copy link
Author

Just rebooted, and still seeing the same behavior. I am guessing this is related to macOS Sierra. How can I tell what is happening during these 40 or so seconds?

@nodesocket
Copy link
Author

nodesocket commented Aug 12, 2016

Here is a gif I made as well showing the behavior. Darn, not that useful, but you get the idea.

rethinkdb-startup

@larkost
Copy link
Collaborator

larkost commented Aug 12, 2016

You could try sending us the output of spindump. Here is a line for the bash shell that should capture it:

./build/debug_clang/rethinkdb 1>/dev/null && sleep 0.5 & sudo spindump rethinkdb

Note that there are two things you need to do first to make sure this goes well:

  1. Run sudo -v shortly before running this command so that it takes you password then, rather than during the command.
  2. Run killall rethinkdb before and after the command to get rid of any other RethinkDB process (so it samples the one that just started).

Then send the spindump to either karl (me) or daniel @rethinkdb.com and we can try to make sense of it.

But I don't think that this is a generic issue on Sierra.

@nodesocket
Copy link
Author

Where do I run:

./build/debug_clang/rethinkdb 1>/dev/null && sleep 0.5 & sudo spindump rethinkdb

I.E. what should be the current working dir to invoke ./build/debug_clang/rethinkdb?

@larkost
Copy link
Collaborator

larkost commented Aug 12, 2016

sorry... I forgot to modify that. Please remove the ./build/debug_clang/ from the front, so:

rethinkdb 1>/dev/null && sleep 0.5 & sudo spindump rethinkdb

@nodesocket
Copy link
Author

I don't think it is working right, I have to control + c out of that command.

➜  Desktop rethinkdb 1>/dev/null && sleep 0.5 & sudo spindump rethinkdb
warn: Cache size does not leave much memory for server and query overhead (available memory: 661 MB).
warn: Cache size is very low and may impact performance.



^C[1] 2166
Cannot find process with pid or partial name rethinkdb
➜  Desktop
[1]  + 2166 done       sleep 0.5
➜  Desktop

@larkost
Copy link
Collaborator

larkost commented Aug 13, 2016

It looks like you are using a shell other than bash, and I don't immediately know what shell you are using. You will need to alter it to fit whatever shell you are using.

@nodesocket
Copy link
Author

I am using zsh, that command should work right?

@larkost
Copy link
Collaborator

larkost commented Aug 16, 2016

Different shells do things differently. I just worked out what zsh needs for this:
rethinkdb 1>/dev/null & sleep 0.5 && sudo spindump rethinkdb

@nodesocket
Copy link
Author

@larkost, just e-mailed the spindump to you and @danielmewes. Let me know what you find. Thanks so much!

@larkost
Copy link
Collaborator

larkost commented Aug 17, 2016

The spindup confirms that you are having network translation issues (specifically in getaddrinfo), so RethinkDB is waiting for the OS to return information about network interfaces. Since that list is required for us to be able to then connect to them (so others can connect to us), there is not a lot we can do, other than maybe put a timer on that request and print a message if we don't get the information by some deadline.

But on a more general level, this is very unlikely to be an actual problem in our code, and more likely to be some bad interaction between MacOS Sierra and something else on your network (my money would be on something mDNS related, like an old AppleTV or AirPort router).

@danielmewes: should we make this report an effort to report when it takes, say 5 or 10 seconds to do that?

@danielmewes
Copy link
Member

Let's merge this with #4600 . It still seems like a fairly rare issue (hence low priority), but we should keep an eye on it and prioritize it more if it hits more people.

@danielmewes danielmewes modified the milestones: duplicate, 2.3.x Aug 17, 2016
@tjramage
Copy link

tjramage commented Oct 3, 2016

@danielmewes I just updated to Sierra and I'm seeing the exact same issue. Running on a MacBook Pro (early 2015). Was fine in El Capitan... @nodesocket I don't suppose you figured out a workaround?

@nodesocket
Copy link
Author

Nope, still seeing long startup times consistently on:

screen shot 2016-10-03 at 2 56 33 pm

@tjramage
Copy link

tjramage commented Oct 3, 2016

Ah, that's a shame. Have you tried uninstalling from brew and using the installer rethinkdb.pkg instead?

@tjramage
Copy link

tjramage commented Oct 3, 2016

...never mind – don't bother! It doesn't change anything.

@scottmartin
Copy link

I just ran into this yesterday. RethinkDB worked fine under El Capitan. I did a clean install of Sierra over the weekend and installed RethinkDB from scratch and now it takes forever to boot.

@scottmartin
Copy link

I just got the chance to work on my project again, and RethinkDB all the sudden works fine now.

@nodesocket
Copy link
Author

Just throwing this out there.

Poll on macOS 10.12 is broken

Could that be related to RethinkDB taking a long time to startup?

@srh
Copy link
Contributor

srh commented Oct 12, 2016

On OS X it uses kqueue.

I noticed that I had the problem at first at home but then it went away. Then I went to Starbucks today, and there had the slow startup again. But then it went away.

@irae
Copy link

irae commented Dec 9, 2016

So... I had no issue a couple of days ago, and suddenly I was having this issue consistently. Here is how I fixed:

I realized I recently renamed my computer. What I had done:
Got to System Preferences > Sharing > Computer name: [new name]

And then I realized a bunch of caches might be influenced by this. I googled a bit and found this commands to set the name in different ways:

sudo hostname [new name]
sudo scutil --set ComputerName [new name]
sudo scutil --set LocalHostName [new name]
sudo scutil --set HostName [new name]
dscacheutil -flushcache

Reboot, and the issue is gone.

@tjramage
Copy link

Awesome. That has fixed the issue for me! Thanks for sharing @irae.

@sorccu
Copy link

sorccu commented Jan 24, 2017

In particular, it seems to be HostName that causes issues. It was unset for me. As soon as I gave it a value the delay went away completely. Did not have to reboot, and I did not touch the other values. On 10.12.2 at the time of writing. Could this perhaps be related to the default server name generation algorithm?

@zappjones
Copy link

We have also been having this issue while running rethinkdb 2.3.5 and macOS Sierra.
The solution seems to have been what sorccu pointed out with
sudo scutil --set HostName [new name]
One gotcha we ran into was to make sure your host name does not include a . character.
Our default host names were user-mac.local and once we removed the . it seemed to work fine.

Looks like this might be fixed with openstf/stf#509 but wanted to leave some bread crumbs in case someone else hits what we ran into.

Thanks!

@sorccu
Copy link

sorccu commented Mar 9, 2017 via email

@oldlam
Copy link

oldlam commented Apr 5, 2017

guess this should be the root cause of this issue on Mac,
in Sierra if nothing is being enabled in Sharing of System Preferences,
then bonjour is not advertising the machine,
which makes the machine itself also cannot reach anything with the hostname,
try enabling anything in Sharing then ping your hostname (with .local one) and you'll be able to reach it.

so it's not related to the hostname setting on Mac,
(for sure if you're setting something w/o .local, which seems to fix it but I don't think it's the proper way)
basically it's pointing to the same problem as on Linux when DNS is very slow to respond @sorccu mentioned above.
which means it's not an issue specific on Mac only.

though... I don't have a proper solution to the problem yet.
there should be something can be done in rethinkdb startup steps to avoid/reduce this problem.
so it just probably circles back to #4600

REF:
https://discussions.apple.com/thread/7721616?start=0&tstart=0

@estrellajm
Copy link

Thanks!!! Ran into this issue. I reinstalled my OSX, and the rethinkdb was slow to load. I ran sudo scutil --set HostName [new name] and it fixed it. No clue how, but it did. Thanks @zappjones @irae. I didn't even have to reboot, so I guess that's good.

Thanks for that explanation @oldlam

@sholladay
Copy link

I had .local at the end of my HostName. I am pretty sure I did that for a reason at some point, but if so, it no longer seems to be relevant.

Running sudo scutil --set HostName 'My-Laptop' fixed it for me. 👌

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests