I've a daemon that pipe stdout and stderr into logging
in order to capture everything it does. It works fine.
However if there is an error throw inside logging, the
error is sent to stderr that got redirect into logging
again. Its seems some lock is not reentrant and it
causes deadlock.


>>> import logging,sys
>>> # a quick and dirty log file object
... class LogFileObj(object):
...     def __init__(self,log):
...         self.log = log
...     def write(self,str):
...         self.log.warn(str)
...
>>> # create a logger for stderr
... log = logging.getLogger()
>>>
>>> # for the purpose of showing this bug, output to a
StreamHandler based on stdout
... handler = logging.StreamHandler(sys.stdout)
>>> handler.setFormatter(logging.Formatter('%(asctime)s
%(message)s'))
>>> log.addHandler(handler)
>>>
>>> # redirect stderr to a logger
... sys.stderr = LogFileObj(log)
>>>
>>> # it works!
... print >>sys.stderr, 'hello world'
2005-10-05 22:52:32,391 hello world
2005-10-05 22:52:32,391

>>>
>>> # now put sys.stderr aside
... # use the logger as usual
... log.warn('hello world')
2005-10-05 22:52:32,401 hello world
>>>
>>> # this one has an error in the number of arguments
... log.warn('hello world %s', 1, 2)


When the last statement is ran, it goes into a deadlock.

It seems this can be workaround by using
threading.RLock instead of thread's lock.


>>> # workaround the deadlock by using RLock
... import threading
>>> handler.lock = threading.RLock()
>>> log.warn('hello world %s', 1, 2)
2005-10-05 22:47:46,390 Traceback (most recent call last):

2005-10-05 22:47:46,400   File
"C:\Python24\lib\logging\__init__.py", line 706, in emit

2005-10-05 22:47:46,400     msg = self.format(record)

2005-10-05 22:47:46,400   File
"C:\Python24\lib\logging\__init__.py", line 592, in format

2005-10-05 22:47:46,400     return fmt.format(record)

2005-10-05 22:47:46,400   File
"C:\Python24\lib\logging\__init__.py", line 382, in format

2005-10-05 22:47:46,400     record.message =
record.getMessage()

2005-10-05 22:47:46,400   File
"C:\Python24\lib\logging\__init__.py", line 253, in
getMessage

2005-10-05 22:47:46,400     msg = msg % self.args

2005-10-05 22:47:46,400 TypeError: not all arguments
converted during string formatting


I'm not too familiar with the implementation of
logging. Please keep me posted whether this is a
legitimate workaround.

Logged In: YES 
user_id=308438

Yes, the problem is there and the proposed solution seems
fine. Also note that if you set logging.raiseExceptions to
0, then exceptions during emitting are silently ignored
rather than raised.

I will change thread.allocate_lock() -> threading.RLock()
and check into CVS soon, then mark this as closed.

Logged In: YES 
user_id=308438

I've just looked into it, and the change has already been
made in CVS (Version 1.27, dated 31/03/2005). The change
should be in Python 2.4.2 final.

Marking as closed.