"pipenv lock --requirements" leaks output from git, making the result invalid, only the first time

[chtseac]

Issue description

One of my dependencies is in the format "lib" = {ref = "branch-name", git = "https://url/to/repo.git"}.

I run pipenv lock --requirements > requirements.txt for the first time inside a docker container.

Expected result

I get a valid requirements.txt

Actual result

See below

Steps to replicate

docker run -it --rm python:3.6 bash

Inside container

pip install pipenv==2018.11.26

echo '                        
[[source]]
url = "https://pypi.org/simple"
verify_ssl = true
name = "pypi"

[dev-packages]

[packages]
"numpy" = {ref = "maintenance/1.15.x", git = "https://github.com/numpy/numpy.git"}
' > Pipfile

pipenv lock --requirements > requirements.txt

Resultant requirements.txt (yes really):

Switched to a new branch 'maintenance/1.15.x'
Branch maintenance/1.15.x set up to track remote branch maintenance/1.15.x from origin.
-i https://pypi.org/simple
git+https://github.com/numpy/numpy.git@3430d78c01a3b9a19adad75f1acb5ae18286da73#egg=numpy

And of course:

root@3f46e6fed2ba:/# pip install -r requirements.txt 
Invalid requirement: 'Switched to a new branch 'maintenance/1.15.x''
It looks like a path. File 'Switched to a new branch 'maintenance/1.15.x'' does not exist.

Workaround

I run pipenv lock --requirements > /dev/null 2>&1 once before running the actual command.

---

Please run $ pipenv --support, and paste the results here. Don't put backticks (`) around it! The output already contains Markdown formatting.

$ pipenv --support

Pipenv version: '2018.11.26'

Pipenv location: '/usr/local/lib/python3.6/site-packages/pipenv'

Python location: '/usr/local/bin/python'

Python installations found:

• 3.6.7: /usr/local/bin/python
• 3.6.7: /usr/local/bin/python3.6m
• 3.5.3: /usr/bin/python3
• 3.5.3: /usr/bin/python3.5m
• 2.7.13: /usr/bin/python2.7

PEP 508 Information:

{'implementation_name': 'cpython',
 'implementation_version': '3.6.7',
 'os_name': 'posix',
 'platform_machine': 'x86_64',
 'platform_python_implementation': 'CPython',
 'platform_release': '4.15.0-39-generic',
 'platform_system': 'Linux',
 'platform_version': '#42~16.04.1-Ubuntu SMP Wed Oct 24 17:09:54 UTC 2018',
 'python_full_version': '3.6.7',
 'python_version': '3.6',
 'sys_platform': 'linux'}

System environment variables:

• LANG
• HOSTNAME
• GPG_KEY
• PWD
• HOME
• TERM
• PYTHON_VERSION
• SHLVL
• PATH
• PYTHON_PIP_VERSION
• _
• PIP_DISABLE_PIP_VERSION_CHECK
• PYTHONDONTWRITEBYTECODE
• PIP_SHIMS_BASE_MODULE
• PIP_PYTHON_PATH
• PYTHONFINDER_IGNORE_UNSUPPORTED

Pipenv–specific environment variables:

Debug–specific environment variables:

• PATH: /usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
• LANG: C.UTF-8
• PWD: /

---

Contents of Pipfile ('/Pipfile'):

[[source]]
url = "https://pypi.org/simple"
verify_ssl = true
name = "pypi"

[dev-packages]

[packages]
"numpy" = {ref = "maintenance/1.15.x", git = "https://github.com/numpy/numpy.git"}

Contents of Pipfile.lock ('/Pipfile.lock'):

{
    "_meta": {
        "hash": {
            "sha256": "e8d89524a159e6d44fa849ffd5e1bf02b13a73b773013996d77d5405776369eb"
        },
        "pipfile-spec": 6,
        "requires": {},
        "sources": [
            {
                "name": "pypi",
                "url": "https://pypi.org/simple",
                "verify_ssl": true
            }
        ]
    },
    "default": {
        "numpy": {
            "git": "https://github.com/numpy/numpy.git",
            "ref": "3430d78c01a3b9a19adad75f1acb5ae18286da73"
        }
    },
    "develop": {}
}

[techalchemy]

Wow that is incredibly frustrating. That is pip logging to standard output.

[techalchemy]

They log literally everything else to standard error....

[chtseac]

I see that the update tries to output the git commit hash as the checkout path instead of the branch name, and somewhere in there must be a git checkout $ref of which output makes its way to stdout, but I haven't dug deep enough to figure out which command is leaking.

[techalchemy]

It’s very indirect. It’s going to be in a super recent change in pipenv/utils.py basically via venv_resolve_deps, which now calls get_vcs_deps directly. This eventually calls get_locked_requirement which calls pipenv.vendor.requirementslib.models.requirements.Requirement() to get access to a contextmanager with access to a temporary checkout of the repo. That ultimately is done in requirementslib.models.vcs but is just delegated to pip’s native VCS handled. I’m pretty confident we moved this to make sure resolution happens in the venv; I guess that’s why we are capturing this...

[techalchemy]

hmmm the specifics are super helpful here, because the output only happens when you clone a branch directly in pip. I have a fix for this but it just basically monkeypatches the defaults to suppress stdout in pip's command runner during vcs operations :|

[cjerdonek]

Wow that is incredibly frustrating. That is pip logging to standard output.

FYI, I'm actually planning on fixing this in pip soon across the board (I coincidentally just had my eye on it). I filed a preliminary PR here: pypa/pip#6154

[techalchemy]

Awesome, thanks @cjerdonek — I merged some changes to requirementslib to monkeypatch pip and capture stdout in the meantime

[asyncmind0]

still exists with version pipenv-2018.11.26