TimedRotatingFileHandler loses data when doRollover is called

Python Help
1

I have a script that runs intermittently. We need to copy its logs to an archive system at intervals. To ensure we don’t lose data or duplicate data, I use the TimedRotatingFileHandler. If I configure this to roll over ever hour, say, then I can copy any “frozen” log files to the archive system and then delete them.

However sometimes the script detects an error in a subsystem and in this circumstance I want to log that error more urgently - I want to roll over the log file immediately and send the frozen log file to the archive system.

If I use RotatingFileHandler then the above works fine. But with TimedRotatingFileHandler, it loses data.

Example code below.

I think it should be smart enough to realise it is going to lose data, and so it should append to the frozen log file, not replace it.

Looking for a workaround, I tried setting the logging interval to 3600 seconds, rather than 1 hour. I thought this would mean that a new log file was created, provided that more than a second had elapsed since the the last roll-over. But it did not work: a new log file was not created by doRollover, even though the old timestamp was now old.

import logging
import logging.config as logconfig


TEST_LOG_CONFIG = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "standard": {
            "format": "%(message)s",
        }
    },
    "handlers": {
        "Timed_Rotating_File_Handler": {
            "level": "DEBUG",
            "formatter": "standard",
            "class": "logging.handlers.TimedRotatingFileHandler",
            "filename": "my_test.log",
            "when": 'H',
            "interval": 1,
            "backupCount": 100
        }
    },
    "loggers": {
        "Timed_Rotating_File_Handler": {
            "handlers": ["Timed_Rotating_File_Handler"],
            "level": "DEBUG",
            "propagate": False
        }
    }
}

logconfig.dictConfig(TEST_LOG_CONFIG)
logger = logging.getLogger("Timed_Rotating_File_Handler")

logger.debug("Output")
logger.handlers[0].doRollover()

# at this stage we have a "frozen" log file containing the "Output" line,
# and an empty "live" log file

logger.debug("Output2")
logger.handlers[0].doRollover()

# The old log output has been lost; we still only have one frozen log file, 
# which now contains only the "Output2" line, and an empty "live" log file
2

Since your use case doesn’t precisely match that of TimedRotatingFileHandler, I suggest you subclass the handler and get it working with your requirements. The handling of rotation in the stdlib class makes certain assumptions that may not hold if you call doRollover at arbitrary times.

1 Like