msg203727 - (view) |
Author: Ned Deily (ned.deily) *  |
Date: 2013-11-22 07:31 |
http://buildbot.python.org/all/builders/AMD64%20Snow%20Leop%203.x/builds/568/steps/test/logs/stdio ====================================================================== ERROR: test_race (test.test_logging.HandlerTest) ---------------------------------------------------------------------- Traceback (most recent call last): File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/test/test_logging.py", line 613, in test_race h.handle(r) File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/logging/__init__.py", line 835, in handle self.emit(record) File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/logging/handlers.py", line 468, in emit self.stream = self._open() File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/logging/__init__.py", line 1005, in _open return open(self.baseFilename, self.mode, encoding=self.encoding) PermissionError: [Errno 1] Operation not permitted: '/tmp/test_logging-3-i5haxx_n.log' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/test/test_logging.py", line 616, in test_race h.close() File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/logging/__init__.py", line 990, in close self.flush() File "/Users/buildbot/buildarea/3.x.murray-snowleopard/build/Lib/logging/__init__.py", line 937, in flush self.stream.flush() ValueError: I/O operation on closed file. The test passed when rerun by regrtest. This looks similar to the failures in Issue14632. |
|
|
msg205112 - (view) |
Author: Vinay Sajip (vinay.sajip) *  |
Date: 2013-12-03 12:29 |
Unfortunately, the race condition can't be removed completely - it was reduced by the patch in #14632 but could not be eliminated altogether. So this test can fail sporadically - tweaking the timeouts might give some temporary respite, but doesn't guarantee the issue won't return when e.g. machines are unusually heavily loaded. I'll add some diagnostics for now and see what they show. |
|
|
msg205113 - (view) |
Author: Roundup Robot (python-dev)  |
Date: 2013-12-03 12:31 |
New changeset 8fe3022af4b3 by Vinay Sajip in branch 'default': Added some diagnostics to help with #19690. http://hg.python.org/cpython/rev/8fe3022af4b3 |
|
|
msg205536 - (view) |
Author: Vinay Sajip (vinay.sajip) *  |
Date: 2013-12-08 10:18 |
I'll close this for now as the failures seem to have stopped. Though I only added some diagnostics, that might have changed the relative timings enough so the race doesn't surface (for now). |
|
|
msg213694 - (view) |
Author: Ned Deily (ned.deily) *  |
Date: 2014-03-16 01:01 |
I've just seen another instance of this failure, this time using a 3.4.0 release test OS X installer build (non-debug, built on and running on OS X 10.5). The added diagnostics show up: [186/389/1] test_logging Deleted at 1394930826.466016, opened at 1394930826.456779 test test_logging failed -- Traceback (most recent call last): File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/test/test_logging.py", line 618, in test_race h.handle(r) File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/logging/__init__.py", line 837, in handle self.emit(record) File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/logging/handlers.py", line 468, in emit self.stream = self._open() File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/logging/__init__.py", line 1007, in _open return open(self.baseFilename, self.mode, encoding=self.encoding) PermissionError: [Errno 1] Operation not permitted: '/tmp/test_logging-3-92xfhrsa.log' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/test/test_logging.py", line 626, in test_race h.close() File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/logging/__init__.py", line 992, in close self.flush() File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/logging/__init__.py", line 939, in flush self.stream.flush() ValueError: I/O operation on closed file. |
|
|
msg226334 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2014-09-03 23:00 |
What is the status of this issue? The failure is still common on the buildbot: http://buildbot.python.org/all/builders/AMD64%20Snow%20Leop%203.4/builds/458/steps/test/logs/stdio ====================================================================== ERROR: test_race (test.test_logging.HandlerTest) ---------------------------------------------------------------------- Traceback (most recent call last): File "/Users/buildbot/buildarea/3.4.murray-snowleopard/build/Lib/test/test_logging.py", line 618, in test_race h.handle(r) File "/Users/buildbot/buildarea/3.4.murray-snowleopard/build/Lib/logging/__init__.py", line 852, in handle self.emit(record) File "/Users/buildbot/buildarea/3.4.murray-snowleopard/build/Lib/logging/handlers.py", line 468, in emit self.stream = self._open() File "/Users/buildbot/buildarea/3.4.murray-snowleopard/build/Lib/logging/__init__.py", line 1029, in _open return open(self.baseFilename, self.mode, encoding=self.encoding) PermissionError: [Errno 1] Operation not permitted: '/tmp/test_logging-3-vrpj_wts.log' |
|
|
msg226338 - (view) |
Author: Vinay Sajip (vinay.sajip) *  |
Date: 2014-09-04 07:04 |
> What is the status of this issue? Sorry, it's been off my radar - I wonder if it has become more common recently. It's hard to reproduce, and tweaking timeouts might make it disappear, but it's a trial-and-error situation because I can hardly ever get the error to occur. The base race condition can't be eliminated, unfortunately. |
|
|