GV

GeezerVison

The World Wide Web, restored to 800 pixels of glory.

Home|About|Gaming cabinet|Archives|How it works|Starter sites

On this site

  • Sign in
  • ActionsCI/CD and automation
  • CodespacesCloud development environments
  • All Features
  • Documentation
  • Training
  • Certifications
  • Build with Copilot
  • Customize Copilot
  • Integrations
  • Trending repos
  • GitHub Sponsors
  • Developer articles
  • Enterprises

This view

  • Original page
  • New address

GeezerVison is showing github.com — test_profile: ProfileTest.test_cprofile() failed on AMD64 Windows PGO Tailcall 3.x · Issue #159117 · python/cpython

test_profile: ProfileTest.test_cprofile() failed on AMD64 Windows PGO Tailcall 3.x #159117

New issue
Copy link
New issue
Copy link
Open
#159664
Open
test_profile: ProfileTest.test_cprofile() failed on AMD64 Windows PGO Tailcall 3.x#159117
#159664
Copy link
Labels
OS-windowstestsTests in the Lib/test dirTests in the Lib/test dirtopic-profilingtype-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error

Description

@vstinner
vstinner
opened on Oct 10, 2026
Issue body actions

AMD64 Windows PGO Tailcall 3.x: https://buildbot.python.org/#/builders/1870/builds/1504

If I read correctly, self.do_profiling() just returned... an empty string?

======================================================================
FAIL: test_cprofile (test.test_profile.ProfileTest.test_cprofile)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/worker/cstratak-CentOS9-x86_64/3.15.cstratak-CentOS9-x86_64.refleak/build/Lib/test/test_profile.py", line 70, in test_cprofile
    self.fail("\n".join(fail))
    ~~~~~~~~~^^^^^^^^^^^^^^^^^
AssertionError: 
Stats.print_stats output for Profile does not fit expectation:
--- 
+++ 
@@ -1,9 +1 @@
-       28   27.972    0.999   27.972    0.999 profilee.py:110(__getattr__)
-        1  269.996  269.996  999.769  999.769 profilee.py:25(testfunc)
-     23/3  149.937    6.519  169.917   56.639 profilee.py:35(factorial)
-       20   19.980    0.999   19.980    0.999 profilee.py:48(mul)
-        2   39.986   19.993  599.830  299.915 profilee.py:55(helper)
-        4  115.984   28.996  119.964   29.991 profilee.py:73(helper1)
-        2   -0.006   -0.003  139.946   69.973 profilee.py:84(helper2_indirect)
-        8  311.976   38.997  399.912   49.989 profilee.py:88(helper2)
-        8   63.976    7.997   79.960    9.995 profilee.py:98(subhelper)
+

Stats.print_callers output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1 @@
-:0(append)                        <- profilee.py:73(helper1)(4)  119.964
-:0(exception)                     <- profilee.py:73(helper1)(4)  119.964
-:0(hasattr)                       <- profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:88(helper2)(8)  399.912
-profilee.py:110(__getattr__)      <- :0(hasattr)(12)   11.964
-                                     profilee.py:98(subhelper)(16)   79.960
-profilee.py:25(testfunc)          <- <string>:1(<module>)(1)  999.767
-profilee.py:35(factorial)         <- profilee.py:25(testfunc)(1)  999.769
-                                     profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:48(mul)               <- profilee.py:35(factorial)(20)  169.917
-profilee.py:55(helper)            <- profilee.py:25(testfunc)(2)  999.769
-profilee.py:73(helper1)           <- profilee.py:55(helper)(4)  599.830
-profilee.py:84(helper2_indirect)  <- profilee.py:55(helper)(2)  599.830
-profilee.py:88(helper2)           <- profilee.py:55(helper)(6)  599.830
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:98(subhelper)         <- profilee.py:88(helper2)(8)  399.912
+

