Potential race condition in Nanny

[FabioLuporini]

Hi everybody, since a few days we're seeing "random" failures in our CI due to distributed emitting:

tornado.application - ERROR - Exception in callback <bound method Nanny.memory_monitor of <Nanny: None, threads: 1>>
Traceback (most recent call last):
  File "/opt/hostedtoolcache/Python/3.7.7/x64/lib/python3.7/site-packages/tornado/ioloop.py", line 907, in _run
    return self.callback()
  File "/opt/hostedtoolcache/Python/3.7.7/x64/lib/python3.7/site-packages/distributed/nanny.py", line 414, in memory_monitor
    process = self.process.process
AttributeError: 'NoneType' object has no attribute 'process'

This feels like a race condition in some situation, e.g. closing of the Nanny because the periodic callbacks are still running but Nanny.process is already None.

I think (still investigating) we've started seeing this only after 2.20 was released.

I cannot attach an MFE yet simply because we don't have one 😬 we only experience this on CI. I'd welcome any sort of feedback. I can try to give some context though: the error is triggered in a Jupyter Notebook by a cell which calls scipy.minimize from a DASK worker (cell 14 here -- look for optimize.minimize). I doubt it's ever going to be useful, but here's an excerpt of the raw log (part of which I pasted above): note that it repeats over and over again for hundreds/thousands of lines...

Thanks!

[mrocklin]

Thank you for raising this issue @FabioLuporini .

At first glance I don't see any obvious cause. A minimal reproducer would be useful. Alternatively, given that this started affecting you only recently, you could also try git bisect on this repository to see if you can isolate the commit that caused this change. This might be hard though if you can only reproduce the issue in CI.

[FabioLuporini]

I could...but it's gonna take forever 😬

so, after an afternoon of CI re-spins, I think we're quite confident to say that 2.19 doesn't exhibit this behaviour

I guess we're gonna enforce <2.20 for now

[mrocklin]

I could...but it's gonna take forever 😬

There are only 13 commits between 2.19 and 2.20. It might not be terrible.

…

On Thu, Jul 9, 2020 at 9:49 AM Fabio Luporini ***@***.***> wrote: I could...but it's gonna take forever 😬 so, after an afternoon of CI re-spins, I think we're quite confident to say that 2.19 doesn't exhibit this behaviour I guess we're gonna enforce <2.20 for now — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#3955 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AACKZTCDK24XT7IAD5WIOADR2XYIXANCNFSM4OVSA4DQ> .

[FabioLuporini]

OK, I thought it was worse than that. Do you suggest I do it on all commits or just on the merge commits (haven't checked the commit history, will do shortly) ?

[mrocklin]

We squash-and-merge, so every commit in history is valid and clean

…

On Thu, Jul 9, 2020 at 10:01 AM Fabio Luporini ***@***.***> wrote: OK, I thought it was worse than that. Do you suggest I do it on all commits or just on the merge commits (haven't checked the commit history, will do shortly) ? — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#3955 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AACKZTBHXFLWWERVVZDJBO3R2XZVZANCNFSM4OVSA4DQ> .

[jrdzha]

I'm also having this issue. I just wanted to add that we're experiencing this about 1 in 30 times.

[mrocklin]

Thanks @jrdzha . Do you have time to try the git-bisect process? I would expect this to take around 30-45 minutes.

[jrdzha]

@mrocklin I'm quite busy for the next few days, but I'll take a look after that.

[FabioLuporini]

@mrocklin sorry -- we did try it (OK, not really git bisect for the reasons explained above, but a conceptually analogous thing). We though bumped into other issues, and I eventually forgot to update this thread. I'll let @rhodrin explain our findings 'cause I don't quite remember what the latest news from this front are

[rhodrin]

@mrocklin Yes, sorry for the delayed response. So we set up an Actions matrix to run our tests many times for each commit between 2.19 and 2.20, and later some earlier and later versions.

Firstly, failures are rare and not particularly consistent (possibly related to load on the github hosted runners). One day we may see a failure 1 in 10 times, the next day we could see ~100 runs with no failure. We managed to produce failures on, I think, all commits between 2.19 and 2.20 and even into some post 2.20 commits. We then tried to produce failures on some older versions, but that day we saw absolutely no failures on any version between 2.16 and 2.21 - I think we ran the tests ~80 times on each version. After that I took a break from this.

So in summary, this one is a real mystery. But my inclining is that it's something memory related: we only managed to produce failures when running a large suite of tests, repeatedly running the failing test individually never produced any failures. Also, I've not managed to reproduce this on my local machine (which is pretty decent).

[jrdzha]

@rhodrin Yes, for our testing the fails seem to occur randomly. We run our tests using LocalCluster on a 'local' machine (not our Kubernetes cluster) though and they are failing there.

[mrocklin]

OK, it seems like the next thing to do here then is for someone to produce a reproducible example.

[miroenev]

Just wanted to chime in that we are consistently seeing the nanny NoneType errors when running LocalCudaCluster/LocalCluster jobs on cloud instances (code gets wrapped into a container/AWS SageMaker Estimator) however the issue seems to not occur when running with containers on a local machine. Interestingly these errors are non-critical and the computations continue to completion, however the errors dominate/clobber the output.

nanny_issues_7_30_2020.txt

https://github.com/rapidsai/cloud-ml-examples/blob/master/aws/notebooks/sagemaker_rapids_hpo.ipynb
https://github.com/rapidsai/cloud-ml-examples/blob/master/aws/code/rapids_cloud_ml.py

[mrocklin]

cc @quasiben