classification
Title: Problems using logging module with idle
Type: behavior Stage:
Components: Library (Lib) Versions: Python 2.4, Python 2.6, Python 2.5
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: ag6502, vinay.sajip
Priority: normal Keywords: patch

Created on 2008-03-02 13:55 by ag6502, last changed 2008-03-16 21:39 by vinay.sajip. This issue is now closed.

Files
File name Uploaded Description Edit
logging.patch ag6502, 2008-03-02 13:55 Patch to remove handler from logger on close(). Allows for multiple (sequential) basicConfig()/shutdown()
Messages (4)
msg63179 - (view) Author: Andrea Griffini (ag6502) * Date: 2008-03-02 13:55
I'm not a user of idle, but when asked about a strange behaviour of the
logging module I digged a bit and found what I think is indeed a problem
in the module itself.
The problem is visible if the module is used from idle (or any other IDE
that keeps the same python instance running for multiple execution of
user code); if you call basicConfig(filename="foo.txt"), do some logging
and call shutdown() the handler is closed (correctly closing the file)
but remains attached to the root logger, and gets called again at next
run (giving an error for invalid I/O on a closed file).
This can also be reproduced in a single run with

import logging
logging.basicConfig(filename="logtest.txt")
logging.warning("This is a test")
logging.shutdown()
logging.basicConfig(filename="logtest2.txt")
logging.warning("This is a test (2)")
logging.shutdown()

I think that it is not correct to close the handler but leave it in
place, so I tried patching the module so that every handler keeps a list
of all loggers it is attached to, and removes itself from loggers at
close() time. This way the above code runs correctly (creating two
files) and the logging module still passes the test suite.
I must however admit that logging logic is a bit beyond my grasp
(including a close() call commented out, some uses of lock/release I
don't understand) so may be the attached patch is not correct even if
passes the test.
msg63207 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2008-03-03 10:39
I don't think this is a bug, though possibly the documentation could be
clarified. The shutdown() method is meant to be called at application
exit; its main purpose is to flush any output in handler buffers. It
doesn't do a complete reversal of what basicConfig() does.

I'll keep this as pending to remind me to update the documentation for
shutdown().
msg63210 - (view) Author: Andrea Griffini (ag6502) * Date: 2008-03-03 11:44
I thougt it was a bug because when calling close() handlers are removed
from some data structure (the global dictionary and the global list) but
they're left inside the loggers they're attached to. Now I understand
that this is a responsibility of who attached the handler; probably my
patch would break or just behave differently with code that already
managed to remove logging handlers from loggers explicitly or that
relied on the fact that even a "closed" handler can still be notified.

Having the logging module to work correctly in IDLE and other
environments that keep a running instance of the interpreter provided
that shutdown is called would have been just a lucky nice side effect of
"fixing" handler.close (of course those IDEs will still have potential
problems with any module that keeps an internal state).
msg63601 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2008-03-16 21:39
Documentation updated in trunk.
History
Date User Action Args
2008-03-16 21:39:57vinay.sajipsetstatus: pending -> closed
messages: + msg63601
2008-03-03 11:44:01ag6502setmessages: + msg63210
2008-03-03 10:39:30vinay.sajipsetstatus: open -> pending
assignee: vinay.sajip
resolution: not a bug
messages: + msg63207
nosy: + vinay.sajip
2008-03-02 13:55:48ag6502create