Stats.print_callees output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1 @@
-:0(hasattr)                       -> profilee.py:110(__getattr__)(12)   27.972
-<string>:1(<module>)              -> profilee.py:25(testfunc)(1)  999.769
-profilee.py:110(__getattr__)      ->
-profilee.py:25(testfunc)          -> profilee.py:35(factorial)(1)  169.917
-                                     profilee.py:55(helper)(2)  599.830
-profilee.py:35(factorial)         -> profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:48(mul)(20)   19.980
-profilee.py:48(mul)               ->
-profilee.py:55(helper)            -> profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-                                     profilee.py:88(helper2)(6)  399.912
-profilee.py:73(helper1)           -> :0(append)(4)   -0.004
-profilee.py:84(helper2_indirect)  -> profilee.py:35(factorial)(2)  169.917
-                                     profilee.py:88(helper2)(2)  399.912
-profilee.py:88(helper2)           -> :0(hasattr)(8)   11.964
-                                     profilee.py:98(subhelper)(8)   79.960
-profilee.py:98(subhelper)         -> profilee.py:110(__getattr__)(16)   27.972
+

----------------------------------------------------------------------
Ran 625 tests in 55.273s

FAILED (failures=1, skipped=1)
test test_profiling failed

Linked PRs

  • gh-159117: Preserve sys.setprofile callbacks when destroying a tracing profiler #159664

Activity

  1. vstinner
    added
    testsTests in the Lib/test dirTests in the Lib/test dir
    OS-windows
    topic-profiling
    on Oct 10, 2026

  2. vstinner commented on Oct 10, 2026

    @vstinner
    vstinner
    on Oct 10, 2026
    MemberAuthor
    More actions

    Similar but different failure on s390x Fedora Stable Refleaks 3.15: https://buildbot.python.org/#/builders/2050/builds/381

    This time, the output is not completely empty:

    ======================================================================
FAIL: test_cprofile (test.test_profile.ProfileTest.test_cprofile)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/worker/cstratak-fedora-stable-s390x/3.15.cstratak-fedora-stable-s390x.refleak/build/Lib/test/test_profile.py", line 70, in test_cprofile
    self.fail("\n".join(fail))
    ~~~~~~~~~^^^^^^^^^^^^^^^^^
AssertionError: 
Stats.print_stats output for Profile does not fit expectation:
--- 
+++ 
@@ -1,9 +1,4 @@
-       28   27.972    0.999   27.972    0.999 profilee.py:110(__getattr__)
-        1  269.996  269.996  999.769  999.769 profilee.py:25(testfunc)
-     23/3  149.937    6.519  169.917   56.639 profilee.py:35(factorial)
-       20   19.980    0.999   19.980    0.999 profilee.py:48(mul)
-        2   39.986   19.993  599.830  299.915 profilee.py:55(helper)
-        4  115.984   28.996  119.964   29.991 profilee.py:73(helper1)
-        2   -0.006   -0.003  139.946   69.973 profilee.py:84(helper2_indirect)
-        8  311.976   38.997  399.912   49.989 profilee.py:88(helper2)
-        8   63.976    7.997   79.960    9.995 profilee.py:98(subhelper)
+        1  890.000  890.000  890.000  890.000 profilee.py:110(__getattr__)
+        1   98.999   98.999  999.996  999.996 profilee.py:25(testfunc)
+        1    0.999    0.999  900.997  900.997 profilee.py:55(helper)
+        1    9.999    9.999  899.998  899.998 profilee.py:73(helper1)

