Raise when workers initialization times out by TomAugspurger · Pull Request #2784 · dask/distributed

TomAugspurger · 2019-06-18T20:29:04Z

This changes Worker / Nanny startup to raise when they timeout.

This bubbles up to the dask-worker CLI.

This changes Worker / Nanny startup to raise when they timeout. This bubbles up to the `dask-worker` CLI. Closes dask#2781

TomAugspurger · 2019-06-18T20:30:51Z

Here's the output

bash-5.0$ dask-worker 192.168.7.26:8786 --death-timeout=2
2019-06-18 15:29:40,340 distributed.nanny[93624] INFO         Start Nanny at: 'tcp://192.168.7.20:52499'
2019-06-18 15:29:41,149 distributed.diskutils[93700] INFO Found stale lock file and directory '/Users/taugspurger/sandbox/distributed/worker-_8p_3v5j', purging
2019-06-18 15:29:41,731 distributed.worker[93700] INFO       Start worker at:   tcp://192.168.7.20:52500
2019-06-18 15:29:41,732 distributed.worker[93700] INFO          Listening to:   tcp://192.168.7.20:52500
2019-06-18 15:29:41,732 distributed.worker[93700] INFO          dashboard at:         192.168.7.20:52501
2019-06-18 15:29:41,733 distributed.worker[93700] INFO Waiting to connect to:    tcp://192.168.7.26:8786
2019-06-18 15:29:41,733 distributed.worker[93700] INFO -------------------------------------------------
2019-06-18 15:29:41,734 distributed.worker[93700] INFO               Threads:                          8
2019-06-18 15:29:41,734 distributed.worker[93700] INFO                Memory:                   17.18 GB
2019-06-18 15:29:41,735 distributed.worker[93700] INFO       Local Directory: /Users/taugspurger/sandbox/distributed/worker-wy_lygiz
2019-06-18 15:29:41,735 distributed.worker[93700] INFO -------------------------------------------------
2019-06-18 15:29:42,354 distributed.nanny[93624] INFO Closing Nanny at 'tcp://192.168.7.20:52499'
2019-06-18 15:29:42,356 distributed.worker[93700] INFO Stopping worker at tcp://192.168.7.20:52500
2019-06-18 15:29:42,411 distributed.nanny[93624] ERROR Timed out connecting Nanny '<Nanny: None, threads: 8>' to scheduler 'tcp://192.168.7.26:8786'
Traceback (most recent call last):
  File "/Users/taugspurger/sandbox/distributed/distributed/nanny.py", line 303, in instantiate
    timedelta(seconds=self.death_timeout), self.process.start()
  File "/Users/taugspurger/Envs/dask-dev/lib/python3.7/site-packages/tornado/gen.py", line 1133, in run
    value = future.result()
tornado.util.TimeoutError: Timeout
2019-06-18 15:29:42,411 distributed.dask_worker[93624] INFO End worker
Traceback (most recent call last):
  File "/Users/taugspurger/.virtualenvs/dask-dev/bin/dask-worker", line 11, in <module>
    load_entry_point('distributed', 'console_scripts', 'dask-worker')()
  File "/Users/taugspurger/sandbox/distributed/distributed/cli/dask_worker.py", line 387, in go
    main()
  File "/Users/taugspurger/Envs/dask-dev/lib/python3.7/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/Users/taugspurger/Envs/dask-dev/lib/python3.7/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/Users/taugspurger/Envs/dask-dev/lib/python3.7/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/Users/taugspurger/Envs/dask-dev/lib/python3.7/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/Users/taugspurger/sandbox/distributed/distributed/cli/dask_worker.py", line 378, in main
    raise TimeoutError("Timed out starting worker.") from None
tornado.util.TimeoutError: Timed out starting worker.

Could maybe cleanup that second traceback a bit, but OK for now I hope.

TomAugspurger · 2019-06-18T20:32:28Z

distributed/worker.py

        logger.info("-" * 49)
        while True:
            if self.death_timeout and time() > start + self.death_timeout:
