Skip to content

test_multiprocessing_forkserver.py, test_multiprocessing_fork.py and test_multiprocessing_spawn.py gives tracebacks #96026

Description

@sharewax

Bug report

During build RPM for python3.11rc1 I've found tracebacks for tests from test suite test_multiprocessing_forkserver.py, test_multiprocessing_fork.py, and test_multiprocessing_spawn.py :

[root@xxx test]# python3.11 test_multiprocessing_forkserver.py
............s..................................................s...............................s.s.s.....s...s...........ss.....s......................................................................................................................................Traceback (most recent call last):
  File "/opt/rh/rh-python311/root/usr/lib64/python3.11/multiprocessing/resource_tracker.py", line 209, in main
.    cache[rtype].remove(name)
KeyError: '/psm_8714e59f'
..............................ssss...............................s.........ss.ss..sss.sss.s.ssss......ss....s.
----------------------------------------------------------------------
Ran 374 tests in 75.001s

OK (skipped=33)
[root@xxx test]# python3.11 test_multiprocessing_spawn.py
............s..............s...................................s...............................s.s.s.....s...s...........ss.....s...............................................................................................ss.....................................Traceback (most recent call last):
  File "/opt/rh/rh-python311/root/usr/lib64/python3.11/multiprocessing/resource_tracker.py", line 209, in main
.    cache[rtype].remove(name)
KeyError: '/psm_e93c9b17'
..............................ssss...............................s.........ss.ss..sss.sss.s.ssss......ss....s.
----------------------------------------------------------------------
Ran 374 tests in 118.379s

OK (skipped=36)

[root@xxx test]# python3.11 test_multiprocessing_fork.py
............s..............s...................................s...............................s.s.s.....s...s...........ss.....s........................................................................................s......ss.....................................Traceback (most recent call last):
  File "/opt/rh/rh-python311/root/usr/lib64/python3.11/multiprocessing/resource_tracker.py", line 209, in main
.    cache[rtype].remove(name)
KeyError: '/psm_1324c68a'
..............................ssss...............................s.........ss.ss..sss.sss.s.ssss......ss....s.
----------------------------------------------------------------------
Ran 374 tests in 67.935s

OK (skipped=37)

I suppose, that tracebacks are not ok during test. Or close the bug, if it normal.
Some KeyError are present in #95396.

Your environment

Python 3.11.0rc1 (main, Aug 13 2022, 18:23:13) [GCC 9.3.1 20200408 (Red Hat 9.3.1-2)] on linux
Centos7 x86_64, python 3.11rc1

