There are three recent examples:

Problem 1: workers die during tests

In each of these cases at least one of the workers dies. That's a dask problem, and maybe some on the OSS team should investigate why workers are losing connection to scheduler during test runs. For example, here's relevant bit of logs from one of the three (!) workers that did this on example (1) above:

2022-11-04 12:21:51,484 - distributed.worker - INFO - Stopping worker at tls://10.0.3.171:43013. Reason: worker-handle-scheduler-connection-broken
2022-11-04 12:21:51,490 - distributed.nanny - INFO - Closing Nanny gracefully at 'tls://10.0.3.171:34553'. Reason: worker-handle-scheduler-connection-broken
2022-11-04 12:21:51,619 - distributed.nanny - INFO - Closing Nanny at 'tls://10.0.3.171:34553'. Reason: nanny-close-gracefully

FWIW, I'd expect that benchmark code killing workings is considered a bad thing and something we'd want to track and something we'd want to look at for performance regressions.

In all of these examples, Coiled does in fact bring up replacement instances (this is because the code running in CI calls scale for each test). But... that takes some time.

That said, I'm looking at these clusters and the replacement workers come up in ~1 minute, so why are we getting 120s timeout?

Problem 2: client.restart() is where we get timeout

Why are we getting 120s timeout if the cluster.scale(10) gets us back to 10 workers in ~1 min?

To answer that, we need to look more closely at the code where the timeout is coming from, and in each of the three examples I've been given, it's this same code:

   @pytest.fixture
    def small_client(
        request,
        testrun_uid,
        small_cluster,
        upload_cluster_dump,
        benchmark_all,
    ):
        test_label = f"{request.node.name}, session_id={testrun_uid}"
        with Client(small_cluster) as client:
            log_on_scheduler(client, "Starting client setup of %s", test_label)
>           client.restart()

conftest.py:486: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/client.py:3416: in restart
    return self.sync(
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/utils.py:339: in sync
    return sync(
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/utils.py:406: in sync
    raise exc.with_traceback(tb)
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/utils.py:379: in f
    result = yield future
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/tornado/gen.py:762: in run
    value = future.result()
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/client.py:3385: in _restart
    await self.scheduler.restart(timeout=timeout, wait_for_workers=wait_for_workers)
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/core.py:1154: in send_recv_from_rpc
    return await send_recv(comm=comm, op=key, **kwargs)
/usr/share/miniconda3/envs/test/lib/python3.9/site-packages/distributed/core.py:944: in send_recv
    raise exc.with_traceback(tb)
/opt/coiled/env/lib/python3.9/site-packages/distributed/core.py:770: in _handle_comm
    ???
/opt/coiled/env/lib/python3.9/site-packages/distributed/utils.py:742: in wrapper
    ???
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

>   ???
E   asyncio.exceptions.TimeoutError: Waited for 10 worker(s) to reconnect after restarting, but after 120s, only 9 have returned. Consider a longer timeout, or `wait_for_workers=False`.

/opt/coiled/env/lib/python3.9/site-packages/distributed/scheduler.py:5804: TimeoutError

Note that the code is calling client.restart() and then client.scale() but never gets to client.scale() in these cases because restart is where we get timeout!

The default behavior of client.restart() is to wait for workers (ultimately by calling scheduler.restart(wait_for_workers=True).

I'm a bit concerned that this won't work if the scheduler still thinks there are N workers but one of those workers has (unknown to the scheduler) died (because it lost connection to scheduler).

Note that the small_client fixture used to do scale then wait_for_workers and then restart, change was made in 150f156 (cc @hendrikmakait who made that change).

If you do things in that order, then I don't think you'd get timeout during restart call.

Assessment/TODOs

As far as I can tell, none of this is caused by Coiled platform issues.

Workers die during tests, that should be addressed.

client.restart() has timeout in some cases (I suspect when scheduler thinks worker is alive when it isn't), You could work around this by calling scale then wait then restart like you used to, but it feels to me like there's a problem with restart that should also be addressed.

Also, I'll mention that troubleshooting would be easier if we had proper timestamps on things in runtime CI, as I've requested in #356.

cc @jrbourbeau @fjetter for visibility on the dask issues

Reconnect times out waiting for workers #468

Description

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions