PyDev unittesting：如何在“捕获的输出”中捕获记录到 logging.Logger 的文本

Question

我正在使用 PyDev 对我的 Python 应用程序进行开发和单元测试。 至于单元测试，除了没有内容被记录到日志框架之外，一切都很好。 PyDev 的“捕获的输出”没有捕获记录器。

我已经将记录的所有内容转发到标准输出，如下所示：

import sys
logger = logging.getLogger()
logger.level = logging.DEBUG
logger.addHandler(logging.StreamHandler(sys.stdout))

尽管如此，“捕获的输出”不显示记录到记录器的内容。

这是一个单元测试脚本示例：test.py

import sys
import unittest
import logging

logger = logging.getLogger()
logger.level = logging.DEBUG
logger.addHandler(logging.StreamHandler(sys.stdout))

class TestCase(unittest.TestCase):
    def testSimpleMsg(self):
        print("AA")
        logging.getLogger().info("BB")

控制台输出为：

Finding files... done.
Importing test modules ... done.

testSimpleMsg (itf.lowlevel.tests.hl7.TestCase) ... AA
2011-09-19 16:48:00,755 - root - INFO - BB
BB
ok

----------------------------------------------------------------------
Ran 1 test in 0.001s

OK

但是测试的CAPTURED OUTPUT是：

======================== CAPTURED OUTPUT =========================
AA

有人知道在执行此测试期间如何捕获记录到logging.Logger 的所有内容吗？

Answer 1

问题是unittest runner 在测试开始之前替换了sys.stdout/sys.stderr，而StreamHandler 仍在写入原来的sys.stdout。

如果您将“当前”sys.stdout 分配给处理程序，它应该可以工作（参见下面的代码）。

import sys
import unittest
import logging

logger = logging.getLogger()
logger.level = logging.DEBUG
stream_handler = logging.StreamHandler(sys.stdout)
logger.addHandler(stream_handler)

class TestCase(unittest.TestCase):
    def testSimpleMsg(self):
        stream_handler.stream = sys.stdout
        print("AA")
        logging.getLogger().info("BB")

虽然，更好的方法是在测试期间添加/删除处理程序：

import sys
import unittest
import logging

logger = logging.getLogger()
logger.level = logging.DEBUG

class TestCase(unittest.TestCase):
    def testSimpleMsg(self):
        stream_handler = logging.StreamHandler(sys.stdout)
        logger.addHandler(stream_handler)
        try:
            print("AA")
            logging.getLogger().info("BB")
        finally:
            logger.removeHandler(stream_handler)

Answer 2

我厌倦了必须手动将Fabio's great code 添加到所有setUps，因此我将unittest.TestCase 子类化为一些__metaclass__ing：

class LoggedTestCase(unittest.TestCase):
    __metaclass__ = LogThisTestCase
    logger = logging.getLogger("unittestLogger")
    logger.setLevel(logging.DEBUG) # or whatever you prefer

class LogThisTestCase(type):
    def __new__(cls, name, bases, dct):
        # if the TestCase already provides setUp, wrap it
        if 'setUp' in dct:
            setUp = dct['setUp']
        else:
            setUp = lambda self: None
            print "creating setUp..."

        def wrappedSetUp(self):
            # for hdlr in self.logger.handlers:
            #    self.logger.removeHandler(hdlr)
            self.hdlr = logging.StreamHandler(sys.stdout)
            self.logger.addHandler(self.hdlr)
            setUp(self)
        dct['setUp'] = wrappedSetUp

        # same for tearDown
        if 'tearDown' in dct:
            tearDown = dct['tearDown']
        else:
            tearDown = lambda self: None

        def wrappedTearDown(self):
            tearDown(self)
            self.logger.removeHandler(self.hdlr)
        dct['tearDown'] = wrappedTearDown

        # return the class instance with the replaced setUp/tearDown
        return type.__new__(cls, name, bases, dct)

现在您的测试用例可以简单地从LoggedTestCase 继承，即class TestCase(LoggedTestCase) 而不是class TestCase(unittest.TestCase)，您就完成了。或者，您可以添加__metaclass__ 行并在测试中定义logger 或稍作修改的LogThisTestCase。

Answer 3

我建议使用 LogCapture 并测试您是否确实在记录您期望记录的内容：

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

Answer 4

在阅读了本文和其他一些相关主题中的答案（谢谢！）之后，这是我放在一起的上下文管理器，它将捕获记录器的输出（如果已发送）。

