Repository navigation
Sporadic failures in Popen() under Windows with processes left in subprocess._active list #508
Description
Under Windows, when running test-cases creating different temporary repositories consecutively, I get sporadic failures when executing the git process:
File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\repo\base.py", line 872, in init
git.init(**kwargs)
File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 466, in <lambda>
return lambda *args, **kwargs: self._call_process(name, *args, **kwargs)
File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 910, in _call_process
return self.execute(make_call(), **_kwargs)
File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 630, in execute
raise GitCommandNotFound(str(err))
git.exc.GitCommandNotFound: [WinError 6] The handle is invalid
- Digging a bit further, I noticed that before executing the failing Popen(), the subprocess._active list contains 2 leftovers processes, while this list is always empty when not failing.
- I tried to add some delays with time.sleep() but it did not help.
- It did help when I simplified my test-cases, i.e. dropping some commit actions.
- Tested under:
- Windows 10,
- WinPython 3.5.2:
- gitpython: both latest in PyPi v2.0.8 and latest master from github(df65f51) (2.0.9-dev0).
- smmap: 0.9.0
- gitdb: 0.6.4
An minor note: the try-catch Popen() code assumes that any exception caught is because git was not found, while above it obviously not the case.
Activity
ankostis commented on Sep 4, 2016
The following TC reproduces stochastically the failure:
import git, io, os.path as osp, tempfile def do_repo(): with tempfile.TemporaryDirectory() as td: r = git.Repo.init(td) newfile = osp.join(r.working_dir, 'foo') with io.open(newfile, 'wt') as fd: fd.write('Hi!') r.index.add([newfile]) r.index.commit('c1') class TestRepoTempPaths(unittest.TestCase): def test_repo(self): for i in range(5): print('Try %d' % i) do_repo()When I run it, on my PC it fails the 3rd time:
Try 1 Try 2 Try 3 ERROR ====================================================================== ERROR: test_repo (tests.sampling.test_project.TestTemp) ---------------------------------------------------------------------- Traceback (most recent call last): File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\objects\commit.py", line 393, in create_from_tree repo.head.set_commit(new_commit, logmsg=message) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 218, in set_commit self.set_object(commit, logmsg) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 247, in set_object return self._get_reference().set_object(object, logmsg) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\reference.py", line 60, in set_object oldbinsha = self.commit.binsha File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 183, in _get_commit obj = self._get_object() File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 176, in _get_object return Object.new_from_sha(self.repo, hex_to_bin(self.dereference_recursive(self.repo, self.path))) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 125, in dereference_recursive hexsha, ref_path = cls._get_ref_info(repo, ref_path) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 157, in _get_ref_info raise ValueError("Reference at %r does not exist" % ref_path) ValueError: Reference at 'refs/heads/master' does not exist During handling of the above exception, another exception occurred: Traceback (most recent call last): File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 627, in execute **subprocess_kwargs File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 842, in __init__ _cleanup() File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 505, in _cleanup res = inst._internal_poll(_deadstate=sys.maxsize) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 1259, in _internal_poll if _WaitForSingleObject(self._handle, 0) == _WAIT_OBJECT_0: OSError: [WinError 6] The handle is invalid During handling of the above exception, another exception occurred: Traceback (most recent call last): File "D:\foo\tests\sampling\test_project.py", line 304, in test_repo do_repo() File "D:\foo\tests\sampling\test_project.py", line 297, in do_repo r.index.commit('c1') File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\index\base.py", line 949, in commit author_date=author_date, commit_date=commit_date) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\objects\commit.py", line 397, in create_from_tree master = git.refs.Head.create(repo, repo.head.ref, new_commit, logmsg="commit (initial): %s" % message) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 527, in create return cls._create(repo, path, cls._resolve_ref_on_create, reference, force, logmsg) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 494, in _create ref.set_reference(target, logmsg) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 321, in set_reference self.log_append(oldbinsha, logmsg) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\refs\symbolic.py", line 375, in log_append committer_or_reader = self.commit.committer File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\gitdb\util.py", line 237, in __getattr__ self._set_cache_(attr) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\objects\commit.py", line 143, in _set_cache_ binsha, typename, self.size, stream = self.repo.odb.stream(self.binsha) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\db.py", line 45, in stream hexsha, typename, size, stream = self._git.stream_object_data(bin_to_hex(sha)) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 1014, in stream_object_data cmd = self._get_persistent_cmd("cat_file_all", "cat_file", batch=True) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 980, in _get_persistent_cmd cmd = self._call_process(cmd_name, *args, **options) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 910, in _call_process return self.execute(make_call(), **_kwargs) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 630, in execute raise GitCommandNotFound(str(err)) git.exc.GitCommandNotFound: [WinError 6] The handle is invalid ---------------------------------------------------------------------- Ran 1 test in 0.756s FAILED (errors=1) Exception ignored in: <bound method Git.AutoInterrupt.__del__ of <git.cmd.Git.AutoInterrupt object at 0x0000023E868FFEF0>> Traceback (most recent call last): File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\site-packages\git\cmd.py", line 290, in __del__ if proc.poll() is not None: File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 1082, in poll return self._internal_poll() File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 1259, in _internal_poll if _WaitForSingleObject(self._handle, 0) == _WAIT_OBJECT_0: OSError: [WinError 6] The handle is invalid Exception ignored in: <bound method Popen.__del__ of <subprocess.Popen object at 0x0000023E86907A90>> Traceback (most recent call last): File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 999, in __del__ self._internal_poll(_deadstate=_maxsize) File "D:\Apps\WinPython-64bit-3.5.2.1\python-3.5.2.amd64\lib\subprocess.py", line 1259, in _internal_poll if _WaitForSingleObject(self._handle, 0) == _WAIT_OBJECT_0: OSError: [WinError 6] The handle is invalidankostis commented on Sep 4, 2016
I managed to workaround it by adding repo.git.clear_cache() at the end after the commit, like that:
def do_repo(): with tempfile.TemporaryDirectory() as td: r = git.Repo.init(td) newfile = osp.join(r.working_dir, 'foo') with io.open(newfile, 'wt') as fd: fd.write('Hi!') r.index.add([newfile]) r.index.commit('c1') r.git.clear_cache()But is this expected?
Byron commented on Sep 11, 2016
Thanks for describing the issue in such great detail, and actually digging down to the root cause of it ! What we might see here is GitPython's failure to cleanup its system resources correctly, as it was made in a time when destructors actually ran deterministically even in python. GitPython itself seems to expect this, even though that never runs in newer python interpreters as the GC runs too rarely.
The side-effect of the resource leakage appears to be the issue you have noticed.
It's a general problem, and the only workaround I see is to make these calls manually. The problem is that everything allocating resources should in fact be used in a context to assure proper cleanup, which would require something like GitPython 3.0. The latter will require a lot of community effort to make happen.
@ankostis What do you think can be sensibly be done here ?
ankostis commented on Sep 11, 2016
Thank you for your frank clarification of the problem.
In cases like that, where I now the problem but it's huge and I don't have the resources, I enter damage control mode: adding "Known Limitations" sections in the manual, or marking every possible resource method as problematic in the docs.
In the good case, people start to get annoyed and search for workarounds.
If I'm lucky, one fits better :-).
Byron commented on Sep 11, 2016
Great idea ! I have just added a new Limitations section in the Readme and the documentation, which should help let people known what they are getting themselves into ;).
Also I chose the easy way out, as searching for __del__ usually is all one needs to learn about required cleanup.
ankostis commented on Sep 13, 2016
I have identified another "deterministic" failure, with the index code relying on destructor in py3.5. The following code reproduces it:
import git r = git Repo() def add_bad_blob(): r.index.add([git.Blob(r, b'f' * 20, 'bad-permissions', 'foo')]) try: ## 1st fail on purpose adding into index. add_bad_blob() except Exception as ex: """ git\index\base.py in add() @799 git\index\base.py in write() @213 git\index\base.py in _serialize() @180 git\index\fun.py in write_cache() @133 """ assert "required argument is not an integer" in str(ex) try: ## 2nd time fails due to stray lock-file. add_bad_blob() except Exception as ex: assert "index.lock' could not be obtained" in str(ex) import gc gc.collect() try: ## After GC, lock-file gone. add_bad_blob() except Exception as ex: assert "required argument is not an integer" in str(ex)The problem originates at git/index/base.py#L211-214, and can be amended by enclosing them in a try-finally block:
stream = lfd.open(write=True, stream=True) ok= False try: self._serialize(stream, ignore_extension_data) ok = True finally: if not ok: lfd.rollback()But a more proper solution would be to retrifit LockedFD as a context-manager.
ankostis commented on Sep 13, 2016
I note that the previous "index" issue is a show-stopper, and impossible to workaround even when applying the advice you wrote in the manual, because the LockedFD variable instance goes out of scope.
So either you a) modify the project sources, or b) try-catch and explicitly invoke GC then, which is pretty ugly. I would really suggest (b) (a), specifically retrofitting LockedFD as a context manager.
By the way, I believe that the duplicated gitdb.utils.LockedFD class in that project is never used, and can be safely removed.
ankostis commented on Sep 13, 2016
@Byron I can open it as a new issue if you think it is worth it.
Byron commented on Sep 13, 2016
Thanks for your investigation , I would love to have an issue for this and
will be happy to attempt a fix.
Thanks again
On Tue, 13 Sep 2016 at 14:03, Kostis Anagnostopoulos <
notifications@github.com> wrote:
doc(limitations): be very clear about known issues