Activity

  1. serhiy-storchaka commented on Aug 18, 2022

    @serhiy-storchaka
    Member

    I seen this output many times, but cannot reproduce locally (on Ubuntu).

    It is bad because it looks like an error even if test reports OK. It is mixed with real errors report and make it more difficult to analyze. It can also be a symptom of a problem with resource management.

  2. sharewax commented on Aug 18, 2022

    @sharewax
    Author

    As for KeyError psm it looks like issues with shared memory. Some things was discussed in #91577.
    I see that in commit 9a458be was added resource_tracker, maybe it's connected somehow.

  3. sharewax commented on Aug 18, 2022

    @sharewax
    Author

    shared_memory.py

    ...
                try:
                    if create and size:
                        os.ftruncate(self._fd, size)
                    stats = os.fstat(self._fd)
                    size = stats.st_size
                    self._mmap = mmap.mmap(self._fd, size)
                except OSError:
                    self.unlink()
                    raise
    
                resource_tracker.register(self._name, "shared_memory")
    

    So if OSError exist, it tries to do resource_tracker.unregister which is contained in self.unlink(), but maybe it can be situation when resource_tracker.register wasn't register before?

  4. sharewax commented on Aug 18, 2022

    @sharewax
    Author

    maybe connected with #89372 ?
    I've found the test which reproduce this traceback

    python -m test -v test_multiprocessing_forkserver -m test_shared_memory_cleaned_after_process_termination
    == CPython 3.11.0rc1 (main, Aug 13 2022, 18:23:13) [GCC 9.3.1 20200408 (Red Hat 9.3.1-2)]
    == Linux-3.10.0-1160.62.1.el7.x86_64-x86_64-with-glibc2.17 little-endian
    == cwd: /tmp/test_python_43253æ
    == CPU count: 40
    == encodings: locale=UTF-8, FS=utf-8
    0:00:00 load avg: 21.34 Run tests sequentially
    0:00:00 load avg: 21.34 [1/1] test_multiprocessing_forkserver
    test_shared_memory_cleaned_after_process_termination (test.test_multiprocessing_forkserver.WithProcessesTestSharedMemory.test_shared_memory_cleaned_after_process_termination) ... Traceback (most recent call last):
      File "/opt/rh/rh-python311/root/usr/lib64/python3.11/multiprocessing/resource_tracker.py", line 209, in main
    ok
        cache[rtype].remove(name)
    KeyError: '/psm_60e6d44e'
    
    ----------------------------------------------------------------------
    Ran 1 test in 0.235s
    
    OK
    
    == Tests result: SUCCESS ==
    
    1 test OK.
    
    Total duration: 420 ms
    Tests result: SUCCESS
    

    it is reproducable for test_multiprocessing_fork, test_multiprocessing_forkserver, test_multiprocessing_spawn

    In my case reverting patch f604cf1 doesn't produce any key error and other UserWarning.
    So it's like specific for Windows tests?
    Checked on current MacOS:

    python3.10 -m test -v test_multiprocessing_spawn -v -m test_shared_memory_cleaned_after_process_termination
    Raised RLIMIT_NOFILE: 256 -> 1024
    == CPython 3.10.6 (main, Aug 6 2022, 22:42:17) [Clang 13.1.6 (clang-1316.0.21.2.5)]
    == macOS-12.5-x86_64-i386-64bit little-endian
    == cwd: /private/var/folders/pr/4ktlw3_s2bxfb3ggg496dc1h0000gp/T/test_python_92918æ
    == CPU count: 8
    == encodings: locale=UTF-8, FS=utf-8
    0:00:00 load avg: 1.90 Run tests sequentially
    0:00:00 load avg: 1.90 [1/1] test_multiprocessing_spawn
    test_shared_memory_cleaned_after_process_termination (test.test_multiprocessing_spawn.WithProcessesTestSharedMemory) ... ok
    unregister /psm_9b1c91a5
    Traceback (most recent call last):
      File "/opt/local/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/resource_tracker.py", line 211, in main
        cache[rtype].remove(name)
    KeyError: '/psm_9b1c91a5'
    
    ----------------------------------------------------------------------
    Ran 1 test in 0.237s
    
    OK
    
    == Tests result: SUCCESS ==
    
    1 test OK.
    
    Total duration: 373 ms
    Tests result: SUCCESS
    

    it tries to run resource_tracker.unregister on the resource which wasn't added into resource_tracker before.

    0:00:00 load avg: 20.19 [1/1] test_multiprocessing_spawn
    test_shared_memory_cleaned_after_process_termination (test.test_multiprocessing_spawn.WithProcessesTestSharedMemory.test_shared_memory_cleaned_after_process_termination) ... b'REGISTER:/mp-kxz5k9_d:semaphore\n'
    register /mp-kxz5k9_d
    b'PROBE:0:noop\n'
    b'UNREGISTER:/mp-kxz5k9_d:semaphore\n'
    unregister /mp-kxz5k9_d
    resource_tracker.unregister name is: psm_674b5480
    b'PROBE:0:noop\n'
    b'UNREGISTER:/psm_674b5480:shared_memory\n'
    unregister /psm_674b5480
    Traceback (most recent call last):
      File "/opt/rh/rh-python311/root/usr/lib64/python3.11/multiprocessing/resource_tracker.py", line 212, in main
    ok
        cache[rtype].remove(name)
    KeyError: '/psm_674b5480'
    
    ----------------------------------------------------------------------
    Ran 1 test in 0.220s
    
  5. sergeykolosov commented on Aug 22, 2022

    @sergeykolosov

    I'm not entirely confident yet, but it appears that after 9a458be got merged, the workaround from f604cf1 is no longer needed (and causes the reported issue).

  6. sharewax commented on Aug 25, 2022

    @sharewax
    Author

    @tiran is it possible to fix it by reverting workaround as mentioned in comment by @sergeykolosov ?

  7. tiran commented on Aug 25, 2022

    @tiran
    Member

    @sharewax Please refrain from pinging core developers on issues to draw their attention. It's distracting. Triagers may ping core devs or assign tickets that are listed as experts in https://devguide.python.org/core-developers/experts/index.html.

  8. sharewax commented on Aug 25, 2022

    @sharewax
    Author

    sorry for that :(

  9. codeofandrin commented on Jan 10, 2025

    @codeofandrin

    Also encountered this problem for Python 3.9.21 on macOS arm64.

  10. added a commit that references this issue on Apr 30, 2025
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

    Projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions