`test_perf_profiler` fails on aarch64 Fedora Stable buildbots

[encukou]

Bug report

Since about 4 days ago, test_perf_profiler.test_python_calls_appear_in_the_stack_if_perf_activated usually fails on refleaks buildbots with one of these (see build 416 for both):

• AssertionError: 'py::foo:/tmp/test_python_2wtkitdm/tmpv30razor/perftest.py' not found in <very long string containing frames with a different temp dir instead: /tmp/test_python_ecqze28x/tmpz61vpvo4/perftest.py+0xb here>
• unexpected stderr:

  Warning:
  Processed 688 events and lost 3 chunks!
  
  Check IO/CPU overload!
  

Linked PRs

• gh-131038: Use text=True in subprocesses in test_perf_profiler #137117
• [3.14] gh-131038: Use text=True in subprocesses in test_perf_profiler (GH-137117) #137124
• [3.13] gh-131038: Use text=True in subprocesses in test_perf_profiler (GH-137117) #137125
• [3.12] gh-131038: Use text=True in subprocesses in test_perf_profiler (#137117) #138024

[vstinner]

cc @pablogsal @stratakis

[pablogsal]

Unfortunately I cannot reproduce this locally and I don't have any idea of what may be happening in the buildbot. Was this updated recently?

[pablogsal]

I cannot reproduce in the buildbot either:

pablo@localhost:~/cpython$ ./python -m test test_perf_profiler -v
== CPython 3.14.0a5+ (heads/main:8431b1fee88, Mar 10 2025, 16:20:11) [GCC 14.2.1 20250110 (Red Hat 14.2.1-7)]
== Linux-6.13.5-200.fc41.aarch64-aarch64-with-glibc2.40 little-endian
== Python build: debug
== cwd: /home/pablo/cpython/build/test_python_worker_160904æ
== CPU count: 40
== encodings: locale=UTF-8 FS=utf-8
== resources: all test resources are disabled, use -u option to unskip tests

Using random seed: 2682059707
0:00:00 load avg: 16.79 Run 1 test sequentially in a single process
0:00:00 load avg: 16.79 [1/1] test_perf_profiler
test_pre_fork_compile (test.test_perf_profiler.TestPerfProfiler.test_pre_fork_compile) ... ok
test_python_calls_appear_in_the_stack_if_perf_activated (test.test_perf_profiler.TestPerfProfiler.test_python_calls_appear_in_the_stack_if_perf_activated) ... ok
test_python_calls_do_not_appear_in_the_stack_if_perf_deactivated (test.test_perf_profiler.TestPerfProfiler.test_python_calls_do_not_appear_in_the_stack_if_perf_deactivated) ... ok
test_python_calls_appear_in_the_stack_if_perf_activated (test.test_perf_profiler.TestPerfProfilerWithDwarf.test_python_calls_appear_in_the_stack_if_perf_activated) ... ok
test_python_calls_do_not_appear_in_the_stack_if_perf_deactivated (test.test_perf_profiler.TestPerfProfilerWithDwarf.test_python_calls_do_not_appear_in_the_stack_if_perf_deactivated) ... ok
test_sys_api (test.test_perf_profiler.TestPerfTrampoline.test_sys_api) ... ok
test_sys_api_get_status (test.test_perf_profiler.TestPerfTrampoline.test_sys_api_get_status) ... ok
test_sys_api_with_existing_trampoline (test.test_perf_profiler.TestPerfTrampoline.test_sys_api_with_existing_trampoline) ... ok
test_sys_api_with_invalid_trampoline (test.test_perf_profiler.TestPerfTrampoline.test_sys_api_with_invalid_trampoline) ... ok
test_trampoline_works (test.test_perf_profiler.TestPerfTrampoline.test_trampoline_works) ... ok
test_trampoline_works_with_forks (test.test_perf_profiler.TestPerfTrampoline.test_trampoline_works_with_forks) ... ok

----------------------------------------------------------------------
Ran 11 tests in 19.774s

OK
0:00:20 load avg: 24.35 [1/1] test_perf_profiler passed

== Tests result: SUCCESS ==

1 test OK.

Total duration: 20.9 sec
Total tests: run=11
Total test files: run=1/1
Result: SUCCESS
pablo@localhost:~/cpython$ uname -a
Linux localhost.localdomain 6.13.5-200.fc41.aarch64 #1 SMP PREEMPT_DYNAMIC Thu Feb 27 15:30:52 UTC 2025 aarch64 GNU/Linux

It seems to be related to perf dropping events under high CPU usage. I honestly don't want to skip the test in this case because that is going to be a pain if we have real failures

[pablogsal]

@stratakis Can you investigate if something has changed recently in the buildbot?

[pablogsal]

I have been testing under high load using this script:

import multiprocessing
import time
import argparse

def cpu_load(duration=None, intensity=1.0):
    """
    Generate CPU load on a single core.
    
    Args:
        duration (float, optional): Duration in seconds to run the load.
                                   If None, runs until interrupted.
        intensity (float): Value between 0.0 and 1.0 to control load intensity.
                          1.0 means 100% load, 0.5 means approximately 50% load.
    """
    start_time = time.time()
    
    while True:
        # Busy work
        x = 0
        # Adjust end range to control intensity
        end = int(10000000 * intensity)
        for i in range(end):
            x += i
            x *= 1.0000001
        
        # Sleep to reduce CPU usage if intensity < 1.0
        if intensity < 1.0:
            time.sleep((1.0 - intensity) * 0.1)
            
        # Check if duration has been reached
        if duration is not None and time.time() - start_time >= duration:
            break

def run_load_test(cores=None, duration=None, intensity=1.0):
    """
    Run CPU load test on multiple cores.
    
    Args:
        cores (int, optional): Number of cores to utilize. 
                              If None, uses all available cores.
        duration (float, optional): Duration in seconds to run the test.
                                   If None, runs until interrupted.
        intensity (float): Value between 0.0 and 1.0 to control load intensity.
    """
    if cores is None:
        cores = multiprocessing.cpu_count()
    
    print(f"Starting CPU load test on {cores} cores with {intensity*100}% intensity")
    if duration:
        print(f"Test will run for {duration} seconds")
    else:
        print("Test will run until interrupted with Ctrl+C")
    
    # Create and start processes
    processes = []
    try:
        for _ in range(cores):
            p = multiprocessing.Process(target=cpu_load, args=(duration, intensity))
            processes.append(p)
            p.start()
        
        # Wait for processes to complete if duration is specified
        if duration:
            for p in processes:
                p.join()
            print("CPU load test completed")
        else:
            # Keep the main process running until interrupted
            while True:
                time.sleep(1)
                
    except KeyboardInterrupt:
        print("Stopping CPU load test...")
        for p in processes:
            if p.is_alive():
                p.terminate()
        print("CPU load test stopped")

if __name__ == "__main__":
    parser = argparse.ArgumentParser(description="Generate CPU load for testing")
    parser.add_argument("-c", "--cores", type=int, default=None, 
                        help="Number of cores to utilize (default: all available)")
    parser.add_argument("-d", "--duration", type=float, default=None,
                        help="Duration in seconds (default: run until interrupted)")
    parser.add_argument("-i", "--intensity", type=float, default=1.0,
                        help="Load intensity from 0.0 to 1.0 (default: 1.0)")
    
    args = parser.parse_args()
    
    run_load_test(args.cores, args.duration, args.intensity)

and still can't reproduce even on the buildbot

[pablogsal]

I'm testing with the buildbot at 147.75.54.63

[stratakis]

The failures coincide with the dnf update I've done a couple of day ago.

More specifically the kernel (hence Perf as well) got updated from 6.12.11-200 to 6.13.5-200.

update.txt

I'm attaching the full dnf transaction.

[stratakis]

However I was running last week some Python compilations of my own to test some thing in the buildbot and if that happened at the same time a ref leak build was running that could be the problem. I'd let this open until a couple more refleak builds occur and if nothing shows up, we can close the issue.

[encukou]

That was probably it. The refleak buildbots were green for a while, before starting to fail with an unrelated change.
I'll confirm tomorrow.

[encukou]

Yup.
Sorry for the noise!