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
|
@ -34,6 +34,7 @@ from pip.utils import (
|
||||||
get_installed_version, canonicalize_name
|
get_installed_version, canonicalize_name
|
||||||
)
|
)
|
||||||
from pip.utils.logging import indent_log
|
from pip.utils.logging import indent_log
|
||||||
|
from pip.utils.ui import open_spinner
|
||||||
from pip.req.req_uninstall import UninstallPathSet
|
from pip.req.req_uninstall import UninstallPathSet
|
||||||
from pip.vcs import vcs
|
from pip.vcs import vcs
|
||||||
from pip.wheel import move_wheel_files, Wheel
|
from pip.wheel import move_wheel_files, Wheel
|
||||||
|
@ -828,7 +829,7 @@ exec(compile(
|
||||||
temp_location = tempfile.mkdtemp('-record', 'pip-')
|
temp_location = tempfile.mkdtemp('-record', 'pip-')
|
||||||
record_filename = os.path.join(temp_location, 'install-record.txt')
|
record_filename = os.path.join(temp_location, 'install-record.txt')
|
||||||
try:
|
try:
|
||||||
install_args = [sys.executable]
|
install_args = [sys.executable, "-u"]
|
||||||
install_args.append('-c')
|
install_args.append('-c')
|
||||||
install_args.append(
|
install_args.append(
|
||||||
"import setuptools, tokenize;__file__=%r;"
|
"import setuptools, tokenize;__file__=%r;"
|
||||||
|
@ -854,12 +855,14 @@ exec(compile(
|
||||||
install_args += ['--install-headers',
|
install_args += ['--install-headers',
|
||||||
os.path.join(sys.prefix, 'include', 'site',
|
os.path.join(sys.prefix, 'include', 'site',
|
||||||
py_ver_str, self.name)]
|
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():
|
with indent_log():
|
||||||
call_subprocess(
|
call_subprocess(
|
||||||
install_args + install_options,
|
install_args + install_options,
|
||||||
cwd=self.source_dir,
|
cwd=self.source_dir,
|
||||||
show_stdout=False,
|
show_stdout=False,
|
||||||
|
spinner=spinner,
|
||||||
)
|
)
|
||||||
|
|
||||||
if not os.path.exists(record_filename):
|
if not os.path.exists(record_filename):
|
||||||
|
|
|
@ -3,7 +3,9 @@ from __future__ import absolute_import
|
||||||
import contextlib
|
import contextlib
|
||||||
import errno
|
import errno
|
||||||
import locale
|
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 re
|
||||||
import os
|
import os
|
||||||
import posixpath
|
import posixpath
|
||||||
|
@ -43,8 +45,7 @@ __all__ = ['rmtree', 'display_path', 'backup_dir',
|
||||||
'get_installed_version']
|
'get_installed_version']
|
||||||
|
|
||||||
|
|
||||||
logger = logging.getLogger(__name__)
|
logger = std_logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
BZ2_EXTENSIONS = ('.tar.bz2', '.tbz')
|
BZ2_EXTENSIONS = ('.tar.bz2', '.tbz')
|
||||||
ZIP_EXTENSIONS = ('.zip', '.whl')
|
ZIP_EXTENSIONS = ('.zip', '.whl')
|
||||||
|
@ -642,8 +643,8 @@ def remove_tracebacks(output):
|
||||||
|
|
||||||
def call_subprocess(cmd, show_stdout=True, cwd=None,
|
def call_subprocess(cmd, show_stdout=True, cwd=None,
|
||||||
raise_on_returncode=True,
|
raise_on_returncode=True,
|
||||||
command_level=logging.DEBUG, command_desc=None,
|
command_level=std_logging.DEBUG, command_desc=None,
|
||||||
extra_environ=None):
|
extra_environ=None, spinner=None):
|
||||||
if command_desc is None:
|
if command_desc is None:
|
||||||
cmd_parts = []
|
cmd_parts = []
|
||||||
for part in cmd:
|
for part in cmd:
|
||||||
|
@ -651,17 +652,13 @@ def call_subprocess(cmd, show_stdout=True, cwd=None,
|
||||||
part = '"%s"' % part.replace('"', '\\"')
|
part = '"%s"' % part.replace('"', '\\"')
|
||||||
cmd_parts.append(part)
|
cmd_parts.append(part)
|
||||||
command_desc = ' '.join(cmd_parts)
|
command_desc = ' '.join(cmd_parts)
|
||||||
if show_stdout:
|
|
||||||
stdout = None
|
|
||||||
else:
|
|
||||||
stdout = subprocess.PIPE
|
|
||||||
logger.log(command_level, "Running command %s", command_desc)
|
logger.log(command_level, "Running command %s", command_desc)
|
||||||
env = os.environ.copy()
|
env = os.environ.copy()
|
||||||
if extra_environ:
|
if extra_environ:
|
||||||
env.update(extra_environ)
|
env.update(extra_environ)
|
||||||
try:
|
try:
|
||||||
proc = subprocess.Popen(
|
proc = subprocess.Popen(
|
||||||
cmd, stderr=subprocess.STDOUT, stdin=None, stdout=stdout,
|
cmd, stderr=subprocess.STDOUT, stdin=None, stdout=subprocess.PIPE,
|
||||||
cwd=cwd, env=env)
|
cwd=cwd, env=env)
|
||||||
except Exception as exc:
|
except Exception as exc:
|
||||||
logger.critical(
|
logger.critical(
|
||||||
|
@ -669,18 +666,22 @@ def call_subprocess(cmd, show_stdout=True, cwd=None,
|
||||||
)
|
)
|
||||||
raise
|
raise
|
||||||
all_output = []
|
all_output = []
|
||||||
if stdout is not None:
|
|
||||||
while True:
|
while True:
|
||||||
line = console_to_str(proc.stdout.readline())
|
line = console_to_str(proc.stdout.readline())
|
||||||
if not line:
|
if not line:
|
||||||
break
|
break
|
||||||
line = line.rstrip()
|
line = line.rstrip()
|
||||||
all_output.append(line + '\n')
|
all_output.append(line + '\n')
|
||||||
|
if show_stdout:
|
||||||
logger.debug(line)
|
logger.debug(line)
|
||||||
if not all_output:
|
if spinner is not None:
|
||||||
returned_stdout, returned_stderr = proc.communicate()
|
spinner.spin()
|
||||||
all_output = [returned_stdout or '']
|
|
||||||
proc.wait()
|
proc.wait()
|
||||||
|
if spinner is not None:
|
||||||
|
if proc.returncode:
|
||||||
|
spinner.finish("error")
|
||||||
|
else:
|
||||||
|
spinner.finish("done")
|
||||||
if proc.returncode:
|
if proc.returncode:
|
||||||
if raise_on_returncode:
|
if raise_on_returncode:
|
||||||
if all_output:
|
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 "%s" had error code %s in %s',
|
||||||
command_desc, proc.returncode, cwd,
|
command_desc, proc.returncode, cwd,
|
||||||
)
|
)
|
||||||
if stdout is not None:
|
if not show_stdout:
|
||||||
return remove_tracebacks(''.join(all_output))
|
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 itertools
|
||||||
import sys
|
import sys
|
||||||
from signal import signal, SIGINT, default_int_handler
|
from signal import signal, SIGINT, default_int_handler
|
||||||
|
import time
|
||||||
|
import contextlib
|
||||||
|
import logging
|
||||||
|
|
||||||
from pip.compat import WINDOWS
|
from pip.compat import WINDOWS
|
||||||
from pip.utils import format_size
|
from pip.utils import format_size
|
||||||
from pip.utils.logging import get_indentation
|
from pip.utils.logging import get_indentation
|
||||||
from pip._vendor import six
|
from pip._vendor import six
|
||||||
from pip._vendor.progress.bar import Bar, IncrementalBar
|
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
|
from pip._vendor.progress.spinner import Spinner
|
||||||
|
|
||||||
try:
|
try:
|
||||||
|
@ -20,6 +24,8 @@ try:
|
||||||
except Exception:
|
except Exception:
|
||||||
colorama = None
|
colorama = None
|
||||||
|
|
||||||
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
def _select_progress_class(preferred, fallback):
|
def _select_progress_class(preferred, fallback):
|
||||||
encoding = getattr(preferred.file, "encoding", None)
|
encoding = getattr(preferred.file, "encoding", None)
|
||||||
|
@ -197,3 +203,137 @@ class DownloadProgressSpinner(WindowsMixin, InterruptibleMixin,
|
||||||
])
|
])
|
||||||
|
|
||||||
self.writeln(line)
|
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 import pep425tags
|
||||||
from pip.utils import (
|
from pip.utils import (
|
||||||
call_subprocess, ensure_dir, captured_stdout, rmtree, canonicalize_name)
|
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.utils.logging import indent_log
|
||||||
from pip._vendor.distlib.scripts import ScriptMaker
|
from pip._vendor.distlib.scripts import ScriptMaker
|
||||||
from pip._vendor import pkg_resources
|
from pip._vendor import pkg_resources
|
||||||
|
@ -686,7 +687,7 @@ class WheelBuilder(object):
|
||||||
|
|
||||||
def _base_setup_args(self, req):
|
def _base_setup_args(self, req):
|
||||||
return [
|
return [
|
||||||
sys.executable, '-c',
|
sys.executable, "-u", '-c',
|
||||||
"import setuptools;__file__=%r;"
|
"import setuptools;__file__=%r;"
|
||||||
"exec(compile(open(__file__).read().replace('\\r\\n', '\\n'), "
|
"exec(compile(open(__file__).read().replace('\\r\\n', '\\n'), "
|
||||||
"__file__, 'exec'))" % req.setup_py
|
"__file__, 'exec'))" % req.setup_py
|
||||||
|
@ -695,7 +696,8 @@ class WheelBuilder(object):
|
||||||
def __build_one(self, req, tempd, python_tag=None):
|
def __build_one(self, req, tempd, python_tag=None):
|
||||||
base_args = self._base_setup_args(req)
|
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)
|
logger.debug('Destination directory: %s', tempd)
|
||||||
wheel_args = base_args + ['bdist_wheel', '-d', tempd] \
|
wheel_args = base_args + ['bdist_wheel', '-d', tempd] \
|
||||||
+ self.build_options
|
+ self.build_options
|
||||||
|
@ -704,9 +706,11 @@ class WheelBuilder(object):
|
||||||
wheel_args += ["--python-tag", python_tag]
|
wheel_args += ["--python-tag", python_tag]
|
||||||
|
|
||||||
try:
|
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
|
return True
|
||||||
except:
|
except:
|
||||||
|
spinner.finish("error")
|
||||||
logger.error('Failed building wheel for %s', req.name)
|
logger.error('Failed building wheel for %s', req.name)
|
||||||
return False
|
return False
|
||||||
|
|
||||||
|
|
Loading…
Reference in a new issue