python logging ensure a handler is added only once
Asked Answered
B

5

62

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

Bestead answered 13/6, 2011 at 17:27 Comment(1)
I think you should reevaluate the answers, because mouad's answer (at time of writing) ignores the fact that multiple calls to a method returning the same logger object CAN add duplicate handlers. narayan does a good job of explaining this.Petal
S
56

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

Spotty answered 4/8, 2015 at 3:17 Comment(5)
This is definitively the best answer. mouad's answer is unfortunately shortsighted in that it misses the possibility of duplicate handlers (not singletons) for a single instance of a logger (the singleton). Your answer helped me solve my problem.Petal
"logger.handlers returns a list of all the handlers associated with the given logger" ... yes it does, but can I ask you how you found this out? Did you go back to the source code? Because the python logging module documentation docs.python.org/2/library/logging.html does not reveal this info. Sometimes I feel Python's standard documentation is a bit lacking... anything better you could recommend?Jainism
@mikerodent I found about logger.handlers on SO when I was struggling with this duplicate output issue in logging and verified the same in the source code. Regarding documentation, more often than not, the standard docs do the job. pymotw helps me whenever I want something specific to be done with the help of python standard library.Spotty
Thank you very much, your (great btw) answer helped me a lot.Drexler
I'm using Python 2.7.12, logging-0.5.1.2. I initialize a logger in my main module and add a StreamHandler. In a different module, I then create another logger instance using logger2 = logging.getLogger(__name__). Then logger2.handlers returns []. I needed to do logger2.root.handlers to check for handlers. FYI.Schoonover
M
18

Well the logger.addHandler() will not add a handler if the handler already exists. To check if the handler is already there you can check the logger.handlers list:

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)
print logger.handlers
# [<logging.FileHandler object at 0x14542d0>]
logger.addHandler(hdlr)
print logger.handlers
# [<logging.FileHandler object at 0x14542d0>]

Beside that I will suggest putting this code in your main() function if you have one or in the __init__.py file of your package so to not have to call it each time. I will also suggest that you use a named logger, and do not use the root logger. Something like this:

logger = logging.getLogger(__name__)
...

Hope this was helpful :)

Melmon answered 13/6, 2011 at 17:42 Comment(4)
is the `Logger.handlers' list documented anywhere? I could not find it on docs.python.org/2/library/logging.htmlBathelda
@MariuszPluciński: Yeah i don't think it's documented anywhere, but if i remember well i had to check the Logger class code to understand how this work: hg.python.org/cpython/file/482590320549/Lib/logging/…Melmon
But if it's undocumented, then it may silently disappear in some future version of logging library. I'm not sure if it's good to depend on this feature (but I agree that, there doesn't seem to be any documented way to check this).Bathelda
This isn't entirely correct, as it is possible to add the same type of handler multiple times: [I know the comment formatting is gruesome]>>> log = logging.getLogger() >>> hdlr = logging.StreamHandler() >>> hndl = logging.StreamHandler() >>> hdlr <logging.StreamHandler object at 0x10e077ed0> >>> hndl <logging.StreamHandler object at 0x10e167150> >>> log.addHandler(hdlr) >>> log.addHandler(hndl) >>> log.handlers [<logging.StreamHandler object at 0x10e077ed0>, <logging.StreamHandler object at 0x10e167150>]Runty
T
6

You can also just check to see whether the handler list is empty. Here's the solution I wound up with:

def setup_logging(self, logfile):
    self._logger = logging.getLogger('TestSuite')
    self._logger.setLevel(logging.INFO)
    host = socket.gethostname().split('.')[0]
    if self._logger.handlers == []:
        fh = logging.handlers.RotatingFileHandler(logfile,
                                                  maxBytes=10*1024*1024,
                                                  backupCount=5)
        strfmt = "%" + "(asctime)s [%s] " % host + "%" + "(message)s"
        fmt = logging.Formatter(strfmt, datefmt="%Y.%m%d %H:%M:%S")
        fh.setFormatter(fmt)

        self._logger.addHandler(fh)
    self._logger.info('-' * (55 - len(host)))

I was seeing the handler added multiple times, so each log message was getting written to the log file more than once, and this fixed it.

Tarkington answered 23/10, 2013 at 14:10 Comment(0)
S
3

If you are familiar with AWS Lambda, then you might already know that in some contexts, the handlers come pre-configured [1]. Assuming logger.handlers is not empty, is not enough. I recommend setting an attribute on the logger instance, like so:

def init_logger(logger):
    if hasattr(logger, 'initialized'):
        return logger  # No need for addHandler
    else:
        setattr(logger, 'initialized', True)

    # Initialize the logger
    # ...

[1] Using python Logging with AWS Lambda

Smidgen answered 3/2, 2020 at 15:35 Comment(0)
I
1

Try checking if logger is already set. For example, if this code is inside a function:

logger = None
def init_logger():
    global logger
    if logger is not None:
        #logger has already been initialized
        return
    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)
Ilke answered 13/6, 2011 at 17:42 Comment(1)
I guess the check if logger is not None is not thread safe so there's no guarantee the initialization code won't run more than once.Petrina

© 2022 - 2024 — McMap. All rights reserved.