Bugs item #1277903, was opened at 2005-09-01 04:49
Message generated for change (Settings changed) made by vsajip
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: Closed
>Resolution: Invalid
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: Vinay Sajip (vsajip)
Date: 2005-09-02 10:05

Message:
Logged In: YES 
user_id=308438

The problem is occurring because the main thread exits, 
which causes shutdown of the logging system via an atexit 
hook. If you add either of the following lines at the end of your 
__name__ == "__main__" clause:

raw_input("Press a key:")

or

mythread.join()

Then the thread continues to run:

2005-09-02 10:23:37,023 2564 INFO: logging initialized
2005-09-02 10:23:37,023 2564 INFO: initializing MyThread
2005-09-02 10:23:37,023 2564 INFO: test (before starting 
thread)
2005-09-02 10:23:37,032 2220 INFO: MyThread starting
2005-09-02 10:23:37,032 2564 INFO: test (after starting 
thread)
2005-09-02 10:23:37,032 2220 INFO: MyThread ticking...
2005-09-02 10:23:39,036 2220 INFO: MyThread ticking...
2005-09-02 10:23:41,039 2220 INFO: MyThread ticking...
2005-09-02 10:23:43,042 2220 INFO: MyThread ticking...
2005-09-02 10:23:45,045 2220 INFO: MyThread ticking...
2005-09-02 10:23:47,048 2220 INFO: MyThread ticking...

(I modified the format string to show the thread ID in the 
logged message).

Hence, this is not a bug and I am closing this entry 
as "Invalid".

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

Comment By: Lenny G. Arbage (alengarbage)
Date: 2005-09-01 22: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 16:04

Message:
Logged In: YES 
user_id=1338323

file attached

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

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

Message:
Logged In: YES 
user_id=1338323

file attached

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

Comment By: Alen Peacock (alenlpeacock)
Date: 2005-09-01 16: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 12: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
_______________________________________________
Python-bugs-list mailing list 
Unsubscribe: 
http://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

Reply via email to