在使用nose测试Python代码时如何验证日志消息？

Question

我正在尝试写一个简单的单元测试，目的是验证在某种条件下，我应用中的一个类会通过标准的日志记录API记录错误。不过，我不知道测试这个情况的最佳方法是什么。

我知道nose已经通过它的日志插件捕获日志输出，但这似乎主要是为了帮助报告和调试失败的测试。

我能想到的两种方法是：

• 模拟日志模块，可以部分模拟（比如用mymodule.logging = mockloggingmodule）或者使用一个专门的模拟库。
• 编写或使用一个现有的nose插件来捕获输出并进行验证。

如果我选择第一种方法，我想知道重置全局状态到我模拟日志模块之前的状态的最佳方法是什么。

期待你们的建议和技巧……

Answer 1

更新: 下面的答案不再需要了。请直接使用Python自带的方法！

这个回答是在https://stackoverflow.com/a/1049375/1286628的基础上扩展的。处理程序大体上是一样的（构造函数更符合习惯，使用了super）。此外，我还添加了如何在标准库的unittest中使用这个处理程序的示例。

class MockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs.

    Messages are available from an instance's ``messages`` dict, in order, indexed by
    a lowercase log level string (e.g., 'debug', 'info', etc.).
    """

    def __init__(self, *args, **kwargs):
        self.messages = {'debug': [], 'info': [], 'warning': [], 'error': [],
                         'critical': []}
        super(MockLoggingHandler, self).__init__(*args, **kwargs)

    def emit(self, record):
        "Store a message from ``record`` in the instance's ``messages`` dict."
        try:
            self.messages[record.levelname.lower()].append(record.getMessage())
        except Exception:
            self.handleError(record)

    def reset(self):
        self.acquire()
        try:
            for message_list in self.messages.values():
                message_list.clear()
        finally:
            self.release()

然后你可以像这样在标准库的unittest.TestCase中使用这个处理程序：

import unittest
import logging
import foo

class TestFoo(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        super(TestFoo, cls).setUpClass()
        # Assuming you follow Python's logging module's documentation's
        # recommendation about naming your module's logs after the module's
        # __name__,the following getLogger call should fetch the same logger
        # you use in the foo module
        foo_log = logging.getLogger(foo.__name__)
        cls._foo_log_handler = MockLoggingHandler(level='DEBUG')
        foo_log.addHandler(cls._foo_log_handler)
        cls.foo_log_messages = cls._foo_log_handler.messages

    def setUp(self):
        super(TestFoo, self).setUp()
        self._foo_log_handler.reset() # So each test is independent

    def test_foo_objects_fromble_nicely(self):
        # Do a bunch of frombling with foo objects
        # Now check that they've logged 5 frombling messages at the INFO level
        self.assertEqual(len(self.foo_log_messages['info']), 5)
        for info_message in self.foo_log_messages['info']:
            self.assertIn('fromble', info_message)

Answer 2

从Python 3.4开始，标准的unittest库新增了一个测试断言的上下文管理器，叫做assertLogs。你可以在文档中找到更多信息：

with self.assertLogs('foo', level='INFO') as cm:
    logging.getLogger('foo').info('first message')
    logging.getLogger('foo.bar').error('second message')
    self.assertEqual(cm.output, ['INFO:foo:first message',
                                 'ERROR:foo.bar:second message'])

Answer 3

我以前习惯于模拟日志记录器，但在这种情况下，我发现使用日志处理器更好。所以我根据jkp推荐的文档（现在已经无法访问，但可以在互联网档案馆找到缓存的版本）写了这个。

class MockLoggingHandler(logging.Handler):
    """Mock logging handler to check for expected logs."""

    def __init__(self, *args, **kwargs):
        self.reset()
        logging.Handler.__init__(self, *args, **kwargs)

    def emit(self, record):
        self.messages[record.levelname.lower()].append(record.getMessage())

    def reset(self):
        self.messages = {
            'debug': [],
            'info': [],
            'warning': [],
            'error': [],
            'critical': [],
        }