From 11196e7b6972474c09aa8aa24e9de6fe8927f1af Mon Sep 17 00:00:00 2001 From: Todd Gamblin Date: Sun, 20 Aug 2017 00:12:05 -0700 Subject: Preserve verbosity across installs when 'v' is pressed. - 'v' toggle was previously only good for the current install. - subsequent installs needed user to press 'v' again. - 'v' state is now preserved across dependency installs. --- lib/spack/llnl/util/tty/log.py | 184 +++++++++++++++++++++++++---------- lib/spack/spack/build_environment.py | 11 ++- lib/spack/spack/package.py | 30 ++++-- 3 files changed, 159 insertions(+), 66 deletions(-) (limited to 'lib') diff --git a/lib/spack/llnl/util/tty/log.py b/lib/spack/llnl/util/tty/log.py index ac77e2dc8d..2b3ad22c2d 100644 --- a/lib/spack/llnl/util/tty/log.py +++ b/lib/spack/llnl/util/tty/log.py @@ -29,6 +29,7 @@ import os import re import select import sys +import traceback from contextlib import contextmanager import llnl.util.tty as tty @@ -44,6 +45,7 @@ _escape = re.compile(r'\x1b[^m]*m|\x1b\[?1034h') xon, xoff = '\x11\n', '\x13\n' control = re.compile('(\x11\n|\x13\n)') + def _strip(line): """Strip color and control characters from a line.""" return _escape.sub('', line) @@ -76,6 +78,9 @@ class keyboard_input(object): Args: stream (file-like): stream on which to accept keyboard input + + Note that stream can be None, in which case ``keyboard_input`` + will do nothing. """ self.stream = stream @@ -88,7 +93,7 @@ class keyboard_input(object): self.old_cfg = None # Ignore all this if the input stream is not a tty. - if not self.stream.isatty(): + if not self.stream or not self.stream.isatty(): return try: @@ -119,6 +124,30 @@ class keyboard_input(object): self.stream.fileno(), termios.TCSADRAIN, self.old_cfg) +def _file_descriptors_work(): + """Whether we can get file descriptors for stdout and stderr. + + This tries to call ``fileno()`` on ``sys.stdout`` and ``sys.stderr`` + and returns ``False`` if anything goes wrong. + + This can happen, when, e.g., the test framework replaces stdout with + a ``StringIO`` object. + + We have to actually try this to see whether it works, rather than + checking for the fileno attribute, beacuse frameworks like pytest add + dummy fileno methods on their dummy file objects that return + ``UnsupportedOperationErrors``. + + """ + # test whether we can get fds for out and error + try: + sys.stdout.fileno() + sys.stderr.fileno() + return True + except: + return False + + class log_output(object): """Context manager that logs its output to a file. @@ -135,7 +164,7 @@ class log_output(object): # do things ... output will be logged and printed out And, if you just want to echo *some* stuff from the parent, use - ``force_echo``: + ``force_echo``:: with log_output('logfile.txt', echo=False) as logger: # do things ... output will be logged @@ -155,7 +184,7 @@ class log_output(object): work within test frameworks like nose and pytest. """ - def __init__(self, filename, echo=False, debug=False): + def __init__(self, filename=None, echo=False, debug=False): """Create a new output log context manager. Logger daemon is not started until ``__enter__()``. @@ -166,10 +195,38 @@ class log_output(object): self._active = False # used to prevent re-entry + def __call__(self, filename=None, echo=None, debug=None): + """Thie behaves the same as init. It allows a logger to be reused. + + With the ``__call__`` function, you can save state between uses + of a single logger. This is useful if you want to remember, + e.g., the echo settings for a prior ``with log_output()``:: + + logger = log_output() + + with logger('foo.txt'): + # log things; user can change echo settings with 'v' + + with logger('bar.txt'): + # log things; logger remembers prior echo settings. + + """ + if filename is not None: + self.filename = filename + if echo is not None: + self.echo = echo + if debug is not None: + self.debug = debug + return self + def __enter__(self): if self._active: raise RuntimeError("Can't re-enter the same log_output!") + if self.filename is None: + raise RuntimeError( + "filename must be set by either __init__ or __call__") + # record parent color settings before redirecting. We do this # because color output depends on whether the *original* stdout # is a TTY. New stdout won't be a TTY so we force colorization. @@ -183,10 +240,17 @@ class log_output(object): # OS-level pipe for redirecting output to logger self.read_fd, self.write_fd = os.pipe() + # Multiprocessing pipe for communication back from the daemon + # Currently only used to save echo value between uses + self.parent, self.child = multiprocessing.Pipe() + # Sets a daemon that writes to file what it reads from a pipe try: # need to pass this b/c multiprocessing closes stdin in child. - input_stream = os.fdopen(os.dup(sys.stdin.fileno())) + try: + input_stream = os.fdopen(os.dup(sys.stdin.fileno())) + except: + input_stream = None # just don't forward input if this fails self.process = multiprocessing.Process( target=self._writer_daemon, args=(input_stream,)) @@ -195,7 +259,8 @@ class log_output(object): os.close(self.read_fd) # close in the parent process finally: - input_stream.close() + if input_stream: + input_stream.close() # Flush immediately before redirecting so that anything buffered # goes to the original stream @@ -203,8 +268,8 @@ class log_output(object): sys.stderr.flush() # Now do the actual output rediction. - self.use_fds = True - try: + self.use_fds = _file_descriptors_work() + if self.use_fds: # We try first to use OS-level file descriptors, as this # redirects output for subprocesses and system calls. @@ -217,13 +282,11 @@ class log_output(object): os.dup2(self.write_fd, sys.stderr.fileno()) os.close(self.write_fd) - except AttributeError: - # Using file descriptors can fail if stdout and stderr don't - # have a fileno attribute. This can happen, when, e.g., the - # test framework replaces stdout with a StringIO object. We - # handle thi the Python way. This won't redirect lower-level - # output, but it's the best we can do. - self.use_fds = False + else: + # Handle I/O the Python way. This won't redirect lower-level + # output, but it's the best we can do, and the caller + # shouldn't expect any better, since *they* have apparently + # redirected I/O the Python way. # Save old stdout and stderr file objects self._saved_stdout = sys.stdout @@ -262,6 +325,9 @@ class log_output(object): sys.stdout = self._saved_stdout sys.stderr = self._saved_stderr + # recover and store echo settings from the child before it dies + self.echo = self.parent.recv() + # join the daemon process. The daemon will quit automatically # when the write pipe is closed; we just wait for it here. self.process.join() @@ -299,43 +365,53 @@ class log_output(object): echo = self.echo # initial echo setting, user-controllable force_echo = False # parent can force echo for certain output - with open(self.filename, 'w') as log_file: - with keyboard_input(stdin): - while True: - # Without the last parameter (timeout) select will - # wait until at least one of the two streams are - # ready. This may cause the function to hang. - rlist, _, xlist = select.select( - [in_pipe, stdin], [], [], 0) - - # Allow user to toggle echo with 'v' key. - # Currently ignores other chars. - if stdin in rlist: - if stdin.read(1) == 'v': - echo = not echo - - # Handle output from the with block process. - if in_pipe in rlist: - # If we arrive here it means that in_pipe was - # ready for reading : it should never happen that - # line is false-ish - line = in_pipe.readline() - if not line: - break # EOF - - # find control characters and strip them. - controls = control.findall(line) - line = re.sub(control, '', line) - - # Echo to stdout if requested or forced - if echo or force_echo: - sys.stdout.write(line) - - # Stripped output to log file. - log_file.write(_strip(line)) - log_file.flush() - - if xon in controls: - force_echo = True - if xoff in controls: - force_echo = False + # list of streams to select from + istreams = [in_pipe, stdin] if stdin else [in_pipe] + + try: + with open(self.filename, 'w') as log_file: + with keyboard_input(stdin): + while True: + # Without the last parameter (timeout) select will + # wait until at least one of the two streams are + # ready. This may cause the function to hang. + rlist, _, xlist = select.select(istreams, [], [], 0) + + # Allow user to toggle echo with 'v' key. + # Currently ignores other chars. + if stdin in rlist: + if stdin.read(1) == 'v': + echo = not echo + + # Handle output from the with block process. + if in_pipe in rlist: + # If we arrive here it means that in_pipe was + # ready for reading : it should never happen that + # line is false-ish + line = in_pipe.readline() + if not line: + break # EOF + + # find control characters and strip them. + controls = control.findall(line) + line = re.sub(control, '', line) + + # Echo to stdout if requested or forced + if echo or force_echo: + sys.stdout.write(line) + + # Stripped output to log file. + log_file.write(_strip(line)) + log_file.flush() + + if xon in controls: + force_echo = True + if xoff in controls: + force_echo = False + + except: + tty.error("Exception occurred in writer daemon!") + traceback.print_exc() + + # send echo value back to the parent so it can be preserved. + self.child.send(echo) diff --git a/lib/spack/spack/build_environment.py b/lib/spack/spack/build_environment.py index 53aa14ebc1..339468f4be 100644 --- a/lib/spack/spack/build_environment.py +++ b/lib/spack/spack/build_environment.py @@ -550,8 +550,8 @@ def fork(pkg, function, dirty=False): try: setup_package(pkg, dirty=dirty) - function() - child_pipe.send(None) + return_value = function() + child_pipe.send(return_value) except StopIteration as e: # StopIteration is used to stop installations # before the final stage, mainly for debug purposes @@ -598,11 +598,12 @@ def fork(pkg, function, dirty=False): if input_stream is not None: input_stream.close() - child_exc = parent_pipe.recv() + child_result = parent_pipe.recv() p.join() - if child_exc is not None: - raise child_exc + if isinstance(child_result, ChildError): + raise child_result + return child_result def get_package_context(traceback): diff --git a/lib/spack/spack/package.py b/lib/spack/spack/package.py index c94772c2a5..ef1c411f66 100644 --- a/lib/spack/spack/package.py +++ b/lib/spack/spack/package.py @@ -542,6 +542,9 @@ class PackageBase(with_metaclass(PackageMeta, object)): #: Defaults to the empty string. license_url = '' + # Verbosity level, preserved across installs. + _verbose = None + def __init__(self, spec): # this determines how the package should be built. self.spec = spec @@ -1275,8 +1278,13 @@ class PackageBase(with_metaclass(PackageMeta, object)): # Then install the package itself. def build_process(): - """Forked for each build. Has its own process and python - module space set up by build_environment.fork().""" + """This implements the process forked for each build. + + Has its own process and python module space set up by + build_environment.fork(). + + This function's return value is returned to the parent process. + """ start_time = time.time() if not fake: @@ -1289,6 +1297,11 @@ class PackageBase(with_metaclass(PackageMeta, object)): 'Building {0} [{1}]'.format(self.name, self.build_system_class) ) + # get verbosity from do_install() parameter or saved value + echo = verbose + if PackageBase._verbose is not None: + echo = PackageBase._verbose + self.stage.keep = keep_stage with self._stage_and_write_lock(): # Run the pre-install hook in the child process after @@ -1314,10 +1327,7 @@ class PackageBase(with_metaclass(PackageMeta, object)): # Spawn a daemon that reads from a pipe and redirects # everything to log_path - with log_output(log_path, - echo=verbose, - debug=True) as logger: - + with log_output(log_path, echo, True) as logger: for phase_name, phase_attr in zip( self.phases, self._InstallPhase_phases): @@ -1328,6 +1338,7 @@ class PackageBase(with_metaclass(PackageMeta, object)): phase = getattr(self, phase_attr) phase(self.spec, self.prefix) + echo = logger.echo self.log() # Run post install hooks before build stage is removed. spack.hooks.post_install(self.spec) @@ -1342,13 +1353,18 @@ class PackageBase(with_metaclass(PackageMeta, object)): _hms(self._total_time))) print_pkg(self.prefix) + # preserve verbosity across runs + return echo + try: # Create the install prefix and fork the build process. if not os.path.exists(self.prefix): spack.store.layout.create_install_directory(self.spec) # Fork a child to do the actual installation - spack.build_environment.fork(self, build_process, dirty=dirty) + # we preserve verbosity settings across installs. + PackageBase._verbose = spack.build_environment.fork( + self, build_process, dirty=dirty) # If we installed then we should keep the prefix keep_prefix = self.last_phase is None or keep_prefix -- cgit v1.2.3-60-g2f50