我正在尝试编写一个简单的单元测试，以验证在特定条件下，我的应用程序中的一个类将通过标准日志记录 API 记录错误。我不知道测试这种情况的最干净的方法是什么。
我知道鼻子已经通过它的日志插件捕获日志输出，但这似乎是为了作为失败测试的报告和调试帮助。
我可以看到的两种方法是：
如果我采用前一种方法，我想知道将全局状态重置为模拟日志模块之前的状态的最简洁方法。
期待您对此的提示和技巧...
【问题讨论】：
标签： python unit-testing mocking nose
从 python 3.4 开始，标准 unittest 库提供了一个新的测试断言上下文管理器 assertLogs。来自docs：
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'])
【讨论】：
幸运的是，这不是你必须自己写的东西； testfixtures 包提供了一个上下文管理器，它捕获出现在 with 语句主体中的所有日志记录输出。你可以在这里找到这个包：
http://pypi.python.org/pypi/testfixtures
这里是关于如何测试日志记录的文档：
【讨论】：
更新：不再需要下面的答案。请改用built-in Python way！
这个答案扩展了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)
【讨论】：
foo_log_handler 变量之前缺少下划线
我曾经模拟记录器，但在这种情况下，我发现最好使用记录处理程序，所以我根据the document suggested by jkp（现在已死，但缓存在Internet Archive）上写了这个
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': [],
}
【讨论】：
AttributeError: class MockLoggingHandler has no attribute 'level' 时不断收到错误消息。
布兰登的回答：
pip install testfixtures
sn-p:
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插件输出不冲突
【讨论】：
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 固定装置有很多值得您喜欢的地方。
【讨论】：
作为 Reef 回答的后续行动，我冒昧地使用 pymox 编写了一个示例。 它引入了一些额外的辅助函数，使存根函数和方法更容易。
import logging
# Code under test:
class Server(object):
def __init__(self):
self._payload_count = 0
def do_costly_work(self, payload):
# resource intensive logic elided...
pass
def process(self, payload):
self.do_costly_work(payload)
self._payload_count += 1
logging.info("processed payload: %s", payload)
logging.debug("payloads served: %d", self._payload_count)
# Here are some helper functions
# that are useful if you do a lot
# of pymox-y work.
import mox
import inspect
import contextlib
import unittest
def stub_all(self, *targets):
for target in targets:
if inspect.isfunction(target):
module = inspect.getmodule(target)
self.StubOutWithMock(module, target.__name__)
elif inspect.ismethod(target):
self.StubOutWithMock(target.im_self or target.im_class, target.__name__)
else:
raise NotImplementedError("I don't know how to stub %s" % repr(target))
# Monkey-patch Mox class with our helper 'StubAll' method.
# Yucky pymox naming convention observed.
setattr(mox.Mox, 'StubAll', stub_all)
@contextlib.contextmanager
def mocking():
mocks = mox.Mox()
try:
yield mocks
finally:
mocks.UnsetStubs() # Important!
mocks.VerifyAll()
# The test case example:
class ServerTests(unittest.TestCase):
def test_logging(self):
s = Server()
with mocking() as m:
m.StubAll(s.do_costly_work, logging.info, logging.debug)
# expectations
s.do_costly_work(mox.IgnoreArg()) # don't care, we test logging here.
logging.info("processed payload: %s", 'hello')
logging.debug("payloads served: %d", 1)
# verified execution
m.ReplayAll()
s.process('hello')
if __name__ == '__main__':
unittest.main()
【讨论】：
您应该使用模拟，因为有一天您可能希望将您的记录器更改为数据库之一。如果它在鼻子测试期间尝试连接到数据库，您将不会高兴。
即使标准输出被抑制，模拟仍将继续工作。
我使用了pyMox 的存根。记得在测试后取消设置存根。
【讨论】：
如果你定义一个这样的辅助方法：
import logging
def capture_logging():
records = []
class CaptureHandler(logging.Handler):
def emit(self, record):
records.append(record)
def __enter__(self):
logging.getLogger().addHandler(self)
return records
def __exit__(self, exc_type, exc_val, exc_tb):
logging.getLogger().removeHandler(self)
return CaptureHandler()
然后你可以这样写测试代码：
with capture_logging() as log:
... # trigger some logger warnings
assert len(log) == ...
assert log[0].getMessage() == ...
【讨论】：
发现one answer，因为我发布了这个。还不错。
在 tornado 中实现的 ExpectLog 类是一个很棒的实用程序：
with ExpectLog('channel', 'message regex'):
do_it()
http://tornado.readthedocs.org/en/latest/_modules/tornado/testing.html#ExpectLog
【讨论】：
关闭@Reef 的答案，我确实尝试了下面的代码。它适用于 Python 2.7（如果您安装 mock）和 Python 3.4。
"""
Demo using a mock to test logging output.
"""
import logging
try:
import unittest
except ImportError:
import unittest2 as unittest
try:
# Python >= 3.3
from unittest.mock import Mock, patch
except ImportError:
from mock import Mock, patch
logging.basicConfig()
LOG=logging.getLogger("(logger under test)")
class TestLoggingOutput(unittest.TestCase):
""" Demo using Mock to test logging INPUT. That is, it tests what
parameters were used to invoke the logging method, while still
allowing actual logger to execute normally.
"""
def test_logger_log(self):
"""Check for Logger.log call."""
original_logger = LOG
patched_log = patch('__main__.LOG.log',
side_effect=original_logger.log).start()
log_msg = 'My log msg.'
level = logging.ERROR
LOG.log(level, log_msg)
# call_args is a tuple of positional and kwargs of the last call
# to the mocked function.
# Also consider using call_args_list
# See: https://docs.python.org/3/library/unittest.mock.html#unittest.mock.Mock.call_args
expected = (level, log_msg)
self.assertEqual(expected, patched_log.call_args[0])
if __name__ == '__main__':
unittest.main()
【讨论】：