+                logger.exception(


I can't easily comment on it here, but down in https://github.com/dask/distributed/pull/2784/files#diff-3f78e3c9a9a81b6355c8e594dce0b8f3R766 we also may handle TimeoutError. In that case we logger.info and move on.

I'm not quite sure when that is reached, but I think since we're under this while True we'll still end up here.

mrocklin · 2019-06-18T20:43:12Z

distributed/cli/dask_worker.py

-    except (KeyboardInterrupt, TimeoutError):
+    except TimeoutError:
+        # We already log the exception in nanny / worker. Don't do it again.
+        raise TimeoutError("Timed out starting worker.") from None


Whoa, raise from? New syntax for me.

Welcome to the brave new world of Python 3 :)

raise ... from None specifically is useful when you think the original traceback isn't helpful, which I think it isn't here. Otherwise, you can raise from e if you want to include it.

TomAugspurger · 2019-06-19T13:46:44Z

@mrocklin the previous behavior of gracefully closing the worker, without error, was tested. I've removed those tests since I changed the behavior to raise when a worker times out. Does that sound OK? Alternatively, I could somehow check in the dask-worker command that a timeout has occurred, and change the exit code there.

mrocklin · 2019-06-19T14:11:16Z

distributed/tests/test_nanny.py

-@gen_cluster(client=False, nthreads=[])
-def test_nanny_death_timeout(s):
-    yield s.close()
-    w = yield Nanny(s.address, death_timeout=1)


I think that this test is still valid, but you just want to add something like the following:

w = Nanny(s.address, death_timeout=1 with pytest.raises(gen.TimeoutError): yield w

Got it, thanks.

I've removed my new tests, since I think they're duplicative of these now.

This reverts commit acad50a.

TomAugspurger · 2019-06-19T15:21:07Z

All green.

mrocklin · 2019-06-19T15:38:01Z

Thanks @TomAugspurger !

Raise when workers initialization times out

c4cf5c5

This changes Worker / Nanny startup to raise when they timeout. This bubbles up to the `dask-worker` CLI. Closes dask#2781

TomAugspurger commented Jun 18, 2019

View reviewed changes

mrocklin reviewed Jun 18, 2019

View reviewed changes

remove old tests

acad50a

mrocklin reviewed Jun 19, 2019

View reviewed changes

TomAugspurger added 2 commits June 19, 2019 09:19

Revert "remove old tests"

cc91bd5

This reverts commit acad50a.

Test cleanup

c0acd1d

mrocklin merged commit eba954b into dask:master Jun 19, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Raise when workers initialization times out#2784

Raise when workers initialization times out#2784
mrocklin merged 4 commits intodask:masterfrom
TomAugspurger:2781-death-timer

TomAugspurger commented Jun 18, 2019

Uh oh!

TomAugspurger commented Jun 18, 2019

Uh oh!

TomAugspurger Jun 18, 2019

Uh oh!

mrocklin Jun 18, 2019

Uh oh!

TomAugspurger Jun 18, 2019 •

edited

Loading

Uh oh!

TomAugspurger commented Jun 19, 2019

Uh oh!

mrocklin Jun 19, 2019

Uh oh!

TomAugspurger Jun 19, 2019

Uh oh!

TomAugspurger commented Jun 19, 2019

Uh oh!

mrocklin commented Jun 19, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Uh oh!

Conversation

TomAugspurger commented Jun 18, 2019

Uh oh!

TomAugspurger commented Jun 18, 2019

Uh oh!

TomAugspurger Jun 18, 2019

Choose a reason for hiding this comment

Uh oh!

mrocklin Jun 18, 2019

Choose a reason for hiding this comment

Uh oh!

TomAugspurger Jun 18, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

TomAugspurger commented Jun 19, 2019

Uh oh!

mrocklin Jun 19, 2019

Choose a reason for hiding this comment

Uh oh!

TomAugspurger Jun 19, 2019

Choose a reason for hiding this comment

Uh oh!

TomAugspurger commented Jun 19, 2019

Uh oh!

mrocklin commented Jun 19, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

TomAugspurger Jun 18, 2019 •

edited

Loading