Require every call_subprocess call-site to pass command_desc

This serves as additional context that can be presented in error
messages.

Author: pradyunsg

src/pip/_internal/build_env.py

@@ -189,7 +189,8 @@ def install_requirements(
         finder: "PackageFinder",
         requirements: Iterable[str],
         prefix_as_string: str,
-        message: str,
+        *,
+        kind: str,
     ) -> None:
         prefix = self._prefixes[prefix_as_string]
         assert not prefix.setup
@@ -203,7 +204,7 @@ def install_requirements(
                 finder,
                 requirements,
                 prefix,
-                message,
+                kind=kind,
             )
 
     @staticmethod
@@ -212,7 +213,8 @@ def _install_requirements(
         finder: "PackageFinder",
         requirements: Iterable[str],
         prefix: _Prefix,
-        message: str,
+        *,
+        kind: str,
     ) -> None:
         args: List[str] = [
             sys.executable,
@@ -254,8 +256,13 @@ def _install_requirements(
         args.append("--")
         args.extend(requirements)
         extra_environ = {"_PIP_STANDALONE_CERT": where()}
-        with open_spinner(message) as spinner:
-            call_subprocess(args, spinner=spinner, extra_environ=extra_environ)
+        with open_spinner(f"Installing {kind}") as spinner:
+            call_subprocess(
+                args,
+                command_desc=f"pip subprocess to install {kind}",
+                spinner=spinner,
+                extra_environ=extra_environ,
+            )
 
 
 class NoOpBuildEnvironment(BuildEnvironment):
@@ -283,6 +290,7 @@ def install_requirements(
         finder: "PackageFinder",
         requirements: Iterable[str],
         prefix_as_string: str,
-        message: str,
+        *,
+        kind: str,
     ) -> None:
         raise NotImplementedError()

src/pip/_internal/distributions/sdist.py

@@ -56,7 +56,7 @@ def _prepare_build_backend(self, finder: PackageFinder) -> None:
 
         self.req.build_env = BuildEnvironment()
         self.req.build_env.install_requirements(
-            finder, pyproject_requires, "overlay", "Installing build dependencies"
+            finder, pyproject_requires, "overlay", kind="build dependencies"
         )
         conflicting, missing = self.req.build_env.check_requirements(
             self.req.requirements_to_check
@@ -108,7 +108,7 @@ def _install_build_reqs(self, finder: PackageFinder) -> None:
         if conflicting:
             self._raise_conflicts("the backend dependencies", conflicting)
         self.req.build_env.install_requirements(
-            finder, missing, "normal", "Installing backend dependencies"
+            finder, missing, "normal", kind="backend dependencies"
         )
 
     def _raise_conflicts(

src/pip/_internal/operations/build/wheel_legacy.py

@@ -86,6 +86,7 @@ def build_wheel_legacy(
         try:
             output = call_subprocess(
                 wheel_args,
+                command_desc="python setup.py bdist_wheel",
                 cwd=source_dir,
                 spinner=spinner,
             )

src/pip/_internal/operations/install/editable_legacy.py

@@ -42,5 +42,6 @@ def install_editable(
         with build_env:
             call_subprocess(
                 args,
+                command_desc="python setup.py develop",
                 cwd=unpacked_source_directory,
             )

src/pip/_internal/utils/subprocess.py

@@ -110,12 +110,13 @@ def call_subprocess(
     cwd: Optional[str] = None,
     on_returncode: 'Literal["raise", "warn", "ignore"]' = "raise",
     extra_ok_returncodes: Optional[Iterable[int]] = None,
-    command_desc: Optional[str] = None,
     extra_environ: Optional[Mapping[str, Any]] = None,
     unset_environ: Optional[Iterable[str]] = None,
     spinner: Optional[SpinnerInterface] = None,
     log_failed_cmd: Optional[bool] = True,
     stdout_only: Optional[bool] = False,
+    *,
+    command_desc: str,
 ) -> str:
     """
     Args:
@@ -166,9 +167,6 @@ def call_subprocess(
     # and we have a spinner.
     use_spinner = not showing_subprocess and spinner is not None
 
-    if command_desc is None:
-        command_desc = format_command_args(cmd)
-
     log_subprocess("Running command %s", command_desc)
     env = os.environ.copy()
     if extra_environ:
@@ -281,6 +279,7 @@ def runner(
         with open_spinner(message) as spinner:
             call_subprocess(
                 cmd,
+                command_desc=message,
                 cwd=cwd,
                 extra_environ=extra_environ,
                 spinner=spinner,

src/pip/_internal/vcs/git.py

@@ -91,7 +91,12 @@ def is_immutable_rev_checkout(self, url: str, dest: str) -> bool:
         return not is_tag_or_branch
 
     def get_git_version(self) -> Tuple[int, ...]:
-        version = self.run_command(["version"], show_stdout=False, stdout_only=True)
+        version = self.run_command(
+            ["version"],
+            command_desc="git version",
+            show_stdout=False,
+            stdout_only=True,
+        )
         match = GIT_VERSION_REGEX.match(version)
         if not match:
             logger.warning("Can't parse git version: %s", version)

src/pip/_internal/vcs/versioncontrol.py

@@ -31,7 +31,12 @@
     is_installable_dir,
     rmtree,
 )
-from pip._internal.utils.subprocess import CommandArgs, call_subprocess, make_command
+from pip._internal.utils.subprocess import (
+    CommandArgs,
+    call_subprocess,
+    format_command_args,
+    make_command,
+)
 from pip._internal.utils.urls import get_url_scheme
 
 if TYPE_CHECKING:
@@ -634,6 +639,8 @@ def run_command(
         command name, and checks that the VCS is available
         """
         cmd = make_command(cls.name, *cmd)
+        if command_desc is None:
+            command_desc = format_command_args(cmd)
         try:
             return call_subprocess(
                 cmd,

src/pip/_internal/wheel_builder.py

@@ -310,7 +310,9 @@ def _clean_one_legacy(req: InstallRequirement, global_options: List[str]) -> boo
 
     logger.info("Running setup.py clean for %s", req.name)
     try:
-        call_subprocess(clean_args, cwd=req.source_dir)
+        call_subprocess(
+            clean_args, command_desc="python setup.py clean", cwd=req.source_dir
+        )
         return True
     except Exception:
         logger.error("Failed cleaning build dir for %s", req.name)

tests/unit/test_utils_subprocess.py

@@ -163,6 +163,7 @@ def test_call_subprocess_stdout_only(
             "-c",
             "import sys; sys.stdout.write('out\\n'); sys.stderr.write('err\\n')",
         ],
+        command_desc="test stdout_only",
         stdout_only=stdout_only,
     )
     assert out in expected
@@ -271,7 +272,11 @@ def test_debug_logging(
         """
         log_level = DEBUG
         args, spinner = self.prepare_call(caplog, log_level)
-        result = call_subprocess(args, spinner=spinner)
+        result = call_subprocess(
+            args,
+            command_desc="test debug logging",
+            spinner=spinner,
+        )
 
         expected = (
             ["Hello", "world"],
@@ -301,7 +306,11 @@ def test_info_logging(
         """
         log_level = INFO
         args, spinner = self.prepare_call(caplog, log_level)
-        result = call_subprocess(args, spinner=spinner)
+        result = call_subprocess(
+            args,
+            command_desc="test info logging",
+            spinner=spinner,
+        )
 
         expected: Tuple[List[str], List[Tuple[str, int, str]]] = (
             ["Hello", "world"],
@@ -331,7 +340,11 @@ def test_info_logging__subprocess_error(
         args, spinner = self.prepare_call(caplog, log_level, command=command)
 
         with pytest.raises(InstallationSubprocessError) as exc:
-            call_subprocess(args, spinner=spinner)
+            call_subprocess(
+                args,
+                command_desc="test info logging with subprocess error",
+                spinner=spinner,
+            )
         result = None
         exc_message = str(exc.value)
         assert exc_message.startswith("Command errored out with exit status 1: ")
@@ -390,7 +403,12 @@ def test_info_logging_with_show_stdout_true(
         """
         log_level = INFO
         args, spinner = self.prepare_call(caplog, log_level)
-        result = call_subprocess(args, spinner=spinner, show_stdout=True)
+        result = call_subprocess(
+            args,
+            command_desc="test info logging with show_stdout",
+            spinner=spinner,
+            show_stdout=True,
+        )
 
         expected = (
             ["Hello", "world"],
@@ -456,6 +474,7 @@ def test_spinner_finish(
         try:
             call_subprocess(
                 args,
+                command_desc="spinner go spinny",
                 show_stdout=show_stdout,
                 extra_ok_returncodes=extra_ok_returncodes,
                 spinner=spinner,
@@ -474,6 +493,7 @@ def test_closes_stdin(self) -> None:
             call_subprocess(
                 [sys.executable, "-c", "input()"],
                 show_stdout=True,
+                command_desc="stdin reader",
             )
 
 
@@ -487,6 +507,7 @@ def test_unicode_decode_error(caplog: pytest.LogCaptureFixture) -> None:
             "-c",
             "import sys; sys.stdout.buffer.write(b'\\xff')",
         ],
+        command_desc="invalid decode output",
         show_stdout=True,
     )