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

Question

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

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

两种方法可以做到这一点，我可以看到的是：

• 模拟出日志模块，无论是在零敲碎打的方式（mymodule.logging = mockloggingmodule）或用适当的嘲弄库。
• 编写或使用现有的插件来捕获输出并进行验证。

如果我采用前一种方法，我想知道什么是最简单的方法来重新设置全局状态到我嘲笑日志记录模块之前的状态。

期待您的提示和技巧在这一个...

Answer 1

我用来模拟记录器，但在这种情况下，我发现最好用日志处理程序，所以我写了这个一个基于the document suggested by 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 2

你应该用嘲弄的，因为有一天你可能想改变你的记录到，比方说，数据库中的一个。如果在测试鼻子时尝试连接数据库，你将不会高兴。

即使标准输出被抑制，嘲笑仍将继续工作。

我已经使用了pyMox的存根。记得在测试后取消设置存根。

Answer 3

找到了one answer因为我发布了这个。不错。

Answer 4

作为珊瑚礁的答案的后续行动，我冒充编码使用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() 

Answer 5

还好，这是不是你要的东西写下你自己; testfixtures包提供了一个上下文管理器，用于捕获发生在with语句正文中的所有日志输出。你可以在这里找到包：

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

这里是它如何测试记录文档：

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

Answer 6

UPDATE：不再需要为下面的答案。改为使用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) 

Answer 7

在龙卷风中实现的ExpectLog类是一个很大的实用工具：

with ExpectLog('channel', 'message regex'): 
    do_it() 

http://tornado.readthedocs.org/en/latest/_modules/tornado/testing.html#ExpectLog

Answer 8

布兰登的回答是：

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和获取工具

Answer 9

键控关闭的logCapture插件的输出冲突@珊瑚礁的答案，我确实尝试了下面的代码。它适用于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() 

Answer 10

蟒蛇3.4，标准单元测试库提供了一个新的测试断言上下文管理，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'])