test_profiling.test_sampling_profiler: test_is_python_process_non_python_subprocess() failed on AMD64 Alpine Linux NoGIL PR

AMD64 Alpine Linux NoGIL PR: https://buildbot.python.org/#/builders/1820/builds/75

FAIL: test_is_python_process_non_python_subprocess (test.test_profiling.test_sampling_profiler.test_children.TestIsPythonProcess.test_is_python_process_non_python_subprocess)
Test that a non-Python subprocess is not detected as Python.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/buildbot/buildarea/pull_request.ware-alpine.nogil/build/Lib/test/test_profiling/test_sampling_profiler/test_children.py", line 649, in test_is_python_process_non_python_subprocess
    self.assertFalse(
    ~~~~~~~~~~~~~~~~^
        is_python_process(proc.pid),
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        f"Non-Python subprocess 'sleep' (PID {proc.pid}) should NOT be "
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        f"detected as Python",
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
AssertionError: True is not false : Non-Python subprocess 'sleep' (PID 1478327) should NOT be detected as Python

Linked PRs

Oh, it seems like the test doesn't fail on AMD64 Alpine Linux NoGIL 3.x: https://buildbot.python.org/#/builders/1819/builds/3396.

AMD64 Alpine Linux NoGIL PR: https://buildbot.python.org/#/builders/1820/builds/75

test.pythoninfo:

platform.freedesktop_os_release[NAME]: Alpine Linux
platform.freedesktop_os_release[VERSION_ID]: 3.24.2

os.uname: posix.uname_result(sysname='Linux', nodename='ea59ad688dfd', release='6.12.111+deb13-amd64', version='#1 SMP PREEMPT_DYNAMIC Debian 6.12.111-1 (2026-09-28)', machine='x86_64')

platform.libc_ver: musl 1.2.6
platform.platform: Linux-6.12.111+deb13-amd64-x86_64-with-musl1.2.6

system.boot_id: 8abce604-2ac7-4108-b6c4-f93a6e21ab92
system.uptime: 7 days, 15:48:41
system.virt: podman

I can reproduce the test failure on a Debian 12 VM by running the stress test:

./python -m test test_profiling.test_sampling_profiler.test_children -v -m test_is_python_process_non_python_subprocess -F

It takes 9 minutes and 5297 tries to reproduce the issue!

On my Fedora 44 laptop, I failed to reproduce the issue (I ran the stress test for 10 minutes, 7572 runs).

search_linux_map_for_section() open /proc/{pid}/maps to read "sleep" process maps.

When the bug occurs, /proc/{pid}/maps is not the sleep maps, but maps of a Python process. If I reopen the same path, I get the sleep maps.

Example where f file is the search_linux_map_for_section() maps_file and f2 is a fresh file opening the same path. You can see that the two files don't return the same contents, but os.fstat() pretends that it's the same file!?

(Pdb) f.seek(0); f.readline()
0
'55bbf8367000-55bbf8402000 r--p 00000000 fe:01 146247                     /home/vstinner/python/main/python\n'
(Pdb) f2.seek(0); f2.readline()
0
'563875d05000-563875d07000 r--p 00000000 fe:01 654379                     /usr/bin/sleep\n'
(Pdb) p os.fstat(f.fileno()) == os.fstat(f2.fileno())
True

and

vstinner@debian12:~/python/main$ cat /proc/21201/fdinfo/5
pos:	0
flags:	0100000
mnt_id:	23
ino:	80475

vstinner@debian12:~/python/main$ cat /proc/21201/fdinfo/8
pos:	0
flags:	02100000
mnt_id:	23
ino:	80475

vstinner@debian12:~/python/main$ grep ^23 /proc/24915/mountinfo 
23 27 0:21 / /proc rw,nosuid,nodev,noexec,relatime shared:12 - proc proc rw

Script to reproduce the issue:

import sys
import subprocess
import os.path
import time


GLOBAL_PIDS = set()

def _wait_for_process_ready(proc, timeout):
    # Wait for a subprocess to be ready using polling instead of fixed sleep.
    # Returns True if process is ready, False if it exited or timeout.
    deadline = time.time() + timeout
    poll_interval = 0.01

    while time.time() < deadline:
        if proc.poll() is not None:
            return False

        try:
            if sys.platform == "linux":
                if os.path.exists(f"/proc/{proc.pid}/exe"):
                    return True
            else:
                return True
        except OSError:
            pass

        time.sleep(poll_interval)
        poll_interval = min(poll_interval * 2, 0.1)

    return proc.poll() is None


def _cleanup_process(proc, timeout=30):
    print("terminate", proc.pid)
    proc.terminate()
    proc.wait(timeout=timeout)

def is_python_process(pid):
    filename = f"/proc/{pid}/maps"
    for test in range(8):
        f = open(filename)
        data = f.read()
        if "python" in data:
            print(f". test {test}")

            os.system(f"cat {filename}")

            print("BUG! FOUND PYTHON IN MAPS")

            f2 = open(filename)
            data2 = f2.read()

            fd1 = f.fileno()
            fd2 = f2.fileno()

            print(f"fd1={fd1} fd2={fd2}")
            print("reopen()+read(): same data?", data2 == data)
            print("same fstat for the 2 lines?", os.fstat(fd1) == os.fstat(fd2)) 
            print(f"first line of data: {data.splitlines()[0]!r}")
            print(f"first line of data2: {data2.splitlines()[0]!r}")

            breakpoint()
            return True
        f.close()
    return False

def func():
    proc = subprocess.Popen(
        ["sleep", "3600"],
        stdout=subprocess.DEVNULL,
        stderr=subprocess.DEVNULL,
    )

    try:
        # Wait for process to be ready using polling
        pid = proc.pid
        if pid in GLOBAL_PIDS:
            print("PID RECYCLED " + "@" * 40)
            print("PID RECYCLED " + "@" * 40)
            print("PID RECYCLED " + "@" * 40)
        GLOBAL_PIDS.add(pid)

        print(f"non-python process: pid {pid}")
        if not _wait_for_process_ready(proc, 30):
            print(f"Process {proc.pid} should be ready within {SHORT_TIMEOUT}s")
            sys.exit(1)

        python = is_python_process(proc.pid)
        if python:
            print("BUG!")
            breakpoint()
    finally:
        _cleanup_process(proc)

i = 0
while True:
    i += 1
    print(f"Run #{i}")
    func()

Example of output on my Debian 12 VM:

(...)
Run #461
non-python process: pid 28127
terminate 28127
Run #462
non-python process: pid 28128
terminate 28128
Run #463
non-python process: pid 28129
. test 0
5597c5d52000-5597c5d54000 r--p 00000000 fe:01 654379                     /usr/bin/sleep
5597c5d54000-5597c5d59000 r-xp 00002000 fe:01 654379                     /usr/bin/sleep
5597c5d59000-5597c5d5b000 r--p 00007000 fe:01 654379                     /usr/bin/sleep
5597c5d5b000-5597c5d5c000 r--p 00009000 fe:01 654379                     /usr/bin/sleep
5597c5d5c000-5597c5d5d000 rw-p 0000a000 fe:01 654379                     /usr/bin/sleep
5597eab2f000-5597eab50000 rw-p 00000000 00:00 0                          [heap]
7f65ad200000-7f65ad4e9000 r--p 00000000 fe:01 653660                     /usr/lib/locale/locale-archive
7f65ad616000-7f65ad619000 rw-p 00000000 00:00 0 
7f65ad619000-7f65ad63f000 r--p 00000000 fe:01 652819                     /usr/lib/x86_64-linux-gnu/libc.so.6
7f65ad63f000-7f65ad795000 r-xp 00026000 fe:01 652819                     /usr/lib/x86_64-linux-gnu/libc.so.6
7f65ad795000-7f65ad7e8000 r--p 0017c000 fe:01 652819                     /usr/lib/x86_64-linux-gnu/libc.so.6
7f65ad7e8000-7f65ad7ec000 r--p 001cf000 fe:01 652819                     /usr/lib/x86_64-linux-gnu/libc.so.6
7f65ad7ec000-7f65ad7ee000 rw-p 001d3000 fe:01 652819                     /usr/lib/x86_64-linux-gnu/libc.so.6
7f65ad7ee000-7f65ad7fb000 rw-p 00000000 00:00 0 
7f65ad801000-7f65ad803000 rw-p 00000000 00:00 0 
7f65ad803000-7f65ad804000 r--p 00000000 fe:01 652815                     /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f65ad804000-7f65ad82a000 r-xp 00001000 fe:01 652815                     /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f65ad82a000-7f65ad834000 r--p 00027000 fe:01 652815                     /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f65ad834000-7f65ad836000 r--p 00031000 fe:01 652815                     /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f65ad836000-7f65ad838000 rw-p 00033000 fe:01 652815                     /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7ffdf1bea000-7ffdf1c0b000 rw-p 00000000 00:00 0                          [stack]
7ffdf1c70000-7ffdf1c74000 r--p 00000000 00:00 0                          [vvar]
7ffdf1c74000-7ffdf1c76000 r-xp 00000000 00:00 0                          [vdso]
BUG! FOUND PYTHON IN MAPS
fd1=3 fd2=4
reopen()+read(): same data? False
same fstat for the 2 lines? True
first line of data: '564aff128000-564aff1c3000 r--p 00000000 fe:01 146247                     /home/vstinner/python/main/python'
first line of data2: '5597c5d52000-5597c5d54000 r--p 00000000 fe:01 654379                     /usr/bin/sleep'
> /home/vstinner/python/main/x.py(63)is_python_process()
-> breakpoint()
(Pdb)

So when the 463th process is created, reading /proc/28129/maps gets the maps of the current Python process, rather than reading maps of the sleep process.

If /proc/28129/maps is open again, sleep maps is read as expected.

Also, running cat /proc/28129/maps also shows the sleep maps (as expected).

I can quickly reproduce the issue on the AMD64 Debian root 3.x buildbot: https://buildbot.python.org/#/builders/345/builds/15743

For example, I reproduced the issue after only 17 runs. The buildbot runs on Linux kernel 6.1.0-54-amd64.

My Debian 12 VM runs on the same Linux kernel 6.1.0-54-amd64.

Ah wait, I understood the root cause. is_python_process(proc.pid) is called as soon as the sleep 10 process is created. Sometimes, the test process can still see Python mappings in /proc/{pid}/maps just because the sleep 10 process is not sleep executable yet, but is still a freshly forked Python process. The problem is that we don't wait until exec() completed in the child process.

pythongh-159534: Fix race condition in test_sampling_profiler

gh-159534: Fix race condition in test_sampling_profiler (#160028)

[3.15] gh-159534: Fix race condition in test_sampling_profiler (GH-16…

I think this left the test broken on Alpine, and also broke it on RHEL-UBI9.
See #160881

Navigation Menu

Repository navigation

test_profiling.test_sampling_profiler: test_is_python_process_non_python_subprocess() failed on AMD64 Alpine Linux NoGIL PR #159534

Linked PRs

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

test_profiling.test_sampling_profiler: test_is_python_process_non_python_subprocess() failed on AMD64 Alpine Linux NoGIL PR #159534

Description

Linked PRs

Activity

vstinner commented on Oct 16, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

vstinner commented on Oct 21, 2026

thomgree commented on Oct 29, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions