Threading Lock issue with to_netcdf and Dask arrays

[bilelomrani1]

I have multiple netCDF files that I process and write to a single output file.

from pathlib import Path

import xarray as xr

DS = xr.open_mfdataset(Path('L3_data/').glob('**/*.nc'),
                       combine='nested',
                       concat_dim='time',
                       decode_times=False,
                       chunks={'time': 200})

DS.to_netcdf('test.nc')

I was not able to reproduce the issue with a simple example, here are the files : L3_data.zip. The issue does not appear systematically but sometimes, .to_netcdf blocks indefinitely. When interrupted manually, the trace is the following:

Traceback (most recent call last):
  File "test_xarray.py", line 11, in <module>
    DS.to_netcdf('test.nc')
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/xarray/core/dataset.py", line 1568, in to_netcdf
    invalid_netcdf=invalid_netcdf,
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/xarray/backends/api.py", line 1090, in to_netcdf
    writes = writer.sync(compute=compute)
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/xarray/backends/common.py", line 204, in sync
    regions=self.regions,
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/array/core.py", line 945, in store
    result.compute(**kwargs)
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/base.py", line 167, in compute
    (result,) = compute(self, traverse=False, **kwargs)
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/base.py", line 452, in compute
    results = schedule(dsk, keys, **kwargs)
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/threaded.py", line 84, in get
    **kwargs
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/local.py", line 475, in get_async
    key, res_info, failed = queue_get(queue)
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/site-packages/dask/local.py", line 133, in queue_get
    return q.get()
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/queue.py", line 170, in get
    self.not_empty.wait()
  File "/Users/bilelomrani/opt/miniconda3/envs/s5p/lib/python3.7/threading.py", line 296, in wait
    waiter.acquire()
KeyboardInterrupt

Environment:

I'm on Mac OS 10.15.6

Output of xr.show_versions()

INSTALLED VERSIONS

commit: None
python: 3.7.8 | packaged by conda-forge | (default, Jul 31 2020, 02:37:09)
[Clang 10.0.1 ]
python-bits: 64
OS: Darwin
OS-release: 19.6.0
machine: x86_64
processor: i386
byteorder: little
LC_ALL: None
LANG: fr_FR.UTF-8
LOCALE: fr_FR.UTF-8
libhdf5: 1.10.4
libnetcdf: 4.6.2

xarray: 0.16.0
pandas: 1.1.1
numpy: 1.19.1
scipy: 1.3.1
netCDF4: 1.5.1.2
pydap: None
h5netcdf: None
h5py: None
Nio: None
zarr: None
cftime: 1.2.1
nc_time_axis: None
PseudoNetCDF: None
rasterio: 1.0.28
cfgrib: None
iris: None
bottleneck: None
dask: 2.25.0
distributed: 2.25.0
matplotlib: 3.3.1
cartopy: None
seaborn: None
numbagg: None
pint: None
setuptools: 49.6.0.post20200814
pip: 20.2.2
conda: None
pytest: None
IPython: 5.8.0
sphinx: None

[hansukyang]

I seem to also have similar issue, running under docker/linux environment. It doesn't happen always, maybe once out of 4~5 times. Wondering if this is related to NetCDF/HDF5 file locking issue (https://support.nesi.org.nz/hc/en-gb/articles/360000902955-NetCDF-HDF5-file-locking).

[bekatd]

Using:

• xarray=0.16.0
• dask=2.25.0
• netcdf4=1.5.4

I am experiencing same when trying to write netcdf file using to_netcdf() on a files opened via xr.open_mfdataset with lock=None (which is default).

Then I tried to open files with lock=False and it worked like a charm. Issue have been gone for 100% of times.

BUT

Now I am facing different issue. Seems that hdf5 IS NOT thread safe, since I encounter NetCDF: HDF error while applying different function on a netcdf files which were previously processed by another functions with lock=False.
Script just terminates not even reaching any calculation step in the code. seems like lock=False works opposite and file is in a corrupted mode?

