Can't start worker on MacOS

[bnaul]

On current master distributed-2.9.1+13.g7d2ed43c (and tornado==6.0.3), I get the following error on MacOS but not in Docker:

# already running dask scheduler
(.venv) ➜  model git:(nyc) ✗ PYTHONPATH=. dask-worker 'localhost:8786' --nthreads 1 --memory-limit 6GB --local-directory /tmp/ --nprocs 1
distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:55985'
objc[39479]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called.
objc[39479]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead. Set a breakpoint on objc_initializeAfterForkError to debug.
distributed.nanny - INFO - Worker process 39479 was killed by signal 6
tornado.application - ERROR - Exception in callback functools.partial(<bound method IOLoop._discard_future_result of <tornado.platform.asyncio.AsyncIOMainLoop object at 0x118220490>>, <Task finished coro=<Nanny._on_exit() done, defined at /Users/brett/model/.venv/lib/python3.7/site-packages/distributed/nanny.py:396> exception=TypeError('addresses should be strings or tuples, got None')>)
Traceback (most recent call last):
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/tornado/ioloop.py", line 743, in _run_callback
    ret = callback()
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/tornado/ioloop.py", line 767, in _discard_future_result
    future.result()
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/nanny.py", line 399, in _on_exit
    await self.scheduler.unregister(address=self.worker_address)
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/core.py", line 757, in send_recv_from_rpc
    result = await send_recv(comm=comm, op=key, **kwargs)
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/core.py", line 556, in send_recv
    raise exc.with_traceback(tb)
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/core.py", line 408, in handle_comm
    result = handler(comm, **msg)
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/scheduler.py", line 2122, in remove_worker
    address = self.coerce_address(address)
  File "/Users/brett/model/.venv/lib/python3.7/site-packages/distributed/scheduler.py", line 4831, in coerce_address
    raise TypeError("addresses should be strings or tuples, got %r" % (addr,))
TypeError: addresses should be strings or tuples, got None
distributed.nanny - INFO - Closing Nanny at 'tcp://127.0.0.1:55985'
distributed.dask_worker - INFO - End worker

No issues in the latest release (2.9.1). Possibly related to #3356 but I didn't see any similar error messages so I figured I'd keep it separate for now.

[quasiben]

I have a similar setup on MacOS but I can't reproduce. Can you also post your dask version ?

[mrocklin]

Brett, if you have the time, this sounds like a good opportunity to use git bisect

…

On Wed, Jan 15, 2020 at 11:35 AM Benjamin Zaitlen ***@***.***> wrote: I have a similar setup on MacOS but I can't reproduce. Can you also post your dask version ? — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#3374?email_source=notifications&email_token=AACKZTFLB5OBLV6KV66SGNLQ55QRNA5CNFSM4KHIKTX2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEJBRCWY#issuecomment-574820699>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AACKZTE6N3JSW2YGUT2CDN3Q55QRNANCNFSM4KHIKTXQ> .

[bnaul]

Hmm, I'm also not able to reproduce on a fresh virtualenv so perhaps it's related to some other installed packages. I'll try something like a bisect on my pip freeze and see what I find :)

[bnaul]

@mrocklin I did a bisect and found the offending commit: 32cb96effe9287fdc42dd73be36989be13abe99d is the first bad commit.

# crashes
(.venv)  ➜  distributed git:(32cb96ef) ✗ dask-worker localhost:8786 --nanny
distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:52119'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/brett/Dropbox/Documents/distributed/worker-g6fkk6vp', purging
objc[77514]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called.
objc[77514]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead. Set a breakpoint on objc_initializeAfterForkError to debug.
distributed.nanny - INFO - Worker process 77514 was killed by signal 6
distributed.nanny - INFO - Closing Nanny at 'tcp://127.0.0.1:52119'
distributed.dask_worker - INFO - End worker

