classification
Title: Logging problem on Windows XP
Type: Stage:
Components: None Versions:
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: loewis Nosy List: eloff, loewis, mikepowers48, pavel_krupets
Priority: high Keywords:

Created on 2006-09-27 11:49 by pavel_krupets, last changed 2007-01-04 21:08 by loewis. This issue is now closed.

Files
File name Uploaded Description Edit
sample.zip pavel_krupets, 2006-09-29 13:52 sample application
threading.diff loewis, 2006-12-06 07:29
Messages (11)
msg30019 - (view) Author: Pavel Krupets (pavel_krupets) Date: 2006-09-27 11:49
Traceback (most recent call last):
  File "C:\Python\Lib\logging\handlers.py", line 73, in
emit
    if self.shouldRollover(record):
  File "C:\Python\Lib\logging\handlers.py", line 147,
in shouldRollover
    self.stream.seek(0, 2)  #due to non-posix-compliant
Windows feature
ValueError: I/O operation on closed file

not sure why this file is closed.
msg30020 - (view) Author: Pavel Krupets (pavel_krupets) Date: 2006-09-27 12:01
Logged In: YES 
user_id=1007725

And I think python crashes on Windows if I try to use logger
from several threads.

Unhandled exception at 0x7c901010 in python.exe: 0xC0000005:
Access violation reading location 0x00000034.

>	ntdll.dll!7c901010() 	
 	[Frames below may be incorrect and/or missing, no symbols
loaded for ntdll.dll]	
 	msvcr71.dll!7c34f639() 	
 	msvcr71.dll!7c36b3b1() 	
 	python25.dll!1e06c6c0() 	
 	python25.dll!1e08dc97() 	
 	python25.dll!1e03ac12() 	
 	python25.dll!1e03c735() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e04026b() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e04026b() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e04026b() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e04026b() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e04026b() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e03db7d() 	
 	python25.dll!1e0715df() 	
 	python25.dll!1e0268ec() 	
 	python25.dll!1e040a04() 	
 	python25.dll!1e039a8c() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e0622d3() 	
 	python25.dll!1e062660() 	
 	python25.dll!1e061028() 	
 	python25.dll!1e0db1bd() 	
 	python25.dll!1e062676() 	
 	python25.dll!1e03e8c1() 	
 	python25.dll!1e041475() 	
 	python25.dll!1e0414c3() 	
 	python25.dll!1e094093() 	
 	python25.dll!1e062676() 	
 	python25.dll!1e0268ec() 	
 	python25.dll!1e03987a() 	
 	python25.dll!1e033edc() 	
 	python25.dll!1e08dc97() 	
 	python25.dll!1e03ac12() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e07041e() 	
 	python25.dll!1e070385() 	
 	python25.dll!1e03db7d() 	
 	python25.dll!1e039a8c() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e07041e() 	
 	python25.dll!1e039a2e() 	
 	python25.dll!1e03ac82() 	
 	python25.dll!1e03cc5f() 	
 	python25.dll!1e07041e() 	
 	python25.dll!1e03db7d() 	
 	python25.dll!1e0715df() 	
 	python25.dll!1e0268ec() 	
 	python25.dll!1e040a04() 	
 	ntdll.dll!7c90d625() 	
 	ntdll.dll!7c90eacf() 	
 	python25.dll!1e0258d2() 	
 	ntdll.dll!7c9105c8() 	
 	ntdll.dll!7c910551() 	
 	ntdll.dll!7c91056d() 	
 	kernel32.dll!7c80261a() 	
 	kernel32.dll!7c8025f0() 	
 	kernel32.dll!7c8025f0() 	
 	kernel32.dll!7c802532() 	
 	python25.dll!1e0268ec() 	
 	python25.dll!1e03987a() 	
 	python25.dll!1e0cdf07() 	
 	python25.dll!1e0cd899() 	
 	msvcr71.dll!7c34940f() 	
 	kernel32.dll!7c80b683() 	
msg30021 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2006-09-28 03:29
Logged In: YES 
user_id=21627

Can you provide a test case for either problem?
msg30022 - (view) Author: Pavel Krupets (pavel_krupets) Date: 2006-09-29 13:52
Logged In: YES 
user_id=1007725

to start application please use: src/py/run.bat
to get closed handler error (if you manage to start it)
please open your web browser and try to visit:
http://localhost:8080

You can change http settings in src/conf/development/robot.conf

sorry code is quite raw just started. :)
msg30023 - (view) Author: Daniel Eloff (eloff) Date: 2006-12-06 03:05
I have this problem, I'm googling this and finding lots of people having the same problem. I'm running python 2.5 on windows XP and using the rotating file handler. I've disabled the logger in my application so I can continue development.
msg30024 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2006-12-06 07:29
Ok, so tsample.zip is a test case for the original problem, right? 
I can reproduce the problem on Linux also.

I can't make it crash (on Linux); what do have to do to make it crash?
If I access localhost:8080, I get log messages saying
2006-12-06 07:21:06,999 INFO servlet::__init__:1091 code 404, message File not found

eloff: this report actually reports two problems (the I/O error, and the crash).
Which of these are you having and have found lots of people having?

As for the traceback problem: this is due to the main thread terminating, and
therefore the logging atexit handler getting invoked, which closes the file.
Only then is the threading atexit handler invoked, which waits until all
non-daemon threads terminate.

As a work-around, add httpServer.join() at the end of your script.

I'll attach a patch that fixes this problem in the Python library.
File Added: threading.diff
msg30025 - (view) Author: Mike Powers (mikepowers48) Date: 2006-12-06 15:22
I'm seeing the I/O error and crash a lot on Windows and the I/O error on Linux.
Any help would be greatly appreciated.
msg30026 - (view) Author: Daniel Eloff (eloff) Date: 2006-12-06 18:43
Thanks Martin, I applied the patch.

The problem I was having was the IO Error, sorry for being vague.

The part I don't understand is I should not have had other threads running (and definately should not have had the logger being used outside the main thread.) Can the problem occur with just one thread? I was running under the debugger in wing, I don't know if that might cause this problem.

Anyway if I find out anything else I'll let you know. If you don't hear from me then everything is working great.
msg30027 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2006-12-06 18:58
eloff: It may be that there are different problems that all show the symptom; *this* problem reported here can only occur if you are using multiple threads (atleast for the ValueError; haven't looked into the crash at all).

Yes, you can run multiple threads, and yes, you can use logging freely. However, you should not let the main thread just "run off". Instead, you should end your main thread with an explicit .join() operation on all threads it has created; those threads themselves should perform explicit .join() operations on all threads they create. That way, you can guarantee orderly shutdown. threading.py tries to do the joining if you don't, but fails (and the approach it uses is inherently error-prone).
msg30028 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2006-12-18 17:26
I cannot reproduce the crash with the example given, neither with the released binaries, nor with any of the trunk or release25-maint subversion branches. Therefore, I declare that this report is only about the ValueError; if anybody has a way to provoke a crash in a reproducable way, please submit it as a separate report, along with precise instructions on how to provoke the crash.
msg30029 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2007-01-04 21:08
Thanks again for the report. This is now fixed in r53249 and r53250.
History
Date User Action Args
2006-09-27 11:49:49pavel_krupetscreate