Bug 1257516 - Make the ConfigureOutputHandler keep some debug messages to... (c7b519d6) · Commits · clairehurst / Tor Browser

python/mozbuild/mozbuild/configure/init.py

+12 −8

Original line number	Diff line number	Diff line
		@@ -10,6 +10,7 @@ import os
		import sys
		import types
		from collections import OrderedDict
		from contextlib import contextmanager
		from functools import wraps
		from mozbuild.configure.options import (
		CommandLineHelper,
		@@ -130,21 +131,26 @@ class ConfigureSandbox(dict):

		if logger is None:
		logger = moz_logger = logging.getLogger('moz.configure')
		logger.setLevel(logging.INFO)
		logger.setLevel(logging.DEBUG)
		formatter = logging.Formatter('%(levelname)s: %(message)s')
		handler = ConfigureOutputHandler(stdout, stderr)
		handler.setLevel(logging.INFO)
		handler.setFormatter(formatter)
		queue_debug = handler.queue_debug
		logger.addHandler(handler)

		else:
		assert isinstance(logger, logging.Logger)
		moz_logger = None
		@contextmanager
		def queue_debug():
		yield

		self.log_impl = ReadOnlyNamespace(**{
		log_namespace = {
		k: getattr(logger, k)
		for k in ('debug', 'info', 'warning', 'error')
		})
		}
		log_namespace['queue_debug'] = queue_debug
		self.log_impl = ReadOnlyNamespace(**log_namespace)

		self._help = None
		self._help_option = self.option_impl('--help',
		@@ -156,9 +162,7 @@ class ConfigureSandbox(dict):
		self._help = HelpFormatter(argv[0])
		self._help.add(self._help_option)
		elif moz_logger:
		logger.setLevel(logging.DEBUG)
		handler = logging.FileHandler('config.log', mode='w', delay=True)
		handler.setLevel(logging.DEBUG)
		handler.setFormatter(formatter)
		logger.addHandler(handler)

python/mozbuild/mozbuild/configure/util.py

+45 −1

Original line number	Diff line number	Diff line
		@@ -8,6 +8,8 @@ import itertools
		import logging
		import os
		import sys
		from collections import deque
		from contextlib import contextmanager
		from distutils.version import LooseVersion


		@@ -46,8 +48,15 @@ class ConfigureOutputHandler(logging.Handler):
		Messages sent to stdout are not formatted with the attached Formatter.
		Additionally, if they end with '... ', no newline character is printed,
		making the next message printed follow the '... '.

		Only messages above log level INFO (included) are logged.

		Messages below that level can be kept until an ERROR message is received,
		at which point the last `maxlen` accumulated messages below INFO are
		printed out. This feature is only enabled under the `queue_debug` context
		manager.
		'''
		def __init__(self, stdout=sys.stdout, stderr=sys.stderr):
		def __init__(self, stdout=sys.stdout, stderr=sys.stderr, maxlen=20):
		super(ConfigureOutputHandler, self).__init__()
		self._stdout, self._stderr = stdout, stderr
		try:
		@@ -57,6 +66,8 @@ class ConfigureOutputHandler(logging.Handler):
		except AttributeError:
		self._same_output = self._stdout == self._stderr
		self._stdout_waiting = None
		self._debug = deque(maxlen=maxlen + 1)
		self._keep_if_debug = self.THROW

		@staticmethod
		def _is_same_output(fd1, fd2):
		@@ -66,9 +77,15 @@ class ConfigureOutputHandler(logging.Handler):
		stat2 = os.fstat(fd2)
		return stat1.st_ino == stat2.st_ino and stat1.st_dev == stat2.st_dev

		# possible values for _stdout_waiting
		WAITING = 1
		INTERRUPTED = 2

		# possible values for _keep_if_debug
		THROW = 0
		KEEP = 1
		PRINT = 2

		def emit(self, record):
		try:
		if record.levelno == logging.INFO:
		@@ -83,7 +100,27 @@ class ConfigureOutputHandler(logging.Handler):
		else:
		self._stdout_waiting = None
		msg = '%s\n' % msg
		elif (record.levelno < logging.INFO and
		self._keep_if_debug != self.PRINT):
		if self._keep_if_debug == self.KEEP:
		self._debug.append(record)
		return
		else:
		if record.levelno >= logging.ERROR and len(self._debug):
		self._keep_if_debug = self.PRINT
		if len(self._debug) == self._debug.maxlen:
		r = self._debug.popleft()
		self.emit(logging.LogRecord(
		r.name, r.levelno, r.pathname, r.lineno,
		'<truncated - see config.log for full output>',
		(), None))
		while True:
		try:
		self.emit(self._debug.popleft())
		except IndexError:
		break
		self._keep_if_debug = self.KEEP

		if self._stdout_waiting == self.WAITING and self._same_output:
		self._stdout_waiting = self.INTERRUPTED
		self._stdout.write('\n')
		@@ -97,6 +134,13 @@ class ConfigureOutputHandler(logging.Handler):
		except:
		self.handleError(record)

		@contextmanager
		def queue_debug(self):
		self._keep_if_debug = self.KEEP
		yield
		self._keep_if_debug = self.THROW
		self._debug.clear()


		class LineIO(object):
		'''File-like class that sends each line of the written data to a callback

python/mozbuild/mozbuild/test/configure/test_util.py

+83 −2

Original line number	Diff line number	Diff line
		@@ -33,10 +33,11 @@ class TestConfigureOutputHandler(unittest.TestCase):
		logger.error('foo')
		logger.warning('bar')
		logger.info('baz')
		# DEBUG level is not printed out by this handler
		logger.debug('qux')

		self.assertEqual(out.getvalue(), 'baz\n')
		self.assertEqual(err.getvalue(), 'foo\nbar\nqux\n')
		self.assertEqual(err.getvalue(), 'foo\nbar\n')

		def test_format(self):
		out = StringIO()
		@@ -51,6 +52,7 @@ class TestConfigureOutputHandler(unittest.TestCase):
		logger.error('foo')
		logger.warning('bar')
		logger.info('baz')
		# DEBUG level is not printed out by this handler
		logger.debug('qux')

		self.assertEqual(out.getvalue(), 'baz\n')
		@@ -58,7 +60,6 @@ class TestConfigureOutputHandler(unittest.TestCase):
		err.getvalue(),
		'ERROR:foo\n'
		'WARNING:bar\n'
		'DEBUG:qux\n'
		)

		def test_continuation(self):
		@@ -149,6 +150,86 @@ class TestConfigureOutputHandler(unittest.TestCase):
		'WARNING:fuga\n'
		)

		def test_queue_debug(self):
		out = StringIO()
		name = '%s.test_queue_debug' % self.__class__.__name__
		logger = logging.getLogger(name)
		logger.setLevel(logging.DEBUG)
		handler = ConfigureOutputHandler(out, out, maxlen=3)
		handler.setFormatter(logging.Formatter('%(levelname)s:%(message)s'))
		logger.addHandler(handler)

		with handler.queue_debug():
		logger.info('checking bar... ')
		logger.debug('do foo')
		logger.info('yes')
		logger.info('qux')

		self.assertEqual(
		out.getvalue(),
		'checking bar... yes\n'
		'qux\n'
		)

		out.seek(0)
		out.truncate()

		with handler.queue_debug():
		logger.info('checking bar... ')
		logger.debug('do foo')
		logger.info('no')
		logger.error('fail')

		self.assertEqual(
		out.getvalue(),
		'checking bar... no\n'
		'DEBUG:do foo\n'
		'ERROR:fail\n'
		)

		out.seek(0)
		out.truncate()

		with handler.queue_debug():
		logger.info('checking bar... ')
		logger.debug('do foo')
		logger.debug('do bar')
		logger.debug('do baz')
		logger.info('no')
		logger.error('fail')

		self.assertEqual(
		out.getvalue(),
		'checking bar... no\n'
		'DEBUG:do foo\n'
		'DEBUG:do bar\n'
		'DEBUG:do baz\n'
		'ERROR:fail\n'
		)

		out.seek(0)
		out.truncate()

		with handler.queue_debug():
		logger.info('checking bar... ')
		logger.debug('do foo')
		logger.debug('do bar')
		logger.debug('do baz')
		logger.debug('do qux')
		logger.debug('do hoge')
		logger.info('no')
		logger.error('fail')

		self.assertEqual(
		out.getvalue(),
		'checking bar... no\n'
		'DEBUG:<truncated - see config.log for full output>\n'
		'DEBUG:do baz\n'
		'DEBUG:do qux\n'
		'DEBUG:do hoge\n'
		'ERROR:fail\n'
		)

		def test_is_same_output(self):
		fd1 = sys.stderr.fileno()
		fd2 = os.dup(fd1)