奇怪：記錄器只使用第一個處理程序的格式化程序的例外

Question

我目睹記錄模塊的行爲有趣。我錯過了什麼嗎？

我正在做兩個處理程序的常見事情：一個StreamHandler只記錄信息和更高的控制檯，和一個FileHandler，它也將處理所有的DEBUG信息。

它工作得很好，直到我決定使用不同的格式。我想在文件中使用完整的堆棧跟蹤，但只是控制檯上的異常類型和值。由於處理程序有一個setFormatter函數，並且由於編寫logging.Formatter的子類似乎很容易，所以我認爲它會起作用。

控制檯處理程序和文件處理程序都有自己的格式化程序。代碼中的打印語句證明了這一點。但是，對logger.exception的調用將只使用第一個處理程序的formatException = added異常將以其在控制檯中應具有的格式記錄在文件中。更改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

我發現你的問題！如果您在logger/__init__.py在源代碼中尋找Formatter.format，上線440（用於py2.6），你會看到以下內容：

 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（並相應地修復縮進），它似乎按預期工作。

的錯誤似乎已在此報告： http://bugs.python.org/issue6435

Answer 2

我第一次跑了你的代碼，我得到了回溯：

Traceback (most recent call last): 
    File "logger.py", line 42, in <module> 
    setup('test.log') 
    File "logger.py", line 37, in setup 
    print console_formatter.formatException 
NameError: global name 'console_formatter' is not defined 

這可能是問題的根源。當我更改console_handler代碼時，格式正確：

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

Answer 3

這是我想出了一個代碼。它做的工作:)。

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_test = 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")