Stats.print_callers output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1,5 @@
-:0(append)                        <- profilee.py:73(helper1)(4)  119.964
-:0(exception)                     <- profilee.py:73(helper1)(4)  119.964
-:0(hasattr)                       <- profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:88(helper2)(8)  399.912
-profilee.py:110(__getattr__)      <- :0(hasattr)(12)   11.964
-                                     profilee.py:98(subhelper)(16)   79.960
-profilee.py:25(testfunc)          <- <string>:1(<module>)(1)  999.767
-profilee.py:35(factorial)         <- profilee.py:25(testfunc)(1)  999.769
-                                     profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:48(mul)               <- profilee.py:35(factorial)(20)  169.917
-profilee.py:55(helper)            <- profilee.py:25(testfunc)(2)  999.769
-profilee.py:73(helper1)           <- profilee.py:55(helper)(4)  599.830
-profilee.py:84(helper2_indirect)  <- profilee.py:55(helper)(2)  599.830
-profilee.py:88(helper2)           <- profilee.py:55(helper)(6)  599.830
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:98(subhelper)         <- profilee.py:88(helper2)(8)  399.912
+:0(hasattr)                   <- profilee.py:73(helper1)(1)  899.998
+profilee.py:110(__getattr__)  <- :0(hasattr)(1)  889.999
+profilee.py:25(testfunc)      <- <string>:1(<module>)(1)  999.995
+profilee.py:55(helper)        <- profilee.py:25(testfunc)(1)  999.996
+profilee.py:73(helper1)       <- profilee.py:55(helper)(1)  900.997

Stats.print_callees output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1,6 @@
-:0(hasattr)                       -> profilee.py:110(__getattr__)(12)   27.972
-<string>:1(<module>)              -> profilee.py:25(testfunc)(1)  999.769
-profilee.py:110(__getattr__)      ->
-profilee.py:25(testfunc)          -> profilee.py:35(factorial)(1)  169.917
-                                     profilee.py:55(helper)(2)  599.830
-profilee.py:35(factorial)         -> profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:48(mul)(20)   19.980
-profilee.py:48(mul)               ->
-profilee.py:55(helper)            -> profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-                                     profilee.py:88(helper2)(6)  399.912
-profilee.py:73(helper1)           -> :0(append)(4)   -0.004
-profilee.py:84(helper2_indirect)  -> profilee.py:35(factorial)(2)  169.917
-                                     profilee.py:88(helper2)(2)  399.912
-profilee.py:88(helper2)           -> :0(hasattr)(8)   11.964
-                                     profilee.py:98(subhelper)(8)   79.960
-profilee.py:98(subhelper)         -> profilee.py:110(__getattr__)(16)   27.972
+:0(hasattr)                   -> profilee.py:110(__getattr__)(1)  890.000
+<string>:1(<module>)          -> profilee.py:25(testfunc)(1)  999.996
+profilee.py:110(__getattr__)  ->
+profilee.py:25(testfunc)      -> profilee.py:55(helper)(1)  900.997
+profilee.py:55(helper)        -> profilee.py:73(helper1)(1)  899.998
+profilee.py:73(helper1)       -> :0(hasattr)(1)  889.999

----------------------------------------------------------------------
Ran 625 tests in 54.221s

FAILED (failures=1, skipped=1)
test test_profiling failed
  3. vstinner
    added
    type-bugAn unexpected behavior, bug, or errorAn unexpected behavior, bug, or error
    on Oct 10, 2026

  4. vstinner commented on Oct 18, 2026

    @vstinner
    vstinner
    on Oct 18, 2026
    MemberAuthor
    More actions

    Another example on aarch64 CentOS9 Refleaks 3.x: https://buildbot.python.org/#/builders/840/builds/2864

    FAIL: test_cprofile (test.test_profile.ProfileTest.test_cprofile)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/worker/cstratak-CentOS9-aarch64/3.x.cstratak-CentOS9-aarch64.refleak/build/Lib/test/test_profile.py", line 70, in test_cprofile
    self.fail("\n".join(fail))
    ~~~~~~~~~^^^^^^^^^^^^^^^^^
