mirror of
https://github.com/pypa/pip
synced 2023-12-13 21:30:23 +01:00
Display spinner during long setup.py calls
One of the downsides of pip's new hiding of build chatter is that for packages that take a very long time to build (e.g. scipy) the user gets no indication that anything is happening for a very long time (e.g. tens of minutes), and is likely to get frustrated and hit Control-C. This can also create issues for automated systems that kill jobs that don't produce occasional output (e.g. Travis-CI). This commit implements an idea discussed here: https://github.com/pypa/pip/issues/2732#issuecomment-153215371 where we put up a spinner that rotates whenever the underlying build produces output. I tried it on scipy, and it the experience was quite pleasant! It spun around, sometimes fast and sometimes slow, and then there was one uncomfortable pause for ~1 minute while a very gnarly C++ file got compiled, but that's okay because it was actually providing accurate feedback. It looks like: ``` Running setup.py install for scipy ... / Running setup.py install for scipy ... - Running setup.py install for scipy ... \ Running setup.py install for scipy ... done ``` or if the command has non-zero return code, or an exception is raised, you get: ``` Running setup.py install for scipy ... / Running setup.py install for scipy ... - Running setup.py install for scipy ... \ Running setup.py install for scipy ... error ```
This commit is contained in:
parent
28f658f908
commit
5bb9899938
4 changed files with 191 additions and 43 deletions
|
@ -34,6 +34,7 @@ from pip.utils import (
|
|||
get_installed_version, canonicalize_name
|
||||
)
|
||||
from pip.utils.logging import indent_log
|
||||
from pip.utils.ui import open_spinner
|
||||
from pip.req.req_uninstall import UninstallPathSet
|
||||
from pip.vcs import vcs
|
||||
from pip.wheel import move_wheel_files, Wheel
|
||||
|
@ -828,7 +829,7 @@ exec(compile(
|
|||
temp_location = tempfile.mkdtemp('-record', 'pip-')
|
||||
record_filename = os.path.join(temp_location, 'install-record.txt')
|
||||
try:
|
||||
install_args = [sys.executable]
|
||||
install_args = [sys.executable, "-u"]
|
||||
install_args.append('-c')
|
||||
install_args.append(
|
||||
"import setuptools, tokenize;__file__=%r;"
|
||||
|
@ -854,12 +855,14 @@ exec(compile(
|
|||
install_args += ['--install-headers',
|
||||
os.path.join(sys.prefix, 'include', 'site',
|
||||
py_ver_str, self.name)]
|
||||
logger.info('Running setup.py install for %s', self.name)
|
||||
msg = 'Running setup.py install for %s' % (self.name,)
|
||||
with open_spinner(msg) as spinner:
|
||||
with indent_log():
|
||||
call_subprocess(
|
||||
install_args + install_options,
|
||||
cwd=self.source_dir,
|
||||
show_stdout=False,
|
||||
spinner=spinner,
|
||||
)
|
||||
|
||||
if not os.path.exists(record_filename):
|
||||
|
|
|
@ -3,7 +3,9 @@ from __future__ import absolute_import
|
|||
import contextlib
|
||||
import errno
|
||||
import locale
|
||||
import logging
|
||||
# we have a submodule named 'logging' which would shadow this if we used the
|
||||
# regular name:
|
||||
import logging as std_logging
|
||||
import re
|
||||
import os
|
||||
import posixpath
|
||||
|
@ -43,8 +45,7 @@ __all__ = ['rmtree', 'display_path', 'backup_dir',
|
|||
'get_installed_version']
|
||||
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
logger = std_logging.getLogger(__name__)
|
||||
|
||||
BZ2_EXTENSIONS = ('.tar.bz2', '.tbz')
|
||||
ZIP_EXTENSIONS = ('.zip', '.whl')
|
||||
|
@ -642,8 +643,8 @@ def remove_tracebacks(output):
|
|||
|
||||
def call_subprocess(cmd, show_stdout=True, cwd=None,
|
||||
raise_on_returncode=True,
|
||||
command_level=logging.DEBUG, command_desc=None,
|
||||
extra_environ=None):
|
||||
command_level=std_logging.DEBUG, command_desc=None,
|
||||
extra_environ=None, spinner=None):
|
||||
if command_desc is None:
|
||||
cmd_parts = []
|
||||
for part in cmd:
|
||||
|
@ -651,17 +652,13 @@ def call_subprocess(cmd, show_stdout=True, cwd=None,
|
|||
part = '"%s"' % part.replace('"', '\\"')
|
||||
cmd_parts.append(part)
|
||||
command_desc = ' '.join(cmd_parts)
|
||||
if show_stdout:
|
||||
stdout = None
|
||||
else:
|
||||
stdout = subprocess.PIPE
|
||||
logger.log(command_level, "Running command %s", command_desc)
|
||||
env = os.environ.copy()
|
||||
if extra_environ:
|
||||
env.update(extra_environ)
|
||||
try:
|
||||
proc = subprocess.Popen(
|
||||
cmd, stderr=subprocess.STDOUT, stdin=None, stdout=stdout,
|
||||
cmd, stderr=subprocess.STDOUT, stdin=None, stdout=subprocess.PIPE,
|
||||
cwd=cwd, env=env)
|
||||
except Exception as exc:
|
||||
logger.critical(
|
||||
|
@ -669,18 +666,22 @@ def call_subprocess(cmd, show_stdout=True, cwd=None,
|
|||
)
|
||||
raise
|
||||
all_output = []
|
||||
if stdout is not None:
|
||||
while True:
|
||||
line = console_to_str(proc.stdout.readline())
|
||||
if not line:
|
||||
break
|
||||
line = line.rstrip()
|
||||
all_output.append(line + '\n')
|
||||
if show_stdout:
|
||||
logger.debug(line)
|
||||
if not all_output:
|
||||
returned_stdout, returned_stderr = proc.communicate()
|
||||
all_output = [returned_stdout or '']
|
||||
if spinner is not None:
|
||||
spinner.spin()
|
||||
proc.wait()
|
||||
if spinner is not None:
|
||||
if proc.returncode:
|
||||
spinner.finish("error")
|
||||
else:
|
||||
spinner.finish("done")
|
||||
if proc.returncode:
|
||||
if raise_on_returncode:
|
||||
if all_output:
|
||||
|
@ -699,7 +700,7 @@ def call_subprocess(cmd, show_stdout=True, cwd=None,
|
|||
'Command "%s" had error code %s in %s',
|
||||
command_desc, proc.returncode, cwd,
|
||||
)
|
||||
if stdout is not None:
|
||||
if not show_stdout:
|
||||
return remove_tracebacks(''.join(all_output))
|
||||
|
||||
|
||||
|
|
142
pip/utils/ui.py
142
pip/utils/ui.py
|
@ -4,13 +4,17 @@ from __future__ import division
|
|||
import itertools
|
||||
import sys
|
||||
from signal import signal, SIGINT, default_int_handler
|
||||
import time
|
||||
import contextlib
|
||||
import logging
|
||||
|
||||
from pip.compat import WINDOWS
|
||||
from pip.utils import format_size
|
||||
from pip.utils.logging import get_indentation
|
||||
from pip._vendor import six
|
||||
from pip._vendor.progress.bar import Bar, IncrementalBar
|
||||
from pip._vendor.progress.helpers import WritelnMixin
|
||||
from pip._vendor.progress.helpers import (WritelnMixin,
|
||||
HIDE_CURSOR, SHOW_CURSOR)
|
||||
from pip._vendor.progress.spinner import Spinner
|
||||
|
||||
try:
|
||||
|
@ -20,6 +24,8 @@ try:
|
|||
except Exception:
|
||||
colorama = None
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
def _select_progress_class(preferred, fallback):
|
||||
encoding = getattr(preferred.file, "encoding", None)
|
||||
|
@ -197,3 +203,137 @@ class DownloadProgressSpinner(WindowsMixin, InterruptibleMixin,
|
|||
])
|
||||
|
||||
self.writeln(line)
|
||||
|
||||
|
||||
################################################################
|
||||
# Generic "something is happening" spinners
|
||||
#
|
||||
# We don't even try using progress.spinner.Spinner here because it's actually
|
||||
# simpler to reimplement from scratch than to coerce their code into doing
|
||||
# what we need.
|
||||
################################################################
|
||||
|
||||
@contextlib.contextmanager
|
||||
def hidden_cursor(file):
|
||||
# The Windows terminal does not support the hide/show cursor ANSI codes,
|
||||
# even via colorama. So don't even try.
|
||||
if WINDOWS:
|
||||
yield
|
||||
else:
|
||||
file.write(HIDE_CURSOR)
|
||||
try:
|
||||
yield
|
||||
finally:
|
||||
file.write(SHOW_CURSOR)
|
||||
|
||||
|
||||
class RateLimiter(object):
|
||||
def __init__(self, min_update_interval_seconds):
|
||||
self._min_update_interval_seconds = min_update_interval_seconds
|
||||
self._last_update = 0
|
||||
|
||||
def ready(self):
|
||||
now = time.time()
|
||||
delta = now - self._last_update
|
||||
return delta >= self._min_update_interval_seconds
|
||||
|
||||
def reset(self):
|
||||
self._last_update = time.time()
|
||||
|
||||
|
||||
class InteractiveSpinner(object):
|
||||
def __init__(self, message, file=None, spin_chars="-\\|/",
|
||||
# Empirically, 8 updates/second looks nice
|
||||
min_update_interval_seconds=0.125):
|
||||
self._message = message
|
||||
if file is None:
|
||||
file = sys.stdout
|
||||
self._file = file
|
||||
self._rate_limiter = RateLimiter(min_update_interval_seconds)
|
||||
self._finished = False
|
||||
|
||||
self._spin_cycle = itertools.cycle(spin_chars)
|
||||
|
||||
self._file.write(" " * get_indentation() + self._message + " ... ")
|
||||
self._width = 0
|
||||
|
||||
def _write(self, status):
|
||||
assert not self._finished
|
||||
# Erase what we wrote before by backspacing to the beginning, writing
|
||||
# spaces to overwrite the old text, and then backspacing again
|
||||
backup = "\b" * self._width
|
||||
self._file.write(backup + " " * self._width + backup)
|
||||
# Now we have a blank slate to add our status
|
||||
self._file.write(status)
|
||||
self._width = len(status)
|
||||
self._file.flush()
|
||||
self._rate_limiter.reset()
|
||||
|
||||
def spin(self):
|
||||
if self._finished:
|
||||
return
|
||||
if not self._rate_limiter.ready():
|
||||
return
|
||||
self._write(next(self._spin_cycle))
|
||||
|
||||
def finish(self, final_status):
|
||||
if self._finished:
|
||||
return
|
||||
self._write(final_status)
|
||||
self._file.write("\n")
|
||||
self._file.flush()
|
||||
self._finished = True
|
||||
|
||||
|
||||
# Used for dumb terminals, non-interactive installs (no tty), etc.
|
||||
# We still print updates occasionally (once every 60 seconds by default) to
|
||||
# act as a keep-alive for systems like Travis-CI that take lack-of-output as
|
||||
# an indication that a task has frozen.
|
||||
class NonInteractiveSpinner(object):
|
||||
def __init__(self, message, min_update_interval_seconds=60):
|
||||
self._message = message
|
||||
self._finished = False
|
||||
self._rate_limiter = RateLimiter(min_update_interval_seconds)
|
||||
self._update("started")
|
||||
|
||||
def _update(self, status):
|
||||
assert not self._finished
|
||||
self._rate_limiter.reset()
|
||||
logger.info("%s: %s", self._message, status)
|
||||
|
||||
def spin(self):
|
||||
if self._finished:
|
||||
return
|
||||
if not self._rate_limiter.ready():
|
||||
return
|
||||
self._update("still running...")
|
||||
|
||||
def finish(self, final_status):
|
||||
if self._finished:
|
||||
return
|
||||
self._update("finished with status '%s'" % (final_status,))
|
||||
self._finished = True
|
||||
|
||||
|
||||
@contextlib.contextmanager
|
||||
def open_spinner(message):
|
||||
# Interactive spinner goes directly to sys.stdout rather than being routed
|
||||
# through the logging system, but it acts like it has level INFO,
|
||||
# i.e. it's only displayed if we're at level INFO or better.
|
||||
# Non-interactive spinner goes through the logging system, so it is always
|
||||
# in sync with logging configuration.
|
||||
if sys.stdout.isatty() and logger.getEffectiveLevel() <= logging.INFO:
|
||||
spinner = InteractiveSpinner(message)
|
||||
else:
|
||||
spinner = NonInteractiveSpinner(message)
|
||||
try:
|
||||
with hidden_cursor(sys.stdout):
|
||||
yield spinner
|
||||
except KeyboardInterrupt:
|
||||
spinner.finish("canceled")
|
||||
raise
|
||||
except Exception:
|
||||
spinner.finish("error")
|
||||
raise
|
||||
else:
|
||||
spinner.finish("done")
|
||||
|
|
10
pip/wheel.py
10
pip/wheel.py
|
@ -32,6 +32,7 @@ from pip.locations import distutils_scheme, PIP_DELETE_MARKER_FILENAME
|
|||
from pip import pep425tags
|
||||
from pip.utils import (
|
||||
call_subprocess, ensure_dir, captured_stdout, rmtree, canonicalize_name)
|
||||
from pip.utils.ui import open_spinner
|
||||
from pip.utils.logging import indent_log
|
||||
from pip._vendor.distlib.scripts import ScriptMaker
|
||||
from pip._vendor import pkg_resources
|
||||
|
@ -686,7 +687,7 @@ class WheelBuilder(object):
|
|||
|
||||
def _base_setup_args(self, req):
|
||||
return [
|
||||
sys.executable, '-c',
|
||||
sys.executable, "-u", '-c',
|
||||
"import setuptools;__file__=%r;"
|
||||
"exec(compile(open(__file__).read().replace('\\r\\n', '\\n'), "
|
||||
"__file__, 'exec'))" % req.setup_py
|
||||
|
@ -695,7 +696,8 @@ class WheelBuilder(object):
|
|||
def __build_one(self, req, tempd, python_tag=None):
|
||||
base_args = self._base_setup_args(req)
|
||||
|
||||
logger.info('Running setup.py bdist_wheel for %s', req.name)
|
||||
spin_message = 'Running setup.py bdist_wheel for %s' % (req.name,)
|
||||
with open_spinner(spin_message) as spinner:
|
||||
logger.debug('Destination directory: %s', tempd)
|
||||
wheel_args = base_args + ['bdist_wheel', '-d', tempd] \
|
||||
+ self.build_options
|
||||
|
@ -704,9 +706,11 @@ class WheelBuilder(object):
|
|||
wheel_args += ["--python-tag", python_tag]
|
||||
|
||||
try:
|
||||
call_subprocess(wheel_args, cwd=req.source_dir, show_stdout=False)
|
||||
call_subprocess(wheel_args, cwd=req.source_dir,
|
||||
show_stdout=False, spinner=spinner)
|
||||
return True
|
||||
except:
|
||||
spinner.finish("error")
|
||||
logger.error('Failed building wheel for %s', req.name)
|
||||
return False
|
||||
|
||||
|
|
Loading…
Reference in a new issue