# go back one commit, no more crash
(.venv)  ➜  distributed git:(32cb96ef) ✗ gco @~1
Previous HEAD position was 32cb96ef Rework version checking (#2627)
HEAD is now at f68119a4 Add websocket scheduler plugin (#3335)
(.venv)  ➜  distributed git:(f68119a4) ✗ dask-worker localhost:8786 --nanny
distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:52128'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/brett/Dropbox/Documents/distributed/worker-1r16h2w2', purging
distributed.dashboard.proxy - INFO - To route to workers diagnostics web server please install jupyter-server-proxy: pip install jupyter-server-proxy
distributed.worker - INFO -       Start worker at:      tcp://127.0.0.1:52133
distributed.worker - INFO -          Listening to:      tcp://127.0.0.1:52133
distributed.worker - INFO -          dashboard at:            127.0.0.1:52134
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - -------------------------------------------------
distributed.worker - INFO -               Threads:                          8
distributed.worker - INFO -                Memory:                   17.18 GB
distributed.worker - INFO -       Local Directory: /Users/brett/Dropbox/Documents/distributed/worker-by5wbx39
distributed.worker - INFO - -------------------------------------------------

Still having trouble nailing down exactly which other packages are causing a conflict (sort of hard to really "bisect" when there's so many interdependencies between things) but maybe something about that commit rings a bell to someone..?

[bnaul]

Update: there seems to be a bad interaction w/ bokeh..? But I still can't recreate on a fresh environment + distributed + bokeh so there's more to it than that 🤔

(dask_test)  ➜  distributed git:(master) ✗ pip uninstall -y bokeh
Uninstalling bokeh-1.4.0:
  Successfully uninstalled bokeh-1.4.0
(dask_test)  ➜  distributed git:(master) ✗ /Users/brett/venvs/dask_test/bin/dask-worker localhost:8786
distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:59081'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/brett/Dropbox/Documents/distributed/worker-7og5yzoa', purging
distributed.worker - INFO -       Start worker at:      tcp://127.0.0.1:59082
distributed.worker - INFO -          Listening to:      tcp://127.0.0.1:59082
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
...



(dask_test)  ➜  distributed git:(master) ✗ pip install bokeh
Successfully installed bokeh-1.4.0

(dask_test)  ➜  distributed git:(master) ✗ /Users/brett/venvs/dask_test/bin/dask-worker localhost:8786
distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:59603'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/brett/Dropbox/Documents/distributed/worker-ysqtkwgv', purging
objc[82717]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called.
objc[82717]: +[__NSPlaceholderDictionary initialize] may have been in progress in another thread when fork() was called. We cannot safely call it or ignore it in the fork() child process. Crashing instead. Set a breakpoint on objc_initializeAfterForkError to debug.
distributed.nanny - INFO - Worker process 82717 was killed by signal 6

[mrocklin]

Interesting. @bnaul can I ask you to try out #3394 ?

[mrocklin]

Wait, nm, scratch that. I got my comments crossed.

[bnaul]

Found the offending line: 32cb96e#diff-14c5e43ed851ac4e461cda22da5340a8L24. Adding pandas back to this list fixes the issue for me on master.

Maybe something to do with the order of imports? I couldn't reproduce by stepping through in a debugger so it could also just be a very sensitive race condition...?

Also forgot to mention above but --no-nanny also avoids the issue

[mrocklin]

Wow, that's a weird thing to hang on.

Can I ask you to add a time.sleep(0.5) in the get_version function and see if that would also make the problem go away? Pandas is notable in that it takes a little bit of time to import.

[mrocklin]

(also, thanks for searching and finding that there)

[bnaul]

I've been sprinkling some sleeps and can't seem to fix it but given the error message I assume it has to do with set_forkserver_preload(preload) where preload comes from {required,optional}_packages

[bnaul]

@mrocklin any suggestions for a possible workaround for this? @quasiben if you'd like to try to reproduce, the following steps work for me on 3.7.6:

venvs/dask/bin/python3 -m venv venvs/dask_test
source venvs/dask_test/bin/activate
pip install numpy==1.18.1 Cython==0.29.14
pip install distributed pandas bokeh lz4 dask_ml blosc  # these are all the packages involved in the lines I posted above
venvs/dask_test/bin/dask-worker localhost:8786 --nanny

Full resulting package list:

blosc==1.8.3
bokeh==1.4.0
Click==7.0
cloudpickle==1.2.2
Cython==0.29.14
dask==2.9.2
dask-glm==0.2.0
dask-ml==1.2.0
distributed==2.9.3
HeapDict==1.0.1
Jinja2==2.11.0
joblib==0.14.1
llvmlite==0.31.0
lz4==3.0.2
MarkupSafe==1.1.1
msgpack==0.6.2
multipledispatch==0.6.0
numba==0.47.0
numpy==1.18.1
packaging==20.1
pandas==0.25.3
Pillow==7.0.0
psutil==5.6.7
pyparsing==2.4.6
python-dateutil==2.8.1
pytz==2019.3
PyYAML==5.3
scikit-learn==0.22.1
scipy==1.4.1
six==1.14.0
sortedcontainers==2.1.0
tblib==1.6.0
toolz==0.10.0
tornado==6.0.3
zict==1.0.0

[jrbourbeau]

Thanks for the continuing to investigate on this @bnaul! I installed the set of packages listed (copied the full list into a requirements.txt file and pip installed them) in a fresh conda environment with Python 3.7.6, but wasn't able to reproduce the error. Here's the output I get after running dask-worker localhost:8786 --nanny:

dask worker output:

distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:64126'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/jbourbeau/Desktop/worker-gkoh4zuf', purging
distributed.dashboard.proxy - INFO - To route to workers diagnostics web server please install jupyter-server-proxy: pip install jupyter-server-proxy
distributed.worker - INFO -       Start worker at:      tcp://127.0.0.1:64127
distributed.worker - INFO -          Listening to:      tcp://127.0.0.1:64127
distributed.worker - INFO -          dashboard at:            127.0.0.1:64128
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - -------------------------------------------------
distributed.worker - INFO -               Threads:                          4
distributed.worker - INFO -                Memory:                    8.59 GB
distributed.worker - INFO -       Local Directory: /Users/jbourbeau/Desktop/worker-w7vu2nso
distributed.worker - INFO - -------------------------------------------------

We had a report about test failures on MacOS over in #3356. Just a shot in the dark, but does @quasiben's comment over there (#3356 (comment) and the following comment) apply to your system?

[bnaul]

I don't believe that's related based on the errors. @jrbourbeau any chance you're able to try w/ a homebrew Python install instead of conda? That seems like a pretty big difference and likely to explain the discrepancy.

[jrbourbeau]

Still getting a similar output when using Python 3.7.6 from homebrew:

distributed.nanny - INFO -         Start Nanny at: 'tcp://127.0.0.1:55503'
distributed.diskutils - INFO - Found stale lock file and directory '/Users/jbourbeau/Desktop/worker-w7vu2nso', purging
distributed.dashboard.proxy - INFO - To route to workers diagnostics web server please install jupyter-server-proxy: pip install jupyter-server-proxy
distributed.worker - INFO -       Start worker at:      tcp://127.0.0.1:55504
distributed.worker - INFO -          Listening to:      tcp://127.0.0.1:55504
distributed.worker - INFO -          dashboard at:            127.0.0.1:55505
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - -------------------------------------------------
distributed.worker - INFO -               Threads:                          4
distributed.worker - INFO -                Memory:                    8.59 GB
distributed.worker - INFO -       Local Directory: /Users/jbourbeau/Desktop/worker-0fw5zl57
distributed.worker - INFO - -------------------------------------------------
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786
distributed.worker - INFO - Waiting to connect to:       tcp://localhost:8786