Why doesn't my TimedRotatingFileHandler rotate

Question

This is my config file:

[loggers]
keys=root

[handlers]
keys=TimedRotatingFileHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=TimedRotatingFileHandler

[handler_TimedRotatingFileHandler]
class=handlers.TimedRotatingFileHandler
level=DEBUG
formatter=simpleFormatter
args=('driver.log', 'midnight', 1, 30)

[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=

In my code I setup and use the logger like this:

import logging
import logging.config

logging.config.fileConfig('logging.conf')
logging.info('Some message...')

Messages are logged to the file I specify (driver.log), but the rotations at midnight never happen.

Must the process be running at midnight for the rotation to occur? This is a batch process that I run every 15 minutes and it is never actually running at midnight.

Answer 1

The answer is that the process must be running all the time for this to work properly.

From http://bytes.com/topic/python/answers/595931-timedrotatingfilehandler-isnt-rotating-midnight:

Rotating should happen when the logging process creates the handler before midnight and makes a logging call destined for that handler after midnight.

Answer 2

I have also run into this problem, for various reasons I couldn't use rotatelog and a cron to rotate logs is just adding an extra thing that might go wrong. I used the function below to rotate the files, on a daily basis.

import os
import datetime
import glob

def sort_number_ext(s):
    try:
        return int(os.path.splitext(s)[1][1:])
    except:
        return s

def rotate_file(file, keep=30):
    """ Rotate a file if needed. If the file wasn't modified today then we
    rotate it around and remove old files """

    modified_date = datetime.datetime.fromtimestamp(os.path.getmtime(file))

    if modified_date.date() == datetime.datetime.today().date():
        return False

    old_files = glob.glob(file + ".*")
    old_files.sort(key=sort_number_ext, reverse=True)

    for f in old_files:
        try:
            number = int(os.path.splitext(f)[1][1:])
        except ValueError:
            continue

        if number >= keep:
            # If at or above keep limit, remove.
            os.unlink(f)
        else:
            # Increment.
            new = "%s.%s" % (os.path.splitext(f)[0], number + 1)
            os.rename(f, new)

    # Finally rename our log.
    os.rename(file, "%s.1" % file)
    return True

I call this to rotate my logs before initializing the logger.

Answer 3

I would guess this really only happens when the process is running at midnight. In your case (cronjob not running very long), you should go with a simple log file, where the current date is added to the logfilename. This way, a "rollover" happens automatically.