issue_comments

Please try with fsspec master.

I'm still suffering from IndexError: pop from an empty deque. Can somebody tell me which s3fs version to use after fix by @martindurant?

Here are my relevant packages:

# Name                    Version                   Build  Channel
aiobotocore               0.10.3                     py_0    conda-forge
aiohttp                   3.7.3            py39hb82d6ee_0    conda-forge
botocore                  1.12.91                    py_0    conda-forge
dask                      2.30.0                     py_0    conda-forge
dask-core                 2.30.0                     py_0    conda-forge
distributed               2.30.1           py39hcbf5309_0    conda-forge
fsspec                    0.8.4                      py_0    conda-forge
python                    3.9.0           h7840368_5_cpython    conda-forge
s3fs                      0.5.1                      py_0    conda-forge
xarray                    0.16.2             pyhd8ed1ab_0    conda-forge
zarr                      2.5.0                      py_0    conda-forge

Thanks in advance!

Welcome to the world of light-sheet microscopy. And this would be considered a tiny dataset.. 😄

@rabernat thanks for the tip. I was wondering what would be best chunk-size for s3 bucket storages. Will aim for that size once performance tweaking.

Thanks a lot!

@jhnnsrs: just a tip based on my own experience. In the code above, you are not specifying any chunks explicitly. The default is then to let zarr choose the chunk sizes. Zarr's default chunks are usually much smaller than what is optimal with cloud storage. I would recommend you explicitly chunk you array and aim for chunks around 100 MB.

Closing this as it appears to be fixed by @martindurant's quick response in fsspec / s3fs.

That's a lot of data!

Confirmed! Works like a charm. Went up all the way to (1024,1024,100,3,1) without any issues. Thanks for the fast fix! 👍

Can you confirm that this works ok with fsspec and s3fs master?

I have reproduced it locally (also with moto). Indeed, many threads are trying to stall the event loop at once. This will take a little finesse.

Thanks for the digging, I'll look into it

Okay. That was too fast. Wasn't able to get the django implementation running, so I setup a testing environment with a docker composition running minio and a python3.8 based container with the libraries (repo attached). The setup runs fine for dask arrays of size (1024,1024,8,2,1) but causes the same asyncio problematic at (1024,1024,10,2,1) (tested with random arrays)

https://github.com/jhnnsrs/s3fs_bugreport

Thanks for the troubleshooting. I encountered the problem within an sync worker in django channels (has been and is still working with s3fs=0.4.1 ) (same error). So I tried running the refactored relevant code in a vanilla python script on a linux docker container with WSL2 backend, no event loops and no threads running. Same results and the reason I posted in in xarray issues.

No coming back to this problem a day the vanilla script works perfectly sound and gets the job down! The Django sync worker example still runs into problems:

[ERROR] asyncio 2020-10-02 09:40:10,950 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:11,609 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:12,478 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:12,743 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:12,745 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:12,757 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:13,631 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:13,633 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:15,025 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state [ERROR] asyncio 2020-10-02 09:40:16,317 :: Exception in callback BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000)) handle: <Handle BaseSelectorEventLoop._sock_connect_cb(<Future finished result=None>, <socket.socke...8.0.4', 9000)>, ('172.18.0.4', 9000))> Traceback (most recent call last): File "/usr/local/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/asyncio/selector_events.py", line 510, in _sock_connect_cb fut.set_result(None) asyncio.base_futures.InvalidStateError: invalid state Exception in thread Thread-1: Traceback (most recent call last): File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner self.run() File "/usr/local/lib/python3.7/threading.py", line 870, in run self._target(*self._args, **self._kwargs) File "/usr/local/lib/python3.7/asyncio/base_events.py", line 541, in run_forever self._run_once() File "/usr/local/lib/python3.7/asyncio/base_events.py", line 1771, in _run_once handle = self._ready.popleft() IndexError: pop from an empty deque

I guess this is now more of a problem with the way django >=3.1 and particularly django-channels is dealing with the event loop. Do you have by any chance quick thoughts on this? Is there a way to get the django "superpowered" event loop instead of the asyncio one?

Anyway will mark this bug report as resolved as it is cleary not xarrays issue. Thanks a lot !

Martin, thanks for your comments. I have read them several times but am left scratching my head as to their meaning. It would be useful if you could help identify a specific development direction to address @jhnnsrs's bug. In your best judgement, is this - a bug in xarray - a bug in dask - a bug in zarr - a bug in s3fs - some problem relating to @jhnnsrs's environment / dependencies - something else?

File "/usr/local/lib/python3.7/asyncio/base_events.py", line 1771, in _run_once handle = self._ready.popleft()

This looks like it may be a race conditions where multiple threads are calling the event loop at once. I wonder if you could list the event loops in use and the threads (perhaps best run with base python than ipython/jupyter).

The following code, modified to the style of the s3fs test suite, works OK: ```python def test_with_xzarr(s3): da = pytest.importorskip("dask.array") xr = pytest.importorskip("xarray") name = "sample"

nana = xr.DataArray(da.zeros((1023, 1023, 3)))

s3_path = f"{test_bucket_name}/{name}"
s3store = s3.get_mapper(s3_path)

print("Storing")
nana.to_dataset().to_zarr(store=s3store, mode="w", consolidated=True, compute=True)

```

Thanks for the bug report! There were recently some big changes to s3fs. We will look into it.

cc @martindurant