By using this site, you agree to our updated Privacy Policy and our Terms of Use. Manage your Cookies Settings.
446,370 Members | 1,188 Online
Bytes IT Community
+ Ask a Question
Need help? Post your question and get tips & solutions from a community of 446,370 IT Pros & Developers. It's quick & easy.

logging.shutdown() ValueError: I/O operation on closed file

P: n/a
Hello,

I'm trying to understand the behavior of the Python 2.3 logging module (MS
Windows 2k) with regard to RotatingFileHandler. The following script
illustrates a puzzling problem. What is wrong with this script?

Thanks,

-- jv

BEGIN FILE _________________________________________
'''
This script terminates as follows:

Traceback (most recent call last):
File "D:\$PROJECTS\experimental\Py Logging\t_xb.py", line 63, in ?
shutdown()
File "C:\Python23\lib\logging\__init__.py", line 1195, in shutdown
h.flush()
File "C:\Python23\lib\logging\__init__.py", line 661, in flush
self.stream.flush()
ValueError: I/O operation on closed file

What is wrong with it?
'''

from logging import getLogger, Formatter, shutdown, DEBUG, INFO, WARNING,
ERROR, CRITICAL
from logging.handlers import RotatingFileHandler

def logger_for(component):
'''
RETURNS a logger for the specified component.

SIDE-EFFECTS
(re)assigns the logger handler
'''

global handler

logger = getLogger(component)

if handler:
handler.flush()
handler.close()
logger.removeHandler(handler)

# In normal, operational mode, the following parameters:
filename = '%s.log'%component
mode = 'a'
maxBytes = 100
backupCount = 5
# would be user-configurable "on the fly" hence the reason for this
function.

handler = RotatingFileHandler(filename, mode, maxBytes, backupCount)

handler.setLevel(DEBUG)

logger.addHandler(handler)

return logger

handler = None

for i in range(20):
log = logger_for('supplier')
log.error('testing Python logging module')

shutdown()
END FILE _________________________________________
Jul 18 '05 #1
Share this Question
Share on Google+
5 Replies


P: n/a
j vickroy wrote:
I'm trying to understand the behavior of the Python 2.3 logging module (MS
Windows 2k) with regard to RotatingFileHandler. The following script
illustrates a puzzling problem. What is wrong with this script? if handler:
handler.flush()
handler.close()
logger.removeHandler(handler)


The handler is stored in the logging._handlers dictionary in order to close
it when shutdown() is called. But you already did close it manually.
I think you have three options to fix your script.

(1) Don't call shutdown() at all and manually close the last handler
instead.

(2) Change the above to

if handler:
logger.removeHandler(handler)
handler.flush()
handler.close()
del logging._handlers[handler]

so that shutdown() cannot touch closed handlers, or

(3) don't close handlers manually

if handler:
logger.removeHandler(handler)

so that shutdown() gets a still open handler as expected. I would go with
the latter, as it does not rely on implementation details.

(all untested, use at your own risk)

Peter

Jul 18 '05 #2

P: n/a

Here is the result of not closing a handler manually -- Peter's suggestion
(3)

Traceback (most recent call last):
File
"C:\Python23\lib\site-packages\Pythonwin\pywin\framework\scriptutils.py" ,
line 310, in RunScript
exec codeObject in __main__.__dict__
File "E:\$PROJECTS\experimental\Py Logging\t_xc.py", line 61, in ?
log.error('testing Python logging module')
File "C:\Python23\lib\logging\__init__.py", line 923, in error
apply(self._log, (ERROR, msg, args), kwargs)
File "C:\Python23\lib\logging\__init__.py", line 994, in _log
self.handle(record)
File "C:\Python23\lib\logging\__init__.py", line 1004, in handle
self.callHandlers(record)
File "C:\Python23\lib\logging\__init__.py", line 1037, in callHandlers
hdlr.handle(record)
File "C:\Python23\lib\logging\__init__.py", line 592, in handle
self.emit(record)
File "C:\Python23\lib\logging\handlers.py", line 105, in emit
self.doRollover()
File "C:\Python23\lib\logging\handlers.py", line 90, in doRollover
os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied

and here is the script that generated the above behavior:

begin -------------------------------------------------
from logging import getLogger, Formatter, shutdown, DEBUG, INFO, WARNING,
ERROR, CRITICAL
from logging.handlers import RotatingFileHandler

def logger_for(component):
'''
RETURNS a logger for the specified component.

SIDE-EFFECTS
(re)assigns the logger handler
'''

