PyDev unittest: 如何捕获记录到日志中的文本

我正在使用 PyDev 进行 Python 应用程序的开发和单元测试。 As for unit-testing, everything works great except the fact that no content is logged to the logging framework. The logger is not captured by the "Captured output" of PyDev.

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

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

然而,“捕获的输出”并不显示记录到日志的内容。

下面是一个 unittest-script 示例: < em > 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的所有内容吗?

77129 次浏览

问题在于 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)

我厌倦了不得不手动将 Fabio 的代码很棒添加到所有 setUp中,所以我用一些 __metaclass__ing 对 unittest.TestCase进行子类化:

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

我建议使用 LogCapture 并测试您是否真的在记录您希望记录的内容:

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

我也遇到了这个问题。最后,我对 StreamHandler 进行了子类化,并使用一个获取 sys.stdout 的属性覆盖 stream 属性。这样,处理程序将使用单元测试的流。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()

这可能不是最干净的方法,但它非常简单,对我来说很有效。

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

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

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

This replaces the console handler with a FileHandler and means still get logging but I do not have to touch the production code base.

在阅读了这个和其他一些相关的线程的答案之后(谢谢!),这里是我放在一起的上下文管理器,它将捕获日志记录器的输出(如果有的话)。

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 所追求的,但是这很好地满足了我的需要。

这是一个小黑客,但它为我工作。如果要显示捕获的日志,请添加此代码。不需要的时候再拿出来。

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将抛出获取错误的函数,并捕获和显示 printlogging.*内容。

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

如果想在实际测试中捕获特定的日志,我发现自从 Python 3.4以来,unittest.TestCase提供了 assertLogs(),它返回一个上下文管理器来捕获当前的日志消息。来自 单位文件:

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 问题,而是提供了一种以编程方式检查创建的消息的方法。

对于那些熟悉 派特的人来说,可以使用 --log-cli-level=LEVEL标志(例如 pytest --log-cli-level=info)将格式良好的日志消息转发到控制台。