mirror of https://github.com/pypa/pip
Improve error message formatting when a subprocess command errors out.
This commit is contained in:
parent
fc46a18563
commit
9eab3526a8
|
@ -0,0 +1 @@
|
|||
Improve error message formatting when a command errors out in a subprocess.
|
|
@ -724,6 +724,41 @@ def format_command_args(args):
|
|||
return ' '.join(shlex_quote(arg) for arg in args)
|
||||
|
||||
|
||||
def make_subprocess_output_error(
|
||||
cmd_args, # type: List[str]
|
||||
cwd, # type: Optional[str]
|
||||
lines, # type: List[Text]
|
||||
exit_status, # type: int
|
||||
):
|
||||
# type: (...) -> Text
|
||||
"""
|
||||
Create and return the error message to use to log a subprocess error
|
||||
with command output.
|
||||
|
||||
:param lines: A list of lines, each ending with a newline.
|
||||
"""
|
||||
command = format_command_args(cmd_args)
|
||||
# We know the joined output value ends in a newline.
|
||||
output = ''.join(lines)
|
||||
msg = (
|
||||
# We need to mark this explicitly as a unicode string to avoid
|
||||
# "UnicodeEncodeError: 'ascii' codec can't encode character ..."
|
||||
# errors in Python 2 since e.g. `output` is a unicode string.
|
||||
u'Command errored out with exit status {exit_status}:\n'
|
||||
' command: {command}\n'
|
||||
' cwd: {cwd}\n'
|
||||
'Complete output ({line_count} lines):\n{output}{divider}'
|
||||
).format(
|
||||
exit_status=exit_status,
|
||||
command=command,
|
||||
cwd=cwd,
|
||||
line_count=len(lines),
|
||||
output=output,
|
||||
divider=LOG_DIVIDER,
|
||||
)
|
||||
return msg
|
||||
|
||||
|
||||
def call_subprocess(
|
||||
cmd, # type: List[str]
|
||||
show_stdout=False, # type: bool
|
||||
|
@ -803,6 +838,7 @@ def call_subprocess(
|
|||
raise
|
||||
all_output = []
|
||||
while True:
|
||||
# The "line" value is a unicode string in Python 2.
|
||||
line = console_to_str(proc.stdout.readline())
|
||||
if not line:
|
||||
break
|
||||
|
@ -832,14 +868,18 @@ def call_subprocess(
|
|||
if not showing_subprocess:
|
||||
# Then the subprocess streams haven't been logged to the
|
||||
# console yet.
|
||||
subprocess_logger.error(
|
||||
'Complete output from command %s:', command_desc,
|
||||
msg = make_subprocess_output_error(
|
||||
cmd_args=cmd,
|
||||
cwd=cwd,
|
||||
lines=all_output,
|
||||
exit_status=proc.returncode,
|
||||
)
|
||||
# The all_output value already ends in a newline.
|
||||
subprocess_logger.error(''.join(all_output) + LOG_DIVIDER)
|
||||
raise InstallationError(
|
||||
'Command "%s" failed with error code %s in %s'
|
||||
% (command_desc, proc.returncode, cwd))
|
||||
subprocess_logger.error(msg)
|
||||
exc_msg = (
|
||||
'Command errored out with exit status {}: {} '
|
||||
'Check the logs for full command output.'
|
||||
).format(proc.returncode, command_desc)
|
||||
raise InstallationError(exc_msg)
|
||||
elif on_returncode == 'warn':
|
||||
subprocess_logger.warning(
|
||||
'Command "%s" had error code %s in %s',
|
||||
|
|
|
@ -938,7 +938,7 @@ def test_install_package_that_emits_unicode(script, data):
|
|||
)
|
||||
assert (
|
||||
'FakeError: this package designed to fail on install' in result.stderr
|
||||
)
|
||||
), 'stderr: {}'.format(result.stderr)
|
||||
assert 'UnicodeDecodeError' not in result.stderr
|
||||
assert 'UnicodeDecodeError' not in result.stdout
|
||||
|
||||
|
|
|
@ -15,6 +15,7 @@ import time
|
|||
import warnings
|
||||
from io import BytesIO
|
||||
from logging import DEBUG, ERROR, INFO, WARNING
|
||||
from textwrap import dedent
|
||||
|
||||
import pytest
|
||||
from mock import Mock, patch
|
||||
|
@ -29,8 +30,8 @@ from pip._internal.utils.glibc import check_glibc_version
|
|||
from pip._internal.utils.hashes import Hashes, MissingHashes
|
||||
from pip._internal.utils.misc import (
|
||||
call_subprocess, egg_link_path, ensure_dir, format_command_args,
|
||||
get_installed_distributions, get_prog, normalize_path,
|
||||
normalize_version_info, path_to_url, redact_netloc,
|
||||
get_installed_distributions, get_prog, make_subprocess_output_error,
|
||||
normalize_path, normalize_version_info, path_to_url, redact_netloc,
|
||||
redact_password_from_url, remove_auth_from_url, rmtree,
|
||||
split_auth_from_netloc, split_auth_netloc_from_url, untar_file, unzip_file,
|
||||
)
|
||||
|
@ -744,6 +745,50 @@ def test_format_command_args(args, expected):
|
|||
assert actual == expected
|
||||
|
||||
|
||||
def test_make_subprocess_output_error():
|
||||
cmd_args = ['test', 'has space']
|
||||
cwd = '/path/to/cwd'
|
||||
lines = ['line1\n', 'line2\n', 'line3\n']
|
||||
actual = make_subprocess_output_error(
|
||||
cmd_args=cmd_args,
|
||||
cwd=cwd,
|
||||
lines=lines,
|
||||
exit_status=3,
|
||||
)
|
||||
expected = dedent("""\
|
||||
Command errored out with exit status 3:
|
||||
command: test 'has space'
|
||||
cwd: /path/to/cwd
|
||||
Complete output (3 lines):
|
||||
line1
|
||||
line2
|
||||
line3
|
||||
----------------------------------------""")
|
||||
assert actual == expected, 'actual: {}'.format(actual)
|
||||
|
||||
|
||||
# This test is mainly important for checking unicode in Python 2.
|
||||
def test_make_subprocess_output_error__unicode():
|
||||
"""
|
||||
Test a line with non-ascii unicode characters.
|
||||
"""
|
||||
lines = [u'curly-quote: \u2018\n']
|
||||
actual = make_subprocess_output_error(
|
||||
cmd_args=['test'],
|
||||
cwd='/path/to/cwd',
|
||||
lines=lines,
|
||||
exit_status=1,
|
||||
)
|
||||
expected = dedent(u"""\
|
||||
Command errored out with exit status 1:
|
||||
command: test
|
||||
cwd: /path/to/cwd
|
||||
Complete output (1 lines):
|
||||
curly-quote: \u2018
|
||||
----------------------------------------""")
|
||||
assert actual == expected, u'actual: {}'.format(actual)
|
||||
|
||||
|
||||
class FakeSpinner(SpinnerInterface):
|
||||
|
||||
def __init__(self):
|
||||
|
@ -866,14 +911,17 @@ class TestCallSubprocess(object):
|
|||
command = 'print("Hello"); print("world"); exit("fail")'
|
||||
args, spinner = self.prepare_call(caplog, log_level, command=command)
|
||||
|
||||
with pytest.raises(InstallationError):
|
||||
with pytest.raises(InstallationError) as exc:
|
||||
call_subprocess(args, spinner=spinner)
|
||||
result = None
|
||||
exc_message = str(exc.value)
|
||||
assert exc_message.startswith(
|
||||
'Command errored out with exit status 1: '
|
||||
)
|
||||
assert exc_message.endswith('Check the logs for full command output.')
|
||||
|
||||
expected = (None, [
|
||||
('pip.subprocessor', ERROR, 'Complete output from command '),
|
||||
# The "failed" portion is later on in this "Hello" string.
|
||||
('pip.subprocessor', ERROR, 'Hello'),
|
||||
('pip.subprocessor', ERROR, 'Complete output (3 lines):\n'),
|
||||
])
|
||||
# The spinner should spin three times in this case since the
|
||||
# subprocess output isn't being written to the console.
|
||||
|
@ -892,12 +940,22 @@ class TestCallSubprocess(object):
|
|||
# guarantee the order in which stdout and stderr will appear.
|
||||
# For example, we observed the stderr lines coming before stdout
|
||||
# in CI for PyPy 2.7 even though stdout happens first chronologically.
|
||||
assert sorted(lines) == [
|
||||
actual = sorted(lines)
|
||||
# Test the "command" line separately because we can't test an
|
||||
# exact match.
|
||||
command_line = actual.pop(1)
|
||||
assert actual == [
|
||||
' cwd: None',
|
||||
'----------------------------------------',
|
||||
'Command errored out with exit status 1:',
|
||||
'Complete output (3 lines):',
|
||||
'Hello',
|
||||
'fail',
|
||||
'world',
|
||||
], 'lines: {}'.format(lines) # Show the full output on failure.
|
||||
], 'lines: {}'.format(actual) # Show the full output on failure.
|
||||
|
||||
assert command_line.startswith(' command: ')
|
||||
assert command_line.endswith('print("world"); exit("fail")\'')
|
||||
|
||||
def test_info_logging_with_show_stdout_true(self, capfd, caplog):
|
||||
"""
|
||||
|
|
Loading…
Reference in New Issue