PyDev 单元测试：如何捕获记录到“捕获的输出”中的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 =========================
AA

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

Answer 1

问题是 unittest 运行程序在测试开始之前替换了 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 的出色代码 添加到所有 setUp 中，因此我将其子类化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__ 行并在测试或稍微修改的 LogThisTestCase 中定义 logger。

Answer 3

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

如果想在实际测试中捕获特定日志，我发现从 Python 3.4 开始，unittest.TestCase 提供了 assertLogs()，它返回一个捕获当前日志的上下文管理器消息。从 unittest 文档：

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 标志，（例如py测试--log-cli-level=info）。

Answer 4

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

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

Answer 5

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

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 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

我创建了这个单元测试：

import logging
from io import StringIO

def test_stream():
    logger = logging.getLogger()
    logger.level = logging.DEBUG
    strStream = StringIO()
    streamHandler = logging.StreamHandler(strStream)
    logger.addHandler(streamHandler)
    logger.info('Hello World!')

    assert strStream.getvalue() == 'Hello World!\n'

    strStream.close()

Answer 8

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

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

common.py 执行所有主要配置，包括此代码片段：

    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 9

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

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.* 内容。