AssertionError: 
Stats.print_stats output for Profile does not fit expectation:
--- 
+++ 
@@ -1,9 +1,7 @@
-       28   27.972    0.999   27.972    0.999 profilee.py:110(__getattr__)
-        1  269.996  269.996  999.769  999.769 profilee.py:25(testfunc)
-     23/3  149.937    6.519  169.917   56.639 profilee.py:35(factorial)
-       20   19.980    0.999   19.980    0.999 profilee.py:48(mul)
-        2   39.986   19.993  599.830  299.915 profilee.py:55(helper)
-        4  115.984   28.996  119.964   29.991 profilee.py:73(helper1)
-        2   -0.006   -0.003  139.946   69.973 profilee.py:84(helper2_indirect)
-        8  311.976   38.997  399.912   49.989 profilee.py:88(helper2)
-        8   63.976    7.997   79.960    9.995 profilee.py:98(subhelper)
+       12   11.988    0.999   11.988    0.999 profilee.py:110(__getattr__)
+        1   98.999   98.999  999.938  999.938 profilee.py:25(testfunc)
+        1   18.994   18.994  900.939  900.939 profilee.py:55(helper)
+        2   57.992   28.996   59.982   29.991 profilee.py:73(helper1)
+        1   -0.001   -0.001  671.996  671.996 profilee.py:84(helper2_indirect)
+        4  127.990   31.997  821.964  205.491 profilee.py:88(helper2)
+        3   23.991    7.997   29.985    9.995 profilee.py:98(subhelper)
Stats.print_callers output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1,13 @@
-:0(append)                        <- profilee.py:73(helper1)(4)  119.964
-:0(exception)                     <- profilee.py:73(helper1)(4)  119.964
-:0(hasattr)                       <- profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:88(helper2)(8)  399.912
-profilee.py:110(__getattr__)      <- :0(hasattr)(12)   11.964
-                                     profilee.py:98(subhelper)(16)   79.960
-profilee.py:25(testfunc)          <- <string>:1(<module>)(1)  999.767
-profilee.py:35(factorial)         <- profilee.py:25(testfunc)(1)  999.769
-                                     profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:48(mul)               <- profilee.py:35(factorial)(20)  169.917
-profilee.py:55(helper)            <- profilee.py:25(testfunc)(2)  999.769
-profilee.py:73(helper1)           <- profilee.py:55(helper)(4)  599.830
-profilee.py:84(helper2_indirect)  <- profilee.py:55(helper)(2)  599.830
-profilee.py:88(helper2)           <- profilee.py:55(helper)(6)  599.830
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-profilee.py:98(subhelper)         <- profilee.py:88(helper2)(8)  399.912
+:0(append)                        <- profilee.py:73(helper1)(2)   59.982
+:0(exception)                     <- profilee.py:73(helper1)(2)   59.982
+:0(hasattr)                       <- profilee.py:73(helper1)(2)   59.982
+                                     profilee.py:88(helper2)(4)  821.964
+profilee.py:110(__getattr__)      <- :0(hasattr)(6)  665.983
+                                     profilee.py:98(subhelper)(6)   29.985
+profilee.py:25(testfunc)          <- <string>:1(<module>)(1)  999.937
+profilee.py:55(helper)            <- profilee.py:25(testfunc)(1)  999.938
+profilee.py:73(helper1)           <- profilee.py:55(helper)(2)  900.939
+profilee.py:84(helper2_indirect)  <- profilee.py:55(helper)(1)  900.939
+profilee.py:88(helper2)           <- profilee.py:55(helper)(3)  900.939
+                                     profilee.py:84(helper2_indirect)(1)  671.996
+profilee.py:98(subhelper)         <- profilee.py:88(helper2)(3)  821.964
Stats.print_callees output for Profile does not fit expectation:
--- 
+++ 
@@ -1,17 +1,12 @@
-:0(hasattr)                       -> profilee.py:110(__getattr__)(12)   27.972
-<string>:1(<module>)              -> profilee.py:25(testfunc)(1)  999.769
+:0(hasattr)                       -> profilee.py:110(__getattr__)(6)   11.988
+<string>:1(<module>)              -> profilee.py:25(testfunc)(1)  999.938
 profilee.py:110(__getattr__)      ->