from io import StringIO
import logging
class CaptureLogger:
    """Context manager to capture `logging` streams

    Args:
        - logger: 'logging` logger object

    Results:
        The captured output is available via `self.out`

    """

    def __init__(self, logger):
        self.logger = logger
        self.io = StringIO()
        self.sh = logging.StreamHandler(self.io)
        self.out = ''

    def __enter__(self):
        self.logger.addHandler(self.sh)
        return self

    def __exit__(self, *exc):
        self.logger.removeHandler(self.sh)
        self.out = self.io.getvalue()

    def __repr__(self):
        return f"captured: {self.out}\n"

使用示例：

logger = logging.getLogger()
msg = "Testing 1, 2, 3"
with CaptureLogger(logger) as cl:
    logger.error(msg)
assert cl.out, msg+"\n"

由于 OP 要求将其放入捕获的 stdout 流中，您可以将其打印到 __exit__ 中的 stdout，因此添加一行如下：

    def __exit__(self, *exc):
        self.logger.removeHandler(self.sh)
        self.out = self.io.getvalue()
        print(self.out)

这个解决方案的不同之处在于它会收集日志输出，并在所有正常的print() 调用（如果有）之后一次性将其全部转出。所以它可能是也可能不是 OP 所追求的，但这对我的需求很有效。

Answer 5

有些人可能会访问此线程以找到将测试期间创建的日志转发到控制台或 PyDev 的方法。以上答案已经提供了一些解决方案。

如果想在实际测试中捕获特定日志，我发现从 Python 3.4 开始，unittest.TestCase 提供了assertLogs()，它返回一个捕获当前日志消息的上下文管理器。来自unittest 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'])

消息在cm.output 中捕获。如需更多详细信息（如时间、文件、行号等，cm.records 包含LogRecords 的列表。

所有这些都没有直接解决面对 PyDev 的 OP，而是提供了一种以编程方式检查创建的消息的方法。

对于熟悉pytest 的用户，可以使用--log-cli-level=LEVEL 标志（例如pytest --log-cli-level=info）将格式精美的日志消息转发到控制台。

Answer 6

我也遇到过这个问题。我最终继承了 StreamHandler，并使用获取 sys.stdout 的属性覆盖了流属性。这样，处理程序将使用 unittest.TestCase 已交换到 sys.stdout 的流：

class CapturableHandler(logging.StreamHandler):

    @property
    def stream(self):
        return sys.stdout

    @stream.setter
    def stream(self, value):
        pass

然后您可以在运行测试之前设置日志处理程序（这会将自定义处理程序添加到根记录器）：

def setup_capturable_logging():
    if not logging.getLogger().handlers:
        logging.getLogger().addHandler(CapturableHandler())

如果像我一样，您在单独的模块中进行测试，您可以在每个单元测试模块的导入后放置一行，以确保在运行测试之前设置日志记录：

import logutil

logutil.setup_capturable_logging()

这可能不是最干净的方法，但它非常简单并且对我来说效果很好。

Answer 7

如果您有不同的初始化模块用于测试、开发和生产，那么您可以禁用任何东西或在初始化程序中重定向它。

我有 local.py、test.py 和 production.py，它们都继承自 common.y

common.py 完成所有主要配置，包括这个 sn-p ：

    LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[%(server_time)s] %(message)s',
        },
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
    },
    'filters': {
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'handlers': {
        'django.server': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'django.server',
        },
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler'
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': 'INFO',
            'propagate': True,
        },
        'celery.tasks': {
            'handlers': ['console'],
            'level': 'DEBUG',
            'propagate': True,
        },
        'django.server': {
            'handlers': ['django.server'],
            'level': 'INFO',
            'propagate': False,
        },
    }

然后在 test.py 我有这个：

console_logger = Common.LOGGING.get('handlers').get('console')
console_logger['class'] = 'logging.FileHandler
console_logger['filename'] = './unitest.log

这将控制台处理程序替换为 FileHandler，这意味着仍然可以获取日志记录，但我不必接触生产代码库。

Answer 8

这是一个小技巧，但对我有用。当您想要显示捕获的日志时添加此代码。不需要后将其删除。

self.assertEqual(1, 0)

例子：

def test_test_awesome_function():
    print("Test 1")
    logging.info("Test 2")
    logging.warning("Test 3")

    self.assertEqual(1, 0)

更新：

顺便说一句，这不是一个长期的解决方案，当您想快速调试目标函数上的某些内容时，此解决方案很有帮助。

一旦断言失败，unittest 将抛出哪些函数出现错误，并捕获并显示 print、logging.* 内容。