12a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller""" 22a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex MillerAutotest has some surprisingly complicated logging behaviour. 32a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 42a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex MillerManagers allow you to define logging contexts, which define a set of rules on 52a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerhow to handle stdout/stderr. The niceness that you get by going through the 62a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerlogging_manager for this is that you can push/pop these contexts. So if you 72a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerwish to temporarily change how logging works, this gives you that mechanism. 82a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 92a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex MillerMost of this file is actually setting up for a confusing 102a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerfork-for-a-logging-subprocess ordeal that's better explained as 112a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 122a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller normal python logging 132a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller ^ 142a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | 152a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller +--------+ | 162a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller |AUTOSERV| +---+---+ 172a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | +------stdout---->+LOGGING| 182a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | fork() | +---+---+ 192a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller ++------++ ^ 202a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | | | 212a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller +--------+ +--------+ stdout 222a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | | | 232a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller +---------+--------+ +--------+---------+ | 242a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | AUTOSERV | | AUTOSERV | | 252a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller | | | | | 262a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller ++----------------++ ++----------------++ | 272a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller || test || || test || | 282a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller || || || ||---+ 292a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller ||logging.info('')|| ||logging.info('')|| 302a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller |------------------| |------------------| 312a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller +------------------+ +------------------+ 322a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 332a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex MillerEach top-level box is a process. When autoserv starts up, it'll fork off a 342a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerlogging subprocess, and set its stdout/stderr fd's to the subprocess's stdin. 352a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex MillerWhen we fork to create the processes that will run the test code, they inherit 362a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerthis. As do any processes they themselves fork and exec (such as shelling out 372a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerto some command). This isn't the nicest, as it involves closing and dup'ing 382a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerover stdout/stderr, but it does make sure that the whole process tree logs to 392a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Millerpython logging in a very consistent way. 402a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller""" 412a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 422a9a2bbe07f25c95a5243fd4588d8ca8a33e761fAlex Miller 43b1091da4c4a811e4e1460b9847f42f73a24b6b45J. Richard Barnetteimport fcntl, logging, os, signal, sys, warnings 44e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 45e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard# primary public APIs 46e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 47e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showarddef configure_logging(logging_config, **kwargs): 48e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 49e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Configure the logging module using the specific configuration object, which 50e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard should be an instance of logging_config.LoggingConfig (usually of a 51e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard subclass). Any keyword args will be passed to the object's 52e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard configure_logging() method. 53e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 54e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Every entry point should call this method at application startup. 55e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 56e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard LoggingManager.logging_config_object = logging_config 57e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logging_config.configure_logging(**kwargs) 58e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 59e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 60e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showarddef get_logging_manager(manage_stdout_and_stderr=False, redirect_fds=False): 61e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 62e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Create a LoggingManager that's managing sys.stdout and sys.stderr. 63e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 64e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Every entry point that wants to capture stdout/stderr and/or use 65e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard LoggingManager to manage a stack of destinations should call this method 66e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard at application startup. 67e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 6875cdfee87bfaa3cf3f9860832b228a6d32aaed2fshoward if redirect_fds: 69e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard manager = FdRedirectionLoggingManager() 70e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard else: 71e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard manager = LoggingManager() 72e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if manage_stdout_and_stderr: 73e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard manager.manage_stdout() 74e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard manager.manage_stderr() 75e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return manager 76e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 77e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 78e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard# implementation follows 79e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 80e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardlogger = logging.getLogger() 81e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 8289f901697a27eb9a4da647176e3556b2840f0956showard 83e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showarddef _current_handlers(): 84e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return set(logger.handlers) 85e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 86e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 8789f901697a27eb9a4da647176e3556b2840f0956showard_caller_code_to_skip_in_logging_stack = set() 8889f901697a27eb9a4da647176e3556b2840f0956showard 8989f901697a27eb9a4da647176e3556b2840f0956showard 9048e69052c17e7f7a0647e7711dd18d8571789172showarddef do_not_report_as_logging_caller(func): 9189f901697a27eb9a4da647176e3556b2840f0956showard """Decorator to annotate functions we will tell logging not to log.""" 9289f901697a27eb9a4da647176e3556b2840f0956showard # These are not the droids you are looking for. 9389f901697a27eb9a4da647176e3556b2840f0956showard # You may go about your business. 9489f901697a27eb9a4da647176e3556b2840f0956showard _caller_code_to_skip_in_logging_stack.add(func.func_code) 9589f901697a27eb9a4da647176e3556b2840f0956showard return func 9689f901697a27eb9a4da647176e3556b2840f0956showard 9789f901697a27eb9a4da647176e3556b2840f0956showard 9889f901697a27eb9a4da647176e3556b2840f0956showard# Copied from Python 2.4 logging/__init__.py Logger.findCaller and enhanced. 9989f901697a27eb9a4da647176e3556b2840f0956showard# The logging code remains the same and compatible with this monkey patching 10089f901697a27eb9a4da647176e3556b2840f0956showard# through at least Python version 2.6.2. 10189f901697a27eb9a4da647176e3556b2840f0956showarddef _logging_manager_aware_logger__find_caller(unused): 10289f901697a27eb9a4da647176e3556b2840f0956showard """ 10389f901697a27eb9a4da647176e3556b2840f0956showard Find the stack frame of the caller so that we can note the source 10489f901697a27eb9a4da647176e3556b2840f0956showard file name, line number and function name. 10589f901697a27eb9a4da647176e3556b2840f0956showard """ 1068f2ac92f35081c8bf66d831569dcc5c8c32426e0showard f = sys._getframe(2).f_back 10789f901697a27eb9a4da647176e3556b2840f0956showard rv = "(unknown file)", 0, "(unknown function)" 10889f901697a27eb9a4da647176e3556b2840f0956showard while hasattr(f, "f_code"): 10989f901697a27eb9a4da647176e3556b2840f0956showard co = f.f_code 11089f901697a27eb9a4da647176e3556b2840f0956showard filename = os.path.normcase(co.co_filename) 11189f901697a27eb9a4da647176e3556b2840f0956showard if filename == logging._srcfile: 11289f901697a27eb9a4da647176e3556b2840f0956showard f = f.f_back 11389f901697a27eb9a4da647176e3556b2840f0956showard continue 11489f901697a27eb9a4da647176e3556b2840f0956showard ### START additional code. 11589f901697a27eb9a4da647176e3556b2840f0956showard if co in _caller_code_to_skip_in_logging_stack: 11689f901697a27eb9a4da647176e3556b2840f0956showard f = f.f_back 11789f901697a27eb9a4da647176e3556b2840f0956showard continue 11889f901697a27eb9a4da647176e3556b2840f0956showard ### END additional code. 11989f901697a27eb9a4da647176e3556b2840f0956showard rv = (filename, f.f_lineno, co.co_name) 12089f901697a27eb9a4da647176e3556b2840f0956showard break 12189f901697a27eb9a4da647176e3556b2840f0956showard return rv 12289f901697a27eb9a4da647176e3556b2840f0956showard 12389f901697a27eb9a4da647176e3556b2840f0956showard 124861b2d54aec24228cdb3895dbc40062cb40cb2adEric Liif sys.version_info[:2] > (2, 7): 125358276bc2d7f7453fde90b87b19f3c7bcaa21a0bmbligh warnings.warn('This module has not been reviewed for Python %s' % 12689f901697a27eb9a4da647176e3556b2840f0956showard sys.version) 12789f901697a27eb9a4da647176e3556b2840f0956showard 12889f901697a27eb9a4da647176e3556b2840f0956showard 12989f901697a27eb9a4da647176e3556b2840f0956showard# Monkey patch our way around logging's design... 13089f901697a27eb9a4da647176e3556b2840f0956showard_original_logger__find_caller = logging.Logger.findCaller 13189f901697a27eb9a4da647176e3556b2840f0956showardlogging.Logger.findCaller = _logging_manager_aware_logger__find_caller 13289f901697a27eb9a4da647176e3556b2840f0956showard 13389f901697a27eb9a4da647176e3556b2840f0956showard 134e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardclass LoggingFile(object): 135e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 136e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard File-like object that will receive messages pass them to the logging 137e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard infrastructure in an appropriate way. 138e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 13928ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller 14028ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # This object is used to replace stdout and stderr, but doesn't expose 14128ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # the same interface as a file object. To work around the most troublesome 14228ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # part of the API, |fileno()|, we need to be able to provide a fake fd that 14328ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # can pass basic checks. 14428ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller _fake_fds = os.pipe() 14528ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller 146e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def __init__(self, prefix='', level=logging.DEBUG): 147e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 148e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param prefix - The prefix for each line logged by this object. 149e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 150e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._prefix = prefix 151e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._level = level 152e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._buffer = [] 153e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 154e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 15548e69052c17e7f7a0647e7711dd18d8571789172showard @do_not_report_as_logging_caller 156e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def write(self, data): 157e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """" 158e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Writes data only if it constitutes a whole line. If it's not the case, 159e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard store it in a buffer and wait until we have a complete line. 160e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param data - Raw data (a string) that will be processed. 161e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 162e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # splitlines() discards a trailing blank line, so use split() instead 163e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard data_lines = data.split('\n') 164e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if len(data_lines) > 1: 165e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._buffer.append(data_lines[0]) 166e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._flush_buffer() 167e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for line in data_lines[1:-1]: 168e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._log_line(line) 169e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if data_lines[-1]: 170e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._buffer.append(data_lines[-1]) 171e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 172e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 17348e69052c17e7f7a0647e7711dd18d8571789172showard @do_not_report_as_logging_caller 174e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _log_line(self, line): 175e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 176e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Passes lines of output to the logging module. 177e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 178e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logging.log(self._level, self._prefix + line) 179e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 180e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 18148e69052c17e7f7a0647e7711dd18d8571789172showard @do_not_report_as_logging_caller 182e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _flush_buffer(self): 183e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if self._buffer: 184e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._log_line(''.join(self._buffer)) 185e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._buffer = [] 186e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 187e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 18848e69052c17e7f7a0647e7711dd18d8571789172showard @do_not_report_as_logging_caller 189e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def flush(self): 190e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._flush_buffer() 191e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 192e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 19328ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller @do_not_report_as_logging_caller 194221f5f0775f7f1c35ebf58ee08131cf256bf8cb0Achuith Bhandarkar def isatty(self): 195221f5f0775f7f1c35ebf58ee08131cf256bf8cb0Achuith Bhandarkar return False 196221f5f0775f7f1c35ebf58ee08131cf256bf8cb0Achuith Bhandarkar 197221f5f0775f7f1c35ebf58ee08131cf256bf8cb0Achuith Bhandarkar 198221f5f0775f7f1c35ebf58ee08131cf256bf8cb0Achuith Bhandarkar @do_not_report_as_logging_caller 19928ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller def fileno(self): 20028ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # We return the read end of the pipe here becauase if we return the 20128ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # write end, one can make the reasonable assumption that writing to the 20228ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # fd is the same as stdout.write(). As we aren't reading from the other 20328ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller # end of the pipe, writing to this fd should be an error. 20428ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller return self._fake_fds[0] 20528ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller 20628ddb13065900aa6dfcb8d41311367d0a9ecbc2dAlex Miller 207e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardclass _StreamManager(object): 208e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 209e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Redirects all output for some output stream (normally stdout or stderr) to 210e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard the logging module by replacing the file objects with a new LoggingFile 211e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard that calls logging.log(). 212e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 213e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def __init__(self, stream, level, stream_setter): 214e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 215e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param stream: stream object to manage 216e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param level: level at which data written to the stream will be logged 217e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param stream_setter: function accepting a stream object that will 218e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard replace the given stream in its original location. 219e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 220e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._stream = stream 221e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._level = level 222e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._stream_setter = stream_setter 223e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._logging_stream = None 224e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 225e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 226e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _replace_with_logger(self): 227e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._logging_stream = LoggingFile(level=self._level) 228e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._stream_setter(self._logging_stream) 229e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 230e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 231e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _restore_stream(self): 232e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._stream_setter(self._stream) 233e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 234e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 235e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def flush(self): 236e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._logging_stream.flush() 237e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 238e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 239e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def start_logging(self): 240e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Start directing the stream to the logging module.""" 241e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._replace_with_logger() 242e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 243e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 244e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def stop_logging(self): 245e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Restore the stream to its original settings.""" 246e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._restore_stream() 247e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 248e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 249e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def on_push_context(self, context): 250e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 251e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Called when the logging manager is about to push a new context onto the 252e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stack and has changed logging settings. The StreamHandler can modify 253e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard the context to be saved before returning. 254e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 255e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard pass 256e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 257e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 258e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def on_restore_context(self, context): 259e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 260e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Called when the logging manager is restoring a previous context. 261e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 262e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard pass 263e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 264e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 265e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 266e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardclass LoggingManager(object): 267e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 268e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Manages a stack of logging configurations, allowing clients to conveniently 269e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard add and remove logging destinations. Also keeps a list of StreamManagers 270e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard to easily direct streams into the logging module. 271e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 272e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 273e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard STREAM_MANAGER_CLASS = _StreamManager 274e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 275e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logging_config_object = None 276e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 277e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def __init__(self): 278e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 279e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard This class should not ordinarily be constructed directly (other than in 280e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard tests). Use the module-global factory method get_logging_manager() 281e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard instead. 282e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 283e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if self.logging_config_object is None: 284e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise RuntimeError('You must call configure_logging() before this') 285e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 286e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # _context_stack holds a stack of context dicts. Each context dict 287e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # contains: 288e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # * old_handlers: list of registered logging Handlers 289e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # contexts may also be extended by _StreamHandlers 290e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._context_stack = [] 291e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._streams = [] 292e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._started = False 293e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 294e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 295e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def manage_stream(self, stream, level, stream_setter): 296e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 297e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Tells this manager to manage the given stream. All data written to the 298e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream will be directed to the logging module instead. Must be called 299e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard before start_logging(). 300e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 301e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param stream: stream to manage 302e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param level: level to log data written to this stream 303e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param stream_setter: function to set the stream to a new object 304e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 305e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if self._started: 306e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise RuntimeError('You must call this before start_logging()') 307e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._streams.append(self.STREAM_MANAGER_CLASS(stream, level, 308e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_setter)) 309e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 310e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 311e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _sys_stream_setter(self, stream_name): 312e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard assert stream_name in ('stdout', 'stderr'), stream_name 313e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def set_stream(file_object): 314e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard setattr(sys, stream_name, file_object) 315e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return set_stream 316e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 317e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 318e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def manage_stdout(self): 31929f590933b82f3b6d60ab760d3ae5cf007e82a28showard self.manage_stream(sys.stdout, logging.INFO, 320e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._sys_stream_setter('stdout')) 321e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 322e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 323e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def manage_stderr(self): 32410d8417b8c3576e1ba80ce00b6ae2e9cea826bc0showard self.manage_stream(sys.stderr, self.logging_config_object.stderr_level, 325e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._sys_stream_setter('stderr')) 326e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 327e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 328e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def start_logging(self): 329e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 330e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Begin capturing output to the logging module. 331e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 332e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for stream_manager in self._streams: 333e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_manager.start_logging() 334e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._started = True 335e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 336e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 337e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def stop_logging(self): 338e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 339e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Restore output to its original state. 340e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 341e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard while self._context_stack: 342e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._pop_context() 343e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 344e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for stream_manager in self._streams: 345e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_manager.stop_logging() 346e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 347e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._started = False 348e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 349e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 350e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _clear_all_handlers(self): 351e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in _current_handlers(): 352e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logger.removeHandler(handler) 353e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 354e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 355e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _get_context(self): 356e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return {'old_handlers': _current_handlers()} 357e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 358e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 359e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _push_context(self, context): 360e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for stream_manager in self._streams: 361e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_manager.on_push_context(context) 362e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._context_stack.append(context) 363e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 364e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 365e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _flush_all_streams(self): 366e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for stream_manager in self._streams: 367e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_manager.flush() 368e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 369e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 370e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _add_log_handlers(self, add_handlers_fn): 371e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 372e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Modify the logging module's registered handlers and push a new context 373e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard onto the stack. 374e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param add_handlers_fn: function to modify the registered logging 375e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handlers. Accepts a context dictionary which may be modified. 376e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 377e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._flush_all_streams() 378e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard context = self._get_context() 379e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 380e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard add_handlers_fn(context) 381e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 382e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._push_context(context) 383e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 384e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 385e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard class _TaggingFormatter(logging.Formatter): 386e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 387e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Delegates to a given formatter, but prefixes each line of output with a 388e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard tag. 389e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 390e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def __init__(self, base_formatter, tag): 391e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self.base_formatter = base_formatter 392e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard prefix = tag + ' : ' 393e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fmt = base_formatter._fmt.replace('%(message)s', 394e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard prefix + '%(message)s') 395e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self.datefmt = base_formatter.datefmt 396e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 397e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 398e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _add_tagging_formatter(self, tag): 399e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in _current_handlers(): 400e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard tagging_formatter = self._TaggingFormatter(handler.formatter, tag) 401e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.setFormatter(tagging_formatter) 402e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 403e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 404e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _do_redirect(self, stream=None, filename=None, level=None, 405e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard clear_other_handlers=False): 406e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 407e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard @param clear_other_handlers - if true, clear out all other logging 408e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handlers. 409e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 410e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard assert bool(stream) != bool(filename) # xor 411e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if not self._started: 412e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise RuntimeError('You must call start_logging() before this') 413e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 414e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def add_handler(context): 415e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if clear_other_handlers: 416e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._clear_all_handlers() 417e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 418e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if stream: 419e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler = self.logging_config_object.add_stream_handler(stream) 420e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard else: 421e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler = self.logging_config_object.add_file_handler(filename) 422e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 423e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if level: 424e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.setLevel(level) 425e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 426e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._add_log_handlers(add_handler) 427e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 428e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 429e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def redirect(self, filename): 430e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Redirect output to the specified file""" 431e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._do_redirect(filename=filename, clear_other_handlers=True) 432e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 433e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 434e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def redirect_to_stream(self, stream): 435e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Redirect output to the given stream""" 436e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._do_redirect(stream=stream, clear_other_handlers=True) 437e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 438e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 439e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def tee_redirect(self, filename, level=None): 440e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Tee output to the specified file""" 441e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._do_redirect(filename=filename, level=level) 442e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 443e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 444e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def tee_redirect_to_stream(self, stream): 445e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """Tee output to the given stream""" 446e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._do_redirect(stream=stream) 447e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 448e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 449e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def tee_redirect_debug_dir(self, debug_dir, log_name=None, tag=None): 450e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 451e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Tee output to a full new set of debug logs in the given directory. 452e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 453e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def add_handlers(context): 454e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if tag: 455e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._add_tagging_formatter(tag) 456e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard context['tag_added'] = True 457e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self.logging_config_object.add_debug_file_handlers( 458e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard debug_dir, log_name=log_name) 459e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._add_log_handlers(add_handlers) 460e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 461e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 462e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _restore_context(self, context): 463e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for stream_handler in self._streams: 464e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_handler.on_restore_context(context) 465e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 466e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # restore logging handlers 467e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard old_handlers = context['old_handlers'] 468e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in _current_handlers() - old_handlers: 469e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.close() 470e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._clear_all_handlers() 471e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in old_handlers: 472e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logger.addHandler(handler) 473e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 474e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if 'tag_added' in context: 475e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in _current_handlers(): 476e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard tagging_formatter = handler.formatter 477e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.setFormatter(tagging_formatter.base_formatter) 478e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 479e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 480e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _pop_context(self): 481e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._flush_all_streams() 482e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard context = self._context_stack.pop() 483e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._restore_context(context) 484e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 485e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 486e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def undo_redirect(self): 487e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 488e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Undo the last redirection (that hasn't yet been undone). 489e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 490e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard If any subprocesses have been launched since the redirection was 491e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard performed, they must have ended by the time this is called. Otherwise, 492e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard this will hang waiting for the logging subprocess to end. 493e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 494e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if not self._context_stack: 495e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise RuntimeError('No redirects to undo') 496e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._pop_context() 497e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 498e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 499e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def restore(self): 500e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 501e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Same as undo_redirect(). For backwards compatibility with 502e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard fd_stack. 503e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 504e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self.undo_redirect() 505e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 506e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 507e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardclass _FdRedirectionStreamManager(_StreamManager): 508e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 509e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Like StreamManager, but also captures output from subprocesses by modifying 510e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard the underlying file descriptors. 511e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 512e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard For the underlying file descriptors, we spawn a subprocess that writes all 513e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard input to the logging module, and we point the FD to that subprocess. As a 514e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard result, every time we redirect output we need to spawn a new subprocess to 515e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard pick up the new logging settings (without disturbing any existing processes 516e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard using the old logging subprocess). 517e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 518e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard If, one day, we could get all code using utils.run() and friends to launch 519e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard subprocesses, we'd no longer need to handle raw FD output, and we could 520e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard get rid of all this business with subprocesses. Another option would be 521e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard to capture all stray output to a single, separate destination. 522e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 523e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def __init__(self, stream, level, stream_setter): 524e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if not hasattr(stream, 'fileno'): 525e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # with fake, in-process file objects, subprocess output won't be 526e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # captured. this should never happen in normal use, since the 527e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # factory methods will only pass sys.stdout and sys.stderr. 528e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise ValueError("FdRedirectionLoggingManager won't work with " 529e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard "streams that aren't backed by file " 530e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard "descriptors") 531e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 532e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard super(_FdRedirectionStreamManager, self).__init__(stream, level, 533e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard stream_setter) 534e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fd = stream.fileno() 535e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fd_copy_stream = None 536e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 537e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 538e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _point_stream_handlers_to_copy(self): 539e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 540e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard point logging StreamHandlers that point to this stream to a safe 541e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard copy of the underlying FD. otherwise, StreamHandler output will go 542e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard to the logging subprocess, effectively getting doubly logged. 543e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 544e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard fd_copy = os.dup(self._fd) 545e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fd_copy_stream = os.fdopen(fd_copy, 'w') 546e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._redirect_logging_stream_handlers(self._stream, 547e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fd_copy_stream) 548e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 549e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 550e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _restore_stream_handlers(self): 551e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ point logging StreamHandlers back to the original FD """ 552e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._redirect_logging_stream_handlers(self._fd_copy_stream, 553e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._stream) 554e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._fd_copy_stream.close() 555e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 556e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 557e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _redirect_logging_stream_handlers(self, old_stream, new_stream): 558e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 559e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Redirect all configured logging StreamHandlers pointing to 560e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard old_stream to point to new_stream instead. 561e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 562e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for handler in _current_handlers(): 563e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard points_to_stream = (isinstance(handler, logging.StreamHandler) and 564e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard hasattr(handler.stream, 'fileno') and 565e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.stream.fileno() == old_stream.fileno()) 566e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if points_to_stream: 567e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logger.removeHandler(handler) 568e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard handler.close() # doesn't close the stream, just the handler 569e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 570e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard new_handler = logging.StreamHandler(new_stream) 571e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard new_handler.setLevel(handler.level) 572e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard new_handler.setFormatter(handler.formatter) 573e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for log_filter in handler.filters: 574e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard new_handler.addFilter(log_filter) 575e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logger.addHandler(new_handler) 576e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 577e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 578e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def start_logging(self): 579e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard super(_FdRedirectionStreamManager, self).start_logging() 580e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._point_stream_handlers_to_copy() 581e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 582e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 583e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def stop_logging(self): 584e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard super(_FdRedirectionStreamManager, self).stop_logging() 585e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._restore_stream_handlers() 586e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 587e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 588e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _spawn_logging_subprocess(self): 589e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 590e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Spawn a subprocess to log all input to the logging module with the 591e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard current settings, and direct output to it. 592e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 593e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard read_end, write_end = os.pipe() 594e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard pid = os.fork() 595e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if pid: # parent 596e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os.close(read_end) 597e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os.dup2(write_end, self._fd) # point FD to the subprocess 598e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os.close(write_end) 599b1091da4c4a811e4e1460b9847f42f73a24b6b45J. Richard Barnette fd_flags = fcntl.fcntl(self._fd, fcntl.F_GETFD) 600b1091da4c4a811e4e1460b9847f42f73a24b6b45J. Richard Barnette fcntl.fcntl(self._fd, fcntl.F_SETFD, 601b1091da4c4a811e4e1460b9847f42f73a24b6b45J. Richard Barnette fd_flags | fcntl.FD_CLOEXEC) 602e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return pid 603e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard else: # child 604e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard try: 605d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski os.close(write_end) 606d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski # ensure this subprocess doesn't hold any pipes to others 607d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski os.close(1) 608d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski os.close(2) 609e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._run_logging_subprocess(read_end) # never returns 610e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard except: 611e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # don't let exceptions in the child escape 612d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski try: 613d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski logging.exception('Logging subprocess died:') 614d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski finally: 615d3e3ac94941f88ceac69834bea39c8dbe0c9d851jadmanski os._exit(1) 616e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 617e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 618e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _run_logging_subprocess(self, read_fd): 619e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 620e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard Always run from a subprocess. Read from read_fd and write to the 621e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logging module until EOF. 622e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 623e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard signal.signal(signal.SIGTERM, signal.SIG_DFL) # clear handler 624e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard input_file = os.fdopen(read_fd, 'r') 625e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard for line in iter(input_file.readline, ''): 626e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard logging.log(self._level, line.rstrip('\n')) 6272d76764179a2f1c25c3e9911d0e046b644babb20showard logging.debug('Logging subprocess finished') 628e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os._exit(0) 629e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 630e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 631e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def _context_id(self): 632e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard return '%s_context' % id(self) 633e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 634e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 635e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def on_push_context(self, context): 636e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # adds a context dict for this stream, $id_context, with the following: 637e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # * old_fd: FD holding a copy of the managed FD before launching a new 638e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # subprocess. 639e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # * child_pid: PID of the logging subprocess launched 640e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard fd_copy = os.dup(self._fd) 641e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard child_pid = self._spawn_logging_subprocess() 642e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard my_context = {'old_fd': fd_copy, 'child_pid': child_pid} 643e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard context[self._context_id()] = my_context 644e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 645e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 646e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def on_restore_context(self, context): 647e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard my_context = context[self._context_id()] 648e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 649e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # shut down subprocess 650e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard child_pid = my_context['child_pid'] 6512d76764179a2f1c25c3e9911d0e046b644babb20showard try: 6522d76764179a2f1c25c3e9911d0e046b644babb20showard os.close(self._fd) 6532d76764179a2f1c25c3e9911d0e046b644babb20showard os.waitpid(child_pid, 0) 6542d76764179a2f1c25c3e9911d0e046b644babb20showard except OSError: 6552d76764179a2f1c25c3e9911d0e046b644babb20showard logging.exception('Failed to cleanly shutdown logging subprocess:') 656e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 657e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # restore previous FD 658e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard old_fd = my_context['old_fd'] 659e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os.dup2(old_fd, self._fd) 660e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard os.close(old_fd) 661e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 662e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 663e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showardclass FdRedirectionLoggingManager(LoggingManager): 664e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 665e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard A simple extension of LoggingManager to use FdRedirectionStreamManagers, 666e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard so that managed streams have their underlying FDs redirected. 667e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard """ 668e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 669e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard STREAM_MANAGER_CLASS = _FdRedirectionStreamManager 670e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 671e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def start_logging(self): 672e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard super(FdRedirectionLoggingManager, self).start_logging() 673e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # spawn the initial logging subprocess 674e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard self._push_context(self._get_context()) 675e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 676e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard 677e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard def undo_redirect(self): 678e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # len == 1 would mean only start_logging() had been called (but no 679e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard # redirects had occurred) 680e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard if len(self._context_stack) < 2: 681e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard raise RuntimeError('No redirects to undo') 682e96f7a905b3dd758e034e75ca5d29a5bfcbf4610showard super(FdRedirectionLoggingManager, self).undo_redirect() 683