McSinyx
/
pip
mirror of https://github.com/pypa/pip
1
1
Fork 0
Code Issues Releases Activity

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:
Nathaniel J. Smith 2015-11-04 00:06:50 -08:00
parent 28f658f908
commit 5bb9899938
4 changed files with 191 additions and 43 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

19
pip/req/req_install.py
View File

@ -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,13 +855,15 @@ 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)
with indent_log():
call_subprocess(
install_args + install_options,
cwd=self.source_dir,
show_stdout=False,
)
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):
logger.debug('Record file %s not found', record_filename)

43
pip/utils/__init__.py
View File

@ -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')
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
View File

@ -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")

30
pip/wheel.py
View File

@ -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,20 +696,23 @@ 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)
logger.debug('Destination directory: %s', tempd)
wheel_args = base_args + ['bdist_wheel', '-d', tempd] \
+ self.build_options
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
if python_tag is not None:
wheel_args += ["--python-tag", python_tag]
if python_tag is not None:
wheel_args += ["--python-tag", python_tag]
try:
call_subprocess(wheel_args, cwd=req.source_dir, show_stdout=False)
return True
except:
logger.error('Failed building wheel for %s', req.name)
return False
try:
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
def _clean_one(self, req):
base_args = self._base_setup_args(req)