GitCommand missing stderr

[muggenhor]

With GitPython 3.1.14 GitCommandError, for failed clones would pass on the captured stderr output into its stderr attribute. With 3.1.15 this contains the empty string instead.

This was caught by this unit test: https://github.com/tomtom-international/hopic/blob/9a35520388f8109ccff6a89407bc2429ed0d0557/hopic/test/test_checkout.py#L84-L103

A reduced test that reduces this to only testing GitPython (instead of the full integration with hopic) looks like the code below. That exhibits the exact same problem:

import git
import pytest

def test_checkout_in_non_empty_dir(tmp_path):
    orig_repo = tmp_path / "orig"
    with git.Repo.init(orig_repo, expand_vars=False) as repo:
        repo.index.commit(message='Initial commit', **_commitargs)

    non_empty_dir = tmp_path / 'non-empty-clone'
    non_empty_dir.mkdir(parents=True)
    garbage_file = non_empty_dir / 'not-empty'
    garbage_file.write_text('Garbage!')

    # Verify that the clone fails complaining about the target directory not being empty/non-existent
    with pytest.raises(git.GitCommandError, match=r'(?is).*\bfatal:\s+destination\s+path\b.*\bexists\b.*\bnot\b.*\bempty\s+directory\b'):
        git.Repo.clone_from(orig_repo, non_empty_dir)
    assert garbage_file.exists()

With 3.1.14 this passes. With the pytest.raises expectation removed this output is displayed:

___________________________________________________________________ test_checkout_in_non_empty_dir ____________________________________________________________________

tmp_path = PosixPath('/tmp/pytest-of-vanschig/pytest-334/test_checkout_in_non_empty_dir0')

    def test_checkout_in_non_empty_dir(tmp_path):
        orig_repo = tmp_path / "orig"
        with git.Repo.init(orig_repo, expand_vars=False) as repo:
            repo.index.commit(message='Initial commit', **_commitargs)

        non_empty_dir = tmp_path / 'non-empty-clone'
        non_empty_dir.mkdir(parents=True)
        garbage_file = non_empty_dir / 'not-empty'
        garbage_file.write_text('Garbage!')

        # Verify that the clone fails complaining about the target directory not being empty/non-existent
>       git.Repo.clone_from(orig_repo, non_empty_dir)

hopic/test/test_checkout.py:95:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
v3.8/lib/python3.8/site-packages/git/repo/base.py:1032: in clone_from
    return cls._clone(git, url, to_path, GitCmdObjectDB, progress, multi_options, **kwargs)
v3.8/lib/python3.8/site-packages/git/repo/base.py:973: in _clone
    finalize_process(proc, stderr=stderr)
