Merge pull request #9331 from sbidoul/7969-revert-sbi

Revert #7969 and fix VCS stdout/stderr capture

Author: pradyunsg

news/8876.bugfix.rst

@@ -0,0 +1,3 @@
+Fixed hanging VCS subprocess calls when the VCS outputs a large amount of data
+on stderr. Restored logging of VCS errors that was inadvertently removed in pip
+20.2.

src/pip/_internal/cli/base_command.py

@@ -22,7 +22,6 @@
     InstallationError,
     NetworkConnectionError,
     PreviousBuildDirError,
-    SubProcessError,
     UninstallationError,
 )
 from pip._internal.utils.deprecation import deprecated
@@ -196,7 +195,7 @@ def _main(self, args):
 
             return PREVIOUS_BUILD_DIR_ERROR
         except (InstallationError, UninstallationError, BadCommand,
-                SubProcessError, NetworkConnectionError) as exc:
+                NetworkConnectionError) as exc:
             logger.critical(str(exc))
             logger.debug('Exception information:', exc_info=True)
 

src/pip/_internal/exceptions.py

@@ -82,11 +82,6 @@ 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"""
 

src/pip/_internal/utils/subprocess.py

@@ -115,7 +115,8 @@ def call_subprocess(
     extra_environ=None,  # type: Optional[Mapping[str, Any]]
     unset_environ=None,  # type: Optional[Iterable[str]]
     spinner=None,  # type: Optional[SpinnerInterface]
-    log_failed_cmd=True  # type: Optional[bool]
+    log_failed_cmd=True,  # type: Optional[bool]
+    stdout_only=False,  # type: Optional[bool]
 ):
     # type: (...) -> str
     """
@@ -127,6 +128,9 @@ def call_subprocess(
       unset_environ: an iterable of environment variable names to unset
         prior to calling subprocess.Popen().
       log_failed_cmd: if false, failed commands are not logged, only raised.
+      stdout_only: if true, return only stdout, else return both. When true,
+        logging of both stdout and stderr occurs when the subprocess has
+        terminated, else logging occurs as subprocess output is produced.
     """
     if extra_ok_returncodes is None:
         extra_ok_returncodes = []
@@ -177,38 +181,59 @@ def call_subprocess(
         proc = subprocess.Popen(
             # Convert HiddenText objects to the underlying str.
             reveal_command_args(cmd),
-            stderr=subprocess.STDOUT, stdin=subprocess.PIPE,
-            stdout=subprocess.PIPE, cwd=cwd, env=env,
+            stdin=subprocess.PIPE,
+            stdout=subprocess.PIPE,
+            stderr=subprocess.STDOUT if not stdout_only else subprocess.PIPE,
+            cwd=cwd,
+            env=env,
         )
-        assert proc.stdin
-        assert proc.stdout
-        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 = console_to_str(proc.stdout.readline())
-        if not line:
-            break
-        line = line.rstrip()
-        all_output.append(line + '\n')
+    if not stdout_only:
+        assert proc.stdout
+        assert proc.stdin
+        proc.stdin.close()
+        # In this mode, stdout and stderr are in the same pipe.
+        while True:
+            # The "line" value is a unicode string in Python 2.
+            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)
+            # Update the spinner.
+            if use_spinner:
+                assert spinner
+                spinner.spin()
+        try:
+            proc.wait()
+        finally:
+            if proc.stdout:
+                proc.stdout.close()
+        output = ''.join(all_output)
+    else:
+        # In this mode, stdout and stderr are in different pipes.
+        # We must use communicate() which is the only safe way to read both.
+        out_bytes, err_bytes = proc.communicate()
+        # log line by line to preserve pip log indenting
+        out = console_to_str(out_bytes)
+        for out_line in out.splitlines():
+            log_subprocess(out_line)
+        all_output.append(out)
+        err = console_to_str(err_bytes)
+        for err_line in err.splitlines():
+            log_subprocess(err_line)
+        all_output.append(err)
+        output = out
 
-        # Show the line immediately.
-        log_subprocess(line)
-        # Update the spinner.
-        if use_spinner:
-            assert spinner
-            spinner.spin()
-    try:
-        proc.wait()
-    finally:
-        if proc.stdout:
-            proc.stdout.close()
     proc_had_error = (
         proc.returncode and proc.returncode not in extra_ok_returncodes
     )
@@ -243,7 +268,7 @@ def call_subprocess(
         else:
             raise ValueError('Invalid value: on_returncode={!r}'.format(
                              on_returncode))
-    return ''.join(all_output)
+    return output
 
 
 def runner_with_spinner_message(message):

src/pip/_internal/vcs/bazaar.py

@@ -44,7 +44,8 @@ def export(self, location, url):
 
         url, rev_options = self.get_url_rev_options(url)
         self.run_command(
-            make_command('export', location, url, rev_options.to_args())
+            make_command('export', location, url, rev_options.to_args()),
+            show_stdout=False,
         )
 
     def fetch_new(self, dest, url, rev_options):
@@ -82,7 +83,9 @@ def get_url_rev_and_auth(cls, url):
     @classmethod
     def get_remote_url(cls, location):
         # type: (str) -> str
-        urls = cls.run_command(['info'], cwd=location)
+        urls = cls.run_command(
+            ['info'], show_stdout=False, stdout_only=True, cwd=location
+        )
         for line in urls.splitlines():
             line = line.strip()
             for x in ('checkout of branch: ',
@@ -98,7 +101,7 @@ def get_remote_url(cls, location):
     def get_revision(cls, location):
         # type: (str) -> str
         revision = cls.run_command(
-            ['revno'], cwd=location,
+            ['revno'], show_stdout=False, stdout_only=True, cwd=location,
         )
         return revision.splitlines()[-1]
 

src/pip/_internal/vcs/git.py

@@ -9,7 +9,7 @@
 
 from pip._vendor.packaging.version import parse as parse_version
 
-from pip._internal.exceptions import BadCommand, SubProcessError
+from pip._internal.exceptions import BadCommand, InstallationError
 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
@@ -77,7 +77,9 @@ def is_immutable_rev_checkout(self, url, dest):
 
     def get_git_version(self):
         VERSION_PFX = 'git version '
-        version = self.run_command(['version'])
+        version = self.run_command(
+            ['version'], show_stdout=False, stdout_only=True
+        )
         if version.startswith(VERSION_PFX):
             version = version[len(VERSION_PFX):].split()[0]
         else:
@@ -100,7 +102,11 @@ def get_current_branch(cls, location):
         # and to suppress the message to stderr.
         args = ['symbolic-ref', '-q', 'HEAD']
         output = cls.run_command(
-            args, extra_ok_returncodes=(1, ), cwd=location,
+            args,
+            extra_ok_returncodes=(1, ),
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
         )
         ref = output.strip()
 
@@ -119,7 +125,7 @@ def export(self, location, url):
             self.unpack(temp_dir.path, url=url)
             self.run_command(
                 ['checkout-index', '-a', '-f', '--prefix', location],
-                cwd=temp_dir.path
+                show_stdout=False, cwd=temp_dir.path
             )
 
     @classmethod
@@ -133,13 +139,13 @@ def get_revision_sha(cls, dest, rev):
           rev: the revision name.
         """
         # Pass rev to pre-filter the list.
-
-        output = ''
-        try:
-            output = cls.run_command(['show-ref', rev], cwd=dest)
-        except SubProcessError:
-            pass
-
+        output = cls.run_command(
+            ['show-ref', rev],
+            cwd=dest,
+            show_stdout=False,
+            stdout_only=True,
+            on_returncode='ignore',
+        )
         refs = {}
         for line in output.strip().splitlines():
             try:
@@ -314,7 +320,10 @@ def get_remote_url(cls, location):
         # 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, ), cwd=location,
+            extra_ok_returncodes=(1, ),
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
         )
         remotes = stdout.splitlines()
         try:
