Log rotation with Python

Some time ago I got the task to implement log rotation in Torando web service. At first sight, it looks easy to do: the problem is known and should be easy to find. But.

As always if you have a little bit different use case you get some problems and you have to find a solution yourself. Or just read the docs.

TL;DR

If you want to implement a log rotation with requirements:

  1. One log file per day
  2. The filename should be in a custom format. For example, %Y%m%d.%i.log where %Y, %m, %d is a year, month and day of the current date. %i is the index for the file if the service restarted.

For that case you should use TimedRotatingFileHandler. Use namer and suffix properties to configure filename format:

def get_filename(filename):
    # Get to log directory
    log_directory = os.path.split(filename)[0]

    # Extension of the filename is the suffix property 
    # (in our case - %Y%m%d) (for example, .20181231).
    # We don't need dot. Our file name will be suffix.log (20181231.log)
    date = os.path.splitext(filename)[1][1:]

    # New file name
    filename = os.path.join(log_directory, date)
    
    if not os.path.exists('{}.log'.format(filename)):
        return '{}.log'.format(filename)

    # Looking for minimum `i` that we can use (file name with the same `i` not exists).
    index = 0
    f = '{}.{}.log'.format(filename, index)
    while os.path.exists(f):
        index += 1
        f = '{}.{}.log'.format(filename, index)
    return f

rotation_logging_handler = TimedRotatingFileHandler(
                               './logs/log.log', 
                               when='m', 
                               interval=1, 
                               backupCount=5)
rotation_logging_handler.suffix = '%Y%m%d'
rotation_logging_handler.namer = get_filename

logger.addHandler(rotation_logging_handler)

More detailed

The problem

Let’s start from the beginning. I have to implement a logging system in our Tornado service. Requirements:

Python has logging module and pack of different Handlers. Each handler helps to implement different strategies:

For the task, we should use the second one.

TimedRotatingFileHandler

First Attempt

At first sight, the task seems to be easy and everything should work out of the box.

import logging as logging
from logging.handlers import TimedRotatingFileHandler
from time import sleep

# 'when' and 'interval' parameters combination defines period 
# when new log file create.
# In this example new file will create every minute 
# (interval=1, when='m').
rotation_logging_handler = TimedRotatingFileHandler(
                               './logs/log.log', 
                               when='m', 
                               interval=1, 
                               backupCount=5)

logger = logging.getLogger()
logger.addHandler(rotation_logging_handler)

for i in range(121):
    sleep(1)
    print('current iteration: {}'.format(i))
    logger.error('current iteration: {}'.format(i))

Let’s run this program. You can see that in the logs directory there are three files: log.log and two log.log.date-and-time. In the easiest case, this solution will work. But I want the names of my log files will be yearmonthday.index.log. So, let’s continue.

Second Attempt

Okay, the first attempt got us working but not an expected result. Let’s improve our example. As we can see in the documentation logger has suffix property. We’ll change this property with expected format %Y%m%d:

import logging as logging
from logging.handlers import TimedRotatingFileHandler
from time import sleep

# 'when' and 'interval' parameters combination defines period 
# when new log file create.
# In this example new file will create every minute 
# (interval=1, when='m').
rotation_logging_handler = TimedRotatingFileHandler(
                               './logs/log.log', 
                               when='m', 
                               interval=1, 
                               backupCount=5)
rotation_logging_handler.suffix = '%Y%m%d'

logger = logging.getLogger()
logger.addHandler(rotation_logging_handler)

for i in range(121):
    sleep(1)
    print('current iteration: {}'.format(i))
    logger.error('current iteration: {}'.format(i))

logs directory contains only one file log.log.date. I expected two files: after first and after the second minutes. As I can see this doesn’t work.

Okay. I find how log’s file name made up in logger sources. I found the property namer. namer is a function that overrides how log’s filename should make up. If I were more attentive I would find this information in the documentation.

Third Attempt

Improve the example with new pieces of knowledge:

import logging as logging
from logging.handlers import TimedRotatingFileHandler
from time import sleep

def get_filename(filename):
    # Get the log directory
    log_directory = os.path.split(filename)[0]

    # suffix - log file's extension (with dot). 
    # In this example - %Y%m%d. For example ".20181231".
    # We don't need a dot, becouse file name should be suffix.log (20181231.log)
    date = os.path.splitext(filename)[1][1:]

    # New file name for a new log file.
    filename = os.path.join(log_directory, date)

    if not os.path.exists('{}.log'.format(filename)):
        return '{}.log'.format(filename)

    # Get minimal index that we can use.
    index = 0
    f = '{}.{}.log'.format(filename, index)
    while os.path.exists(f):
        index += 1
        f = '{}.{}.log'.format(filename, index)
    return f


rotation_logging_handler = TimedRotatingFileHandler(
                               './logs/log.log', 
                               when='m', 
                               interval=1, 
                               backupCount=5)
rotation_logging_handler.suffix = '%Y%m%d'
rotation_logging_handler.namer = get_filename

logger = logging.getLogger()
logger.addHandler(rotation_logging_handler)

for i in range(121):
    sleep(1)
    print('current iteration: {}'.format(i))
    logger.error('current iteration: {}'.format(i))

If you run last code snippet you’ll see expected behavior: script works 2 minutes and a new log file is created every minute with the name {yearmonthday}.{index}.log.

comments powered by Disqus