如何在Python中临时重定向日志输出？

Question

这里已经有一个问题回答了如何处理关于 sys.stdout 和 sys.stderr 的内容: https://dev59.com/bGzXa4cB1Zd3GeqPY-Y8#14197079

但是这并不适用于所有情况。日志模块似乎会输出到 sys.stdout 和 sys.stderr，但我无法使用上述的上下文管理器来捕获它。

在下面的示例代码中，我试图捕获上下文管理器内的所有输出，但无法捕获日志记录语句:

from __future__ import print_function
import contextlib
import sys
import logging
from StringIO import StringIO

# taken from https://dev59.com/bGzXa4cB1Zd3GeqPY-Y8#14197079
@contextlib.contextmanager
def stdout_redirect(where):
    prev_stdout = sys.stdout
    prev_stderr = sys.stderr
    prev_stdout.flush()
    sys.stdout = where
    sys.stderr = where
    try:
        yield where
    finally:
        where.flush()
        sys.stdout = prev_stdout
        sys.stderr = prev_stderr

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

print("\t\tOUTSIDE: stdout", file=sys.stdout)
print("\t\tOUTSIDE: stderr", file=sys.stderr)
logger.info("\tOUTSIDE: info")
logger.debug("\tOUTSIDE: debug")
logger.warn("\tOUTSIDE: warn")
logger.error("\tOUTSIDE: error")
logger.critical("\tOUTSIDE: critical")

print("=============== DIVIDER ================")

s = ""
with stdout_redirect(StringIO()) as new_stdout:
    print("\t\tINSIDE: stdout", file=sys.stdout)
    print("\t\tINSIDE: stderr", file=sys.stderr)
    logger.info("\tINSIDE: info")
    logger.debug("\tINSIDE: debug")
    logger.warn("\tINSIDE: warn")
    logger.error("\tINSIDE: error")
    logger.critical("\tINSIDE: critical")


print("=============== DIVIDER ===============")
print(new_stdout.getvalue())

print("=============== LOGGING ===============")

print(logger.handlers)
print(logger.root.handlers)

我该如何暂时重定向记录器输出到stdout并捕获它们？我查看了logging/init.py，但它没有立即告诉我需要做什么。

我的动机是想为一个庞大的代码库配备测试，每个测试都捕获所调用的大量日志输出。我可以捕获外部程序，但似乎无法捕获我在nose中运行的测试。

目前不能重新编写冗长的部分，但这绝对是未来的目标。

编辑，关于ubuntu

这是我尝试使用nosetests运行的内容：

from __future__ import print_function
import sys

def test_funky_shurane():
    import logging
    logging.basicConfig(level=logging.DEBUG)
    logging.info("===== shurane info")
    logging.warn("===== shurane warn")
    logging.error("===== shurane error")
    logging.critical("===== shurane critical")
    print("===== shurane stdout", file=sys.stdout)
    print("===== shurane stderr", file=sys.stderr)
    assert True

然后使用以下命令运行：

nosetests test_logging.py
nosetests --nocapture test_logging.py

- Ehtesh Choudhury

---

你是否正在使用 nose 带有 --nocapture 标志运行？ - unutbu

我不确定，但似乎只影响标准输出/错误。 - Ehtesh Choudhury

你是想要仅捕获只输出到stdout/stderr的日志输出吗？还是想要捕获所有输出到stdout/stderr的输出？或者你想要捕获已经配置为输出到其他源（如文件、套接字、数据库等）的所有日志输出？logging包可以将日志记录到除了stdout/stderr之外的许多地方。 - snapshoe

如果可能的话，我想捕获所有输出到stdout/stderr的内容，而不必配置现有代码。我知道logging非常灵活，可以输出到多个源；我只是在寻找那些输出到stdout/stderr的内容。 - Ehtesh Choudhury

Answer 1

logging.basicConfig()是一种方便的方式，以非常简单的方式设置一些日志处理。如果您需要更多内容，则不应使用basicConfig()。这并不是什么大问题，因为它并没有做太多事情。我们需要为两个流配置日志记录。

import logging, sys
fmt = logging.Formatter(BASIC_FORMAT)

hdlr_stderr = logging.StreamHandler(sys.stderr)
hdlr_stderr.setFormatter(fmt)
hdlr_stdout = logging.StreamHandler(sys.stdout)
hdlr_stdout.setFormatter(fmt)
root.addHandler(hdlr_stderr)
root.addHandler(hdlr_stdout)
root.setLevel(logging.DEBUG)

默认情况下，记录器会记录它们接收到的所有消息；但最初，我们不想将任何消息记录到sys.stdout：

hdlr_stdout.level = float('inf')  # larger than any log level; nothing gets logged

那么，您的上下文管理器可能会像这样：

接下来是需要翻译的内容：

@contextlib.contextmanager
def redirect_stderr_logging(where):
    hdlr_stderr.level = float('inf')
    hdlr_stdout.level = logging.NOTSET
    try:
        yield where
    finally:
        hdlr_stderr.level = logging.NOTSET
        hdlr_stdout.level = float('inf')

- SingleNegationElimination

---

我不确定我理解了你的意思；你是在建议将stdout和stderr作为“StreamHandler”实例添加到根记录器中吗？上面代码中的日志设置是假设的；我有一个更大的代码库正在使用日志记录，并已经输出到stdout和/或stderr。 - Ehtesh Choudhury

@Shurane 你能展示设置代码吗？如何定义输出到stdout和stderr？ - tmr232

@Shurane: 问题在于 StreamHandler 直接持有对输出流的引用; 如果您想要静音，您必须找到一些方法来调整它; 您可以假设遍历记录器树，查找对 sys.stderr 有引用的 StreamHandler 实例，但这听起来相当冒险; 更好的选择是修改配置日志的代码，只做您真正想做的事情。 - SingleNegationElimination

Answer 2

重定向无法工作，因为你最初设置的记录器直接指向标准输出。请参考以下内容。

logging_test.py

import logging
import sys

SIMPLE_LOG_FORMAT = '[%(asctime)s] {%(filename)s:%(lineno)d} %(levelname)s - %(message)s'
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)
formatter = logging.Formatter(SIMPLE_LOG_FORMAT)
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)

logger.info("Message before redirecting stdout and stderr")
# Checking what logger is writing to
logger.info('Before Redirection. logger writing to {} '.format(logger.handlers[0].stream))

log_file = open('log_file.log', 'w')
sys.stdout = log_file
sys.stderr = log_file
# Checking what logger is writing to
logger.info('After Redirection. logger writing to {} '.format(logger.handlers[0].stream))
logger.info("Message after redirecting stdout and stderr")

log_file.close()

Output:

[2018-06-01 16:27:10,670] {logging_test.py:12} INFO - Message before redirecting stdout and stderr
[2018-06-01 16:27:10,670] {logging_test.py:14} INFO - Before Redirection. logger writing to <open file '<stdout>', mode 'w' at 0x10cd74150> 
[2018-06-01 16:27:10,670] {logging_test.py:20} INFO - After Redirection. logger writing to <open file '<stdout>', mode 'w' at 0x10cd74150> 
[2018-06-01 16:27:10,670] {logging_test.py:21} INFO - Message after redirecting stdout and stderr

正如您在输出的第二行和第三行中所看到的，logger 仍然直接引用。

解决此问题的方法之一是执行以下操作：

logger.handlers[0].stream = open('log_file.log', 'w')

请注意，如果您正在使用多个线程，对其中一个线程进行此类更改将导致其他线程的输出也开始重定向输出。

- kvb