[ python-Bugs-1277903 ] logging module broken for multiple threads?

[SourceForge.net]

Bugs item #1277903, was opened at 2005-08-31 23:49
Message generated for change (Comment added) made by alengarbage
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1277903&group_id=5470

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: None
Group: Python 2.4
Status: Open
Resolution: None
Priority: 5
Submitted By: Lenny G. Arbage (alengarbage)
Assigned to: Vinay Sajip (vsajip)
Summary: logging module broken for multiple threads?

Initial Comment:
After upgrading from python 2.2, I noticed that the
logging facility doesn't seem to work in my code anymore.

As far as I can tell, after spending a bit of time
isolating the problem, this is an issue with threading.
 In the main thread, logging works without a hitch.  In
the secondary thread (which is run via
twisted.reactor), any attempt to write to the log
results in:

Traceback (most recent call last):
  File "/usr/lib/python2.4/logging/__init__.py", line
712, in emit
    self.stream.write(fs % msg)
ValueError: I/O operation on closed file

The code that initializes the logger is as follows:
        logger = logging.getLogger('mylogger')
        screenhandler = logging.StreamHandler()
        screenhandler.setLevel(logging.INFO)
        logger.addHandler(self.screenhandler)

        logfile = "/tmp/testlog"
        if os.path.isfile(logfile):
            os.remove(logfile)
        handler = logging.FileHandler(logfile)
        formatter = logging.Formatter('%(asctime)s
%(levelname)s: %(message)s')
        handler.setFormatter(formatter)
        logger.addHandler(handler)
        logger.setLevel(logging.INFO)

Alone, this works fine.  It is only when a the second
thread does a 'logger = logging.getLogger('mylogger')
and subsequently calls 'logger.log()' that the above
error is produced.

----------------------------------------------------------------------

>Comment By: Lenny G. Arbage (alengarbage)
Date: 2005-09-01 17:29

Message:
Logged In: YES 
user_id=1338323

Here's an even more minimal snippet of code that produces
the error.  Nothing but a logger and a thread.  No need for
twisted anything.  Ignore the previous example.

Does this code do something to abuse the logging facility?

----------------------------------------------------------------------

Comment By: Lenny G. Arbage (alengarbage)
Date: 2005-09-01 11:04

Message:
Logged In: YES 
user_id=1338323

file attached

----------------------------------------------------------------------

Comment By: Lenny G. Arbage (alengarbage)
Date: 2005-09-01 11:04

Message:
Logged In: YES 
user_id=1338323

file attached

----------------------------------------------------------------------

Comment By: Alen Peacock (alenlpeacock)
Date: 2005-09-01 11:00

Message:
Logged In: YES 
user_id=1239721

I'm attaching a minimal program that demonstrates the
behavior.  You'll need twisted installed to run it.  I've
tested on python 2.4.1 and 2.4.14, both produce the error.

----------------------------------------------------------------------

Comment By: Raymond Hettinger (rhettinger)
Date: 2005-09-01 07:54

Message:
Logged In: YES 
user_id=80475

It looks to me like you've created a race condition that
became evident only when switching Python versions. 
Assigning to Vijay so he can give advice on the best way to
code this (most likely by moving resource competing calls to
the main thread).

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1277903&group_id=5470