How to debug ZRAN_READ_FAIL?

[piskvorky]

I recently switched processing .tgz archives from "native" tarfile to tarfile + indexed_gzip, to improve performance because my application does a lot of seeking back and forth.

During testing, reading inside a deeply nested archive (path like zip.tgz.tar.bz2.tar.gz//home/zip.tgz.tar.bz2//home/zip.tgz//home/home.zip) fails with:

 Traceback (most recent call last):
   File "/usr/lib/python3.10/zipfile.py", line 925, in read
     data = self._read1(n)
   File "/usr/lib/python3.10/zipfile.py", line 995, in _read1
     data = self._read2(n)
   File "/usr/lib/python3.10/zipfile.py", line 1025, in _read2
     data = self._fileobj.read(n)
   File "/usr/lib/python3.10/zipfile.py", line 745, in read
     data = self._file.read(n)
   File "/usr/lib/python3.10/tarfile.py", line 696, in readinto
     buf = self.read(len(b))
   File "/usr/lib/python3.10/tarfile.py", line 685, in read
     b = self.fileobj.read(length)
   File "indexed_gzip/indexed_gzip.pyx", line 797, in indexed_gzip.indexed_gzip._IndexedGzipFile.readinto
 indexed_gzip.indexed_gzip.ZranError: zran_read returned error: ZRAN_READ_FAIL (file: <ExFileObject name=None>)

The archive is 100% valid and can be opened / read with Python's built-in tarfile and zipfile.

To open the tar.gz members, I'm using tarfile.open(fileobj=IndexedGzipFile(fileobj=file_obj, mode='rb', auto_build=True), mode='r').

I realize that reading nested archives on-the-fly like that is a bit unusual, but this should work, right? Is igzip a drop-in replacement for gzip or are there any gotchas?

I'll try to create a minimal reproducing dataset, but any clues about how to debug this problem would be welcome. Why would ZRAN_READ_FAIL ever fail on a valid archive?

[piskvorky]

Hm, I'm also getting ZRAN_SEEK_FAIL, at different places, even on re-runs on exactly the same data:

   File "/usr/lib/python3.10/tarfile.py", line 2342, in next
     self.fileobj.seek(self.offset - 1)
   File "indexed_gzip/indexed_gzip.pyx", line 670, in indexed_gzip.indexed_gzip._IndexedGzipFile.seek
 indexed_gzip.indexed_gzip.ZranError: zran_seek returned error: ZRAN_SEEK_FAIL (file: home/radim/research/thesaurus/data/thesaurus.tgz)

This non-determinism hints at some threading issues… not sure if in my code or in zipfile or tarfile or igzip. How does igzip handle multi-threading? I remember seeing some locks in its source code.

EDIT: Looking into this zipfile's thread safety, python/cpython#26974. Although that fix seems to have been backported into Python 3.10 which is what I'm using.

tarfile access I'm locking myself python/cpython#67837 (comment), so that's unlikely to be the problem.

Anyway, in case the issue turns out to unrelated to igzip I'll close this issue. Sorry for the noise.

[piskvorky]

Locking access to zipfile.ZipFile fixed the problem. Sorry for the long monologue :)

[pauldmccarthy]

@piskvorky Apologies for the delay (busy at work at the moment), glad you resolved the problem. The IndexedGzipFile class protects access to the underlying file with a threading.RLock, but this protection only applies to access via a single IndexedGzipFile instance..

[piskvorky]

Understood. The objects are nested, so a seek() inside the innermost IndexedGzipFile object ultimately triggers a seek() in the outermost IndexedGzipFile, so that's fine, it's ultimately the same lock.

Confirmed by my tests – after fixing zipfile everything works.

(The trouble was zipfile (somewhere, internally) did a seek() followed by a read(), and even though the individual reads and seeks themselves were done cleanly by igzip, there was a race condition where another thread could jump in between zipfile's seek() and read(), causing trouble.)