# HG changeset patch # User David Anderson # Date 1236985963 0 # Node ID ac30e04bcbba4e1b68288938f7a2147266fca37b # Parent 2651cb3979dbdaf0f7c2b623c4577f89c9d9c764 Redirect stdout/stderr through the logging system. This change also causes the uncaptured output of subprocesses to be routed to the logging system for recording in the session transcript. diff -r 2651cb3979db -r ac30e04bcbba scripts/release/log.py --- a/scripts/release/log.py Fri Mar 13 23:12:40 2009 +0000 +++ b/scripts/release/log.py Fri Mar 13 23:12:43 2009 +0000 @@ -26,10 +26,31 @@ ] import logging +import sys import util +# A logging level that is even lower than DEBUG. We use this level to +# log to file only, when we need to replay something output by +# bypassing the logging system. +_TERMINAL_ECHO = 5 + + +# Pull in the functions from the logging module, for ease of use +debug = logging.debug +info = logging.info +error = logging.error +raw = debug # Used for logging raw output like subprocess stdout data. + + +# Save the actual out/err streams before init() replaces them. Users +# of the logging system can use these files if they need to bypass the +# logging system for some reason. +stdout = sys.stdout +stderr = sys.stderr + + class _ColorizingFormatter(logging.Formatter): """A logging formatter that colorizes based on log levels.""" @@ -51,6 +72,35 @@ return util.decolorize(logging.Formatter.format(self, record)) +class FileLikeLogger(object): + """A file-like object that logs anything written to it.""" + + def __init__(self): + self._buffer = [] + + def _getBuffer(self): + data, self._buffer = ''.join(self._buffer), [] + return data + + def close(self): + self.flush() + + def flush(self): + raw(self._getBuffer()) + + def write(self, str): + lines = str.split('\n') + self.writelines(lines[0:-1]) + self._buffer.append(lines[-1]) + + def writelines(self, lines): + if not lines: + return + lines[0] = self._getBuffer() + lines[0] + for line in lines: + raw(line) + + def init(logfile=None): """Initialize the logging subsystem. @@ -59,7 +109,7 @@ """ root = logging.getLogger('') - root.setLevel(logging.DEBUG) + root.setLevel(_TERMINAL_ECHO) console = logging.StreamHandler() console.setLevel(logging.DEBUG) @@ -68,11 +118,27 @@ if logfile: transcript = logging.FileHandler(logfile, 'w') - transcript.setLevel(logging.DEBUG) + transcript.setLevel(_TERMINAL_ECHO) transcript.setFormatter(_DecolorizingFormatter()) root.addHandler(transcript) + # Redirect sys.stdout and sys.stderr to logging streams. This will + # force everything that is output in this process, even through + # 'print', to go to both the console and the transcript (if active). + sys.stdout = FileLikeLogger() + sys.stderr = FileLikeLogger() -debug = logging.debug -info = logging.info -error = logging.error + +def terminal_echo(text, *args, **kwargs): + """Echo a message written manually to the terminal. + + This function should be used when you want to echo into the logging + system something that you manually wrote to the real + stdout/stderr. + + For example, when asking the user for input, you would output the + raw prompt to the terminal manually, read the user's response, and + then echo both the prompt and the answer back into the logging + system for recording. + """ + logging.log(_TERMINAL_ECHO, text, *args, **kwargs) diff -r 2651cb3979db -r ac30e04bcbba scripts/release/release.py --- a/scripts/release/release.py Fri Mar 13 23:12:40 2009 +0000 +++ b/scripts/release/release.py Fri Mar 13 23:12:43 2009 +0000 @@ -46,6 +46,7 @@ import re import subprocess import sys +import threading import error import log @@ -83,6 +84,20 @@ """An error occured while accessing a file.""" +def getString(prompt): + """Prompt for and return a string.""" + prompt += ' ' + log.stdout.write(prompt) + log.stdout.flush() + + response = sys.stdin.readline() + log.terminal_echo(prompt + response.strip()) + if not response: + raise AbortedByUser('Aborted by ctrl+D') + + return response.strip() + + def confirm(prompt, default=False): """Ask a yes/no question and return the answer. @@ -97,14 +112,11 @@ True if the user answered affirmatively, False otherwise. """ if default: - question = prompt + ' [Yn] ' + question = prompt + ' [Yn]' else: - question = prompt + ' [yN] ' + question = prompt + ' [yN]' while True: - try: - answer = raw_input(question).strip().lower() - except EOFError: - raise AbortedByUser('Aborted by ctrl+D') + answer = getString(question) if not answer: return default elif answer in ('y', 'yes'): @@ -115,14 +127,6 @@ log.error('Please answer yes or no.') -def getString(prompt): - """Prompt for and return a string.""" - try: - return raw_input(prompt + ' ').strip() - except EOFError: - raise AbortedByUser('Aborted by ctrl+D') - - def getNumber(prompt): """Prompt for and return a number. diff -r 2651cb3979db -r ac30e04bcbba scripts/release/util.py --- a/scripts/release/util.py Fri Mar 13 23:12:40 2009 +0000 +++ b/scripts/release/util.py Fri Mar 13 23:12:43 2009 +0000 @@ -27,9 +27,15 @@ import os.path import re +try: + import cStringIO as StringIO +except ImportError: + import StringIO import subprocess +import threading import error +import log class Error(error.Error): @@ -129,7 +135,26 @@ return os.path.exists(self.path(path)) -def run(argv, cwd=None, capture=False, split_capture=True, stdin=''): +class _PipeAdapter(threading.Thread): + """A thread that connects one file-like object to another""" + def __init__(self, pipe, logfile): + threading.Thread.__init__(self) + self.pipe, self.logfile = pipe, logfile + self.setDaemon(True) + self.start() + + def run(self): + try: + while True: + data = self.pipe.read(512) # Small to retain interactivity + if not data: + return + self.logfile.write(data) + except (EOFError, OSError): + pass + + +def run(argv, cwd=None, capture=False, split_capture=True, stdin=None): """Run the given command and optionally return its output. Note that if you set capture=True, the command's output is @@ -156,19 +181,46 @@ SubprocessFailed: The subprocess exited with a non-zero exit code. """ - print colorize('# ' + ' '.join(argv), WHITE, bold=True) + log.debug(colorize('# ' + ' '.join(argv), WHITE, bold=True)) process = subprocess.Popen(argv, shell=False, cwd=cwd, - stdin=subprocess.PIPE, - stdout=(subprocess.PIPE if capture else None), - stderr=None) - output, _ = process.communicate(input=stdin) + stdin=(subprocess.PIPE if stdin else None), + stdout=subprocess.PIPE, + stderr=subprocess.PIPE) + + # Spin up threads to capture stdout and stderr. Depending on the + # value of the capture parameter, stdout is pushed either into the + # log or into a string for processing. stderr always goes + # into the log. + # + # Threads are necessary because all of writing to stdin, reading + # from stdout and reading from stderr must all happen + # simultaneously. Otherwise, there is a risk that one of the pipes + # will fill up, causing the subprocess and us to deadlock. So, + # threads are used to keep the pipes safely flowing. + stdout = StringIO.StringIO() if capture else log.FileLikeLogger() + out_adapter = _PipeAdapter(process.stdout, stdout) + err_adapter = _PipeAdapter(process.stderr, log.FileLikeLogger()) + if stdin: + process.stdin.write(stdin) + + out_adapter.join() + err_adapter.join() + process.wait() + if process.returncode != 0: - raise SubprocessFailed('Process %s failed with output: %s' % - (argv[0], output)) - if output is not None and split_capture: - return output.strip().split('\n') - else: - return output + if capture: + raise SubprocessFailed('Process %s failed with output: %s' % + (argv[0], stdout.getvalue())) + else: + raise SubprocessFailed('Process %s failed' % argv[0]) + + if capture: + out = stdout.getvalue() + stdout.close() + + if split_capture: + out = out.strip().split('\n') + return out