Performance issue in h5py in multi-threaded environment

[kif]

In the scope of the development of BLISS (https://bliss.gitlab-pages.esrf.fr/bliss/master/) at ESRF
we found a performance issue related to h5py in a multi-threaded server environment (server unresponsive for seconds).

Basically the thread is blocking when closing the file, GIL not released. After a quick profiling it goes down to h5py._hl.files (line 400 - 422) and most of the time is spent in H5I_dec_ref which does not release the GIL.
We tested to release the GIL there and test passes without crash. I wonder if you know any callback which might be called at the file-driver level which may be implemented in Python and cause GIL-related crashes ?
If there ain't any, would you consider a PR which declares the function from H5I as GIL free ?
Cheer,

Jerome

To assist reproducing bugs, please include the following:

• Operating System Linux, various flavours
• Python version 3.7 ananconda, or system
• h5py version: 2.10, master
• HDF5 version: 1.10.4, 1.10.5 (1.10.6?)

[kif]

The test code is as simple as that:

import numpy, h5py, time
print(f"h5py: {h5py.version.version} hdf5: {h5py.version.hdf5_version}")
SIZE = 1000000000
data = numpy.arange(SIZE)
print(f"Working with dataset of size: {data.nbytes>>20} MB")
t0 = time.time()
f = h5py.File("/tmp/test.h5", "w")
f["data"] = data
f.flush()
f.close()
print(f"Written at {data.nbytes/(time.time()-t0)/(1<<20)} MB/s")

The last but one line (h5py.File.close) is taking ~50s on a spinning disk without releasing the GIL

[kif]

This snippet of code demonstrate that the GIL is not released when the file is being closed, which can last a bit as in this example

from time import sleep
from threading import Thread
import h5py
import numpy

def background_task():
    i = 1
    while not background_task.cancelled:
        print(f"heartbeat {i}")
        i += 1
        sleep(1)

background_task.cancelled = False
heartbeat = Thread(target=background_task)
heartbeat.start()

try:
    data = numpy.arange(1000000000)
    for i in range(2):
            print(f"open h5py.File {i}")
            with h5py.File("/tmp/test.h5", "w") as f:
                print("create dataset ...")
                f["data"] = data
                print("big flush ...")
                f.flush()
                print("big flush done")
            print(f"closed h5py.File {i}")
finally:
    background_task.cancelled = True
    heartbeat.join()

[takluyver]

And it's really closing the file that hangs, not the f.flush() call? I would have guessed that if you explicitly flush first, that would be slow and then close would be (relatively) fast.

In any case, I can't think of any Python callbacks that would fire on close except when you use the fileobj driver, and that's already marked to reacquire the GIL if needed.

[kif]

Hi Thomas,

We double (even triple) checked, it is not the flush that is hanging but the call to h5i.dec_ref (called from close() in h5py._hl.files).
This issue arose ~3 weeks ago in the development of BLISS:
https://gitlab.esrf.fr/bliss/bliss/issues/1431

The fileobj driver has been investigated, it helps a bit: the code is not slower but then the time is spent in the fileobj.close() which is neither releasing the GIL.

I believe it is better (and simpler) to stay with the posix file driver from the HDFgroup (not that I don't trust the fileobj driver). We also found that the position of the bottleneck is related to the speed of the drive: on actual spinning disks (~100-200MB/s) to fast NVMe (2500MB/s) the bottleneck is there. With ramdisks, the bottleneck appears in the dataset creation. I did not investigate networked filesystem for now.

With this patch I get 87 heartbeat with the patch instead of 5 to 12 without for a total execution time of 86.2s (i.e. no lose).

Cheers,

[takluyver]

Yup, sorry, I wasn't suggesting that the fileobj driver would help, just that that's the only case I can think of where it would trigger a Python callback, and that's already handled.

[kif]

I was also afraid of that and checked it did not seg-fault.

[ax3l]

Sorry for hi-jacking this thread. It would be super awesome if we could release the GIL during the execution of filters such as blosc, which supports multi-threaded compressors: Blosc/hdf5-blosc#25
Is that possible?

[takluyver]

AIUI, HDF5 will call the filters during a read/write call. In h5py master, these (H5Dread & H5Dwrite) now release the GIL. So if the filter is implemented in C code with no Python involved, the GIL should be released while it runs. If there's Python in that, it will need to reacquire the GIL to run Python code, and then release it again.

But I think this is orthogonal to whether the filter can use multiple threads internally. The GIL only restricts running Python code; multiple threads can still run concurrently if the GIL is held, so long as they're not running Python code.

[ax3l]

Thank you for your feedback!

I now compiled from master and can definitely say that the c-blosc filter still does not spawn threads. The native python-blosc bindings in turn to thread, with and without releasing the GIL.

The GIL only restricts running Python code; multiple threads can still run concurrently if the GIL is held, so long as they're not running Python code.

I know that you have ton's for experience with CPython, but are you sure this statement is true even for functions (e.g. the filter) called from Python into a C hook? I just read this and it seams to suggest otherwise.

You are probably right and it's quite likely caused by something else. Either way, HDF5 c-blosc filter in h5py is definitely not using its excellent threading features as far as I can test it.

[ax3l]

I added an extended demonstrator here: Blosc/hdf5-blosc#25