在鼻子下测试Python代码时,我应该如何验证日志消息？

Question

我正在尝试编写一个简单的单元测试,它将验证在某种情况下,我的应用程序中的类将通过标准日志记录API记录错误.我无法弄清楚测试这种情况最干净的方法是什么.

我知道鼻子已经通过它的日志插件捕获日志记录输出,但这似乎是作为失败测试的报告和调试帮助.

我能看到的两种方法是:

• 模拟记录模块,以零散的方式(mymodule.logging = mockloggingmodule)或使用适当的模拟库.
• 编写或使用现有的鼻插件来捕获输出并进行验证.

如果我采用前一种方法,我想知道将模拟出日志模块之前将全局状态重置为最简洁的方法.

期待您的提示和技巧......

Answer 1

从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 2

幸运的是,这不是你必须自己写的东西; 该testfixtures包提供了一个上下文管理器,用于捕获with语句正文中出现的所有日志记录输出.你可以在这里找到包裹:

http://pypi.python.org/pypi/testfixtures

以下是有关如何测试日志记录的文档:

http://testfixtures.readthedocs.org/en/latest/logging.html

Answer 3

更新:不再需要以下答案.请改用内置的Python方式!

这个答案扩展了/sf/answers/73456281/中完成的工作.处理程序大致相同(构造函数更惯用,使用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 4

我曾经模拟过记录器,但在这种情况下我发现最好使用日志处理程序,所以我根据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': [],
        }

Answer 5

布兰登的回答:

pip install testfixtures

片段:

import logging
from testfixtures import LogCapture
logger = logging.getLogger('')


with LogCapture() as logs:
    # my awesome code
    logger.error('My code logged an error')
assert 'My code logged an error' in str(logs)

注意:上面的内容与调用nosetests和获取工具的logCapture插件的输出没有冲突

Answer 6

最简单的答案

Pytest 有一个名为caplog. 无需设置。

def test_foo(foo, caplog, expected_msgs):

    foo.bar()

    assert [r.msg for r in caplog.records] == expected_msgs

我希望我在浪费 6 个小时之前就知道了 caplog。

但是警告 - 它会重置，因此您需要在对 caplog 进行断言的同一测试中执行 SUT 操作。

就个人而言，我希望我的控制台输出干净，所以我喜欢这样使 log-to-stderr 静音：

from logging import getLogger
from pytest import fixture


@fixture
def logger(caplog):

    logger = getLogger()
    _ = [logger.removeHandler(h) for h in logger.handlers if h != caplog.handler]       # type: ignore
    return logger


@fixture
def foo(logger):

    return Foo(logger=logger)


@fixture
def expected_msgs():

    # return whatever it is you expect from the SUT


def test_foo(foo, caplog, expected_msgs):

    foo.bar()

    assert [r.msg for r in caplog.records] == expected_msgs

如果您厌倦了可怕的单元测试代码，那么 pytest 固定装置有很多值得喜欢的地方。