很奇怪:logger只使用第一个处理程序的格式化程序来处理异常

Question

我正在目睹日志记录模块以一种有趣的方式运行.我错过了什么吗？

我正在做通常的事情,有两个处理程序:一个StreamHandler,用于仅记录INFO和更高的控制台,以及一个FileHandler,它也将处理所有的DEBUG信息.

它工作正常,直到我决定为exeptions提供不同的格式.我想在文件中有一个完整的堆栈跟踪,但只是控制台上的异常类型和值.由于处理程序具有setFormatter函数,并且因为编写logging.Formatter的子类似乎很容易,所以我认为它会起作用.

控制台处理程序和文件处理程序都有自己的格式化程序.代码中的print语句证明了这一点.但是,对logger.exception的调用将仅使用添加的第一个处理程序的formatException =>在文件中记录异常,并在控制台中记录该格式.更改logger.addHandler行的顺序,然后是遍布各处的文件处理程序的formatException.

import logging
import sys

class ConsoleFormatter(logging.Formatter):
    def formatException(self, exc_info):
        # Ugly but obvious way to see who's talking.
        return "CONSOLE EXCEPTION %s: %s" % exc_info[:2]

def setup(path):
    logger = logging.getLogger()
    #
    file_handler = logging.FileHandler(path, mode='w')
    if __debug__:
        file_handler.setLevel(logging.DEBUG)
    else:
        file_handler.setLevel(logging.INFO)
    formatter = logging.Formatter("%(asctime)s %(levelname)-8s "
                                  "%(name)-16s %(message)s "
                                  "[%(filename)s@%(lineno)d in %(funcName)s]")
    file_handler.setFormatter(formatter)

    #
    console_handler = logging.StreamHandler(sys.stderr)
    console_handler.setLevel(logging.INFO)
    console_formatter = ConsoleFormatter("%(levelname)-8s - %(message)s")
    console_handler.setFormatter(console_formatter)

    # >>> FUN HAPPENS HERE <<<
    # Only the formatter of the first handler is used !  Both on the console
    # and in the file.  Change the order of these two lines to see.
    logger.addHandler(console_handler)
    logger.addHandler(file_handler)
    #
    # Proof that the two handlers have different formatters:
    print logger.handlers
    print file_handler.formatter.formatException
    print console_formatter.formatException
    #
    logger.setLevel(logging.DEBUG)
    logger.info("Logger ready.")

setup('test.log')
logger = logging.getLogger()
logger.debug("Only visible in the file.")
try:
    1/0
except ZeroDivisionError:
    logger.exception("boom")

这是怎么回事 ？

编辑:我顺便使用python 2.6.编辑:关于"console_formatter"变量名称更正的代码错字.

Answer 1

这是我提出的代码.它做的工作:).

class CachelessFormatter(logging.Formatter):
    # I came up with that after reading the answers to
    #     http://stackoverflow.com/questions/5875225/
    # which pointed me to
    #     http://bugs.python.org/issue6435
    # I still think Vinay Sajip has a bit of an attitude :p.
    def format(self, record):
        # Disable the caching of the exception text.
        backup = record.exc_text
        record.exc_text = None
        s = logging.Formatter.format(self, record)
        record.exc_text = backup
        return s

class ConsoleFormatter(CachelessFormatter):
    def formatException(self, exc_info):
        return "           %s: %s" % exc_info[:2]

def setup(path):
    file_handler = logging.FileHandler(path, mode='w')
    file_handler.setLevel(logging.DEBUG)
    formatter = CachelessFormatter("%(asctime)s %(levelname)-8s "
                                   "%(name)-16s %(message)s "
                                   "[%(filename)s@%(lineno)d in %(funcName)s]")
    file_handler.setFormatter(formatter)

    console_handler = logging.StreamHandler(sys.stderr)
    console_handler.setLevel(logging.INFO)
    formatter = ConsoleFormatter("%(levelname)-8s - %(message)s")
    console_handler.setFormatter(formatter)

    logger = logging.getLogger()
    logger.addHandler(file_handler)
    logger.addHandler(console_handler)
    if __debug__:
        logger.setLevel(logging.DEBUG)
    else:
        logger.setLevel(logging.INFO)
    logger.info("Logger ready.")

if __name__ == '__main__':
    setup('test.log')
    logger = logging.getLogger()
    logger.debug("Only shows in the file")
    try:
        1 / 0
    except ZeroDivisionError:
        pass
    logger.exception("boom")

Answer 2

我找到了你的问题!如果您查看第440行(对于py2.6)logger/__init__.py的源代码Formatter.format,您将看到以下内容:

        if record.exc_info:
            # Cache the traceback text to avoid converting it multiple times
            # (it's constant anyway)
            if not record.exc_text:
                record.exc_text = self.formatException(record.exc_info)

在你的情况下,这是不正确的,因为你要覆盖formatException.如果你注释掉if not record.exc_text(并相应地修改缩进),它似乎按预期工作.

这个bug似乎已经在这里报道了:http: //bugs.python.org/issue6435