Very high CPU usage in `profiling.sampling`

[maurycy]

Bug report

Bug description:

While playing with psf/pyperf#230, I noticed that it's profiling.sampling what's taking a lot of CPU!

The problems seems to be a busy loop here:

• cpython/Lib/profiling/sampling/sample.py

  Line 103 in 5f57f69

  if next_time < current_time:

Reproduction

Notice 99% CPU here:

2026-01-30T15:04:49.171073215+0100 maurycy@eiger /home/maurycy/github.com/maurycy/cpython (main) % ./test.sh 
Python: /home/maurycy/work/cpython/python ('--enable-optimizations' '--with-lto')
Target PID: 2907235
Captured 60,001 samples in 60.00 seconds
Sample rate: 1,000.02 samples/sec
Error rate: 0.58
Profile Stats:
       nsamples   sample%   tottime (s)    cumul%   cumtime (s)  filename:lineno(function)
    39116/39116      65.6        39.116      65.6        39.116  foof.py:6(l3)
    19916/19916      33.4        19.916      33.4        19.916  foof.py:5(l3)
      289/59643       0.5         0.289     100.0        59.643  foof.py:19(main)
        177/177       0.3         0.177       0.3         0.177  foof.py:7(l3)
       68/59333       0.1         0.068      99.5        59.333  foof.py:13(l1)
       53/59295       0.1         0.053      99.4        59.295  foof.py:10(l2)
          17/17       0.0         0.017       0.0         0.017  foof.py:3(l3)
          16/16       0.0         0.016       0.0         0.016  foof.py:4(l3)
        0/59652       0.0         0.000     100.0        59.652  foof.py:23(<module>)
            0/9       0.0         0.000       0.0         0.009  foof.py:18(main)

Legend:
  nsamples: Direct/Cumulative samples (direct executing / on call stack)
  sample%: Percentage of total samples this function was directly executing
  tottime: Estimated total time spent directly in this function
  cumul%: Percentage of total samples when this function was on the call stack
  cumtime: Estimated cumulative time (including time in called functions)
  filename:lineno(function): Function location and name

Summary of Interesting Functions:

Functions with Highest Direct/Cumulative Ratio (Hot Spots):
  1.000 direct/cumulative ratio, 99.3% direct samples: foof.py:(l3)
  0.005 direct/cumulative ratio, 0.5% direct samples: foof.py:(main)
  0.001 direct/cumulative ratio, 0.1% direct samples: foof.py:(l1)

Functions with Highest Call Frequency (Indirect Calls):
  59652 indirect calls, 100.0% total stack presence: foof.py:(<module>)
  59363 indirect calls, 100.0% total stack presence: foof.py:(main)
  59265 indirect calls, 99.5% total stack presence: foof.py:(l1)

Functions with Highest Call Magnification (Cumulative/Direct):
  1118.8x call magnification, 59242 indirect calls from 53 direct: foof.py:(l2)
  872.5x call magnification, 59265 indirect calls from 68 direct: foof.py:(l1)
  206.4x call magnification, 59363 indirect calls from 289 direct: foof.py:(main)
60.04user 0.00system 1:00.05elapsed 99%CPU (0avgtext+0avgdata 21108maxresident)k
0inputs+0outputs (0major+3687minor)pagefaults 0swaps

Scripts

test.sh

#!/bin/bash
set -e

PYTHON=~/work/cpython/python
DURATION=60

echo "Python: $PYTHON"
echo "Duration: ${DURATION}s"

$PYTHON foof.py &
TARGET_PID=$!
sleep 1

echo "Target PID: $TARGET_PID"

cleanup() { kill $TARGET_PID 2>/dev/null || true; }
trap cleanup EXIT

/usr/bin/time env PYTHONPATH=. $PYTHON -m profiling.sampling attach $TARGET_PID -d $DURATION #  2>&1

foof.py

import time

def l3():
    total = 0
    for i in range(1_000):
        total += i * i
    return total

def l2():
    return l3()

def l1():
    return l2()

def main():
    start = time.perf_counter()
    iterations = 0
    while time.perf_counter() - start < 120:
        l1()
        iterations += 1

if __name__ == "__main__":
    main()

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

Linked PRs

• gh-144342: Use time.sleep in profiling.sampling #144343