@@ -336,9 +345,11 @@ def has_commit(cls, location, rev):
         """
         try:
             cls.run_command(
-                ['rev-parse', '-q', '--verify', "sha^" + rev], cwd=location
+                ['rev-parse', '-q', '--verify', "sha^" + rev],
+                cwd=location,
+                log_failed_cmd=False,
             )
-        except SubProcessError:
+        except InstallationError:
             return False
         else:
             return True
@@ -349,7 +360,10 @@ def get_revision(cls, location, rev=None):
         if rev is None:
             rev = 'HEAD'
         current_rev = cls.run_command(
-            ['rev-parse', rev], cwd=location,
+            ['rev-parse', rev],
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
         )
         return current_rev.strip()
 
@@ -362,7 +376,10 @@ def get_subdirectory(cls, location):
         # find the repo root
         git_dir = cls.run_command(
             ['rev-parse', '--git-dir'],
-            cwd=location).strip()
+            show_stdout=False,
+            stdout_only=True,
+            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, '..'))
@@ -420,13 +437,16 @@ def get_repository_root(cls, location):
             r = cls.run_command(
                 ['rev-parse', '--show-toplevel'],
                 cwd=location,
+                show_stdout=False,
+                stdout_only=True,
+                on_returncode='raise',
                 log_failed_cmd=False,
             )
         except BadCommand:
             logger.debug("could not determine if %s is under git control "
                          "because git is not available", location)
             return None
-        except SubProcessError:
+        except InstallationError:
             return None
         return os.path.normpath(r.rstrip('\r\n'))
 

src/pip/_internal/vcs/mercurial.py

@@ -5,7 +5,7 @@
 import logging
 import os
 
-from pip._internal.exceptions import BadCommand, SubProcessError
+from pip._internal.exceptions import BadCommand, InstallationError
 from pip._internal.utils.misc import display_path
 from pip._internal.utils.subprocess import make_command
 from pip._internal.utils.temp_dir import TempDirectory
@@ -44,7 +44,7 @@ def export(self, location, url):
             self.unpack(temp_dir.path, url=url)
 
             self.run_command(
-                ['archive', location], cwd=temp_dir.path
+                ['archive', location], show_stdout=False, cwd=temp_dir.path
             )
 
     def fetch_new(self, dest, url, rev_options):
@@ -90,7 +90,10 @@ def get_remote_url(cls, location):
         # type: (str) -> str
         url = cls.run_command(
             ['showconfig', 'paths.default'],
-            cwd=location).strip()
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
+        ).strip()
         if cls._is_local_repository(url):
             url = path_to_url(url)
         return url.strip()
@@ -102,7 +105,11 @@ def get_revision(cls, location):
         Return the repository-local changeset revision number, as an integer.
         """
         current_revision = cls.run_command(
-            ['parents', '--template={rev}'], cwd=location).strip()
+            ['parents', '--template={rev}'],
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
+        ).strip()
         return current_revision
 
     @classmethod
@@ -113,7 +120,10 @@ def get_requirement_revision(cls, location):
         """
         current_rev_hash = cls.run_command(
             ['parents', '--template={node}'],
-            cwd=location).strip()
+            show_stdout=False,
+            stdout_only=True,
+            cwd=location,
+        ).strip()
         return current_rev_hash
 
     @classmethod
@@ -129,7 +139,8 @@ def get_subdirectory(cls, location):
         """
         # find the repo root
         repo_root = cls.run_command(
-            ['root'], cwd=location).strip()
+            ['root'], show_stdout=False, stdout_only=True, 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)
@@ -143,13 +154,16 @@ def get_repository_root(cls, location):
             r = cls.run_command(
                 ['root'],
                 cwd=location,
+                show_stdout=False,
+                stdout_only=True,
+                on_returncode='raise',
                 log_failed_cmd=False,
             )
         except BadCommand:
             logger.debug("could not determine if %s is under hg control "
                          "because hg is not available", location)
             return None
-        except SubProcessError:
+        except InstallationError:
             return None
         return os.path.normpath(r.rstrip('\r\n'))