如何在Django测试用例中测试特定日志消息是否被记录？

Question

我想确保在我的代码中，当某个条件满足时，会有一条日志信息被写入到Django的日志里。我该怎么用Django的单元测试框架来实现这个呢？

有没有地方可以查看这些记录的日志信息，就像我可以查看发送的邮件一样？我的单元测试是基于django.test.TestCase的。

Answer 1

通常，模拟日志记录对象的方法（可以参考Simeon Visser的精彩回答）有点复杂，因为它需要在所有进行日志记录的地方进行模拟。如果日志记录来自多个模块，或者是在你不拥有的代码中，这就会变得很麻烦。如果日志记录的模块更改了名称，你的测试就会失败。

很棒的'testfixtures'包提供了一些工具，可以添加一个日志处理器，捕获所有生成的日志消息，无论它们来自哪里。捕获到的消息可以在测试中进行检查。最简单的形式如下：

假设你要测试的代码会记录日志：

import logging
logger = logging.getLogger()
logger.info('a message')
logger.error('an error')

对此的测试可以是：

from testfixtures import LogCapture
with LogCapture() as l:
    call_code_under_test()
l.check(
    ('root', 'INFO', 'a message'),
    ('root', 'ERROR', 'an error'),
)

这里的'root'表示日志是通过一个使用logging.getLogger()创建的日志记录器发送的（也就是没有参数的情况）。如果你给getLogger传递一个参数（通常使用__name__），那么这个参数就会替代'root'。

这个测试并不关心是哪个模块创建了日志记录。它可以是被我们要测试的代码调用的子模块，也可以是第三方代码。

测试关注的是实际生成的日志消息，而不是模拟的技术，后者关注的是传递的参数。如果日志记录使用了'%s'格式字符串并且有额外的参数，而你没有自己展开这些参数（例如，使用logging.info('total=%s', len(items))而不是logging.info('total=%s' % len(items))，你应该使用前者。这没有额外的工作量，并且可以让将来可能出现的日志聚合服务（比如'Sentry'）正常工作——它们可以看到“total=12”和“total=43”是同一条日志消息的两个实例。这就是为什么pylint会警告后者形式的logging.info调用的原因。）

LogCapture包含日志过滤等功能。它的父包'testfixtures'是由另一位出色的开发者Chris Withers编写的，里面包含了许多其他有用的测试工具。文档在这里：http://pythonhosted.org/testfixtures/logging.html

Answer 2

你还可以使用 assertLogs 这个功能，它来自 django.test.TestCase。

当你的代码是：

import logging

logger = logging.getLogger('my_logger')

def code_that_throws_error_log():
    logger.error("Your log message here")

这是测试代码。

with self.assertLogs(logger='my_logger', level='ERROR') as cm:

    code_that_throws_error_log()

    self.assertIn(
        "ERROR:your.module:Your log message here",
        cm.output
    )

这样你就可以不必为了记录日志而去做额外的修改了。

Answer 3

使用mock模块来模拟日志模块或者日志对象。完成这个后，检查一下调用日志函数时传入的参数。

比如，如果你的代码是这样的：

import logging

logger = logging.getLogger('my_logger')

logger.error("Your log message here")

那么它看起来会是：

from unittest.mock import patch # For python 2.x use from mock import patch

@patch('this.is.my.module.logger')
def test_check_logging_message(self, mock_logger):
    mock_logger.error.assert_called_with("Your log message here")