From 40aace89f0070a06d1654edcfacadccb140c65b4 Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Wed, 23 Jun 2021 18:21:35 +0100 Subject: [PATCH] Capture logs when running custom daemons in probe tests Previously a DebugLogger was used when probe tests ran 'custom daemons', which provided a means to inspect captured logs but logged to console. This patch replaces that DebugLogger with a 'normal' swift logger that is adapted to also capture logs and support log inspection. Change-Id: I25da3aa81018c5de7b63e5584ac6a9dbb73243db --- test/debug_logger.py | 133 ++++++++++++++++++++++++++++++++----------- test/probe/common.py | 12 +++- 2 files changed, 110 insertions(+), 35 deletions(-) diff --git a/test/debug_logger.py b/test/debug_logger.py index 32d3ab274a..99f7ec3a53 100644 --- a/test/debug_logger.py +++ b/test/debug_logger.py @@ -12,7 +12,9 @@ # implied. # See the License for the specific language governing permissions and # limitations under the License. +import contextlib import logging +import mock import sys from collections import defaultdict @@ -27,7 +29,48 @@ class WARN_DEPRECATED(Exception): print(self.msg) -class FakeLogger(logging.Logger, object): +class CaptureLog(object): + """ + Captures log records passed to the ``handle`` method and provides accessor + functions to the captured logs. + """ + def __init__(self): + self.clear() + + def _clear(self): + self.log_dict = defaultdict(list) + self.lines_dict = {'critical': [], 'error': [], 'info': [], + 'warning': [], 'debug': [], 'notice': []} + + clear = _clear # this is a public interface + + def get_lines_for_level(self, level): + if level not in self.lines_dict: + raise KeyError( + "Invalid log level '%s'; valid levels are %s" % + (level, + ', '.join("'%s'" % lvl for lvl in sorted(self.lines_dict)))) + return self.lines_dict[level] + + def all_log_lines(self): + return dict((level, msgs) for level, msgs in self.lines_dict.items() + if len(msgs) > 0) + + def _handle(self, record): + try: + line = record.getMessage() + except TypeError: + print('WARNING: unable to format log message %r %% %r' % ( + record.msg, record.args)) + raise + self.lines_dict[record.levelname.lower()].append(line) + return 0 + + def handle(self, record): + return self._handle(record) + + +class FakeLogger(logging.Logger, CaptureLog): # a thread safe fake logger def __init__(self, *args, **kwargs): @@ -73,25 +116,6 @@ class FakeLogger(logging.Logger, object): self.log_dict[store_name].append((tuple(cargs), captured)) super(FakeLogger, self)._log(level, msg, *args, **kwargs) - def _clear(self): - self.log_dict = defaultdict(list) - self.lines_dict = {'critical': [], 'error': [], 'info': [], - 'warning': [], 'debug': [], 'notice': []} - - clear = _clear # this is a public interface - - def get_lines_for_level(self, level): - if level not in self.lines_dict: - raise KeyError( - "Invalid log level '%s'; valid levels are %s" % - (level, - ', '.join("'%s'" % lvl for lvl in sorted(self.lines_dict)))) - return self.lines_dict[level] - - def all_log_lines(self): - return dict((level, msgs) for level, msgs in self.lines_dict.items() - if len(msgs) > 0) - def _store_in(store_name): def stub_fn(self, *args, **kwargs): self.log_dict[store_name].append((args, kwargs)) @@ -139,18 +163,6 @@ class FakeLogger(logging.Logger, object): def emit(self, record): pass - def _handle(self, record): - try: - line = record.getMessage() - except TypeError: - print('WARNING: unable to format log message %r %% %r' % ( - record.msg, record.args)) - raise - self.lines_dict[record.levelname.lower()].append(line) - - def handle(self, record): - self._handle(record) - def flush(self): pass @@ -210,3 +222,60 @@ class DebugLogAdapter(utils.LogAdapter): def debug_logger(name='test'): """get a named adapted debug logger""" return DebugLogAdapter(DebugLogger(), name) + + +class ForwardingLogHandler(logging.NullHandler): + """ + Provides a LogHandler implementation that simply forwards filtered records + to a given handler function. This can be useful to forward records to a + handler without the handler itself needing to subclass LogHandler. + """ + def __init__(self, handler_fn): + super(ForwardingLogHandler, self).__init__() + self.handler_fn = handler_fn + + def handle(self, record): + return self.handler_fn(record) + + +class CaptureLogAdapter(utils.LogAdapter, CaptureLog): + """ + A LogAdapter that is capable of capturing logs for inspection via accessor + methods. + """ + def __init__(self, logger, name): + super(CaptureLogAdapter, self).__init__(logger, name) + self.clear() + self.handler = ForwardingLogHandler(self.handle) + + def start_capture(self): + """ + Attaches the adapter's handler to the adapted logger in order to start + capturing log messages. + """ + self.logger.addHandler(self.handler) + + def stop_capture(self): + """ + Detaches the adapter's handler from the adapted logger. This should be + called to prevent further logging to the adapted logger (possibly via + other log adapter instances) being captured by this instance. + """ + self.logger.removeHandler(self.handler) + + +@contextlib.contextmanager +def capture_logger(conf, *args, **kwargs): + """ + Yields an adapted system logger based on the conf options. The log adapter + captures logs in order to support the pattern of tests calling the log + accessor methods (e.g. get_lines_for_level) directly on the logger + instance. + """ + with mock.patch('swift.common.utils.LogAdapter', CaptureLogAdapter): + log_adapter = utils.get_logger(conf, *args, **kwargs) + log_adapter.start_capture() + try: + yield log_adapter + finally: + log_adapter.stop_capture() diff --git a/test/probe/common.py b/test/probe/common.py index fac9daea08..6780855734 100644 --- a/test/probe/common.py +++ b/test/probe/common.py @@ -41,7 +41,7 @@ from swift.common.utils import readconf, renamer, \ from swift.common.manager import Manager from swift.common.storage_policy import POLICIES, EC_POLICY, REPL_POLICY from swift.obj.diskfile import get_data_dir -from test.debug_logger import debug_logger +from test.debug_logger import capture_logger from test.probe import CHECK_SERVER_TIMEOUT, VALIDATE_RSYNC, PROXY_BASE_URL @@ -571,8 +571,14 @@ class ProbeTest(unittest.TestCase): conf_file = self.configs[conf_section][conf_index] conf = utils.readconf(conf_file, conf_section) conf.update(custom_conf) - daemon = klass(conf, debug_logger('probe')) - daemon.run_once(**kwargs) + # Use a CaptureLogAdapter in order to preserve the pattern of tests + # calling the log accessor methods (e.g. get_lines_for_level) directly + # on the logger instance + with capture_logger(conf, conf.get('log_name', conf_section), + log_to_console=kwargs.pop('verbose', False), + log_route=conf_section) as log_adapter: + daemon = klass(conf, log_adapter) + daemon.run_once(**kwargs) return daemon