Repository navigation
test_eintr randomly fails on FreeBSD #69309
Description
| BPO | 25122 |
|---|---|
| Nosy | @vstinner |
| Files |
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
assignee = None
closed_at = <Date 2015-09-18.13:19:59.095>
created_at = <Date 2015-09-15.10:09:38.990>
labels = []
title = 'test_eintr randomly fails on FreeBSD'
updated_at = <Date 2015-10-11.20:10:41.078>
user = 'https://github.com/vstinner'bugs.python.org fields:
activity = <Date 2015-10-11.20:10:41.078>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2015-09-18.13:19:59.095>
closer = 'vstinner'
components = []
creation = <Date 2015-09-15.10:09:38.990>
creator = 'vstinner'
dependencies = []
files = ['40485']
hgrepos = []
issue_num = 25122
keywords = []
message_count = 17.0
messages = ['250753', '250754', '250804', '250809', '250810', '250818', '250822', '250828', '250831', '250865', '250867', '250958', '250979', '251219', '251764', '252797', '252824']
nosy_count = 4.0
nosy_names = ['vstinner', 'Arfrever', 'python-dev', 'cem']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = None
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue25122'
versions = ['Python 3.5', 'Python 3.6']
Activity
vstinner commentedon Sep 15, 2015
I'm unable to reproduce the hang. It's probably a race condition since sometimes the test pass. It may depend on the system load, the number of CPU cores, and other factors.
I tried to use faulthandler.dump_traceback_later() in the changeset ebccac60b9e7, but it didn't print the traceback of the blocked test. So I don't know which eintr test is blocked.
In the changeset ed0e6a9c11af, I rewrote test_eintr.py to use subprocess instead of os.fork(). I was supposed to reduce the risk of race condition, but the hang still occurs.
On FreeBSD, I know that any thread can receive a signal, and most Python tests only expect that the signal is received from a specific thread. But test_eintr.py runs Lib/test/eintrdata/eintr_tester.py in a subprocess to avoid threads, and Lib/test/eintrdata/eintr_tester.py itself uses subprocess to spawn child processes, so it should also avoid threads. So I don't think that the issue is related to threads.
At least, it would help to know which test hangs.
Example:
http://buildbot.python.org/all/builders/AMD64%20FreeBSD%209.x%203.x/builds/3337/steps/test/logs/stdio
python-dev commentedon Sep 15, 2015
New changeset 3d9164aecc6f by Victor Stinner in branch 'default':
Issue bpo-25122: try to debug test_eintr hang on FreeBSD
https://hg.python.org/cpython/rev/3d9164aecc6f
python-dev commentedon Sep 15, 2015
New changeset edbc35d8babb by Victor Stinner in branch 'default':
Issue bpo-25122: Fix test_eintr, kill child process on error
https://hg.python.org/cpython/rev/edbc35d8babb
python-dev commentedon Sep 15, 2015
New changeset 24dbca4e746c by Victor Stinner in branch 'default':
Issue bpo-25122: test_eintr: don't redirect stdout to stderr
https://hg.python.org/cpython/rev/24dbca4e746c
python-dev commentedon Sep 15, 2015
New changeset 5388fa98f7a3 by Victor Stinner in branch 'default':
Issue bpo-25122: optimize test_eintr
https://hg.python.org/cpython/rev/5388fa98f7a3
vstinner commentedon Sep 16, 2015
Ok, I got the first interesting result thanks to my enhancements of test_eintr:
[383/398/1] test_eintr
test_read (main.OSEINTRTest) ... ok
test_wait (main.OSEINTRTest) ... ok
test_wait3 (main.OSEINTRTest) ... ok
test_wait4 (main.OSEINTRTest) ... ok
test_waitpid (main.OSEINTRTest) ... ok
test_write (main.OSEINTRTest) ... ok
test_accept (main.SocketEINTRTest) ... ok
test_open (main.SocketEINTRTest) ...
Timeout (0:05:00)!
Thread 0x0000000801807400 (most recent call first):
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/eintrdata/eintr_tester.py", line 340 in <lambda>
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/eintrdata/eintr_tester.py", line 334 in _test_open
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/eintrdata/eintr_tester.py", line 340 in test_open
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/case.py", line 600 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/case.py", line 648 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 122 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 84 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 122 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 84 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/runner.py", line 176 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/support/init.py", line 1775 in _run_suite
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/support/init.py", line 1809 in run_unittest
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/eintrdata/eintr_tester.py", line 461 in test_main
File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/eintrdata/eintr_tester.py", line 465 in <module>
test_all (test.test_eintr.EINTRTests) ... FAIL
======================================================================
FAIL: test_all (test.test_eintr.EINTRTests)
----------------------------------------------------------------------
Ran 1 test in 306.939s
FAILED (failures=1)
Warning -- files was modified by test_eintr
test test_eintr failed
python-dev commentedon Sep 16, 2015
New changeset 30bc256f2346 by Victor Stinner in branch 'default':
Issue bpo-25122: add debug traces to test_eintr.test_open()
https://hg.python.org/cpython/rev/30bc256f2346
vstinner commentedon Sep 16, 2015
More debug traces:
test_open (main.SocketEINTRTest) ... try to open '@test_57236_tmp' fifo for writing, pid 57236
try to open '@test_57236_tmp' fifo for reading, pid 57305, ppid 57236
'@test_57236_tmp' fifo opened for reading and closed, pid 57305, ppid 57236
Timeout (0:05:00)!
Thread 0x0000000802006400 (most recent call first):
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/eintrdata/eintr_tester.py", line 354 in <lambda>
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/eintrdata/eintr_tester.py", line 345 in _test_open
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/eintrdata/eintr_tester.py", line 354 in test_open
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/case.py", line 600 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/case.py", line 648 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/suite.py", line 122 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/suite.py", line 84 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/suite.py", line 122 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/suite.py", line 84 in __call__
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/unittest/runner.py", line 176 in run
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/support/init.py", line 1775 in _run_suite
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/support/init.py", line 1809 in run_unittest
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/eintrdata/eintr_tester.py", line 475 in test_main
File "/usr/home/buildbot/python/3.x.koobs-freebsd10/build/Lib/test/eintrdata/eintr_tester.py", line 479 in <module>
vstinner commentedon Sep 16, 2015
Syscalls traced by truss.
Parent process:
1436: unlink("fifo_5950861521") ERR#2 'No such file or directory'
1436: open("fifo_5950861521",O_WRONLY|O_CLOEXEC,00) ERR#4 'Interrupted system call'
1436: open("fifo_5950861521",O_WRONLY|O_CLOEXEC,00) ERR#4 'Interrupted system call'
...
1436: open("fifo_5950861521",O_WRONLY|O_CLOEXEC,00) ERR#4 'Interrupted system call'
Child process:
2689: open("fifo_5950861521",O_CLOEXEC,00) = 3 (0x3)
2689: close(3) ERR#4 'Interrupted system call'
Hum, it looks like the child process gets signals, many syscalls are interrupted by signals. In my simple test, 7 syscalls were interrupted by signals in the child process. I didn't expect "setitimer" to be inherited by subprocess.Popen.
The suspicious thing is that close() fails with EINTR in the child process and it is not retried.
vstinner commentedon Sep 16, 2015
Ok, I'm now quite sure that it's a bug in the FreeBSD kernel or in the BSD C library.
The C library ignores EINTR: if the close() syscalls fails with EINTR, the C close() function returns a success.
When the close() syscall fails with EINTR, the test hangs. It's unclear to me if the close() syscall fails with EINTR in the parent or in the child process. I'm quite sure that the FreeBSD truss tool (tool to trace syscalls) has bugs too, so it's hard to be sure what happens exactly.
Attached tarball eintr_bug.tar.gz reproduces the bug in a program written in pure C language. So it's not a bug in Python.
For test_eintr, we should skip the test on FreeBSD (until the bug is fixed in FreeBSD).
vstinner commentedon Sep 16, 2015
I reported the bug on the FreeBSD bug tracker:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=203162
python-dev commentedon Sep 18, 2015
New changeset 90722634f211 by Victor Stinner in branch 'default':
Issue bpo-25122: Fix test_eintr.test_open() on FreeBSD
https://hg.python.org/cpython/rev/90722634f211
New changeset f347ea4391f3 by Victor Stinner in branch '3.5':
Issue bpo-25122: sync test_eintr with Python 3.6
https://hg.python.org/cpython/rev/f347ea4391f3
vstinner commentedon Sep 18, 2015
test_eintr should now be fixed in Python 3.5 and 3.6: I skipped the test_open() and test_os_open() tests of test_eintr on FreeBSD.
python-dev commentedon Sep 21, 2015
New changeset 3184c43627f5 by Victor Stinner in branch '3.5':
Issue bpo-25122: test_eintr: the FreeBSD fix will be released in FreeBSD 10.3
https://hg.python.org/cpython/rev/3184c43627f5
python-dev commentedon Sep 28, 2015
New changeset e48ec5f5b82b by Victor Stinner in branch 'default':
Issue bpo-25122: Remove verbose mode of test_eintr
https://hg.python.org/cpython/rev/e48ec5f5b82b
Arfrever commentedon Oct 11, 2015
This could be backported to 3.5 branch. (Verbose mode was added there just 10 days earlier.)
vstinner commentedon Oct 11, 2015
We should remove it, but test_eintr still hangs randomly on freebsd.