日志记录handleError()不拦截异常

Question

我创建了一个定制的Python处理程序，在这里我重写了handleError()方法。为了测试它，我删除了包含日志文件的目录，以强制日志记录错误。当我下一次尝试用记录器记录一些信息时，我希望这会触发对handleError()的调用。然而，这种情况并没有发生。异常直接传递到我的方法进行日志记录。

最小可重现性示例：

import logging
import os
import shutil

from logging.handlers import WatchedFileHandler
from pathlib import Path

class MySpecialWatchedFileHandler(WatchedFileHandler):
    def handleError(self, record):
        print("******************** HANDLING AN ERROR!!!! *********************")
        super().handleError(record)

print("************** Start ************")
test_logger = logging.getLogger(__name__)
test_logger.handlers = []
log_directory = "/tmp/test_logdir"
Path(log_directory).mkdir(parents=True, exist_ok=True)
handler = MySpecialWatchedFileHandler(os.path.join(log_directory, "test_logfile.log"), delay=False)
test_logger.addHandler(handler)
test_logger.setLevel(logging.INFO)

# Force a failure by deleting the logging directory, so that it does not auto-recover.
shutil.rmtree(log_directory, ignore_errors=False)

test_logger.info("This is a test")
print("************** End ************")

结果输出：

/home/joe/percipient/mirage-backend-django/venv/bin/python /home/joe/.config/JetBrains/PyCharm2020.3/scratches/scratch.py
************** Start ************
Traceback (most recent call last):
  File "/home/joe/.config/JetBrains/PyCharm2020.3/scratches/scratch.py", line 25, in <module>
    test_logger.info("This is a test")
  File "/usr/lib/python3.6/logging/__init__.py", line 1308, in info
    self._log(INFO, msg, args, **kwargs)
  File "/usr/lib/python3.6/logging/__init__.py", line 1444, in _log
    self.handle(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 1454, in handle
    self.callHandlers(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 1516, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 865, in handle
    self.emit(record)
  File "/usr/lib/python3.6/logging/handlers.py", line 481, in emit
    self.reopenIfNeeded()
  File "/usr/lib/python3.6/logging/handlers.py", line 471, in reopenIfNeeded
    self.stream = self._open()
  File "/usr/lib/python3.6/logging/__init__.py", line 1061, in _open
    return open(self.baseFilename, self.mode, encoding=self.encoding)
FileNotFoundError: [Errno 2] No such file or directory: '/tmp/test_logdir/test_logfile.log'

Process finished with exit code 1

请注意，******************** HANDLING AN ERROR!!!! *********************从未打印过。

为什么我的处理程序没有捕捉到这个异常？

不确定这是否重要，但我尝试过将logging.raiseExceptions设置为True和False，并在处理程序中将延迟设置为True和False，在这两种选项上的行为都是相同的。

Answer 1

我终于解决了这个问题。在我的自定义处理程序中，我使用我自己的try()方法重写了emit()方法，除了在调用超类的emit()方法之外，它现在在打开日志精细时捕获异常并将其路由到我的handleError()方法。

class MySpecialWatchedFileHandler(WatchedFileHandler):
    def handleError(self, record):
        print("****** HANDLING AN ERROR!!!! *****")
        #
        # Do what I need to do to handle the error here
        #

    def emit(self, record):
        try:
            super().emit(record)
        except Exception:
            record.exc_info = sys.exc_info()
            self.handleError(record)

Answer 2

这是python中的一个"bug“。基本上，reopenIfNeeded()方法在WatchedFileHandler上没有包装到try/ not块中，该块捕获所有其他日志记录错误。根据目标是什么，有两种可能的更改可以使这项工作：

1.)只删除日志文件，而不删除包含日志文件的目录。WatchedFileHandler将能够通过重新创建文件来检测这一点并恢复。

2.)使用常规的FileHandler而不是WatchedFileHandler。不会尝试重新创建丢失的文件，该错误将由handleError按预期处理。

Answer 3

可以通过sys.exc_info访问异常，如下所示：

import sys
import logging


def handleLoggingError(record):
    print(f"exc_info: {sys.exc_info()}")


hdlr = logging.StreamHandler(sys.stdout)
hdlr.handleError = handleLoggingError
logger = logging.getLogger(__name__)
logger.addHandler(hdlr)