test_profiling.test_sampling_profiler fails randomly on "AMD64 Arch Linux Asan 3.x" buildbot

[vstinner]

Bug report

AMD64 Arch Linux Asan 3.x: https://buildbot.python.org/#/builders/582/builds/7178

======================================================================
FAIL: test_script_error_treatment (test.test_profiling.test_sampling_profiler.test_integration.TestSampleProfilerErrorHandling.test_script_error_treatment)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/buildbot/buildarea/3.x.pablogsal-arch-x86_64.asan/build/Lib/test/test_profiling/test_sampling_profiler/test_integration.py", line 699, in test_script_error_treatment
    self.assertIn(
    ~~~~~~~~~~~~~^
        "No such file or directory: 'nonexistent_file.txt'", output
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
AssertionError: "No such file or directory: 'nonexistent_file.txt'" not found in 'Captured 942 samples in 1.00 seconds\nSample rate: 941.99 samples/sec\nError rate: 1.17\nWarning: missed 58 samples from the expected total of 1000 (5.80%)\n\x1b[1;34mProfile Stats:\x1b[0m\n\x1b[1;34m       nsamples\x1b[0m  \x1b[1;34m sample%\x1b[0m  \x1b[1;34mtottime (ms)\x1b[0m  \x1b[1;34m  cumul%\x1b[0m  \x1b[1;34mcumtime (ms)\x1b[0m  \x1b[1;34mfilename:lineno(function)\x1b[0m\n        863/863      92.7       863.000      92.7       863.000  \x1b[32mdataclasses.py\x1b[0m:\x1b[33m499\x1b[0m(\x1b[36m_FuncBuilder.add_fns_to_class\x1b[0m)\n            9/9       1.0         9.000       1.0         9.000  \x1b[32m_colorize.py\x1b[0m:\x1b[33m205\x1b[0m(\x1b[36mCalendar\x1b[0m)\n            8/8       0.9         8.000       0.9         8.000  \x1b[32m<frozen abc>\x1b[0m:\x1b[33m127\x1b[0m(\x1b[36mABCMeta.__new__\x1b[0m)\n            7/7       0.8         7.000       0.8         7.000  \x1b[32m~\x1b[0m:\x1b[33m0\x1b[0m(\x1b[36m<GC>\x1b[0m)\n            5/5       0.5         5.000       0.5         5.000  \x1b[32m<frozen importlib._bootstrap_external>\x1b[0m:\x1b[33m500\x1b[0m(\x1b[36m_compile_bytecode\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32m__init__.py\x1b[0m:\x1b[33m447\x1b[0m(\x1b[36mnamedtuple\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32mdataclasses.py\x1b[0m:\x1b[33m728\x1b[0m(\x1b[36m_frozen_set_del_attr\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32mdataclasses.py\x1b[0m:\x1b[33m851\x1b[0m(\x1b[36m_get_field\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32m<frozen abc>\x1b[0m:\x1b[33m199\x1b[0m(\x1b[36mupdate_abstractmethods\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32mdataclasses.py\x1b[0m:\x1b[33m1171\x1b[0m(\x1b[36m_process_class\x1b[0m)\n            2/2       0.2         2.000       0.2         2.000  \x1b[32mdataclasses.py\x1b[0m:\x1b[33m469\x1b[0m(\x1b[36m_FuncBuilder.add_fn\x1b[0m)\n            1/1       0.1         1.000       0.1         1.000  \x1b[32m_parser.py\x1b[0m:\x1b[33m537\x1b[0m(\x1b[36m_parse\x1b[0m)\n            1/1       0.1         1.000       0.1         1.000  \x1b[32m_parser.py\x1b[0m:\x1b[33m543\x1b[0m(\x1b[36m_parse\x1b[0m)\n            1/1       0.1         1.000       0.1         1.000  \x1b[32m<frozen importlib._bootstrap_external>\x1b[0m:\x1b[33m921\x1b[0m(\x1b[36mFileLoader.get_data\x1b[0m)\n            1/1       0.1         1.000       0.1         1.000  \x1b[32m_compiler.py\x1b[0m:\x1b[33m402\x1b[0m(\x1b[36m_mk_bitmap\x1b[0m)\n\n\x1b[1;34mLegend:\x1b[0m\n  \x1b[33mnsamples\x1b[0m: Direct/Cumulative samples (direct executing / on call stack)\n  \x1b[33msample%\x1b[0m: Percentage of total samples this function was directly executing\n  \x1b[33mtottime\x1b[0m: Estimated total time spent directly in this function\n  \x1b[33mcumul%\x1b[0m: Percentage of total samples when this function was on the call stack\n  \x1b[33mcumtime\x1b[0m: Estimated cumulative time (including time in called functions)\n  \x1b[33mfilename:lineno(function)\x1b[0m: Function location and name\n\n\x1b[1;34mSummary of Interesting Functions:\x1b[0m\n\n\x1b[1;34mFunctions with Highest Direct/Cumulative Ratio (Hot Spots):\x1b[0m\n  1.000 direct/cumulative ratio, 92.7% direct samples: \x1b[32mdataclasses.py\x1b[0m:\x1b[33m\x1b[0m(\x1b[36m_FuncBuilder.add_fns_to_class\x1b[0m)\n  1.000 direct/cumulative ratio, 1.0% direct samples: \x1b[32m_colorize.py\x1b[0m:\x1b[33m\x1b[0m(\x1b[36mCalendar\x1b[0m)\n  1.000 direct/cumulative ratio, 0.9% direct samples: \x1b[32m<frozen abc>\x1b[0m:\x1b[33m\x1b[0m(\x1b[36mABCMeta.__new__\x1b[0m)\n\n\x1b[1;34mFunctions with Highest Call Frequency (Indirect Calls):\x1b[0m\n\n\x1b[1;34mFunctions with Highest Call Magnification (Cumulative/Direct):\x1b[0m\n'

======================================================================
FAIL: test_run_failed_module_live (test.test_profiling.test_sampling_profiler.test_live_collector_ui.TestLiveModeErrors.test_run_failed_module_live)
Test that running a existing module that fails exits with clean error.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/buildbot/buildarea/3.x.pablogsal-arch-x86_64.asan/build/Lib/test/test_profiling/test_sampling_profiler/test_live_collector_ui.py", line 859, in test_run_failed_module_live
    self.assertIn(
    ~~~~~~~~~~~~~^
        'test test_asdasd crashed -- Traceback (most recent call last):',
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        fake_stderr.getvalue()
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
AssertionError: 'test test_asdasd crashed -- Traceback (most recent call last):' not found in ''

======================================================================
FAIL: test_run_failed_script_live (test.test_profiling.test_sampling_profiler.test_live_collector_ui.TestLiveModeErrors.test_run_failed_script_live)
Test that running a failing script exits with clean error.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/buildbot/buildarea/3.x.pablogsal-arch-x86_64.asan/build/Lib/test/test_profiling/test_sampling_profiler/test_live_collector_ui.py", line 885, in test_run_failed_script_live
    self.assertIn('ZeroDivisionError', stderr)
    ~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: 'ZeroDivisionError' not found in ''

----------------------------------------------------------------------
Ran 583 tests in 105.264s

FAILED (failures=3)

Linked PRs

• gh-150720: Remove '-d 1' in test_script_error_treatment #150736
• [3.15] gh-150720: Remove '-d 1' in test_script_error_treatment (GH-150736) #150746

[vstinner]

The 3.15 branch is also affected.

AMD64 Arch Linux Asan 3.15: https://buildbot.python.org/#/builders/2025/builds/19

[lkollar]

I can reproduce this by restricting CPU quota to 10%:
systemd-run --user --scope -p CPUQuota=10% ./python.exe -m test -u curses -F -vvv test.test_profiling.test_sampling_profiler.test_integration -m test_script_error_treatment

An overloaded system ends up running the subprocess under the test so slowly that it doesn't reach the point of emitting the error message when the one second duration in the profiler expires. The fix should be to drop the -d1 and let the subprocess finish running.