Search code examples
pythonloggingpython-logging

python logging ensure a handler is added only once


I have a piece of code that is initializing a logger as below.

logger = logging.getLogger()
hdlr = logging.FileHandler('logfile.log')
formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
hdlr.setFormatter(formatter)
logger.addHandler(hdlr) 
logger.setLevel(logging.DEBUG)

Unfortunately this code is being called multiple times, is there any way I can check to see if the handler already exists - I'd prefer to implement this without having to use a Singleton.

EDIT: Sorry, forgot to mention this is on python 2.5 - cheers, Richard


Solution

  • As @offbyone comments, it is possible to add redundant handlers to the same instance of the logger. The python docs for logging say-

    "Multiple calls to getLogger() with the same name will return a reference to the same logger object."

    So we don't need to worry about making the implementation a singleton, as it already is.

    Unfortunately the same is not true for the handlers associated with the same instance of the logger. There can be duplicate handlers attached.

    Example-

    1. Copy this code and save it in main.py

      import logging
      print 'inside main.py',
      print '-'*50
      def logger():
      
            print 'initializing logger....'
            logPath = '.'
            fileName = 'temp'
      
            # configure log formatter
            logFormatter = logging.Formatter("%(asctime)s [%(filename)s] [%(funcName)s] [%(levelname)s] [%(lineno)d] %(message)s")
      
            # configure file handler
            fileHandler = logging.FileHandler("{0}/{1}.log".format(logPath, fileName))
            fileHandler.setFormatter(logFormatter)
      
            # configure stream handler
            consoleHandler = logging.StreamHandler()
            consoleHandler.setFormatter(logFormatter)
      
            # get the logger instance
            logger = logging.getLogger(__name__)
      
            # set the logging level
            logger.setLevel(logging.DEBUG)
      
            print 'adding handlers- '
      
            #if not len(logger.handlers):
            logger.addHandler(fileHandler)
            logger.addHandler(consoleHandler)
      
            print 'logger initialized....\n'
            print 'associated handlers - ', len(logger.handlers)
            for handler in logger.handlers:
                  print handler
            print
            return logger
      
      main_logger = logger()
      main_logger.info('utilizing main.py logger.')
      print 'exiting main.py',
      print '-'*50
      
    2. and the following code in sub.py

      print 'inside sub.py',
      print '-'*50
      print 'importing main.py'
      import main
      print 'imported main.py'
      import logging
      print 'getting logger instance in sub'
      sub_logger = main.logger()
      print 'got logger instance in sub'
      sub_logger.info("utilizing sub_logger")
      print 'exiting sub.py',
      print '-'*50
      
    3. Run sub.py

      narayan@y510p:~/code/so$ python sub.py
      inside sub.py --------------------------------------------------
      importing main.py
      inside main.py --------------------------------------------------
      initializing logger....
      adding handlers- 
      logger initialized....
      
      associated handlers -  2
      <logging.FileHandler object at 0x7f7158740c90>
      <logging.StreamHandler object at 0x7f7158710b10>
      
      2015-08-04 07:41:01,824 [main.py] [<module>] [INFO] [41] utilizing main.py logger.
      exiting main.py --------------------------------------------------
      imported main.py
      getting logger instance in sub
      initializing logger....
      adding handlers- 
      logger initialized....
      
      associated handlers -  4 # <===== 4 handlers (duplicates added)
      <logging.FileHandler object at 0x7f7158740c90>
      <logging.StreamHandler object at 0x7f7158710b10>
      <logging.FileHandler object at 0x7f7158710bd0>
      <logging.StreamHandler object at 0x7f7158710c10>
      
      got logger instance in sub
      2015-08-04 07:41:01,824 [sub.py] [<module>] [INFO] [10] utilizing sub_logger
      2015-08-04 07:41:01,824 [sub.py] [<module>] [INFO] [10] utilizing sub_logger
      exiting sub.py --------------------------------------------------
      

    Hence multiple calls to the method returning the same logger added duplicate handlers.

    Now, for your question-

    is there any way I can check to see if the handler already exists

    Yes, there is-

    logger.handlers returns a list of all the handlers associated with the given logger.

    Before adding handlers to an instance of the logger, make sure not to add duplicate handlers In main.py, just un-comment the line that says if not len(logger.handlers): and indent the following two lines properly-

    if not len(logger.handlers):
        logger.addHandler(fileHandler)
        logger.addHandler(consoleHandler)
    

    Now again run sub.py

    narayan@y510p:~/code/so$ python sub.py
    inside sub.py --------------------------------------------------
    importing main.py
    inside main.py --------------------------------------------------
    initializing logger....
    adding handlers- 
    logger initialized....
    
    associated handlers -  2
    <logging.FileHandler object at 0x7fd67a891c90>
    <logging.StreamHandler object at 0x7fd67a862b10>
    
    2015-08-04 08:14:45,620 [main.py] [<module>] [INFO] [41] utilizing main.py logger.
    exiting main.py --------------------------------------------------
    imported main.py
    getting logger instance in sub
    initializing logger....
    adding handlers- 
    logger initialized....
    
    associated handlers -  2 # <===== Still 2 handlers (no duplicates)
    <logging.FileHandler object at 0x7fd67a891c90>
    <logging.StreamHandler object at 0x7fd67a862b10>
    
    got logger instance in sub
    2015-08-04 08:14:45,620 [sub.py] [<module>] [INFO] [10] utilizing sub_logger
    exiting sub.py --------------------------------------------------
    

    Further, if you want to limit the type of handlers to be added to the logger instance, you can do something like this-

        print 'adding handlers- '
        # allows to add only one instance of file handler and stream handler
        if len(logger.handlers) > 0:
            print 'making sure we do not add duplicate handlers'
            for handler in logger.handlers:
                  # add the handlers to the logger
                  # makes sure no duplicate handlers are added
    
                  if not isinstance(handler, logging.FileHandler) and not isinstance(handler, logging.StreamHandler):
                        logger.addHandler(fileHandler)
                        print 'added file handler'
                        logger.addHandler(consoleHandler)
                        print 'added stream handler'
        else:
            logger.addHandler(fileHandler)
            logger.addHandler(consoleHandler)
            print 'added handlers for the first time'
    

    Hope this helps!

    Edit:

    Unfortunately the same is not true for the handlers associated with the same instance of the logger. There can be duplicate handlers attached.

    It turns out that that above statement is not entirely true.

    Let's suppose we have created and configured a logger called 'main_logger' in the main module (which simply configures the logger, doesn't return anything).

    # get the logger instance
    logger = logging.getLogger("main_logger")
    # configuration follows
    ...
    

    Now in a sub-module, if we create a child logger following the naming hierarchy 'main_logger.sub_module_logger', we don't need to configure it in the sub-module. Just creation of the logger following the naming hierarchy is sufficient.

    # get the logger instance
    logger = logging.getLogger("main_logger.sub_module_logger")
    # no configuration needed
    # it inherits the configuration from the parent logger
    ...
    

    And it won't add duplicate handler as well.

    Reference- Using logging in multiple modules