64

I have an application which has to run a number of simulation runs. I want to setup a logging mechanisme where all logrecords are logged in a general.log, and all logs for a simulation run go to run00001.log, .... For this I have defined a class Run. in the __init__() a new filehandle is added for the runlog.

The problem is that the logfiles for the runs never get released, so after a number of runs the available handles are exhausted and the run crashes.

I've set up some routines to test this as follows

main routine

import Model
try:
    myrun = Model.Run('20130315150340_run_49295')
    ha = raw_input('enter')
    myrun.log.info("some info")
except:
    traceback.print_exc(file=sys.stdout)

ha = raw_input('enter3')

The class Run is defined in module Model as follows

import logging
class Run(object):

    """ Implements the functionality of a single run. """
    def __init__(self, runid):
        self.logdir="."
        self.runid          = runid
        self.logFile        = os.path.join(self.logdir , self.runid + '.log')
        self.log            = logging.getLogger('Run'+self.runid)
        myformatter         = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
        myhandler      = logging.FileHandler(self.logFile)
        myhandler.setLevel(logging.INFO)
        myhandler.setFormatter(myformatter)
        self.log.addHandler(myhandler) 

Then I use the program process explorer to follow the filehandlers. And I see the runlogs appear, but never disappear.

Is there a way I can force this?

vvvvv
  • 25,404
  • 19
  • 49
  • 81
Bart P.
  • 849
  • 1
  • 8
  • 11
  • 1
    Why not remove the handler again when the run finishes? Presumably you can hook into that event? – Martijn Pieters Mar 15 '13 at 15:04
  • Any advice on how to do that? I have tried with specifying self.log.removeHandler(myhandler) in __del__(), even by calling the destructor explicitly (myrun.__del__()). I've also tried by specifying in __exit__() and using a with statement, as suggested for opening filehandles with open. But no success so far. – Bart P. Mar 15 '13 at 19:21

3 Answers3

112

You need to call .close() on the filehandler.

When your Run class completes, call:

handlers = self.log.handlers[:]
for handler in handlers:
    self.log.removeHandler(handler)
    handler.close()

A file handler will automatically re-open the configured filename every time a new log message arrives, so calling handler.close() may sometimes appear futile. Removing the handler from the logger stops future log records from being sent to it; in the above code we do this first, to avoid an untimely log message from another thread reopening the handler.

Another answer here suggest you use logging.shutdown(). However, all that logging.shutdown() does is call handler.flush() and handler.close(), and I'd not recommend using it. It leaves the logging module in a state where you can't use logging.shutdown() again, not reliably.

Martijn Pieters
  • 1,048,767
  • 296
  • 4,058
  • 3,343
  • I was using an interactive Python environment (Spyder). Apparently, Spyder uses logging internally. So, logging.shutdown() does not produce the desired effect. The next execution of the same program doubled log records, the 3rd execution tripled them, etc. Handlers are apparently not removed by shutdown() in this environment. Also, I did not disrupt Spyder in any way by issuing an explicit shutdown() call. Puzzling. Martijn's code to explicitly close and remove the handlers, one at a time, did work in the Spyder environment. – Richard Elkins May 26 '19 at 19:52
41

You can also shutdown the logging completely. In that case, file handles are being released:

logging.shutdown()

It closes opened handles of all configured logging handlers.

I needed it to be able to delete a log file after a unit test is finished and I was able to delete it right after the call to the logging.shutdown() method.

David Ferenczy Rogožan
  • 23,966
  • 9
  • 79
  • 68
  • 4
    However, you cannot use logging system after this call - just a reminder. – Shital Shah Apr 11 '20 at 12:26
  • 3
    This doesn't shut down logging completely. It calls `flush()` and `close()` on each handler. While `.close()` removes a handler from the global module state and won't be closed *again* after a shutdown() call, file handlers typically **reopen** their file handles on the next log message. Since they haven't been removed from their parent logger, this just means that they open the file again to write the next incoming log record, then can't be closed by the next shutdown call. Leave using `logging.shutdown()` to the interpreter instead. – Martijn Pieters Sep 02 '20 at 10:31
  • @ShitalShah: you can, at least where it comes to file handlers and their subclasses (the stream handler, e.g. console, is a parent class of `FileHandler` and does not do this). `logging.shutdown()` doesn't do anything more than flush and close registered handlers, and `Handler.close()` un-registers the handler on close from the global registry. That's it. Handlers are still connected to loggers, logging will still pass records to handlers, and so they could still emit those records if they have somewhere to emit *to*. – Martijn Pieters Sep 02 '20 at 10:33
0

Probably we'll just want to .close() the FileHandler's and not the others, so the accepted answer could be slightly modified like:

for handler in self.log.handlers:
    if isinstance(handler, logging.FileHandler):
        handler.close()

Also, for the simpler cases where we just have a logger configured with logging.basicConfig(), the handlers can be retrieved by calling logging.getLogger().handlers.

  • Why wouldn't you want to close other handlers? If you are using a socket or syslog or HTTP handler, you probably want to close those too. Bottom line: it depends! – Martijn Pieters Mar 21 '22 at 10:54