Logging Handlers Empty - Why Logging TimeRoatingFileHandler doesn't work

Question

So I do logging.config.fileConfig to setup my logging from a file config that has console and file handler. Then I do logging.getLogger(name) to get my logger and log. At certain times I want the filehandler's filename to change i.e. log rotate (I can't use time rotator because of some issues with Windows platform) so to do that I call logger.handlers - it shows an empty list, so I cant close them!! However when I step through the debugger, its clearly not empty (well of course without it I wouldn't be able to log right)

Not sure whats going on here, any gotchas that I'm missing?

Appreciate any help. Thanks.

Tempt

Answer 1

It seems you need to correctly get the root logger:

logger = logging.getLogger(__name__)
handlers = logger.handlers[:]
print('module {}'.format(handlers))
print('module {}'.format(logger.hasHandlers()))

logger = logging.getLogger('root')
handlers = logger.handlers[:]
print('root {}'.format(handlers))
print('root {}'.format(logger.hasHandlers()))

logger = logging.getLogger()
handlers = logger.handlers[:]
print('blank {}'.format(handlers))
print('blank {}'.format(logger.hasHandlers()))

output:

module []

module True

root []

root True

blank [<logging.handlers.RotatingFileHandler object at 0x108d82898>, <logging.StreamHandler object at 0x108d826d8>]

blank True

Leaven

Answer 2

Firstly the issue is that, if you use a config file to initialise logging with file and console handlers, then it does not populate logging.handlers list, so you can not iterate over it and close+flush the streams prior to opening new one with a new logging file name.

If you want to use TimeRotatingFileHandler or RotatingFileHandler, it sits under logging/handler.py and when it tries to do a roll over, it only closes its own stream, as it has no idea what streams the parent logging (mostly singleton) class may have open. And so when you do a roll over, there is a file lock (file filehandler) and boom it all fails.

So the solution (for me) is to initialise logging programatically and use addHandlers on logging, which also populates logging.handlers [], which I then use to iterate over my console/file handler and close them prior to manually rotating the file.

It to me looks like an obvious bug with the logging class, and if its working on unix - it really shouldn't.

Thanks everyone, especially @falsetru for your help.

Tempt

Answer 3

You can use RotatingFileHandler (not TimedRotatingFileHandler).

Calling doRollover of the handler will rotate the log files.

Digitalize

it seems on windows, logger keeps a lock on the file and rotatingfilehandler fails to rotate, that said it happened when using TimedRotatingFileHandler, but they both call doRollover to do the job which I don't believe plays ball on Windows? – Tempt

@OriginalCliche, Are you opening the file in another program? – Digitalize

@OriginalCliche, Could you try this in you system and check whether app.log, app.log.1 is generated? ideone.com/PBkSA7 – Digitalize

I actually don't have logging.handlers.RotatingFileHandler. I checked out logging_init_.py - its not there!! Although I do have logging.FileHandler and logging.StreamHandler. I'm using python v2.7.1 and in pycharm 3.4 IDE - any ideas? @Digitalize – Tempt

@OriginalCliche, It's in logging/handlers.py. And I tested the script in Python2.7/Python3.4 both in Windows 7 / Ubuntu 14.04. – Digitalize

hmm. thanks for the code demo mate. I get an exception: Traceback (most recent call last): File "C:\Python27\lib\logging_init_.py", line 863, in emit stream.write(fs % msg) ValueError: I/O operation on closed file – Tempt

@OriginalCliche, Did you run the code as is or modified? – Digitalize

i added file and console handler – Tempt

@OriginalCliche, Could you show me the code that caused the exception? – Digitalize

okay got it to work. what i did was gave a name to rotator handler, looped thru all handlers and flushed and closed them (except for rotator) and then used rotator handler to rotate. i suppose i could now just add handlers anew (with my filename, instead and maintain my filename standard of prepending with date) – Tempt

i looked at the rotator code, it only closes its own stream and not any other stream that you have in "Logger" - i am not sure how it is suppose to work in presence of multiple handlers with streams.. – Tempt

Answer 4

Maybe there is no such name as 'TimeRoatingFileHandler' because you missed 'd' in word 'Timed'. So it must be: 'TimedRoatingFileHandler'

Leggett