classification
Title: logging.handlers.RotatingFileHandler fails when delay parameter is set to True
Type: crash Stage:
Components: Library (Lib) Versions: Python 2.6
process
Status: closed Resolution: out of date
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: Eli.Courtwright, vinay.sajip
Priority: normal Keywords:

Created on 2010-03-17 19:58 by Eli.Courtwright, last changed 2010-03-17 23:45 by vinay.sajip. This issue is now closed.

Messages (3)
msg101242 - (view) Author: Eli Courtwright (Eli.Courtwright) Date: 2010-03-17 19:58
Here's a summary of the issue (also presented at http://stackoverflow.com/questions/2465073)

When I run the following code

{{{
import logging
from logging.handlers import RotatingFileHandler

rfh = RotatingFileHandler("testing.log", delay=True)
logging.getLogger().addHandler(rfh)
logging.warning("Boo!")
}}}

then the last line throws "AttributeError: RotatingFileHandler instance has no attribute 'level'".  So I add the line

{{{
rfh.setLevel(logging.DEBUG)
}}}

before the call to addHandler, and then the last line throws "AttributeError: RotatingFileHandler instance has no attribute 'filters'". So if I manually set filters to be an empty list, then it complains about not having the attribute "lock", etc.

When I remove the delay=True, the problem completely goes away.

So one of the parent __init__ methods somewhere up the class hierarchy isn't getting called when delay is set. Examining the source code to the file logging/__init__.py, I see the following code in the FileHandler.__init__ method:

{{{
if delay:
    self.stream = None
else:
    stream = self._open()
    StreamHandler.__init__(self, stream)
}}}

It looks like the FileHandler.emit method checks for un-opened streams and finishes initialization when logging is performed:

{{{
if self.stream is None:
    stream = self._open()
    StreamHandler.__init__(self, stream)
StreamHandler.emit(self, record)
}}}

So the problem is that in the BaseRotatingHandler.emit method, the shouldRollover and doRollover methods are called before emit-ing the record. This causes methods to be called which themselves assumed that the __init__ process has completed.

Unfortunately, I don't have time right now to submit a patch, though I might be able to find the time within the next few months if no one else gets to it first.  Hopefully this report is detailed enough to easily convey the problem.
msg101248 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2010-03-17 23:32
Please check that there is nothing wrong with your Python installation. I get this result:

vinay@eta-jaunty:~/projects/scratch$ ls testing.log
ls: cannot access testing.log: No such file or directory
vinay@eta-jaunty:~/projects/scratch$ cat rfhtest.py 
import logging
from logging.handlers import RotatingFileHandler

rfh = RotatingFileHandler("testing.log", delay=True)
logging.getLogger().addHandler(rfh)
logging.warning("Boo!")

vinay@eta-jaunty:~/projects/scratch$ python --version
Python 2.6.2
vinay@eta-jaunty:~/projects/scratch$ python rfhtest.py
vinay@eta-jaunty:~/projects/scratch$ cat testing.log
Boo!
vinay@eta-jaunty:~/projects/scratch$ 

I'll mark this issue as pending for now, it certainly doesn't fail for me as it does for you, can you give more information about the problem?

I'll investigate the issue based on your analysis - can you tell me more about the platform you're on? Is there an existing log file when you get the error?
msg101249 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2010-03-17 23:43
I've investigated: this issue was fixed in r68829 dated 20 Jan, 2009. This was after the release of 2.6.1 but before the release of 2.6.2.

Please upgrade to Python 2.6.2.
History
Date User Action Args
2010-03-17 23:45:47vinay.sajipsetmessages: - msg101250
2010-03-17 23:45:28vinay.sajipsetmessages: + msg101250
2010-03-17 23:43:13vinay.sajipsetstatus: pending -> closed
resolution: works for me -> out of date
messages: + msg101249
2010-03-17 23:32:06vinay.sajipsetstatus: open -> pending
resolution: works for me
messages: + msg101248
2010-03-17 20:39:26benjamin.petersonsetassignee: vinay.sajip

nosy: + vinay.sajip
2010-03-17 19:58:08Eli.Courtwrightcreate