This is the BIGGEST issue and needs resolve ASAP

[shoyer]

Did this work reliably in the past? If so, any clues about specific versions of dask and/or netCDF that cause the issue would be helpful.

@TomAugspurger do you know off-hand if there have been any recent changes in Dask's scheduler that could have caused this?

[bekatd]

Did this work reliably in the past? If so, any clues about specific versions of dask and/or netCDF that cause the issue would be helpful.

@TomAugspurger do you know off-hand if there have been any recent changes in Dask's scheduler that could have caused this?

I am new to xarray dask thing but month ago it was woking without issues. I recently reinstalled python and dont know if versions differs from previous one

[TomAugspurger]

@TomAugspurger do you know off-hand if there have been any recent changes in Dask's scheduler that could have caused this?

This is just using Dask's threaded scheduler, right? I don't recall any changes there recently.

[bilelomrani1]

Did this work reliably in the past? If so, any clues about specific versions of dask and/or netCDF that cause the issue would be helpful.

I am working on my first project using Dask arrays in cunjunction with xarray so I cannot tell if previous combinations of versions worked. I tried downgrading dask down to v2.20 but the issue is still here.

This is just using Dask's threaded scheduler, right? I don't recall any changes there recently.

Without the option chunks={'time': 200} the previous snippet seems to work very reliably.

[hansukyang]

For my case, I saw this happen only when I started to run xarray scripts with cron, about a month ago. I would run it once every six hours and every day or so, I would see a NetCDF file locked up. I ended up changing the work flow somewhat so I don't do this any more (was using xarray to manipulate NetCDF and re-write to it) but this was confusing me for quite a while.

[shoyer]

was using xarray to manipulate NetCDF and re-write to it

We should probably document this more clearly, but opening and then rewriting the same file in xarray without closing the original file is not something xarray supports.

[hansukyang]

Good point! Yes, after a bit of trial and error, this is what I did. Is there any limitation when over-writing an existing NetCDF file that hasn't been opened by xarray?

[djhoese]

I'm having a similar issue to what is described here, but I'm seeing it even when I'm not rewriting an output file (although it is an option in my code). I have a delayed function that is calling to_netcdf and seem to run into some race condition where I get the same deadlock as the original poster. It seems highly dependent on the number of dask tasks and the number of workers. I think I've gotten around it for now by having my delayed function return the Dataset it is working on and then calling to_dataset later. My problem is I have cases where I might not want to write the file so my delayed function returns None. To handle this I need to pre-compute my delayed functions before calling to_dataset since I don't think there is a way to pass something to to_dataset so it doesn't create a file.

With the original code it happened quite a bit but was part of a much larger application so I can't really get a MWE together. Just wanted to mention it here as another data point (to_netcdf inside a Delayed function may not work 100% of the time).

[tasansal]

I am having a similar issue as well. Using latest versions of dask, xarray, distributed, fsspec, and gcsfs. I use h5netcdf backend because it is the only one that works with fsspec's binary stream, reading from cloud.

My workflow consists of:

1. Start dask client with 1 process per CPU, and 2 threads each. This is because it doesn't scale up reading from the cloud with threads.
2. Opening 12x monthly climate data (hourly sampled) using xarray.open_mfdataset
3. Using reasonable dask chunks in the open function
4. Take monthly average across time axis, and write to local NetCDF.
5. Repeate 2-4 for different years.

It is a hit or miss. It hangs towards the middle or end of a year. Next time I run it, it doesn't.

Once it hangs, and I hit stop, in the traceback it is stuck at await of threading lock.

Any ideas how to avoid this?

Things I tried:

1. Use processes only, 1 thread per worker
2. lock=True, lock=False on open_mfdataset
3. Dask scheduler as: spawn and forkserver
4. Different (but recent) versions of all the libraries