test_nanny_worker_port_range hangs on Windows

[crusaderky]

test_nanny_worker_port_range has started deterministically hanging on Windows.
As it hangs on pytest-timeout, it brings down the whole test suite.

Last successful run March 9th, 6AM
First failing run March 9th, 10AM

Third party dependencies were not updated:

< dask                      2022.2.1+17.g2baf7f47          pypi_0    pypi
> dask                      2022.2.1+18.gd88b3442          pypi_0    pypi
< distributed               2022.2.1+9.gde94b408           dev_0    <develop>
> distributed               2022.2.1+10.ge1e43858           dev_0    <develop>

This regression seems to have been caused by #5897; see latest build on the PR (which predates March 9th).

[crusaderky]

Confirmed that the issue is caused by the one-line change to the logging template.
dask-worker successfully connects to the scheduler (all 3 spawned worker processes) and then just simply gives no answer to the connection attempt from Scheduler.broadcast. Nothing on the stderr/stdout; it's like the connection never reached the worker. It makes no sense.

I'll further investigate. ETA tomorrow for either a fix or a revert.

[crusaderky]

The issue was that the added timestamps caused the popen stderr pipe to fill up and there was nothing flushing it. As a consequence the dask-worker subprocess was getting stuck indefinitely.

[gjoseph92]

added timestamps caused the popen stderr pipe to fill up and there was nothing flushing it

@crusaderky why was this only showing up on Windows? Could it actually happen anywhere, and Windows was just the canary in the coal mine?

[crusaderky]

It was happening on Windows because pipe buffer size is OS-specific and it turns out that on Windows it's slightly smaller.