Called process error output doesn’t all go to stderr

[flying-sheep]

pip 19.1.1, Python: 3.8-dev, Ubuntu xenial

My travis build with Python 3.8 fails: https://travis-ci.org/theislab/scanpy/jobs/550248884#L285

The error occurs when trying to install scipy’s build requirements via pyproject.toml. Confusingly, it reports an environment marker not matching (and the subsequent ignoring of the dependency) as an error:

Installing build dependencies ... error
ERROR: Complete output from command
       …/python …/pip install --ignore-installed --no-user --prefix …/overlay \
       --no-warn-script-location --no-binary :none: --only-binary :none: \
       -i https://pypi.org/simple -- wheel setuptools 'Cython>=0.29.2' \
       'numpy==1.13.3; python_version=='"'"'3.5'"'"'' \
       'numpy==1.13.3; python_version=='"'"'3.6'"'"'' \
       'numpy==1.14.5; python_version>='"'"'3.7'"'"'':
ERROR: Ignoring numpy: markers 'python_version == "3.5"' don't match your environment 
Ignoring numpy: markers 'python_version == "3.6"' don't match your environment

As you can see, the subsequent ignoring of the second line is not reported as an error (as I would expect).

[cjerdonek]

This can be fixed by merging these two log messages into a single message:

pip/src/pip/_internal/utils/misc.py

Lines 835 to 839 in 0dbab23

	subprocess_logger.error(
	'Complete output from command %s:', command_desc,
	)
	# The all_output value already ends in a newline.
	subprocess_logger.error(''.join(all_output) + LOG_DIVIDER)

[flying-sheep]

Well, that would fix the part about one of two identical messages being reported as error.

But I still don’t understand what the error here is. It shouldn’t be an error if some environment marker in the build deps doesn’t match, that dep should simply be skipped.

[cjerdonek]

But I still don’t understand what the error here is.

It looks like you didn't provide all of the output towards the end. Is there more?

[flying-sheep]

The link in the issue descriptions goes there.

And you’re right! The real error(s) happen(s) later but due to only the first line being sent to stdout, I didn’t see that. It’s numpy/numpy#13790

[cjerdonek]

Okay, yeah, I saw after I clicked on it. Basically, this is a formatting / presentation issue IMO where we need to better delineate the beginning and end of the command output (the "Complete output from command" mentioned above).

[cjerdonek]

FYI, I posted PR #6655 to address this.

It would remove the confusing ERROR: before the "Ignoring numpy: ..." line, and it would also improve the formatting more generally. The beginning of the log message lines would look more like this:

ERROR: Command errored out with exit status 1:
 command: /home/travis/virtualenv/python3.8-dev/bin/python ...
     cwd: /tmp/pip-install-12n4c4tn/numpy/
Complete output (7500 lines):
Ignoring numpy: markers 'python_version == "3.5"' don't match your environment 
Ignoring numpy: markers 'python_version == "3.6"' don't match your environment
...
...
...
----------------------------------------