global handler

logger = getLogger(component)

if handler:
## handler.flush()
## handler.close()
logger.removeHandler(handler)

# In normal, operational mode, the following parameters:
filename = '%s.log'%component
mode = 'a'
maxBytes = 100
backupCount = 5
# would be user-configurable "on the fly" hence the reason for this
function.

handler = RotatingFileHandler(filename, mode, maxBytes, backupCount)

handler.setLevel(DEBUG)

logger.addHandler(handler)

return logger

handler = None

for i in range(20):
log = logger_for('supplier')
log.error('testing Python logging module')

shutdown()
end -----------------------------------------

Jul 18 '05 #3

P: n/a
As a follow-up question, why is a handle object not removed from
logging._handlers when its (i.e., handle) close() procedure is applied?

That behavior appears to be responsible for the logging.shutdown() failure.
"j vickroy" <ji*********@noaa.gov> wrote in message
news:bp**********@boulder.noaa.gov...
Hello,

I'm trying to understand the behavior of the Python 2.3 logging module (MS
Windows 2k) with regard to RotatingFileHandler. The following script
illustrates a puzzling problem. What is wrong with this script?

Thanks,

-- jv

BEGIN FILE _________________________________________
'''
This script terminates as follows:

Traceback (most recent call last):
File "D:\$PROJECTS\experimental\Py Logging\t_xb.py", line 63, in ?
shutdown()
File "C:\Python23\lib\logging\__init__.py", line 1195, in shutdown
h.flush()
File "C:\Python23\lib\logging\__init__.py", line 661, in flush
self.stream.flush()
ValueError: I/O operation on closed file

What is wrong with it?
'''

from logging import getLogger, Formatter, shutdown, DEBUG, INFO, WARNING, ERROR, CRITICAL
from logging.handlers import RotatingFileHandler

def logger_for(component):
'''
RETURNS a logger for the specified component.

SIDE-EFFECTS
(re)assigns the logger handler
'''

global handler

logger = getLogger(component)

if handler:
handler.flush()
handler.close()
logger.removeHandler(handler)

# In normal, operational mode, the following parameters:
filename = '%s.log'%component
mode = 'a'
maxBytes = 100
backupCount = 5
# would be user-configurable "on the fly" hence the reason for this
function.

handler = RotatingFileHandler(filename, mode, maxBytes, backupCount)

handler.setLevel(DEBUG)

logger.addHandler(handler)

return logger

handler = None

for i in range(20):
log = logger_for('supplier')
log.error('testing Python logging module')

shutdown()
END FILE _________________________________________

Jul 18 '05 #4

P: n/a
j vickroy wrote:

Here is the result of not closing a handler manually -- Peter's suggestion
(3)

Traceback (most recent call last):
File
"C:\Python23\lib\site-packages\Pythonwin\pywin\framework\scriptutils.py" ,
line 310, in RunScript
exec codeObject in __main__.__dict__
File "E:\$PROJECTS\experimental\Py Logging\t_xc.py", line 61, in ?
log.error('testing Python logging module')
File "C:\Python23\lib\logging\__init__.py", line 923, in error
apply(self._log, (ERROR, msg, args), kwargs)
File "C:\Python23\lib\logging\__init__.py", line 994, in _log
self.handle(record)
File "C:\Python23\lib\logging\__init__.py", line 1004, in handle
self.callHandlers(record)
File "C:\Python23\lib\logging\__init__.py", line 1037, in callHandlers
hdlr.handle(record)
File "C:\Python23\lib\logging\__init__.py", line 592, in handle
self.emit(record)
File "C:\Python23\lib\logging\handlers.py", line 105, in emit
self.doRollover()
File "C:\Python23\lib\logging\handlers.py", line 90, in doRollover
os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied


Works here. Consider switching to an OS where you can rename an open file...
Well, you read my discalimer :-)

Peter
Jul 18 '05 #5

P: n/a
j vickroy wrote:
As a follow-up question, why is a handle object not removed from
logging._handlers when its (i.e., handle) close() procedure is applied?

That behavior appears to be responsible for the logging.shutdown()
failure.


Seems that the author did not consider the use case of consecutively using
different handlers operating on the same file set - I've not yet made up my
mind, if you are misusing the logging system or if that's a bug.

Anyway, as of 2.3.2 the package has still __status__ = "beta", so patches
might be welcome.

Peter
Jul 18 '05 #6

This discussion thread is closed

Replies have been disabled for this discussion.