如何在日志中使用doctest？
下面这个测试代码运行失败：
import logging
logging.basicConfig(level=logging.DEBUG,format='%(message)s')
def say_hello():
'''
>>> say_hello()
Hello!
'''
logging.info('Hello!')
if __name__ == '__main__':
import doctest
doctest.testmod()
这些页面
看起来这些页面建议使用 logging.StreamHandler(sys.stdout) 和 logger.addHandler(handler)，但是我尝试了之后都没有成功。（我刚接触 Python，如果这点不明显的话。）
请帮我修正上面的代码，让测试能够通过。
2017年6月4日更新： 针对 00prometheus 的评论：当我问这个问题时，关于 在 Python 程序中使用 doctest 和 logging 的接受答案看起来复杂得不必要。实际上，确实如此，因为这里的接受答案提供了一个更简单的解决方案。在我个人的偏见看来，我的问题也比我在原帖中链接的那个问题更清晰。
4 个回答
正如其他人提到的，这个问题的关键在于，doctest在basicConfig创建了一个持有自己副本的StreamHandler之后，修改了sys.stdout。解决这个问题的一种方法是创建一个流对象，让它把write和flush的内容转发到sys.stdout。另一种方法是完全绕过这个问题，自己创建一个处理器：
class PrintHandler(logging.Handler):
def emit(self, record):
print(self.format(record))
logging.basicConfig(level=logging.DEBUG, format='%(message)s',
handlers=[PrintHandler()])
我使用以下方法：
- 把日志记录的地方设置成一个叫做StringIO的对象。
- 开始记录日志...
- 打印StringIO对象里的内容，看看输出结果。
- 或者：对StringIO对象里的内容进行检查。
这样就可以了。
下面是一些示例代码。
首先，它在doctest中设置了日志记录的整个过程 - 只是为了展示它是如何工作的。
然后代码展示了如何把这个设置放到一个单独的函数setup_doctest_logging中，这个函数负责设置并返回一个打印日志的函数。这样可以让测试代码更专注，把一些繁琐的部分移出测试。
import logging
def func(s):
"""
>>> import io
>>> string_io = io.StringIO()
>>> # Capture the log output to a StringIO object
>>> # Use force=True to make this configuration stick
>>> logging.basicConfig(stream=string_io, format='%(message)s', level=logging.INFO, force=True)
>>> func('hello world')
>>> # print the contents of the StringIO. I prefer that. Better visibility.
>>> print(string_io.getvalue(), end='')
hello world
>>> # The above needs the end='' because print will otherwise add an new line to the
>>> # one that is already in the string from logging itself
>>> # Or you can just expect an extra empty line like this:
>>> print(string_io.getvalue())
hello world
<BLANKLINE>
>>> func('and again')
>>> # Or just assert on the contents.
>>> assert 'and again' in string_io.getvalue()
"""
logging.info(s)
def setup_doctest_logging(format='%(levelname)s %(message)s', level=logging.WARNING):
"""
This could be put into a separate module to make the logging setup easier
"""
import io
string_io = io.StringIO()
logging.basicConfig(stream=string_io, format=format, level=level, force=True)
def log_printer():
s = string_io.getvalue()
print(s, end='')
return log_printer
def other_logging_func(s, e=None):
"""
>>> print_whole_log = setup_doctest_logging(level=logging.INFO)
>>> other_logging_func('no error')
>>> print_whole_log()
WARNING no error
>>> other_logging_func('I try hard', 'but I make mistakes')
>>> print_whole_log()
WARNING no error
WARNING I try hard
ERROR but I make mistakes
"""
logging.warning(s)
if e is not None:
logging.error(e)
if __name__ == '__main__':
import doctest
doctest.testmod()
一种实现这个功能的方法是对 logging 模块进行“猴子补丁”（这是我写的代码；从 import logging 导入的文档内容与您的问题相关）：
@classmethod
def yield_int(cls, field, text):
"""Parse integer values and yield (field, value)
>>> test = lambda text: dict(Monster.yield_int('passive', text))
>>> test(None)
{}
>>> test('42')
{'passive': 42}
>>> import logging
>>> old_warning = logging.warning
>>> warnings = []
>>> logging.warning = lambda msg: warnings.append(msg)
>>> test('seven')
{}
>>> warnings
['yield_int: failed to parse text "seven"']
>>> logging.warning = old_warning
"""
if text == None:
return
try:
yield (field, int(text))
except ValueError:
logging.warning(f'yield_int: failed to parse text "{text}"')
不过，有一种更简洁的方法是使用 unittest 模块：
>>> from unittest import TestCase
>>> with TestCase.assertLogs(_) as cm:
... print(test('seven'))
... print(cm.output)
{}
['WARNING:root:yield_int: failed to parse text "seven"']
从技术上讲，您应该实例化一个 TestCase 对象，而不是将 _ 作为 self 传递给 assertLogs，因为没有保证这个方法将来不会尝试访问实例属性。
你需要定义一个“记录器”对象。通常在导入之后这样做：
import sys
import logging
log = logging.getLogger(__name__)
当你想记录一条消息时：
log.info('Hello!')
在像脚本一样运行的代码中，你需要设置基本配置：
if __name__ == '__main__':
import doctest
logging.basicConfig(level=logging.DEBUG, stream=sys.stdout, format='%(message)s')
doctest.testmod()
补充：
好吧，你说得对。它确实不工作，但我让它工作了……不过不要这样做！直接使用打印语句或者返回你实际需要检查的内容就行。正如你第二个链接所说，这真的是个坏主意。你不应该检查日志输出（日志是用来记录的）。甚至第二个链接的原作者也说他们通过把日志改成打印来让它工作。但这里有段看似有效的“邪恶代码”：
class MyDocTestRunner(doctest.DocTestRunner):
def run(self, test, compileflags=None, out=None, clear_globs=True):
if out is None:
handler = None
else:
handler = logging.StreamHandler(self._fakeout)
out = sys.stdout.write
logger = logging.getLogger() # root logger (say)
if handler:
logger.addHandler(handler)
try:
doctest.DocTestRunner.run(self, test, compileflags, out, clear_globs)
finally:
if handler:
logger.removeHandler(handler)
handler.close()
if __name__ == '__main__':
logging.basicConfig(level=logging.DEBUG, format='%(message)s')
tests = doctest.DocTestFinder().find(say_hello, __name__)
dt_runner = MyDocTestRunner()
for t in tests:
dt_runner.run(t, out=True)
补充（继续）：
当我尝试你第二个链接建议的方法时，我的尝试也失败了。这是因为内部的 doctest 会把 sys.stdout 重新指向 self._fakeout。所以除了我的小技巧，其他方法都不行。实际上，我是告诉记录器写入这个“假输出”。
补充（对评论的回答）：
这并不是链接中的代码。如果是链接中的代码，我会说这不是个坏选择，因为它没有做什么太复杂的事情。然而，我的代码使用了一个“私有”的内部实例属性，普通用户不应该使用。这就是为什么它是邪恶的原因。
是的，日志可以用来测试输出，但在单元测试或 doctest 中这样做并没有太大意义，这可能也是为什么 doctest 默认不包含这样的功能。你提到的 TextTest 主要是关于功能测试或集成测试的。单元测试（和 doctest）应该测试小的独立组件。如果你必须捕获日志输出来确保你的单元测试或 doctest 是正确的，那么你可能需要考虑将事情分开，或者不在 doctest 中进行这些检查。
我个人只在简单示例和验证中使用 doctest。主要是用作用法示例，因为任何用户都可以看到内联的 doctest。
补充（最后一个）：
同样的解决方案，更简单的代码。这段代码不需要你创建一个自定义的运行器。你仍然需要创建默认的运行器，因为你需要访问“_fakeout”属性。没有办法使用 doctest 来检查日志输出，除非将日志记录到这个属性作为流。
if __name__ == '__main__':
dt_runner = doctest.DocTestRunner()
tests = doctest.DocTestFinder().find(sys.modules[__name__])
logging.basicConfig(level=logging.DEBUG, format='%(message)s', stream=dt_runner._fakeout)
for t in tests:
dt_runner.run(t)