Logging handleError() not intercepting exception

Question

I created a custom Python logging handler, where I overrode the handleError() method. In order to test it, I deleted the directory containing the log file to force a logging error. I was expecting this to trigger a call to handleError() the next time I tried to log something with the logger. However, this did not happen. The exception was passed directly through to my method doing the logging.

Minimal Reproducible Example:

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 ************")

Resulting output:

/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

Note that ******************** HANDLING AN ERROR!!!! ********************* is never printed.

Why is my handler not catching that exception?

Not sure if it matters, but I've tried it with logging.raiseExceptions set to both True and False, and also setting delay to both True and False in the handler, and the behavior is the same either way on both options.

Answer 1

Here's how I finally solved it. In my custom handler, I overrode the emit() method, with my own try/except around the call the super class's emit() method, so that it now catches the exception while opening the log fine and routes it to my handleError() method.

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)