获取所有的日志输出与mock

Question

我想要获取所有的日志输出，使用的是mock工具。我查找了一下，但只找到了一些方法可以模拟 logging.info 或 logging.warn。

我需要获取所有的输出，不管设置了什么日志级别。

def test_foo():

   def my_log(...):
      logs.append(...)

   with mock.patch('logging.???', my_log):
        ...

在我们的库中，我们使用的是这个：

import logging
logger=logging.getLogger(__name__)

def foo():
    logger.info(...)

Answer 1

我找到了这个解决方案：

def test_foo(self):

    logs=[]

    def my_log(self, *args, **kwargs):
        logs.append((args, kwargs))

    with mock.patch('logging.Logger._log', my_log):
        ...

Answer 2

这个模块 testfixtures 有一个类可以处理这个问题：

>>> import logging
>>> from testfixtures import LogCapture
>>> with LogCapture() as l:
...     logger = logging.getLogger()
...     logger.info('a message')
...     logger.error('an error')

>>> l.check(
...     ('root', 'INFO', 'a message'),
...     ('root', 'ERROR', 'another error'),
...     )
Traceback (most recent call last):
 ...
AssertionError: sequence not as expected:

same:
(('root', 'INFO', 'a message'),)

expected:
(('root', 'ERROR', 'another error'),)

actual:
(('root', 'ERROR', 'an error'),)

来源：http://testfixtures.readthedocs.io/en/latest/logging.html

Answer 3

pytest

如果你正在使用pytest来编写测试，可以看看一个很方便的工具叫caplog，它可以帮你捕捉日志记录。它会记录所有产生的日志，你可以通过caplog.records这个列表来访问这些记录。每个元素都是logging.LogRecord的一个实例，所以你可以轻松访问LogRecord的各种属性。举个例子：

# spam.py

import logging
logger=logging.getLogger(__name__)

def foo():
    logger.info('bar')


# tests.py

import logging
from spam import foo

def test_foo(caplog):
    foo()
    assert len(caplog.records) == 1
    record = next(iter(caplog.records))
    assert record.message == 'bar'
    assert record.levelno == logging.INFO
    assert record.module == 'spam'
    # etc

安装

这个工具最初是在一个叫pytest-capturelog的pytest插件中引入的，但现在这个插件已经不再维护了。不过幸运的是，它有一个不错的分支叫pytest-catchlog，最近已经合并到pytest==3.3.0中。所以，如果你使用的是较新版本的pytest，就可以直接使用；如果你用的是旧版本的pytest，可以从PyPI安装pytest-catchlog。

文档

目前，pytest没有提供关于caplog工具的文档（或者至少我找不到），所以你可以参考pytest-catchlog的文档。

普通的unittest

如果pytest不是一个选项，我建议你不要去修改logging，可以直接添加一个自定义的处理器来记录所有的日志。这里有一个简单的例子：

# utils.py

import logging


class RecordsCollector(logging.Handler):

    def __init__(self, *args, **kwargs):
        super().__init__(*args, **kwargs)
        self.records = []

    def emit(self, record):
        self.records.append(record)


# tests.py

import logging
import unittest
from utils import RecordsCollector
from spam import foo


class SpamTests(unittest.TestCase):

    def setUp(self):
        self.collector = RecordsCollector()
        logging.getLogger('spam').addHandler(self.collector)

    def tearDown(self):
        logging.getLogger('spam').removeHandler(self.collector)

    def test_foo(self):
        foo()
        # same checks as in the example above
        self.assertEqual(len(self.collector.records), 1)
        record = next(iter(self.collector.records))
        self.assertEqual(record.message, 'bar')
        self.assertEqual(record.levelno, logging.INFO)
        self.assertEqual(record.module, 'spam')


if __name__ == '__main__':
    unittest.main()

然后你可以扩展这个自定义处理器，实现你需要的逻辑，比如把记录存储在一个dict中，将日志级别映射到记录的列表，或者添加一个contextmanager的实现，这样你就可以在测试中开始和停止捕捉记录：

from contextlib import contextmanager

@contextmanager
def record_logs():
    collector = RecordsCollector()
    logging.getLogger('spam').addHandler(collector)
    yield collector
    logging.getLogger('spam').removeHandler(collector)


def test_foo(self):
    with utils.record_logs() as collector:
        foo()
        self.assertEqual(len(collector.records), 1)

Answer 4

stdlib

从Python 3.4开始，内置的 unittest 模块增加了一个叫 assertLogs 的功能。当你使用这个功能时，如果不提供 logger 和 level 参数，它会捕捉所有的日志信息（并且会屏蔽已有的处理程序）。你可以通过上下文管理器的 records 属性来访问记录的日志条目。文本输出的字符串会存储在 output 列表中。

import logging
import unittest


class TestLogging(unittest.TestCase):

    def test(self):
        with self.assertLogs() as ctx:
            logging.getLogger('foo').info('message from foo')
            logging.getLogger('bar').info('message from bar')
        print(ctx.records)

Tornado

对于Python 2，我通常使用Tornado的 ExpectLog。这个功能是自包含的，适用于普通的Python代码。其实它比标准库的解决方案更优雅，因为 ExpectLog 只是一个普通的 logging.Filter 类（你可以查看它的 源代码）。不过它缺少一些功能，比如无法访问记录的条目，所以我通常会稍微扩展一下它，比如：

class ExpectLog(logging.Filter):

    def __init__(self, logger, regex, required=True, level=None):
        if isinstance(logger, basestring):
            logger = logging.getLogger(logger)
        self.logger = logger
        self.orig_level = self.logger.level
        self.level = level
        self.regex = re.compile(regex)
        self.formatter = logging.Formatter()
        self.required = required
        self.matched = []
        self.logged_stack = False

    def filter(self, record):
        if record.exc_info:
            self.logged_stack = True
        message = self.formatter.format(record)
        if self.regex.search(message):
            self.matched.append(record)
            return False
        return True

    def __enter__(self):
        self.logger.addFilter(self)
        if self.level:
            self.logger.setLevel(self.level)
        return self

    def __exit__(self, typ, value, tb):
        self.logger.removeFilter(self)
        if self.level:
            self.logger.setLevel(self.orig_level)
        if not typ and self.required and not self.matched:
            raise Exception("did not get expected log message")

这样你就可以得到类似的东西：

class TestLogging(unittest.TestCase):

    def testTornadoself):
        logging.basicConfig(level = logging.INFO)

        with ExpectLog('foo', '.*', required = False) as ctxFoo:
            with ExpectLog('bar', '.*', required = False) as ctxBar:
                logging.getLogger('foo').info('message from foo')
                logging.getLogger('bar').info('message from bar')
        print(ctxFoo.matched)
        print(ctxBar.matched)

不过要注意，对于过滤器的方法，当前的日志级别是很重要的（可以通过 level 参数来覆盖），而且你需要为每个感兴趣的日志记录器设置一个过滤器。你可以按照这种方法，制作一个更适合你情况的解决方案。

更新

另外，还有一个 unittest2 的版本可以在Python 2中使用，它也包含了 assertLogs 的功能。