From 1471897b84b43c467c753b5edebe636f835afc6a Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Fri, 3 Apr 2020 13:08:41 +0530 Subject: [PATCH 1/6] Improve check for svn version string --- news/7968.bugfix | 1 + src/pip/_internal/vcs/subversion.py | 15 +++++++++++++-- tests/unit/test_vcs.py | 12 ++++++++++++ 3 files changed, 26 insertions(+), 2 deletions(-) create mode 100644 news/7968.bugfix diff --git a/news/7968.bugfix b/news/7968.bugfix new file mode 100644 index 000000000..d6959730a --- /dev/null +++ b/news/7968.bugfix @@ -0,0 +1 @@ +Look for version string in the entire output of svn --version, not just the first line diff --git a/src/pip/_internal/vcs/subversion.py b/src/pip/_internal/vcs/subversion.py index 0ec659744..d0fe3cd9d 100644 --- a/src/pip/_internal/vcs/subversion.py +++ b/src/pip/_internal/vcs/subversion.py @@ -25,7 +25,7 @@ _svn_info_xml_url_re = re.compile(r'(.*)') if MYPY_CHECK_RUNNING: - from typing import Optional, Tuple + from typing import Optional, Tuple, Text from pip._internal.utils.subprocess import CommandArgs from pip._internal.utils.misc import HiddenText from pip._internal.vcs.versioncontrol import AuthInfo, RevOptions @@ -215,7 +215,18 @@ class Subversion(VersionControl): # svn, version 1.7.14 (r1542130) # compiled Mar 28 2018, 08:49:13 on x86_64-pc-linux-gnu version_prefix = 'svn, version ' - version = self.run_command(['--version'], show_stdout=False) + cmd_output = self.run_command(['--version'], show_stdout=False) + + # Split the output by newline, and find the first line where + # version_prefix is present + output_lines = cmd_output.split('\n') + version = '' # type: Text + + for line in output_lines: + if version_prefix in line: + version = line + break + if not version.startswith(version_prefix): return () diff --git a/tests/unit/test_vcs.py b/tests/unit/test_vcs.py index 590cb5c0b..166585db3 100644 --- a/tests/unit/test_vcs.py +++ b/tests/unit/test_vcs.py @@ -443,6 +443,18 @@ def test_subversion__call_vcs_version(): ('svn, version 1.10.3 (r1842928)\n' ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', (1, 10, 3)), + ('Warning: Failed to set locale category LC_NUMERIC to en_IN.\n' + 'Warning: Failed to set locale category LC_TIME to en_IN.\n' + 'svn, version 1.10.3 (r1842928)\n' + ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', + (1, 10, 3)), + ('Warning: Failed to set locale category LC_NUMERIC to en_IN.\n' + 'Warning: Failed to set locale category LC_TIME to en_IN.\n' + 'svn, version 1.10.3 (r1842928)\n' + ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0' + 'svn, version 1.11.3 (r1842928)\n' + ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', + (1, 10, 3)), ('svn, version 1.9.7 (r1800392)', (1, 9, 7)), ('svn, version 1.9.7a1 (r1800392)', ()), ('svn, version 1.9 (r1800392)', (1, 9)), From 8adbc216a647b6b349f1b7f1eaa9e71cd3108955 Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Sat, 18 Apr 2020 12:47:35 +0530 Subject: [PATCH 2/6] Create call_subprocess just for vcs commands --- src/pip/_internal/exceptions.py | 5 + src/pip/_internal/vcs/subversion.py | 14 +-- src/pip/_internal/vcs/versioncontrol.py | 144 ++++++++++++++++++++++-- tests/unit/test_vcs.py | 12 -- 4 files changed, 139 insertions(+), 36 deletions(-) diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 8ac85485e..e0d7f095d 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -84,6 +84,11 @@ class CommandError(PipError): """Raised when there is an error in command-line arguments""" +class SubProcessError(PipError): + """Raised when there is an error raised while executing a + command in subprocess""" + + class PreviousBuildDirError(PipError): """Raised when there's a previous conflicting build directory""" diff --git a/src/pip/_internal/vcs/subversion.py b/src/pip/_internal/vcs/subversion.py index d0fe3cd9d..3f9d0833f 100644 --- a/src/pip/_internal/vcs/subversion.py +++ b/src/pip/_internal/vcs/subversion.py @@ -25,7 +25,7 @@ _svn_info_xml_url_re = re.compile(r'(.*)') if MYPY_CHECK_RUNNING: - from typing import Optional, Tuple, Text + from typing import Optional, Tuple from pip._internal.utils.subprocess import CommandArgs from pip._internal.utils.misc import HiddenText from pip._internal.vcs.versioncontrol import AuthInfo, RevOptions @@ -215,17 +215,7 @@ class Subversion(VersionControl): # svn, version 1.7.14 (r1542130) # compiled Mar 28 2018, 08:49:13 on x86_64-pc-linux-gnu version_prefix = 'svn, version ' - cmd_output = self.run_command(['--version'], show_stdout=False) - - # Split the output by newline, and find the first line where - # version_prefix is present - output_lines = cmd_output.split('\n') - version = '' # type: Text - - for line in output_lines: - if version_prefix in line: - version = line - break + version = self.run_command(['--version'], show_stdout=True) if not version.startswith(version_prefix): return () diff --git a/src/pip/_internal/vcs/versioncontrol.py b/src/pip/_internal/vcs/versioncontrol.py index 71b4650a2..1956559b3 100644 --- a/src/pip/_internal/vcs/versioncontrol.py +++ b/src/pip/_internal/vcs/versioncontrol.py @@ -6,13 +6,19 @@ import errno import logging import os import shutil +import subprocess import sys from pip._vendor import pkg_resources from pip._vendor.six.moves.urllib import parse as urllib_parse -from pip._internal.exceptions import BadCommand, InstallationError -from pip._internal.utils.compat import samefile +from pip._internal.exceptions import ( + BadCommand, + InstallationError, + SubProcessError, +) +from pip._internal.utils.compat import console_to_str, samefile +from pip._internal.utils.logging import subprocess_logger from pip._internal.utils.misc import ( ask_path_exists, backup_dir, @@ -21,16 +27,20 @@ from pip._internal.utils.misc import ( hide_value, rmtree, ) -from pip._internal.utils.subprocess import call_subprocess, make_command +from pip._internal.utils.subprocess import ( + format_command_args, + make_command, + make_subprocess_output_error, + reveal_command_args, +) from pip._internal.utils.typing import MYPY_CHECK_RUNNING from pip._internal.utils.urls import get_url_scheme if MYPY_CHECK_RUNNING: from typing import ( - Any, Dict, Iterable, Iterator, List, Mapping, Optional, Text, Tuple, + Dict, Iterable, Iterator, List, Optional, Text, Tuple, Type, Union ) - from pip._internal.cli.spinners import SpinnerInterface from pip._internal.utils.misc import HiddenText from pip._internal.utils.subprocess import CommandArgs @@ -71,6 +81,123 @@ def make_vcs_requirement_url(repo_url, rev, project_name, subdir=None): return req +def call_subprocess( + cmd, # type: Union[List[str], CommandArgs] + show_stdout=False, # type: bool + cwd=None, # type: Optional[str] + on_returncode='raise', # type: str + extra_ok_returncodes=None, # type: Optional[Iterable[int]] + log_failed_cmd=True # type: Optional[bool] +): + # type: (...) -> Text + """ + Args: + show_stdout: if true, use INFO to log the subprocess's stderr and + stdout streams. Otherwise, use DEBUG. Defaults to False. + extra_ok_returncodes: an iterable of integer return codes that are + acceptable, in addition to 0. Defaults to None, which means []. + log_failed_cmd: if false, failed commands are not logged, + only raised. + """ + if extra_ok_returncodes is None: + extra_ok_returncodes = [] + # Most places in pip use show_stdout=False. + # What this means is-- + # + # - We log this output of stdout and stderr at DEBUG level + # as it is received. + # - If DEBUG logging isn't enabled (e.g. if --verbose logging wasn't + # requested), then we show a spinner so the user can still see the + # subprocess is in progress. + # - If the subprocess exits with an error, we log the output to stderr + # at ERROR level if it hasn't already been displayed to the console + # (e.g. if --verbose logging wasn't enabled). This way we don't log + # the output to the console twice. + # + # If show_stdout=True, then the above is still done, but with DEBUG + # replaced by INFO. + if show_stdout: + # Then log the subprocess output at INFO level. + log_subprocess = subprocess_logger.info + used_level = logging.INFO + else: + # Then log the subprocess output using DEBUG. This also ensures + # it will be logged to the log file (aka user_log), if enabled. + log_subprocess = subprocess_logger.debug + used_level = logging.DEBUG + + # Whether the subprocess will be visible in the console. + showing_subprocess = subprocess_logger.getEffectiveLevel() <= used_level + + command_desc = format_command_args(cmd) + try: + proc = subprocess.Popen( + # Convert HiddenText objects to the underlying str. + reveal_command_args(cmd), + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + cwd=cwd + ) + if proc.stdin: + proc.stdin.close() + except Exception as exc: + if log_failed_cmd: + subprocess_logger.critical( + "Error %s while executing command %s", exc, command_desc, + ) + raise + all_output = [] + while True: + # The "line" value is a unicode string in Python 2. + line = None + if proc.stdout: + line = console_to_str(proc.stdout.readline()) + if not line: + break + line = line.rstrip() + all_output.append(line + '\n') + + # Show the line immediately. + log_subprocess(line) + try: + proc.wait() + finally: + if proc.stdout: + proc.stdout.close() + + proc_had_error = ( + proc.returncode and proc.returncode not in extra_ok_returncodes + ) + if proc_had_error: + if on_returncode == 'raise': + if not showing_subprocess and log_failed_cmd: + # Then the subprocess streams haven't been logged to the + # console yet. + msg = make_subprocess_output_error( + cmd_args=cmd, + cwd=cwd, + lines=all_output, + exit_status=proc.returncode, + ) + 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 SubProcessError(exc_msg) + elif on_returncode == 'warn': + subprocess_logger.warning( + 'Command "{}" had error code {} in {}'.format( + command_desc, proc.returncode, cwd) + ) + elif on_returncode == 'ignore': + pass + else: + raise ValueError('Invalid value: on_returncode={!r}'.format( + on_returncode)) + return ''.join(all_output) + + def find_path_to_setup_from_repo_root(location, repo_root): # type: (str, str) -> Optional[str] """ @@ -663,9 +790,6 @@ class VersionControl(object): cwd=None, # type: Optional[str] on_returncode='raise', # type: str extra_ok_returncodes=None, # type: Optional[Iterable[int]] - command_desc=None, # type: Optional[str] - extra_environ=None, # type: Optional[Mapping[str, Any]] - spinner=None, # type: Optional[SpinnerInterface] log_failed_cmd=True # type: bool ): # type: (...) -> Text @@ -679,10 +803,6 @@ class VersionControl(object): return call_subprocess(cmd, show_stdout, cwd, on_returncode=on_returncode, extra_ok_returncodes=extra_ok_returncodes, - command_desc=command_desc, - extra_environ=extra_environ, - unset_environ=cls.unset_environ, - spinner=spinner, log_failed_cmd=log_failed_cmd) except OSError as e: # errno.ENOENT = no such file or directory diff --git a/tests/unit/test_vcs.py b/tests/unit/test_vcs.py index 166585db3..590cb5c0b 100644 --- a/tests/unit/test_vcs.py +++ b/tests/unit/test_vcs.py @@ -443,18 +443,6 @@ def test_subversion__call_vcs_version(): ('svn, version 1.10.3 (r1842928)\n' ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', (1, 10, 3)), - ('Warning: Failed to set locale category LC_NUMERIC to en_IN.\n' - 'Warning: Failed to set locale category LC_TIME to en_IN.\n' - 'svn, version 1.10.3 (r1842928)\n' - ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', - (1, 10, 3)), - ('Warning: Failed to set locale category LC_NUMERIC to en_IN.\n' - 'Warning: Failed to set locale category LC_TIME to en_IN.\n' - 'svn, version 1.10.3 (r1842928)\n' - ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0' - 'svn, version 1.11.3 (r1842928)\n' - ' compiled Feb 25 2019, 14:20:39 on x86_64-apple-darwin17.0.0', - (1, 10, 3)), ('svn, version 1.9.7 (r1800392)', (1, 9, 7)), ('svn, version 1.9.7a1 (r1800392)', ()), ('svn, version 1.9 (r1800392)', (1, 9)), From 94882fd1ed9171ea5a2f4b8904dbd8763f05ba68 Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Sat, 18 Apr 2020 14:10:45 +0530 Subject: [PATCH 3/6] Remove show_stdout from run_command args --- src/pip/_internal/vcs/bazaar.py | 7 ++-- src/pip/_internal/vcs/git.py | 19 +++++------ src/pip/_internal/vcs/mercurial.py | 16 ++++----- src/pip/_internal/vcs/subversion.py | 9 +++-- src/pip/_internal/vcs/versioncontrol.py | 44 ++++++++----------------- 5 files changed, 36 insertions(+), 59 deletions(-) diff --git a/src/pip/_internal/vcs/bazaar.py b/src/pip/_internal/vcs/bazaar.py index 347c06f9d..94408c52f 100644 --- a/src/pip/_internal/vcs/bazaar.py +++ b/src/pip/_internal/vcs/bazaar.py @@ -54,8 +54,7 @@ class Bazaar(VersionControl): url, rev_options = self.get_url_rev_options(url) self.run_command( - make_command('export', location, url, rev_options.to_args()), - show_stdout=False, + make_command('export', location, url, rev_options.to_args()) ) def fetch_new(self, dest, url, rev_options): @@ -92,7 +91,7 @@ class Bazaar(VersionControl): @classmethod def get_remote_url(cls, location): - urls = cls.run_command(['info'], show_stdout=False, cwd=location) + urls = cls.run_command(['info'], cwd=location) for line in urls.splitlines(): line = line.strip() for x in ('checkout of branch: ', @@ -107,7 +106,7 @@ class Bazaar(VersionControl): @classmethod def get_revision(cls, location): revision = cls.run_command( - ['revno'], show_stdout=False, cwd=location, + ['revno'], cwd=location, ) return revision.splitlines()[-1] diff --git a/src/pip/_internal/vcs/git.py b/src/pip/_internal/vcs/git.py index e173ec894..61d0ff647 100644 --- a/src/pip/_internal/vcs/git.py +++ b/src/pip/_internal/vcs/git.py @@ -11,7 +11,7 @@ from pip._vendor.packaging.version import parse as parse_version from pip._vendor.six.moves.urllib import parse as urllib_parse from pip._vendor.six.moves.urllib import request as urllib_request -from pip._internal.exceptions import BadCommand, InstallationError +from pip._internal.exceptions import BadCommand, SubProcessError from pip._internal.utils.misc import display_path, hide_url from pip._internal.utils.subprocess import make_command from pip._internal.utils.temp_dir import TempDirectory @@ -78,7 +78,7 @@ class Git(VersionControl): def get_git_version(self): VERSION_PFX = 'git version ' - version = self.run_command(['version'], show_stdout=False) + version = self.run_command(['version']) if version.startswith(VERSION_PFX): version = version[len(VERSION_PFX):].split()[0] else: @@ -101,7 +101,7 @@ class Git(VersionControl): # and to suppress the message to stderr. args = ['symbolic-ref', '-q', 'HEAD'] output = cls.run_command( - args, extra_ok_returncodes=(1, ), show_stdout=False, cwd=location, + args, extra_ok_returncodes=(1, ), cwd=location, ) ref = output.strip() @@ -120,7 +120,7 @@ class Git(VersionControl): self.unpack(temp_dir.path, url=url) self.run_command( ['checkout-index', '-a', '-f', '--prefix', location], - show_stdout=False, cwd=temp_dir.path + cwd=temp_dir.path ) @classmethod @@ -135,7 +135,7 @@ class Git(VersionControl): """ # Pass rev to pre-filter the list. output = cls.run_command(['show-ref', rev], cwd=dest, - show_stdout=False, on_returncode='ignore') + on_returncode='ignore') refs = {} for line in output.strip().splitlines(): try: @@ -286,7 +286,7 @@ class Git(VersionControl): # exits with return code 1 if there are no matching lines. stdout = cls.run_command( ['config', '--get-regexp', r'remote\..*\.url'], - extra_ok_returncodes=(1, ), show_stdout=False, cwd=location, + extra_ok_returncodes=(1, ), cwd=location, ) remotes = stdout.splitlines() try: @@ -306,7 +306,7 @@ class Git(VersionControl): if rev is None: rev = 'HEAD' current_rev = cls.run_command( - ['rev-parse', rev], show_stdout=False, cwd=location, + ['rev-parse', rev], cwd=location, ) return current_rev.strip() @@ -319,7 +319,7 @@ class Git(VersionControl): # find the repo root git_dir = cls.run_command( ['rev-parse', '--git-dir'], - show_stdout=False, cwd=location).strip() + cwd=location).strip() if not os.path.isabs(git_dir): git_dir = os.path.join(location, git_dir) repo_root = os.path.abspath(os.path.join(git_dir, '..')) @@ -378,7 +378,6 @@ class Git(VersionControl): r = cls.run_command( ['rev-parse', '--show-toplevel'], cwd=location, - show_stdout=False, on_returncode='raise', log_failed_cmd=False, ) @@ -386,7 +385,7 @@ class Git(VersionControl): logger.debug("could not determine if %s is under git control " "because git is not available", location) return None - except InstallationError: + except SubProcessError: return None return os.path.normpath(r.rstrip('\r\n')) diff --git a/src/pip/_internal/vcs/mercurial.py b/src/pip/_internal/vcs/mercurial.py index 75e903cc8..b7f8073fd 100644 --- a/src/pip/_internal/vcs/mercurial.py +++ b/src/pip/_internal/vcs/mercurial.py @@ -8,7 +8,7 @@ import os from pip._vendor.six.moves import configparser -from pip._internal.exceptions import BadCommand, InstallationError +from pip._internal.exceptions import BadCommand, SubProcessError from pip._internal.utils.misc import display_path from pip._internal.utils.subprocess import make_command from pip._internal.utils.temp_dir import TempDirectory @@ -47,7 +47,7 @@ class Mercurial(VersionControl): self.unpack(temp_dir.path, url=url) self.run_command( - ['archive', location], show_stdout=False, cwd=temp_dir.path + ['archive', location], cwd=temp_dir.path ) def fetch_new(self, dest, url, rev_options): @@ -92,7 +92,7 @@ class Mercurial(VersionControl): def get_remote_url(cls, location): url = cls.run_command( ['showconfig', 'paths.default'], - show_stdout=False, cwd=location).strip() + cwd=location).strip() if cls._is_local_repository(url): url = path_to_url(url) return url.strip() @@ -103,8 +103,7 @@ class Mercurial(VersionControl): Return the repository-local changeset revision number, as an integer. """ current_revision = cls.run_command( - ['parents', '--template={rev}'], - show_stdout=False, cwd=location).strip() + ['parents', '--template={rev}'], cwd=location).strip() return current_revision @classmethod @@ -115,7 +114,7 @@ class Mercurial(VersionControl): """ current_rev_hash = cls.run_command( ['parents', '--template={node}'], - show_stdout=False, cwd=location).strip() + cwd=location).strip() return current_rev_hash @classmethod @@ -131,7 +130,7 @@ class Mercurial(VersionControl): """ # find the repo root repo_root = cls.run_command( - ['root'], show_stdout=False, cwd=location).strip() + ['root'], cwd=location).strip() if not os.path.isabs(repo_root): repo_root = os.path.abspath(os.path.join(location, repo_root)) return find_path_to_setup_from_repo_root(location, repo_root) @@ -145,7 +144,6 @@ class Mercurial(VersionControl): r = cls.run_command( ['root'], cwd=location, - show_stdout=False, on_returncode='raise', log_failed_cmd=False, ) @@ -153,7 +151,7 @@ class Mercurial(VersionControl): logger.debug("could not determine if %s is under hg control " "because hg is not available", location) return None - except InstallationError: + except SubProcessError: return None return os.path.normpath(r.rstrip('\r\n')) diff --git a/src/pip/_internal/vcs/subversion.py b/src/pip/_internal/vcs/subversion.py index 3f9d0833f..4324a5d9f 100644 --- a/src/pip/_internal/vcs/subversion.py +++ b/src/pip/_internal/vcs/subversion.py @@ -132,7 +132,7 @@ class Subversion(VersionControl): @classmethod def _get_svn_url_rev(cls, location): - from pip._internal.exceptions import InstallationError + from pip._internal.exceptions import SubProcessError entries_path = os.path.join(location, cls.dirname, 'entries') if os.path.exists(entries_path): @@ -165,13 +165,12 @@ class Subversion(VersionControl): # are only potentially needed for remote server requests. xml = cls.run_command( ['info', '--xml', location], - show_stdout=False, ) url = _svn_info_xml_url_re.search(xml).group(1) revs = [ int(m.group(1)) for m in _svn_info_xml_rev_re.finditer(xml) ] - except InstallationError: + except SubProcessError: url, revs = None, [] if revs: @@ -215,7 +214,7 @@ class Subversion(VersionControl): # svn, version 1.7.14 (r1542130) # compiled Mar 28 2018, 08:49:13 on x86_64-pc-linux-gnu version_prefix = 'svn, version ' - version = self.run_command(['--version'], show_stdout=True) + version = self.run_command(['--version']) if not version.startswith(version_prefix): return () @@ -298,7 +297,7 @@ class Subversion(VersionControl): 'export', self.get_remote_call_options(), rev_options.to_args(), url, location, ) - self.run_command(cmd_args, show_stdout=False) + self.run_command(cmd_args) def fetch_new(self, dest, url, rev_options): # type: (str, HiddenText, RevOptions) -> None diff --git a/src/pip/_internal/vcs/versioncontrol.py b/src/pip/_internal/vcs/versioncontrol.py index 1956559b3..02bdda37c 100644 --- a/src/pip/_internal/vcs/versioncontrol.py +++ b/src/pip/_internal/vcs/versioncontrol.py @@ -39,7 +39,7 @@ from pip._internal.utils.urls import get_url_scheme if MYPY_CHECK_RUNNING: from typing import ( Dict, Iterable, Iterator, List, Optional, Text, Tuple, - Type, Union + Type, Union, Mapping, Any ) from pip._internal.utils.misc import HiddenText from pip._internal.utils.subprocess import CommandArgs @@ -83,17 +83,15 @@ def make_vcs_requirement_url(repo_url, rev, project_name, subdir=None): def call_subprocess( cmd, # type: Union[List[str], CommandArgs] - show_stdout=False, # type: bool cwd=None, # type: Optional[str] on_returncode='raise', # type: str + extra_environ=None, # type: Optional[Mapping[str, Any]] extra_ok_returncodes=None, # type: Optional[Iterable[int]] log_failed_cmd=True # type: Optional[bool] ): # type: (...) -> Text """ Args: - show_stdout: if true, use INFO to log the subprocess's stderr and - stdout streams. Otherwise, use DEBUG. Defaults to False. extra_ok_returncodes: an iterable of integer return codes that are acceptable, in addition to 0. Defaults to None, which means []. log_failed_cmd: if false, failed commands are not logged, @@ -101,33 +99,16 @@ def call_subprocess( """ if extra_ok_returncodes is None: extra_ok_returncodes = [] - # Most places in pip use show_stdout=False. - # What this means is-- - # - # - We log this output of stdout and stderr at DEBUG level - # as it is received. - # - If DEBUG logging isn't enabled (e.g. if --verbose logging wasn't - # requested), then we show a spinner so the user can still see the - # subprocess is in progress. - # - If the subprocess exits with an error, we log the output to stderr - # at ERROR level if it hasn't already been displayed to the console - # (e.g. if --verbose logging wasn't enabled). This way we don't log - # the output to the console twice. - # - # If show_stdout=True, then the above is still done, but with DEBUG - # replaced by INFO. - if show_stdout: - # Then log the subprocess output at INFO level. - log_subprocess = subprocess_logger.info - used_level = logging.INFO - else: - # Then log the subprocess output using DEBUG. This also ensures - # it will be logged to the log file (aka user_log), if enabled. - log_subprocess = subprocess_logger.debug - used_level = logging.DEBUG + + # log the subprocess output at DEBUG level. + log_subprocess = subprocess_logger.debug + + env = os.environ.copy() + if extra_environ: + env.update(extra_environ) # Whether the subprocess will be visible in the console. - showing_subprocess = subprocess_logger.getEffectiveLevel() <= used_level + showing_subprocess = True command_desc = format_command_args(cmd) try: @@ -786,9 +767,9 @@ class VersionControl(object): def run_command( cls, cmd, # type: Union[List[str], CommandArgs] - show_stdout=True, # type: bool cwd=None, # type: Optional[str] on_returncode='raise', # type: str + extra_environ=None, # type: Optional[Mapping[str, Any]] extra_ok_returncodes=None, # type: Optional[Iterable[int]] log_failed_cmd=True # type: bool ): @@ -800,8 +781,9 @@ class VersionControl(object): """ cmd = make_command(cls.name, *cmd) try: - return call_subprocess(cmd, show_stdout, cwd, + return call_subprocess(cmd, cwd, on_returncode=on_returncode, + extra_environ=extra_environ, extra_ok_returncodes=extra_ok_returncodes, log_failed_cmd=log_failed_cmd) except OSError as e: From ab3ee7191ca47294f8827916180969e23f5e0381 Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Thu, 14 May 2020 20:06:36 +0530 Subject: [PATCH 4/6] Remove on_returncode parameter from call_subprocess --- src/pip/_internal/vcs/git.py | 10 ++++-- src/pip/_internal/vcs/mercurial.py | 1 - src/pip/_internal/vcs/versioncontrol.py | 42 +++++++++---------------- 3 files changed, 21 insertions(+), 32 deletions(-) diff --git a/src/pip/_internal/vcs/git.py b/src/pip/_internal/vcs/git.py index 61d0ff647..a9c7fb66e 100644 --- a/src/pip/_internal/vcs/git.py +++ b/src/pip/_internal/vcs/git.py @@ -134,8 +134,13 @@ class Git(VersionControl): rev: the revision name. """ # Pass rev to pre-filter the list. - output = cls.run_command(['show-ref', rev], cwd=dest, - on_returncode='ignore') + + output = '' + try: + output = cls.run_command(['show-ref', rev], cwd=dest) + except SubProcessError: + pass + refs = {} for line in output.strip().splitlines(): try: @@ -378,7 +383,6 @@ class Git(VersionControl): r = cls.run_command( ['rev-parse', '--show-toplevel'], cwd=location, - on_returncode='raise', log_failed_cmd=False, ) except BadCommand: diff --git a/src/pip/_internal/vcs/mercurial.py b/src/pip/_internal/vcs/mercurial.py index b7f8073fd..69763feae 100644 --- a/src/pip/_internal/vcs/mercurial.py +++ b/src/pip/_internal/vcs/mercurial.py @@ -144,7 +144,6 @@ class Mercurial(VersionControl): r = cls.run_command( ['root'], cwd=location, - on_returncode='raise', log_failed_cmd=False, ) except BadCommand: diff --git a/src/pip/_internal/vcs/versioncontrol.py b/src/pip/_internal/vcs/versioncontrol.py index 02bdda37c..96f830f99 100644 --- a/src/pip/_internal/vcs/versioncontrol.py +++ b/src/pip/_internal/vcs/versioncontrol.py @@ -84,7 +84,6 @@ def make_vcs_requirement_url(repo_url, rev, project_name, subdir=None): def call_subprocess( cmd, # type: Union[List[str], CommandArgs] cwd=None, # type: Optional[str] - on_returncode='raise', # type: str extra_environ=None, # type: Optional[Mapping[str, Any]] extra_ok_returncodes=None, # type: Optional[Iterable[int]] log_failed_cmd=True # type: Optional[bool] @@ -150,32 +149,21 @@ def call_subprocess( proc.returncode and proc.returncode not in extra_ok_returncodes ) if proc_had_error: - if on_returncode == 'raise': - if not showing_subprocess and log_failed_cmd: - # Then the subprocess streams haven't been logged to the - # console yet. - msg = make_subprocess_output_error( - cmd_args=cmd, - cwd=cwd, - lines=all_output, - exit_status=proc.returncode, - ) - 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 SubProcessError(exc_msg) - elif on_returncode == 'warn': - subprocess_logger.warning( - 'Command "{}" had error code {} in {}'.format( - command_desc, proc.returncode, cwd) + if not showing_subprocess and log_failed_cmd: + # Then the subprocess streams haven't been logged to the + # console yet. + msg = make_subprocess_output_error( + cmd_args=cmd, + cwd=cwd, + lines=all_output, + exit_status=proc.returncode, ) - elif on_returncode == 'ignore': - pass - else: - raise ValueError('Invalid value: on_returncode={!r}'.format( - on_returncode)) + 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 SubProcessError(exc_msg) return ''.join(all_output) @@ -768,7 +756,6 @@ class VersionControl(object): cls, cmd, # type: Union[List[str], CommandArgs] cwd=None, # type: Optional[str] - on_returncode='raise', # type: str extra_environ=None, # type: Optional[Mapping[str, Any]] extra_ok_returncodes=None, # type: Optional[Iterable[int]] log_failed_cmd=True # type: bool @@ -782,7 +769,6 @@ class VersionControl(object): cmd = make_command(cls.name, *cmd) try: return call_subprocess(cmd, cwd, - on_returncode=on_returncode, extra_environ=extra_environ, extra_ok_returncodes=extra_ok_returncodes, log_failed_cmd=log_failed_cmd) From e9f738a3daec91b131ae985e16809d47b1cfdaff Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Fri, 15 May 2020 09:38:53 +0530 Subject: [PATCH 5/6] Bubble up SubProcessError to basecommand._main --- src/pip/_internal/cli/base_command.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/pip/_internal/cli/base_command.py b/src/pip/_internal/cli/base_command.py index 535a49162..c52ffa2f2 100644 --- a/src/pip/_internal/cli/base_command.py +++ b/src/pip/_internal/cli/base_command.py @@ -28,6 +28,7 @@ from pip._internal.exceptions import ( CommandError, InstallationError, PreviousBuildDirError, + SubProcessError, UninstallationError, ) from pip._internal.utils.deprecation import deprecated @@ -201,7 +202,8 @@ class Command(CommandContextMixIn): logger.debug('Exception information:', exc_info=True) return PREVIOUS_BUILD_DIR_ERROR - except (InstallationError, UninstallationError, BadCommand) as exc: + except (InstallationError, UninstallationError, BadCommand, + SubProcessError) as exc: logger.critical(str(exc)) logger.debug('Exception information:', exc_info=True) From 5c615aa775e343dfe7b97bdfc5cb826fa5691061 Mon Sep 17 00:00:00 2001 From: Devesh Kumar Singh Date: Fri, 15 May 2020 12:07:03 +0530 Subject: [PATCH 6/6] Update news entry --- news/7968.bugfix | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/news/7968.bugfix b/news/7968.bugfix index d6959730a..36b282fc8 100644 --- a/news/7968.bugfix +++ b/news/7968.bugfix @@ -1 +1 @@ -Look for version string in the entire output of svn --version, not just the first line +The VCS commands run by pip as subprocesses don't merge stdout and stderr anymore, improving the output parsing by subsequent commands.