Skip to content

Unexpected traceback output in test_concurrent_futures and crash #109370

Closed
Closed
Unexpected traceback output in test_concurrent_futures and crash#109370
Labels
3.13only security fixestestsTests in the Lib/test dirtype-crashA hard crash of the interpreter, possibly with a core dump

Description

@serhiy-storchaka
serhiy-storchaka
opened on Sep 13, 2023

Crash 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

Activity

  1. serhiy-storchaka
    added
    testsTests in the Lib/test dir
    type-crashA hard crash of the interpreter, possibly with a core dump
    on Sep 13, 2023

  2. serhiy-storchaka commented on Sep 13, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Sep 13, 2023
    MemberAuthor

    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.

  3. serhiy-storchaka
    added
    3.13only security fixes
    on Sep 13, 2023

  4. serhiy-storchaka commented on Sep 13, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Sep 13, 2023
    MemberAuthor

    Surprisingly, it is 3.13-only issue.

    cc @vstinner

  5. vstinner commented on Sep 13, 2023

    @vstinner
    vstinner
    on Sep 13, 2023
    Member

    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?

  6. serhiy-storchaka commented on Sep 13, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Sep 13, 2023
    MemberAuthor

    There are two issues which may be related or not related:

    1. Output of tracebacks. Perhaps not caught exceptions in threads?
    2. 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.

  7. serhiy-storchaka commented on Sep 14, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Sep 14, 2023
    MemberAuthor

    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:

    1. 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.
    2. 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?
  8. serhiy-storchaka
    added a commit that references this issue on Sep 14, 2023

    pythongh-109370: Support closing Connection and PipeConnection from o…

    a384425

  9. vstinner commented on Sep 14, 2023

    @vstinner
    vstinner
    on Sep 14, 2023
    Member

    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.

  10. serhiy-storchaka commented on Sep 14, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Sep 14, 2023
    MemberAuthor

    #109397

  11. serhiy-storchaka
    added 2 commits that reference this issue on Sep 23, 2023

    pythongh-109370: Fix unexpected traceback output in test_concurrent_f…

    3030774

    gh-109370: Fix unexpected traceback output in test_concurrent_futures (…

    0b4e090
  12. miss-islington
    added a commit that references this issue on Sep 26, 2023

    pythongh-109370: Fix unexpected traceback output in test_concurrent_f…

    4e08e35
  13. serhiy-storchaka
    added a commit that references this issue on Sep 26, 2023

    [3.11] gh-109370: Fix unexpected traceback output in test_concurrent_…

    8fef834

  14. 3 remaining items

  15. serhiy-storchaka commented on Nov 10, 2023

    @serhiy-storchaka
    serhiy-storchaka
    on Nov 10, 2023
    MemberAuthor

    The superfluous output was fixed. As for the crash, it was difficult to reproduce.

  16. serhiy-storchaka
    closed this as completedon Nov 10, 2023
  17. encukou
    added 2 commits that reference this issue on Jan 23, 2024

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    188228f

    [3.12] gh-114440: Close writer pipe in multiprocessing.Queue, not con…

    c912bc3
  18. naveen521kk
    added 5 commits that reference this issue on Feb 19, 2024

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    c4877f2

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    fd8463b

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    df2288a

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    df5f451

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    69198de
  19. naveen521kk
    added 3 commits that reference this issue on Jul 11, 2024

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    6a3e15b

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    23a82b7

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    701b465
  20. naveen521kk
    added a commit that references this issue on Aug 5, 2024

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    2ce1791
  21. Glyphack
    added a commit that references this issue on Sep 2, 2024

    pythongh-109370: Fix unexpected traceback output in test_concurrent_f…

    25b6222
  22. naveen521kk
    added a commit that references this issue on Sep 4, 2024

    [3.12] pythongh-114440: Close writer pipe in multiprocessing.Queue, n…

    1ca1659
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    3.13only security fixestestsTests in the Lib/test dirtype-crashA hard crash of the interpreter, possibly with a core dump

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions