ValueError: offset must be zero or positive

[cachedout]

Hello,

I have an error that seems to occur occasionally that I'm trying to track down.

First, some versions:

Python 2.7
GitPython: 0.3.6

At times, calling the stream_data method with a file handle on a blob object produces the following:

  File "/testing/salt/fileserver/gitfs.py", line 1314, in find_file
    blob.stream_data(fp_)
  File "/usr/lib/python2.7/site-packages/GitPython-0.3.6-py2.7.egg/git/objects/base.py", line 119, in stream_data
    istream = self.repo.odb.stream(self.binsha)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/base.py", line 208, in stream
    return self._db_query(sha).stream(sha)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/pack.py", line 104, in stream
    return entity.stream_at_index(index)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 778, in stream_at_index
    return self._object(None, True, index)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 731, in _object
    streams = self.collect_streams_at_offset(offset)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 865, in collect_streams_at_offset
    streams = self._pack.collect_streams(offset)
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 607, in collect_streams
    ostream = pack_object_at(c, offset, True)[1]
  File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 92, in pack_object_at
    data = cursor.use_region(offset).buffer()
  File "build/bdist.linux-x86_64/egg/smmap/mman.py", line 158, in buffer
    return buffer(self._region.buffer(), self._ofs, self._size)
ValueError: offset must be zero or positive

As you can see, the traceback begins with a call from the SaltStack fileserver. (I am one of the developers there.)

As mentioned earlier, I can only reproduce this on occasion. I can attempt to gather debugging values as needed, though it will be a little tricky. :]

I would also happily accept any theories about reasons this might happen which are only tangentially related to GitPython (locked files, half-written files, etc). Those shouldn't be ruled out, as this error is produced during our automated integration testing, which creates and destroys git repos for each test case.

Many thanks for any leads or advice. Let me know how I can help. Thanks!

[Byron]

Now live on twitch.

[Byron]

Thanks for the ticket, it's well done :) !

First I could verify that _ofs is indeed a negative value just from checking the error message we see. None is not a possible value here.

There seems to be exactly one place where the offset can become negative, which is here. I have uploaded an smmap branch that might help getting notified exactly at the time the _ofs value turns negative.

When I see At times in one of your first sentences, I am thinking of data races immediately. However, I also believe that this isn't happening in your case as you certainly wouldn't even dare trying to use gitpython like that. After all, it's not threadsafe at all.

Another thing I thought could happen is the test-system running out of resources, which might have (accidentally) triggered an alternative code path. It appears to me though that the code which allocates an memory map would just trigger an exception outright.

What could you do right away ?

1. Avoid the custom gitdb implementation by instantiating your git.Repo objects with git.Repo(path, odbt=git.GitCmdObjectDB). This will have performance implications though, either to the better or the worse ;).
   • If the spurious errors still occour, we know it's something related to system resources - the git-process should suffer the same issues I suppose. If everything works just fine, it could be your fix for now, even though we still wouldn't
2. Try to use the smmap debugging branch

I hope this helps, please let me know if anything else comes up on your side.

[Byron]

You can watch the archived development live-stream on youtube.

[terminalmage]

@Byron I am the primary maintainer of SaltStack's gitfs, which makes use of GitPython.

What kind of performance implications? Also, could you clarify what you mean by "custom gitdb implementation"?

The way we use GitPython is as follows:

1. Try to git.Repo('/path/to/repo') the desired path. If no repo is initialized at that path, instantiate the Repo object using git.Repo.init().
2. If the repo was just init'ed in the previous step, we add a remote using git.Repo.create_remote(), pointing it at the desired repo.

We then proceed to fetch occasionally to keep the repo up-to-date, and when a file is requested, it is retrieved by finding the Tree object corresponding to the newest commit in the desired branch (or for tags, the commit corresponding to the tag). The blob for the desired file is retrieved from the tree, and then the file's data is retrieved from that blob object.

[cachedout]

Hi @Byron

Thanks for looking at this so promptly. I watched some of the debugging session last night while you were webcasting and I must say that it was quite interesting. Thanks for doing that!

No, we aren't doing anything with threading here and as you say, that would certainly be a bad idea!

So, I asked one of our QA engineers today to apply the change you made in the smmap branch and to run a series of tests. He ran our git tests 256 times in a loop and in doing so, received only two errors. They are pasted below:

===========================================================================================================================================
*** integration.fileserver.gitfs_test.GitFSTest Tests  ************************************************************************************
 --------  Failed Tests  ------------------------------------------------------------------------------------------------------------------
   -> integration.fileserver.gitfs_test.GitFSTest.test_file_hash_sha1  ....................................................................
       Traceback (most recent call last):
         File "/root/salt/tests/integration/fileserver/gitfs_test.py", line 159, in test_file_hash_sha1
           gitfs.find_file(target)
         File "/root/salt/salt/fileserver/gitfs.py", line 1309, in find_file
           blob.stream_data(fp_)
         File "/usr/lib/python2.7/site-packages/GitPython-0.3.6-py2.7.egg/git/objects/base.py", line 119, in stream_data
           istream = self.repo.odb.stream(self.binsha)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/base.py", line 208, in stream
           return self._db_query(sha).stream(sha)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/pack.py", line 104, in stream
           return entity.stream_at_index(index)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 778, in stream_at_index
           return self._object(None, True, index)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 731, in _object
           streams = self.collect_streams_at_offset(offset)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 865, in collect_streams_at_offset
           streams = self._pack.collect_streams(offset)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 607, in collect_streams
           ostream = pack_object_at(c, offset, True)[1]
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 92, in pack_object_at
           data = cursor.use_region(offset).buffer()
         File "/root/src/issue/smmap/mman.py", line 134, in use_region
           assert(self._ofs > -1)
       AssertionError
   ........................................................................................................................................
 ------------------------------------------------------------------------------------------------------------------------------------------
*** integration.fileserver.gitfs_test.GitFSTest Tests  ************************************************************************************
 --------  Tests with Errors  -------------------------------------------------------------------------------------------------------------
   -> integration.fileserver.gitfs_test.GitFSTest.test_find_file  .........................................................................
       Traceback (most recent call last):
         File "/root/salt/tests/integration/fileserver/gitfs_test.py", line 125, in test_find_file
           ret = gitfs.find_file('testfile')
         File "/root/salt/salt/fileserver/gitfs.py", line 1309, in find_file
           blob.stream_data(fp_)
         File "/usr/lib/python2.7/site-packages/GitPython-0.3.6-py2.7.egg/git/objects/base.py", line 119, in stream_data
           istream = self.repo.odb.stream(self.binsha)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/base.py", line 208, in stream
           return self._db_query(sha).stream(sha)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/db/pack.py", line 104, in stream
           return entity.stream_at_index(index)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 778, in stream_at_index
           return self._object(None, True, index)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/pack.py", line 732, in _object
           dstream = DeltaApplyReader.new(streams)
         File "/usr/lib/python2.7/site-packages/gitdb-0.6.4-py2.7-linux-x86_64.egg/gitdb/stream.py", line 524, in new
           raise ValueError("Need at least two streams")
       ValueError: Need at least two streams
   ........................................................................................................................................
 ------------------------------------------------------------------------------------------------------------------------------------------
===========================================================================================================================================
FAILED (total=768, skipped=0, passed=766, failures=1, errors=1) 
===========================================================================================================================================

As you can see, one is the same error as we received originally and the other is your assert which you added last night.

To compare this to a run of 128 (only half of the second run) of the unmodified branch, the unmodified run showed 6 stack traces similar to the second one pasted above. ("Need at least two streams".) Obviously, this is a relative increase but it's hard to know if we should draw too much from this conclusion. :]

Additionally, the tester reported no exhaustion of system resources during his testing.

We have not yet implemented the first suggestion in your reply but will do so and report results.

Thanks for your time on this issue. It is very much appreciated by us and by the SaltStack community!

[Byron]

@terminalmage I believe the performance implications and differences between the various git object DB backends are best explained in the respective short section in the docs.

The differences will only affect object access, such reading a blob from a tree. If the GitCmdObjectDB is used, there will be two child processes (git-cat-file) ready to stream data. If the file is big, the process will temporarily allocate a buffer as big as the file itself. GitDB doesn't do that as it is optimized for that case (i.e. everything is a stream and is implemented as a stream).

How to proceed from here ...

@cachedout You are right, the odbt test should definitely be done first as it will not use the entire code-path that is currently showing errors.

As we are dealing with a spurios error, I'd think that the reason for this must be either a data race or memory corruption. The latter is rather unlikely in the python world (at least if there no actual segfault), so lets evaluate the first. Ruling out multi-threading as cause for this, there might be inter-process data races. The question is:

• are there multiple tests running on the same machine at the same time ?
  • GitPython uses tempfile to get directory names to use for testing. It will only generate a name, which then has to be created on disk. In theory, the second process attempting to use an already existing tempdir will fail, besides the fact that clashes should be extremely unlikely. Anyway ;).

However, I wouldn't believe a data race is causing this, but if you say there are multiple tests running on the same machine, we might have something to test at least.

Assuming the error has everything to do with smmap, you might try to use a version that doesn't support python 3 - v0.8.2 should be the one, it is expected to work with the latest gitdb version.

What I am going for here is clearly to bisect smmap (and possibly) gitdb versions to find a version that doesn't show the issue. To do that properly, it might be worth knowing what the last working version for you was. Maybe the diffs would show a clearer image.

OK, that's it for now, sorry for causing so much trouble with my software, there are quiet a few people involved here which shows how expensive bugs can be. The spurious ones are the worst !

[Byron]

Here is the archived session on youtube.

[Byron]

There has been no feedback on this one for a while, and I wonder if the issue is fixed for you.
If so, please close the issue, otherwise we might give it another go to have a chance to get the fix into the upcoming release - it's due for this week
Thank you

[Byron]

I am closing this issue due to inactivity. Please feel free to comment in case you want it to be reopened.
Thanks

[cachedout]

Sorry for the delay in repsonding. We haven't had any more activity on this downstream at saltstack/salt so I think we can keep this closed. Thanks for the investigation. Much appreciated!