Same Log messages multiple times in Python [issue]

The Mistake happened in my python loggers

what ?

I use Python/Flask framework to develop web applications. So, For my few usecase scripts, I have to use the logger to log the flow.I have created a common handler which workes nicely as expected.I have defined the logger in seperate module called utils/__init__.py. From this module I used to import to my script to log the flow.

import logging
import logging.handlers

def get_logger(name, file_name=None):
    LOG_FILENAME = file_name if file_name else name + '.log'
    # Set up a specific logger with our desired output level
    my_logger = logging.getLogger(name)
    # Add the log message handler to the logger
    handler = logging.handlers.RotatingFileHandler(LOG_FILENAME,
                                                      maxBytes=10000000,
                                                      backupCount=5,
                                                      )
    formatter = logging.Formatter("[%(asctime)s] [%(filename)s:%(lineno)s - %(funcName)5s() - %(processName)s] %(levelname)s - %(message)s")
    handler.setFormatter(formatter)
    my_logger.addHandler(handler)
    return my_logger

When I import this logger object to multiple files, log statements getting printed multiple times as many imports i did.

Stackoverflow saved my time.

The reason is Each call(log = get_logger('taleo_integration')) is creating a new log handler for the logger you create as given below.

What is under the hood ?

In [13]: from hirenew.utils import get_logger

In [14]: log.handlers
Out[14]: 
[<logging.handlers.RotatingFileHandler at 0x62f4b50>,
 <logging.handlers.RotatingFileHandler at 0x5ff0790>]

In [15]: log = get_logger('taleo_integration')

In [16]: log.handlers
Out[16]: 
[<logging.handlers.RotatingFileHandler at 0x62f4b50>,
 <logging.handlers.RotatingFileHandler at 0x5ff0790>,
 <logging.handlers.RotatingFileHandler at 0x5ff04d0>]

In [17]: log = get_logger('taleo_integration')

In [18]: log.handlers
Out[18]: 
[<logging.handlers.RotatingFileHandler at 0x62f4b50>,
 <logging.handlers.RotatingFileHandler at 0x5ff0790>,
 <logging.handlers.RotatingFileHandler at 0x5ff04d0>,
 <logging.handlers.RotatingFileHandler at 0x5ff0810>]

Soln

Finally, I added couple of lines in get_logger.

# Set up a specific logger with our desired output level
    my_logger = logging.getLogger(name)
    if not my_logger.handlers:
         # Here I created handler, formatter, loglevel etc..
    return my_logger

This works fine.

 

Advertisements

About Navaneethan

mixed feelings...
This entry was posted in Flask, Python and tagged , . Bookmark the permalink.

2 Responses to Same Log messages multiple times in Python [issue]

  1. Mandar Vaze says:

    For me, the following worked:

    del app.logger.handlers[:]

    This allowed to me to configure my own logger behaviour from scratch

  2. Navaneethan says:

    @Mandar Vaze Thanks for sharing it. This seems it will remove all the pre-defined handlers, and we have to redefine the handler on each worker.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s