Python logging wont shutdown

Question

I have been learning the python logging module but have been having problems getting the logging to shutdown after it's done. Here is an example -

import logging

log = logging.getLogger()
log.setLevel(logging.INFO)
handler = logging.FileHandler('test.log')
handler.setLevel(logging.INFO)
formatter = logging.Formatter(
            fmt='%(asctime)s %(levelname)s: %(message)s',
            datefmt='%Y-%m-%d %H:%M:%S'
            )
handler.setFormatter(formatter)
log.addHandler(handler)

log.info('log file is open')  
logging.shutdown()
log.info('log file should be closed')

But the module is stilling logging after the logging.shutdown() as the log file looks like this -

# cat test.log
2014-07-17 19:39:35 INFO: log file is open
2014-07-17 19:39:35 INFO: log file should be closed

According to the documentation this command should "perform an orderly shutdown by flushing and closing all handlers". Should I be doing something else to close the log file ?

Answer 1

So I found that the file handler for logging is not completely going away by using shutdown(). The best way seems to be to manually remove the file handler -

def main():
    log = logging.getLogger()
    log.setLevel(logging.INFO)
    fh = logging.FileHandler(filename='test.log')
    fh.setLevel(logging.INFO)
    formatter = logging.Formatter(
                    fmt='%(asctime)s %(levelname)s: %(message)s',
                    datefmt='%Y-%m-%d %H:%M:%S'
                    )
    fh.setFormatter(formatter)
    log.addHandler(fh)

    log.info('-------Start--------')
    log.info('this function is doing something')
    log.info('this function is finished')
    log.removeHandler(fh) <--------------------------Add this line
    del log,fh

Answer 2

I had the same probleme with the creation of a new logger with every call of the function. A solution that i found is to clear all handlers after executing the code

log.handlers.clear()

Don't know if it is the correct way but it works for me.

Answer 3

I had this problem while writing a tKinter application. I had extensive logging as various controls were being used and every time I (for instance) pressed a certain button multiple times consecutively, the number of times a line was logged was equal to the number of times I pressed the button consecutively.

I added: log.handlers.clear() at the end of main() and it cleared the issue up.

Answer 4

The Python Doc for shutdown specifies that:

This should be called at application exit and no further use of the logging system should be made after this call.

It does not mean that the logger object cannot be used afterwards. After calling shutdown, simply don't try to log anything else using that logger object and that should be fine.