subprocess.py 9.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280
  1. from __future__ import absolute_import
  2. import logging
  3. import os
  4. import subprocess
  5. from pip._vendor.six.moves import shlex_quote
  6. from pip._internal.cli.spinners import SpinnerInterface, open_spinner
  7. from pip._internal.exceptions import InstallationError
  8. from pip._internal.utils.compat import console_to_str, str_to_display
  9. from pip._internal.utils.logging import subprocess_logger
  10. from pip._internal.utils.misc import HiddenText, path_to_display
  11. from pip._internal.utils.typing import MYPY_CHECK_RUNNING
  12. if MYPY_CHECK_RUNNING:
  13. from typing import (
  14. Any, Callable, Iterable, List, Mapping, Optional, Text, Union,
  15. )
  16. CommandArgs = List[Union[str, HiddenText]]
  17. LOG_DIVIDER = '----------------------------------------'
  18. def make_command(*args):
  19. # type: (Union[str, HiddenText, CommandArgs]) -> CommandArgs
  20. """
  21. Create a CommandArgs object.
  22. """
  23. command_args = [] # type: CommandArgs
  24. for arg in args:
  25. # Check for list instead of CommandArgs since CommandArgs is
  26. # only known during type-checking.
  27. if isinstance(arg, list):
  28. command_args.extend(arg)
  29. else:
  30. # Otherwise, arg is str or HiddenText.
  31. command_args.append(arg)
  32. return command_args
  33. def format_command_args(args):
  34. # type: (Union[List[str], CommandArgs]) -> str
  35. """
  36. Format command arguments for display.
  37. """
  38. # For HiddenText arguments, display the redacted form by calling str().
  39. # Also, we don't apply str() to arguments that aren't HiddenText since
  40. # this can trigger a UnicodeDecodeError in Python 2 if the argument
  41. # has type unicode and includes a non-ascii character. (The type
  42. # checker doesn't ensure the annotations are correct in all cases.)
  43. return ' '.join(
  44. shlex_quote(str(arg)) if isinstance(arg, HiddenText)
  45. else shlex_quote(arg) for arg in args
  46. )
  47. def reveal_command_args(args):
  48. # type: (Union[List[str], CommandArgs]) -> List[str]
  49. """
  50. Return the arguments in their raw, unredacted form.
  51. """
  52. return [
  53. arg.secret if isinstance(arg, HiddenText) else arg for arg in args
  54. ]
  55. def make_subprocess_output_error(
  56. cmd_args, # type: Union[List[str], CommandArgs]
  57. cwd, # type: Optional[str]
  58. lines, # type: List[Text]
  59. exit_status, # type: int
  60. ):
  61. # type: (...) -> Text
  62. """
  63. Create and return the error message to use to log a subprocess error
  64. with command output.
  65. :param lines: A list of lines, each ending with a newline.
  66. """
  67. command = format_command_args(cmd_args)
  68. # Convert `command` and `cwd` to text (unicode in Python 2) so we can use
  69. # them as arguments in the unicode format string below. This avoids
  70. # "UnicodeDecodeError: 'ascii' codec can't decode byte ..." in Python 2
  71. # if either contains a non-ascii character.
  72. command_display = str_to_display(command, desc='command bytes')
  73. cwd_display = path_to_display(cwd)
  74. # We know the joined output value ends in a newline.
  75. output = ''.join(lines)
  76. msg = (
  77. # Use a unicode string to avoid "UnicodeEncodeError: 'ascii'
  78. # codec can't encode character ..." in Python 2 when a format
  79. # argument (e.g. `output`) has a non-ascii character.
  80. u'Command errored out with exit status {exit_status}:\n'
  81. ' command: {command_display}\n'
  82. ' cwd: {cwd_display}\n'
  83. 'Complete output ({line_count} lines):\n{output}{divider}'
  84. ).format(
  85. exit_status=exit_status,
  86. command_display=command_display,
  87. cwd_display=cwd_display,
  88. line_count=len(lines),
  89. output=output,
  90. divider=LOG_DIVIDER,
  91. )
  92. return msg
  93. def call_subprocess(
  94. cmd, # type: Union[List[str], CommandArgs]
  95. show_stdout=False, # type: bool
  96. cwd=None, # type: Optional[str]
  97. on_returncode='raise', # type: str
  98. extra_ok_returncodes=None, # type: Optional[Iterable[int]]
  99. command_desc=None, # type: Optional[str]
  100. extra_environ=None, # type: Optional[Mapping[str, Any]]
  101. unset_environ=None, # type: Optional[Iterable[str]]
  102. spinner=None, # type: Optional[SpinnerInterface]
  103. log_failed_cmd=True # type: Optional[bool]
  104. ):
  105. # type: (...) -> Text
  106. """
  107. Args:
  108. show_stdout: if true, use INFO to log the subprocess's stderr and
  109. stdout streams. Otherwise, use DEBUG. Defaults to False.
  110. extra_ok_returncodes: an iterable of integer return codes that are
  111. acceptable, in addition to 0. Defaults to None, which means [].
  112. unset_environ: an iterable of environment variable names to unset
  113. prior to calling subprocess.Popen().
  114. log_failed_cmd: if false, failed commands are not logged, only raised.
  115. """
  116. if extra_ok_returncodes is None:
  117. extra_ok_returncodes = []
  118. if unset_environ is None:
  119. unset_environ = []
  120. # Most places in pip use show_stdout=False. What this means is--
  121. #
  122. # - We connect the child's output (combined stderr and stdout) to a
  123. # single pipe, which we read.
  124. # - We log this output to stderr at DEBUG level as it is received.
  125. # - If DEBUG logging isn't enabled (e.g. if --verbose logging wasn't
  126. # requested), then we show a spinner so the user can still see the
  127. # subprocess is in progress.
  128. # - If the subprocess exits with an error, we log the output to stderr
  129. # at ERROR level if it hasn't already been displayed to the console
  130. # (e.g. if --verbose logging wasn't enabled). This way we don't log
  131. # the output to the console twice.
  132. #
  133. # If show_stdout=True, then the above is still done, but with DEBUG
  134. # replaced by INFO.
  135. if show_stdout:
  136. # Then log the subprocess output at INFO level.
  137. log_subprocess = subprocess_logger.info
  138. used_level = logging.INFO
  139. else:
  140. # Then log the subprocess output using DEBUG. This also ensures
  141. # it will be logged to the log file (aka user_log), if enabled.
  142. log_subprocess = subprocess_logger.debug
  143. used_level = logging.DEBUG
  144. # Whether the subprocess will be visible in the console.
  145. showing_subprocess = subprocess_logger.getEffectiveLevel() <= used_level
  146. # Only use the spinner if we're not showing the subprocess output
  147. # and we have a spinner.
  148. use_spinner = not showing_subprocess and spinner is not None
  149. if command_desc is None:
  150. command_desc = format_command_args(cmd)
  151. log_subprocess("Running command %s", command_desc)
  152. env = os.environ.copy()
  153. if extra_environ:
  154. env.update(extra_environ)
  155. for name in unset_environ:
  156. env.pop(name, None)
  157. try:
  158. proc = subprocess.Popen(
  159. # Convert HiddenText objects to the underlying str.
  160. reveal_command_args(cmd),
  161. stderr=subprocess.STDOUT, stdin=subprocess.PIPE,
  162. stdout=subprocess.PIPE, cwd=cwd, env=env,
  163. )
  164. assert proc.stdin
  165. assert proc.stdout
  166. proc.stdin.close()
  167. except Exception as exc:
  168. if log_failed_cmd:
  169. subprocess_logger.critical(
  170. "Error %s while executing command %s", exc, command_desc,
  171. )
  172. raise
  173. all_output = []
  174. while True:
  175. # The "line" value is a unicode string in Python 2.
  176. line = console_to_str(proc.stdout.readline())
  177. if not line:
  178. break
  179. line = line.rstrip()
  180. all_output.append(line + '\n')
  181. # Show the line immediately.
  182. log_subprocess(line)
  183. # Update the spinner.
  184. if use_spinner:
  185. assert spinner
  186. spinner.spin()
  187. try:
  188. proc.wait()
  189. finally:
  190. if proc.stdout:
  191. proc.stdout.close()
  192. proc_had_error = (
  193. proc.returncode and proc.returncode not in extra_ok_returncodes
  194. )
  195. if use_spinner:
  196. assert spinner
  197. if proc_had_error:
  198. spinner.finish("error")
  199. else:
  200. spinner.finish("done")
  201. if proc_had_error:
  202. if on_returncode == 'raise':
  203. if not showing_subprocess and log_failed_cmd:
  204. # Then the subprocess streams haven't been logged to the
  205. # console yet.
  206. msg = make_subprocess_output_error(
  207. cmd_args=cmd,
  208. cwd=cwd,
  209. lines=all_output,
  210. exit_status=proc.returncode,
  211. )
  212. subprocess_logger.error(msg)
  213. exc_msg = (
  214. 'Command errored out with exit status {}: {} '
  215. 'Check the logs for full command output.'
  216. ).format(proc.returncode, command_desc)
  217. raise InstallationError(exc_msg)
  218. elif on_returncode == 'warn':
  219. subprocess_logger.warning(
  220. 'Command "%s" had error code %s in %s',
  221. command_desc,
  222. proc.returncode,
  223. cwd,
  224. )
  225. elif on_returncode == 'ignore':
  226. pass
  227. else:
  228. raise ValueError('Invalid value: on_returncode={!r}'.format(
  229. on_returncode))
  230. return ''.join(all_output)
  231. def runner_with_spinner_message(message):
  232. # type: (str) -> Callable[..., None]
  233. """Provide a subprocess_runner that shows a spinner message.
  234. Intended for use with for pep517's Pep517HookCaller. Thus, the runner has
  235. an API that matches what's expected by Pep517HookCaller.subprocess_runner.
  236. """
  237. def runner(
  238. cmd, # type: List[str]
  239. cwd=None, # type: Optional[str]
  240. extra_environ=None # type: Optional[Mapping[str, Any]]
  241. ):
  242. # type: (...) -> None
  243. with open_spinner(message) as spinner:
  244. call_subprocess(
  245. cmd,
  246. cwd=cwd,
  247. extra_environ=extra_environ,
  248. spinner=spinner,
  249. )
  250. return runner