Repository navigation
TCP timeouts connecting to cluster #5099
Description
While running a profiling script that creates ~180 Coiled clusters (max 4 active at once), I'm hitting somewhat frequent TCP connection timeout errors during wait_for_workers, even with DASK_DISTRIBUTED__COMM__TIMEOUTS__CONNECT=60s. Anecdotally, I've noticed it most commonly happens with my 50- or 100-worker clusters, less so with the 2- or 20-worker ones.
I've also tried with #5096 and I'm still seeing the errors, though I can't say statistically if they're any less frequent.
Maybe notable is that I'm using 4 async Clients at once from the same process.
I’m not sure if this is a Dask problem, or a Coiled problem, or both. Wondering if anyone here has ideas on what to debug next. cc @fjetter @jacobtomlinson
Typical traceback:
Traceback (most recent call last):
File "/usr/local/lib/python3.9/site-packages/distributed/comm/tcp.py", line 376, in connect
stream = await self.client.connect(
File "/usr/local/lib/python3.9/site-packages/tornado/tcpclient.py", line 275, in connect
af, addr, stream = await connector.start(connect_timeout=timeout)
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
fut.result()
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.9/site-packages/distributed/comm/core.py", line 286, in connect
comm = await asyncio.wait_for(
File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "//run.py", line 153, in run_trial
tasks, runtime, batched_send_stats = await trial(**vars)
File "//run.py", line 119, in trial
await client.wait_for_workers(cluster_size)
File "/usr/local/lib/python3.9/site-packages/distributed/client.py", line 1219, in _wait_for_workers
info = await self.scheduler.identity()
File "/usr/local/lib/python3.9/site-packages/distributed/core.py", line 863, in send_recv_from_rpc
comm = await self.pool.connect(self.addr)
File "/usr/local/lib/python3.9/site-packages/distributed/core.py", line 1051, in connect
raise exc
File "/usr/local/lib/python3.9/site-packages/distributed/core.py", line 1035, in connect
comm = await fut
File "/usr/local/lib/python3.9/site-packages/distributed/comm/core.py", line 312, in connect
raise OSError(
OSError: Timed out trying to connect to tls://54.188.70.54:8786 after 60 s
Activity
fjetter commentedon Jul 21, 2021
While there are many servers in play (#scheduler x #workers) either server seems to be only busy with a rather limited amount of connections in the order of about a hundred simultaneous connection attempts (e.g. each scheduler will negotiate a connection to the workers plus your client). We actually allow many of simultaneous connections at once (see
socket-backlogconfig option which is set to 2K by default). This backlog size has been introduced in #1232Are you always seeing the
Timed out trying to connect to tomessage or do you also seeTimed out during handshake while connecting to?If there is a more or less homogeneous distribution, this might be genuinely due to load on the respective schedulers. the latter one is raise if there is an established connection but the metadata handshake fails. that handshake is really cheap but still requires a few cycles. if the scheduler on the other end is really busy this might not be sufficient.
If it's just the first one, as you put it in the issue, I'm wondering if it's a low level / kernel problem. I'm also wondering if we shouldn't restrict the size of the socket backlog and rather deal with connection rejections since they are now properly retries with exponential backoffs and jitters anyhow.
I would probably try lowering that backlog size and see if this helps (netutils sets a default at 128 ❗). If that doesn't help, I'd be curious to see TCP connection logs but getting those is a bit more involved (e.g. using iptables)
https://github.com/dask/distributed/issues/5099
fjetter commentedon Sep 7, 2021
@gjoseph92 IIRC this was a coiled issue. I vaguely remember workers not starting fast enough and the scheduler would be dead before
wait_for_workersfinishes.