I am playing with Python's logging system. I have noticed a strange behavior while removing handlers from a Logger object in a loop. Namely, my for loop removes all but one handler. Additional call to .removeHandler
removes the last handler smoothly. No error messages are issued during the calls.
This is the test code:
import logging
import sys
logging.basicConfig()
dbg = logging.getLogger('dbg')
dbg.setLevel(logging.DEBUG)
testLogger = logging.getLogger('mylogger')
sh = logging.StreamHandler(sys.stdout)
fh = logging.FileHandler('mylogfile.log')
dbg.debug('before adding handlers: %d handlers'%len(testLogger.handlers))
testLogger.addHandler(fh)
testLogger.addHandler(sh)
dbg.debug('before removing. %d handlers: %s'%(len(testLogger.handlers),
str(testLogger.handlers)))
for h in testLogger.handlers:
dbg.debug('removing handler %s'%str(h))
testLogger.removeHandler(h)
dbg.debug('%d more to go'%len(testLogger.handlers))
#HERE I EXPECT THAT NO HANDLER WILL REMAIN
dbg.debug('after removing: %d handlers: %s'%(len(testLogger.handlers),
str(testLogger.handlers)))
if len(testLogger.handlers) > 0:
#Why is this happening?
testLogger.removeHandler(testLogger.handlers[0])
dbg.debug('after manually removing the last handler: %d handlers'%len(testLogger.handlers))
I expect that at the end of the loop no handlers will remain in the testLogger
object, however
the last call to .removeHandler
apparently fails, as can be seen from the output below. Nevertheless
additional call to this function removes the handler as expected. Here is the output:
DEBUG:dbg:before adding handlers: 0 handlers
DEBUG:dbg:before removing. 2 handlers: [<logging.FileHandler instance at 0x021263F0>, <logging.StreamHandler instance at 0x021262B0>]
DEBUG:dbg:removing handler <logging.FileHandler instance at 0x021263F0>
DEBUG:dbg:1 more to go
DEBUG:dbg:after removing: 1 handlers: [<logging.StreamHandler instance at 0x021262B0>]
DEBUG:dbg:after manually removing the last handler: 0 handlers
More interestingly, if I replace the original loop with the following one, the loop
works as expected and no handlers remain in the testLogger
object at the end of the loop.
Here is the modified loop:
while len(testLogger.handlers) > 0:
h = testLogger.handlers[0]
dbg.debug('removing handler %s'%str(h))
testLogger.removeHandler(h)
dbg.debug('%d more to go'%len(testLogger.handlers))
What explains this behaviour? Is this a bug or am I missing something?
for h in list(testLogger.handlers)
– Moratorium