-profilee.py:25(testfunc)          -> profilee.py:35(factorial)(1)  169.917
-                                     profilee.py:55(helper)(2)  599.830
-profilee.py:35(factorial)         -> profilee.py:35(factorial)(20)  169.917
-                                     profilee.py:48(mul)(20)   19.980
-profilee.py:48(mul)               ->
-profilee.py:55(helper)            -> profilee.py:73(helper1)(4)  119.964
-                                     profilee.py:84(helper2_indirect)(2)  139.946
-                                     profilee.py:88(helper2)(6)  399.912
-profilee.py:73(helper1)           -> :0(append)(4)   -0.004
-profilee.py:84(helper2_indirect)  -> profilee.py:35(factorial)(2)  169.917
-                                     profilee.py:88(helper2)(2)  399.912
-profilee.py:88(helper2)           -> :0(hasattr)(8)   11.964
-                                     profilee.py:98(subhelper)(8)   79.960
-profilee.py:98(subhelper)         -> profilee.py:110(__getattr__)(16)   27.972
+profilee.py:25(testfunc)          -> profilee.py:55(helper)(1)  900.939
+profilee.py:55(helper)            -> profilee.py:73(helper1)(2)   59.982
+                                     profilee.py:84(helper2_indirect)(1)  671.996
+                                     profilee.py:88(helper2)(3)  821.964
+profilee.py:73(helper1)           -> :0(append)(2)   -0.002
+profilee.py:84(helper2_indirect)  -> profilee.py:88(helper2)(1)  821.964
+profilee.py:88(helper2)           -> :0(hasattr)(4)  665.983
+                                     profilee.py:98(subhelper)(3)   29.985
+profilee.py:98(subhelper)         -> profilee.py:110(__getattr__)(6)   11.988
----------------------------------------------------------------------
Ran 645 tests in 68.975s
FAILED (failures=1, skipped=2)
test test_profiling failed

  5. Cha-Imaa commented on Oct 18, 2026

    @Cha-Imaa
    Cha-Imaa
    on Oct 18, 2026
    More actions

    I reproduced a mechanism that can explain the empty and partial statistics: _lsprof uses sys.monitoring, but profiler_dealloc() still calls _PyEval_SetProfile(tstate, NULL, NULL). If an enabled C profiler loses its monitoring callbacks and is later destroyed, it clears an unrelated sys.setprofile() callback. Garbage collection during ProfileTest.do_profiling() can therefore stop the pure Python profiler partway through the workload.

    I opened #159664 to remove that obsolete cleanup, with a deterministic regression test and a NEWS entry. The regression test fails before the change and passes afterward on a Windows AMD64 debug build. The profiling, profile, sys.setprofile, monitoring, and pstats suites pass, as do reference-leak checks for both profiler implementations. I have not tested the original PGO tail-call or s390x configurations.

  6. Cha-Imaa
    added 2 commits that reference this issue on Oct 18, 2026

    Merge remote-tracking branch 'origin/main' into pythongh-159117-profi…

    b79a6f4

    Merge branch 'main' into pythongh-159117-profiler-dealloc

    4f1bdc9
  7. kevinprimeraquecreo-stack
    added this to Project_VKon Oct 18, 2026
  8. github-project-automation
    moved this to In progress in Project_VKon Oct 18, 2026
  9. kevinprimeraquecreo-stack
    added this to Project_VKon Oct 18, 2026
  10. Cha-Imaa
    added a commit that references this issue on Oct 22, 2026

    Merge branch 'main' into pythongh-159117-profiler-dealloc

    6b3b9b2
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    OS-windowstestsTests in the Lib/test dirTests in the Lib/test dirtopic-profilingtype-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.