GeezerVison is showing github.com — Unexpected traceback output in test_concurrent_futures and crash · Issue #109370 · python/cpython
Unexpected traceback output in test_concurrent_futures and crash #109370DescriptionCrash report
When I run tests in single-process mode I get unexpected traceback output but tests was marked as passed:
Details
$ ./python -m test -r
== CPython 3.13.0a0 (heads/regretest-no-remove-test-module:eb7766baa4, Sep 13 2023, 10:58:19) [GCC 11.4.0]
== Linux-5.15.0-79-generic-x86_64-with-glibc2.35 little-endian
== Python build: debug
== cwd: /home/serhiy/py/cpython/build/test_python_worker_3200061æ
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
Using random seed 68644298
0:00:00 load avg: 0.75 Run 463 tests sequentially
...
0:12:03 load avg: 1.72 [191/463] test.test_concurrent_futures.test_process_pool
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
0:12:21 load avg: 1.52 [192/463] test_codecencodings_tw
...
0:25:47 load avg: 1.21 [361/463] test.test_concurrent_futures.test_deadlock
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 201, in send_bytes
self._send_bytes(m[offset:offset + size])
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 422, in _send_bytes
self._send(buf)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 385, in _send
n = write(self._handle, buf)
^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: 'NoneType' object cannot be interpreted as an integer
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 201, in send_bytes
self._send_bytes(m[offset:offset + size])
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 422, in _send_bytes
self._send(buf)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 385, in _send
n = write(self._handle, buf)
^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: 'NoneType' object cannot be interpreted as an integer
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 201, in send_bytes
self._send_bytes(m[offset:offset + size])
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 422, in _send_bytes
self._send(buf)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 385, in _send
n = write(self._handle, buf)
^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: 'NoneType' object cannot be interpreted as an integer
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
0:26:01 load avg: 1.10 [362/463] test_bigaddrspace
...
0:26:20 load avg: 1.08 [368/463] test.test_concurrent_futures.test_init
Traceback (most recent call last):
File "/home/serhiy/py/cpython/Lib/multiprocessing/queues.py", line 250, in _feed
send_bytes(obj)
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 185, in send_bytes
self._check_closed()
File "/home/serhiy/py/cpython/Lib/multiprocessing/connection.py", line 138, in _check_closed
raise OSError("handle is closed")
OSError: handle is closed
0:26:23 load avg: 1.15 [369/463] test_eof
...
Then Python crashed after reporting total success:
Total duration: 38 min 29 sec
Total tests: run=40,827 skipped=1,248
Total test files: run=453/463 skipped=10 resource_denied=10
Result: SUCCESS
Fatal Python error: Segmentation fault
Current thread 0x00007fb61c438740 (most recent call first):
Garbage-collecting
<no Python frame>
Помилка адресування (збережено знімок оперативної пам’яті)
The last line is "Segfault (core dumped)" in Ukrainian, but I have no core dump because ulimit -c was 0.
I ran tests with a modification of #108952 which does not remove test module or any imported during testing modules before or after running a test.
cc @vstinner
Linked PRs
Activityserhiy-storchaka commented on Sep 13, 2023 Simple
./python -m test test_concurrent_futures.test_process_pool
and
./python -m test test_concurrent_futures.test_deadlock
produce similar tracebacks, but without a crash. serhiy-storchaka commented on Sep 13, 2023 Surprisingly, it is 3.13-only issue.
cc @vstinner vstinner commented on Sep 13, 2023
I ran tests with a modification of #108952
Can you please give precise instructions on how to reproduce the issue? Should I patch Python? The command to reproduce the issue is ./python -m test -r? serhiy-storchaka commented on Sep 13, 2023 There are two issues which may be related or not related:
- Output of tracebacks. Perhaps not caught exceptions in threads?
- Crash at shutdown.
Tracebacks are easy reproducible by running two tests. I did not try to reproduce the crash, because running all tests takes almost 40 minutes, and it may be order-depending. I ran full tests several times with other changes to libregrtest and found other crash, but not this one.
I am not sure that my change to libregrtest was related. It was equivalent to the following patch:
Details
diff --git a/Lib/test/libregrtest/main.py b/Lib/test/libregrtest/main.py
index ba493ae179..98a98e4ea6 100644
--- a/Lib/test/libregrtest/main.py
+++ b/Lib/test/libregrtest/main.py
@@ -293,8 +293,6 @@ def run_tests_sequentially(self, runtests):
else:
tracer = None
- save_modules = sys.modules.keys()
-
jobs = runtests.get_jobs()
if jobs is not None:
tests = count(jobs, 'test')
@@ -317,11 +315,6 @@ def run_tests_sequentially(self, runtests):
result = self.run_test(test_name, runtests, tracer)
- # Unload the newly imported modules (best effort finalization)
- for module in sys.modules.keys():
- if module not in save_modules and module.startswith("test."):
- support.unload(module)
-
if result.must_stop(self.fail_fast, self.fail_env_changed):
break
diff --git a/Lib/test/libregrtest/single.py b/Lib/test/libregrtest/single.py
index de60566287..5c54419cfa 100644
--- a/Lib/test/libregrtest/single.py
+++ b/Lib/test/libregrtest/single.py
@@ -76,10 +76,6 @@ def _load_run_test(result: TestResult, runtests: RunTests) -> None:
# Load the test module and run the tests.
test_name = result.test_name
module_name = abs_module_name(test_name, runtests.test_dir)
-
- # Remove the module from sys.module to reload it if it was already imported
- sys.modules.pop(module_name, None)
-
test_mod = importlib.import_module(module_name)
if hasattr(test_mod, "test_main"):
I.e. simply remove all removing of test modules before and after running a test. Actually, removing a module from sys.modules did not clear it (yet one mistake in this code), because remaining reference from the test module kept them alive, so I am not sure how it could affect finalization at all. serhiy-storchaka commented on Sep 14, 2023 I figured out what is wrong with tracebacks. They are triggered by closing the queue's writer connection in terminate_broken() in #107219. There are two issues:
- One is simple.
_check_closed() should raise OSError with errno=EPIPE. It makes the queue thread to quit silently instead of printing a traceback and hanging.
- The other one is caused by using (closing) the connection from other thread when it is in the middle of reading/writing. Connection should be only used from one thread. But does it include closing?
vstinner commented on Sep 14, 2023
One is simple. _check_closed() should raise OSError with errno=EPIPE. It makes the queue thread to quit silently instead of printing a traceback and hanging.
Do you want to propose a fix for this? It may be a good start. serhiy-storchaka commented on Sep 14, 2023 added 2 commits that reference this issue on Sep 23, 2023gh-109370: Fix unexpected traceback output in test_concurrent_futures (… serhiy-storchaka commented on Nov 10, 2023 The superfluous output was fixed. As for the crash, it was difficult to reproduce.
MetadataMetadataDevelopmentNo branches or pull requestsIssue actions
|