Celery + Python logging: problems and solutions

by Amit

In my current project, I had a few logging requirements for which I had to look around a bit.

First off,  Celery, by default doesn’t respect your application’s logging and redirects all the application’s existing logging to its own logger. I wanted to preserve my application’s logging and this is how I went about doing it based on the answer by Ask Sol on the celery-users list [1]. It worked great.

Second, I wanted the log file to be different everytime a new task was executed. With just the above modification, that won’t happen. Since the after_setup_task_logger signal is invoked only when Celery is starting up. For this, every time a new task request was received, I modified the existing logger handler to a newly created FileHandler.

Finally, I also wanted a way to retrieve the name of the log file which the current logger was using. From the logging documentation, I found that this was not possible. So, I took a hint from this StackOverflow question’s answer [2] and extended the FileHandler class to implement a new method to return the name of the log file.

Here is the complete tasks.py file:

from __future__ import absolute_import
import json
import os
import logging
import time
import tempfile
from celery import Celery
from celery.signals import after_setup_task_logger

class myFileHandler(logging.FileHandler):

    def __init__(self, logfile, mode):
        self.logfile = logfile 
        super(myFileHandler,self).__init__(self.logfile,mode)

    def getlogfile(self):
        return self.logfile

celery = Celery()
celery.config_from_object('celeryconfig')

# Return a filename of the form imagebuild_.log
def getfilename():
    time_now = str(time.time()).split('.')
    logfile = tempfile.gettempdir() + '/imagebuild_{0:s}.log'.format(time_now[0]+time_now[1])
    return logfile

@after_setup_task_logger.connect
def augment_celery_log(**kwargs):
    logger = logging.getLogger('imagebuilder')
    logfile = getfilename()
    handler = myFileHandler(logfile,'w')
    formatter = logging.Formatter('%(asctime)s - %(message)s')

    if not logger.handlers:
        formatter = logging.Formatter(logging.BASIC_FORMAT)
        handler.setFormatter(formatter)
        logger.addHandler(handler)
        logger.propagate = 0

        logger.setLevel(logging.DEBUG)

@celery.task
def build(buildconfig, kickstart):

    logger = logging.getLogger('imagebuilder')
    logfile = getfilename()
    handler = myFileHandler(logfile,'w')
    formatter = logging.Formatter('%(asctime)s - %(message)s')
    handler.setFormatter(formatter)    

    # replace the handler
    logger.handlers[0] = handler

    # Your custom code
    # ..

There may be some unused imports remaining. This solution seems to work for me as of now. Note that this is for Celery 3.0.

Links:

[1] https://groups.google.com/d/topic/celery-users/xNPYTobJ5Rg/discussion

[2] http://stackoverflow.com/questions/9405890/dynamic-filepath-filename-for-filehandler-in-logger-config-file-in-python

Advertisement