v3.8/lib/python3.8/site-packages/git/util.py:329: in finalize_process
    proc.wait(**kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <git.cmd.Git.AutoInterrupt object at 0x7f6a5883f9a0>
stderr = b"fatal: destination path '/tmp/pytest-of-vanschig/pytest-334/test_checkout_in_non_empty_dir0/non-empty-clone' already exists and is not an empty directory.\n"

    def wait(self, stderr=b''):  # TODO: Bad choice to mimic `proc.wait()` but with different args.
        """Wait for the process and return its status code.

        :param stderr: Previously read value of stderr, in case stderr is already closed.
        :warn: may deadlock if output or error pipes are used and not handled separately.
        :raise GitCommandError: if the return status is not 0"""
        if stderr is None:
            stderr = b''
        stderr = force_bytes(data=stderr, encoding='utf-8')

        status = self.proc.wait()

        def read_all_from_possibly_closed_stream(stream):
            try:
                return stderr + force_bytes(stream.read())
            except ValueError:
                return stderr or b''

        if status != 0:
            errstr = read_all_from_possibly_closed_stream(self.proc.stderr)
            log.debug('AutoInterrupt wait stderr: %r' % (errstr,))
>           raise GitCommandError(self.args, status, errstr)
E           git.exc.GitCommandError: Cmd('git') failed due to: exit code(128)
E             cmdline: git clone -v /tmp/pytest-of-vanschig/pytest-334/test_checkout_in_non_empty_dir0/orig /tmp/pytest-of-vanschig/pytest-334/test_checkout_in_non_empty_dir0/non-empty-clone
E             stderr: 'fatal: destination path '/tmp/pytest-of-vanschig/pytest-334/test_checkout_in_non_empty_dir0/non-empty-clone' already exists and is not an empty directory.
E           '

v3.8/lib/python3.8/site-packages/git/cmd.py:408: GitCommandError

With 3.1.15 this output is produced instead (notice the absence of the "stderr: ..." line):

___________________________________________________________________ test_checkout_in_non_empty_dir ____________________________________________________________________

tmp_path = PosixPath('/tmp/pytest-of-vanschig/pytest-336/test_checkout_in_non_empty_dir0')

    def test_checkout_in_non_empty_dir(tmp_path):
        orig_repo = tmp_path / "orig"
        with git.Repo.init(orig_repo, expand_vars=False) as repo:
            repo.index.commit(message='Initial commit', **_commitargs)

        non_empty_dir = tmp_path / 'non-empty-clone'
        non_empty_dir.mkdir(parents=True)
        garbage_file = non_empty_dir / 'not-empty'
        garbage_file.write_text('Garbage!')

        # Verify that the clone fails complaining about the target directory not being empty/non-existent
>       git.Repo.clone_from(orig_repo, non_empty_dir)

hopic/test/test_checkout.py:95:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
v3.8/lib/python3.8/site-packages/git/repo/base.py:1087: in clone_from
    return cls._clone(git, url, to_path, GitCmdObjectDB, progress, multi_options, **kwargs)
v3.8/lib/python3.8/site-packages/git/repo/base.py:1017: in _clone
    handle_process_output(proc, None, progress_checked.new_message_handler(),
v3.8/lib/python3.8/site-packages/git/cmd.py:116: in handle_process_output
    return finalizer(process)
v3.8/lib/python3.8/site-packages/git/util.py:354: in finalize_process
    proc.wait(**kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <git.cmd.Git.AutoInterrupt object at 0x7fcc8fd95820>, stderr = b''

    def wait(self, stderr=b''):  # TODO: Bad choice to mimic `proc.wait()` but with different args.
        """Wait for the process and return its status code.

        :param stderr: Previously read value of stderr, in case stderr is already closed.
        :warn: may deadlock if output or error pipes are used and not handled separately.
        :raise GitCommandError: if the return status is not 0"""
        if stderr is None:
            stderr = b''
        stderr = force_bytes(data=stderr, encoding='utf-8')

        status = self.proc.wait()

        def read_all_from_possibly_closed_stream(stream):
            try:
                return stderr + force_bytes(stream.read())
            except ValueError:
                return stderr or b''

        if status != 0:
            errstr = read_all_from_possibly_closed_stream(self.proc.stderr)
            log.debug('AutoInterrupt wait stderr: %r' % (errstr,))
>           raise GitCommandError(remove_password_if_present(self.args), status, errstr)
E           git.exc.GitCommandError: Cmd('git') failed due to: exit code(128)
E             cmdline: git clone -v --progress /tmp/pytest-of-vanschig/pytest-336/test_checkout_in_non_empty_dir0/orig /tmp/pytest-of-vanschig/pytest-336/test_checkout_in_non_empty_dir0/non-empty-clone

v3.8/lib/python3.8/site-packages/git/cmd.py:409: GitCommandError

When catching the exception and dumping it's stderr attribute it turns out to be an empty string ('').

This seems related to #1220. But it's presentation is different as that issue still reports having content, just wrongly encoded.

[jmcgill298]

@muggenhor I don't believe the issue I raised is related to this. My issue is specifically that bytes are typecast to a str, not that bytes are missing. I have pinpointed the change that has caused this change in behavior in the issue, and these should not have the effect of bytes missing

[muggenhor]

Right, this seems to be introduced by a different change too. This is instead introduced by 85ebfb2 from #1192.

[Byron]

Thanks a lot for researching this. I would be super happy about a PR for a fix that doesn't undo the entirety of 85ebfb2, which assumably you find via bisection or similar.

When looking at the changes, it wasn't immediately obvious why clone() would be affected in that way:

85ebfb2#diff-3cc1aaf2f1e2bc1341d3f71ceec44b2762b981280b4d162e26327bd558721fe1R1050

[muggenhor]

Yes, I discovered the commit through bisection. Just looking at the full diff between 3.1.14 and 3.1.15 didn't give me anything close to a hint.