Github workflows for tests and doc often hang with python 3.11 on linux

[hboisgon]

HydroMT-Wflow version checks

• I have checked that this issue has not already been reported.
• I have checked that this bug exists on the latest version of HydroMT-Wflow.

Reproducible Example

NA

Current behaviour

Github tests and docs workflows often hang on linux with python 3.11. We should investigate why this behavior happens and improve our tests.

Desired behaviour

No more hanging

Additional context

No response

[savente93]

So I've been digging into this for the past two weeks or so, and wanted to at least write down my findings:

This issue was most often observed by me in the docs so I started by disabling all of those, and enabling them one by one to find out if it was one notebook in particular, but this turned out not to be the case. The issue was too inconsistent to reliably reproduce. It has also been observed to happen in the test suite, but primarily on python 3.11 which points to a more generic threading issue rather than any specific problematic code.

It is known that writing to netcdf files can cause xarray/dask to hang due to file locks. (see pydata/xarray#3961 and https://github.com/jessicaaustin/xarray_netcdf_hanging_issue). From experience I can also tell that adding a small sleep before doing a hanging file operation can sometimes resolve the issue, which again points to a threading issue.

While it is very inconsistent to make the hang happen with just running the test or docs workflow, but I found out that I can consistently make the hang happen by opening one of the used .nc files (in this case staticmaps.nc) using open_mfdataset in e.g. a jupyter notebook and then separately running either the docs or tests. So the issue here it seems to me is that there is no detection mechanism that either retries at a later time, or aborts aside from a general purpose timeout.

Aside from being a bit of a blunt force tool, the downside of the timeout is that it also has to be quite high because the actual running of the relevant code, (e.g. buildling a wflow model) takes quite long.

Under the hood xarray uses dask to do it's lazy loading etc, and when unconfigured dask uses threading which is known to be somewhat problematic in python due to interference from the GIL. So what seems to happen is that the main test thread moves to the next test and tries to aquire the lock before the previous is done releasing it. After that for whatever reason the lock either doesn't get released or there is a bug in the waiting logic, causing the thread to wait forever. With some debugging I was able to track it down to this code:

https://github.com/pydata/xarray/blob/52cafdb1c033cfb813e13cf5791aa069083fc447/xarray/backends/file_manager.py#L236 the relevant code also links to a dask issue that hasn't been touched since 2019 (dask/dask#3832)

So, until these issues get solved in the dependencies, (something I'd love to work on, but is hard to argue with out current budget) we will have to resort to workarounds. Below are two I've been able to come up with, that could be applied somewhat independent of eachother:

1. Add a small delay between all tests using something like this:

@pytest.fixture(autouse=True)
def slow_down_tests():
    yield
    time.sleep(0.1)

This is obviously not a perfect solution given that it slows down everything, however, the delay needed to resolve the hanging issues is actually quite small, and given that we currently only have a few tests that are quite long running, the overhead introduced by this should be quite manageable. We could also even choose to insert these at the start of known problematic tests/example notebooks.

2. Currently we do basically no tracking of open files/file handles etc. I think expecting users to do this is unrealistic, since it's already hard for me looking at the current code. I think that either the data catalog or model (preferably both) should provide a way to keep track of which files are opened, and provide something like a .close() method which should close open file handles, flush buffers, close loggers etc. This would also make it possible to use them as context managers like suggested in Model.close() and/or Model as context manager hydromt#778 Given that this sort of hanging is quite a pervasive issue I've seen in many applications I think this should be adopted by core, as well as the plugins. On the data catalog side we cna make the get_* functions do the book keeping, and on the model side I think it makes most sense to make the components do the tracking and closing since most files will be handled primarily by one (I think?). The model can just call .close() on all of it's components. Once this is in place, we can make sure that the tests and examples properly close the files once they are done with them. This is not guaranteed to fix all the issues but should go a long way as well as being useful to users that like to run hydromt in long running interactive sessions.

Personally I'd argue for implementing option 2 since that feels more like an actual solution than just a band-aid to me, but it is significantly more work. What do people think? Is my analysis correct or have I missed anything?

Not saying that I have to be the one, but I'd be willing to lead the charge on these initiatives if we decided to go ahead with them.

[savente93]

@deltamarnix What do you think of these solutions?

[deltamarnix]

Would it be an option to let the user do the closing of the datasets that they retrieve from the DataCatalog?

data_series = DataCatalog().get_rasterdataset(...)

# do things here

data_series.close()

or even with a context manager:

with DataCatalog().get_rasterdataset(...) as data_series:
    # do things here

[savente93]

This works when getting individual datasets, but if the model opens files during processing (which it does in certain worklows) I don't think the user can close them at the moment, and I think that the latter case is what is causing the hanging in the documentation

[Huite]

which points to a more generic threading issue

Drive by remark: did you look at whether using the h5netcdf netCDF backend instead of the standard netCDF4 C one makes any difference?

By the way, note that xarray will automatically open closed datasets as well .... at which point it's very easy to end up with uncloseable datasets:

Deltares/xugrid#333

pydata/xarray#10106

[deltamarnix]

We will do a quick fix by closing the datasets on read_grid, so that staticmaps.nc is closed after it is all loaded into memory. There is no lazy loading used at the moment.

Then we will pick up another ticket in HydroMT core to properly solve it: Deltares/hydromt#778