CODEWITHSUNDEEP
pythonpython-logging
JoeMjr2
JoeMjr2

Reputation: 3944

Logging handleError() not intercepting exception

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.

Upvotes: 3

Views: 1450

Answers (3)

reubano
reubano

Reputation: 5353

You can access the exception via sys.exc_info like so:

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)

Upvotes: 0

JoeMjr2
JoeMjr2

Reputation: 3944

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)

Upvotes: 2

blues
blues

Reputation: 5185

This is a "bug" in python. Basically the reopenIfNeeded() method on the WatchedFileHandler is not wrapped into the try/except block that catches all other logging errors. There is two possible changes to make this work depending on what the goal is:

1.) only delete the log file, and not the directory that contains it. the WatchedFileHandler will be able to detect this and recover by recreating the file

2.) Use a regular FileHandler instead of the WatchedFileHandler. no attempt to recreate the missing file will be made, and the error will be handled by handleError as expected

Upvotes: 0

Related Questions