GeezerVison

I have noticed that the dask benchmark in pyperformance hangs when running it with Python 3.11 with a "high" number of cores on the machine. I have seen issues with 191 and 384 cores.

I started investigated the problem and seen that the issue manifested itself on a machine with a high number of cores.
The benchmarks that hangs is https://github.com/python/pyperformance/blob/main/pyperformance/data-files/benchmarks/bm_dask/run_benchmark.py

When the Worker class get instantiated, it sets the nthreads to the number of CPUs present on the system (here the code)

When this number is relatively high, it causes Python3.11 to hang and all the underlying threads to deadlock on the GIL.

To replicate the issue:

make a copy of the dask benchmark file
set the nthreads of the Worker class to a relatively high number (E.g. 1000).

async with Worker(scheduler.address, nthreads=1000):
...

Create/activate a venv with Python 3.11 and install the dependencies

pip install dask[distributed]==2022.2.0 pyperf

Run a quick stress test

while true; do python run_benchmark.py; done

and wait to hang. It does it at random time.

With the process hanging, gdb shows on a thread (out of the hundreds):

 (gdb) thread 4
[Switching to thread 4 (Thread 0x7f5aeffff640 (LWP 402351))]
#0  __futex_abstimed_wait_common64 (private=-1457409528, cancel=true, abstime=0x7f5aefffde20, op=137, expected=0, futex_word=0x5640a959d354 <_PyRuntime+436>) at ./nptl/futex-internal.c:57
57      in ./nptl/futex-internal.c
(gdb) py-bt
Traceback (most recent call first):
  Waiting for the GIL
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/psutil/_common.py", line 788, in open_binary
    return open(fname, "rb", buffering=FILE_READ_BUFFER_SIZE)
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/psutil/_pslinux.py", line 1967, in memory_info
    with open_binary("%s/%s/statm" % (self._procfs_path, self.pid)) as f:
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/psutil/_pslinux.py", line 1714, in wrapper
    return fun(self, *args, **kwargs)
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/psutil/__init__.py", line 1102, in memory_info
    return self._proc.memory_info()
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/psutil/_common.py", line 495, in wrapper
    return fun(self)
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/distributed/utils_perf.py", line 188, in _gc_callback
    rss = self._proc.memory_info().rss
  <built-in method _current_frames of module object at remote 0x7f5dc0a32ca0>
  File "/home/ent-user/venv/cpython3.11-324490c70469-compat-2d3356be745c/lib/python3.11/site-packages/distributed/profile.py", line 270, in _watch
    frame = sys._current_frames()[thread_id]
  File "/home/ent-user/ci-scripts/tmpdir/prefix/lib/python3.11/threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "/home/ent-user/ci-scripts/tmpdir/prefix/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/home/ent-user/ci-scripts/tmpdir/prefix/lib/python3.11/threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()

A strace of a thread shows (continuously)

...
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=468031783}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=473122144}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=478228035}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=483319687}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=488417438}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=493521779}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=498608771}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=503711922}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=508813993}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=513919325}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
futex(0x55707e87f358, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55707e87f350, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=6498067, tv_nsec=519022166}, FUTEX_BITSET_MATCH_ANY) = -1 ETIMEDOUT (Connection timed out)
...

I tried upgrading Dask[distributed] the latest version but I have the same effects. I think there is something going on in Python 3.11.
This happens only with Python 3.11: 3.9 and 3.12 work as expected.

I've seen it on x86, aarch64 still to test.

CPython versions tested on:

3.11

Operating systems tested on:

Linux

Activity

diegorusso
added
type-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error
on Mar 18, 2024
colesbury commented on Mar 18, 2024
colesbury
on Mar 18, 2024
Contributor
More actions
I was able to reproduce this issue locally on 3.11.8. It's a lock ordering deadlock with HEAD_LOCK(&_PyRuntime); and the GIL.

Thread 1 holds the GIL and is blocked on HEAD_LOCK(&_PyRuntime);. The other threads are blocked on the GIL acquisition.

cpython/Python/pystate.c

Line 820 in db85d51

HEAD_LOCK(runtime);

Thread 2 holds the runtime lock and is trying to execute _PyThread_CurrentFrames. It's blocked trying to re-acquire the GIL while running the garbage collector.

cpython/Python/pystate.c

Line 1408 in db85d51

HEAD_LOCK(runtime);

I think this is not an issue (or less of an issue at least) in 3.12+ because allocating objects won't directly run the GC.
Reacted by stonebig
colesbury commented on Mar 18, 2024
colesbury
on Mar 18, 2024
Contributor
More actions
I think this is the same underlying issue as #106883
Reacted by stonebig
diegorusso commented on Mar 19, 2024
diegorusso
on Mar 19, 2024
ContributorAuthor
More actions
@colesbury thanks for looking into it. For completeness I tested it on AArch64 and had the same behaviour.

As suggested in the Issue you mentioned, I back ported @pablogsal commit (83eb827) to run the GC only on eval breaker to 3.11 and ran the tests again. I confirm that no dead locks are happening anymore (both on x86 and AArch64).
diegorusso commented on Apr 3, 2024
diegorusso
on Apr 3, 2024
ContributorAuthor
More actions

I was able to reproduce this issue locally on 3.11.8. It's a lock ordering deadlock with HEAD_LOCK(&_PyRuntime); and the GIL.

@colesbury are you able to share the code snippet to reproduce the bug?
colesbury commented on Apr 3, 2024
colesbury
on Apr 3, 2024
Contributor
More actions
@diegorusso, I followed your instructions to reproduce the issue. I don't have a small reproducer.
diegorusso commented on Apr 3, 2024
diegorusso
on Apr 3, 2024
ContributorAuthor
More actions

@diegorusso, I followed your instructions to reproduce the issue. I don't have a small reproducer.

oops, my bad. I thought you had something with 2 threads. I have made the patch but I'd like to accompany it with some testing.
diegorusso commented on Apr 12, 2024
diegorusso
on Apr 12, 2024
ContributorAuthor
More actions
For completeness I report the PR I have created to fix the issue: #117332

There are discussions to check if the PR could be accepted or not because in theory 3.11.9 was the last bug fix release.
diegorusso commented on Mar 11, 2025
diegorusso
on Mar 11, 2025
ContributorAuthor
More actions
The PR #117332 has been merged.
diegorusso
closed this as completed on Mar 11, 2025

Metadata

Assignees

No one assigned

Labels

type-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions

You are visitor 01402503 — GeezerVison does not store the pages you look up.
Best viewed with Netscape Navigator 4.7 or Internet Explorer 6 at 800×600. No cookies required.

GeezerVison

Issue with Python 3.11 and dask[distributed] with high number of threads #116969

Description

Bug report

Bug description:

CPython versions tested on:

Operating systems tested on:

Activity

colesbury commented on Mar 18, 2024

colesbury commented on Mar 18, 2024

diegorusso commented on Mar 19, 2024

diegorusso commented on Apr 3, 2024

colesbury commented on Apr 3, 2024

diegorusso commented on Apr 3, 2024

diegorusso commented on Apr 12, 2024

diegorusso commented on Mar 11, 2025

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions