Python logger prints the same output several times in multithreaded environment [duplicate]

Question

In my code, somehow the logger prints out events twice, but conventional print shows correct number of events.

select 1,2
select 1,2
2013-04-19 18:37:30,618:4561354752 - SQLLogger - DEBUG - select 1,2
2013-04-19 18:37:30,618:4561354752 - SQLLogger - DEBUG - select 1,2
2013-04-19 18:37:30,618:4565561344 - SQLLogger - DEBUG - select 1,2
2013-04-19 18:37:30,618:4565561344 - SQLLogger - DEBUG - select 1,2

It is not clear to me why the same message is being published mutliple times in multithreaded situations.

import logging
from threading import Thread

class SQLEngine(object):
    def __init__(self, DB_PATH):
        ch = logging.StreamHandler()
        ch.setLevel(logging.DEBUG)
        formatter = logging.Formatter('%(asctime)s:%(thread)d - %(name)s - %(levelname)s - %(message)s')
        ch.setFormatter(formatter)
        self.logger = logging.getLogger('SQLLogger')
        self.logger.setLevel(logging.DEBUG)
        self.logger.addHandler(ch)

    def execute(self,SQL,):
            self.logger.debug(SQL)
            print SQL

class DBWorker(Thread):
    def __init__(self, name):
        Thread.__init__(self)
        self.name = name

    def run(self):
        db = SQLEngine('')
        db.execute('select 1,2')

if __name__ == '__main__':
    DBWorker('thread 1').start()
    DBWorker('thread 2').start()

Answer 1

Looking at the logger documentation:

Loggers are never instantiated directly, but always through the module-level function logging.getLogger(name). Multiple calls to getLogger() with the same name will always return a reference to the same Logger object.

Now your constructor is calling the following code:

ch = logging.StreamHandler()
self.logger = logging.getLogger('SQLLogger')
self.logger.addHandler(ch)

Note you don't create a new logger for every SQLEngine object, but always get a reference to the same logger instance. It means you're always adding handler to one and the same logger, hence after creating the second object your logger has two handlers, each of them printing to the screen.

You we'll need either register only one handler (for example outside of the SQLEngine constructor) or call getLogger in the __init__ with a different name for every SQLEngine instance.