cProfile does not work in pdb

[impact27]

Bug report

While debugging, cProfile fails to work, while profile does work, see session below:

Python 3.10.8 (main, Oct 13 2022, 09:48:40) [Clang 14.0.0 (clang-1400.0.29.102)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import pdb
>>> db = pdb.Pdb()
>>> db.run("aaa")
> <string>(1)<module>()
(Pdb) import profile, cProfile
(Pdb) cProfile.run("print(0)")
0
*** TypeError: Cannot create or construct a <class 'pstats.Stats'> object from <cProfile.Profile object at 0x1028d5660>
(Pdb) profile.run("print(0)")
0
         1 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 profile:0(print(0))
        0    0.000             0.000          profile:0(profiler)


(Pdb) q
>>> cProfile.run("print(0)")
0
         4 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
        1    0.000    0.000    0.000    0.000 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.print}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


>>> profile.run("print(0)")
0
         5 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 :0(exec)
        1    0.000    0.000    0.000    0.000 :0(print)
        1    0.000    0.000    0.000    0.000 :0(setprofile)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
        1    0.000    0.000    0.000    0.000 profile:0(print(0))
        0    0.000             0.000          profile:0(profiler)


>>> 

Your environment

• CPython versions tested on: Python 3.10.8 (main, Oct 13 2022, 09:48:40) [Clang 14.0.0 (clang-1400.0.29.102)] on darwin
• Operating system and architecture: Apple M1 Max - 13.1 (22C65)

Linked PRs

• gh-102249: Expand sys.call_tracing documentation #102806
• [3.12] gh-102249: Expand sys.call_tracing documentation (GH-102806) #111557
• [3.11] gh-102249: Expand sys.call_tracing documentation (GH-102806) #111558

[impact27]

Apparently the problem is with settrace:

Python 3.10.8 (main, Oct 13 2022, 09:48:40) [Clang 14.0.0 (clang-1400.0.29.102)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> def fun(frame, event, arg):
...     import cProfile
...     cProfile.run("print(0)")
...     sys.settrace(None)
... 
>>> import sys
>>> sys.settrace(fun)
>>> print(1)
0
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 3, in fun
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/cProfile.py", line 16, in run
    return _pyprofile._Utils(Profile).run(statement, filename, sort)
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/profile.py", line 57, in run
    self._show(prof, filename, sort)
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/profile.py", line 72, in _show
    prof.print_stats(sort)
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/cProfile.py", line 42, in print_stats
    pstats.Stats(self).strip_dirs().sort_stats(sort).print_stats()
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/pstats.py", line 114, in __init__
    self.init(arg)
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/pstats.py", line 128, in init
    self.load_stats(arg)
  File "/opt/homebrew/Cellar/[email protected]/3.10.8/Frameworks/Python.framework/Versions/3.10/lib/python3.10/pstats.py", line 154, in load_stats
    raise TypeError("Cannot create or construct a %r object from %r"
TypeError: Cannot create or construct a <class 'pstats.Stats'> object from <cProfile.Profile object at 0x1029d6980>
>>> 

[impact27]

The problem is that the profiling function (set by sys.setprofile) is not called while tracing. I have a minimal example:

Python 3.10.8 (main, Oct 13 2022, 09:48:40) [Clang 14.0.0 (clang-1400.0.29.102)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> def fun_prof(frame, event, arg):
...     print("profiling")
... 
>>> def fun_trace(frame, event, arg):
...     print("tracing")
...     sys.setprofile(fun_prof)
...     print("Call func")
...     sys.setprofile(None)
...     sys.settrace(None)
... 
>>> sys.settrace(fun_trace)
>>> print(0)
tracing
Call func
0
>>> 

[impact27]

I can use sys.call_tracing as a workaround, but https://docs.python.org/3/library/sys.html#sys.call_tracing doesn't mention anything about profiling, only tracing:

Call func(*args), while tracing is enabled. The tracing state is saved, and restored afterwards. This is intended to be called from a debugger from a checkpoint, to recursively debug some other code.

[arhadthedev]

@iritkatriel @gvanrossum as more-than-once committers into pdb and cProfile correspondingly still active.

[gvanrossum]

I'm sorry, I no longer have a working knowledge of these APIs. Historically, it never occurred to me that these APIs would be combined.

[CAM-Gerlach]

FWIW, I can repro this on 3.11.0 on Windows:

Python 3.11.0 | packaged by conda-forge | (main, Oct 25 2022, 06:12:32) [MSC v.1929 64 bit (AMD64)] on win32
Type "help", "copyright", "credits" or "license" for more information.
>>> import pdb
>>> db = pdb.Pdb()
>>> db.run("aaa")
> <string>(1)<module>()
(Pdb) import profile, cProfile
(Pdb) profile.run("print(0)")
0
         1 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 profile:0(print(0))
        0    0.000             0.000          profile:0(profiler)


(Pdb) cProfile.run("print(0)")
0
*** TypeError: Cannot create or construct a <class 'pstats.Stats'> object from <cProfile.Profile object at 0x0000000003814C20>
(Pdb)

[impact27]

I guess the best way to address this would be to update the doc so it is clear that sys.call_tracing works for both sys.settrace and sys.setprofile, at least in https://docs.python.org/3/library/sys.html#sys.call_tracing and maybe a note on https://docs.python.org/3/library/sys.html#sys.setprofile . The name "call_tracing" suggest it would only work for sys.settrace.

If I can add a small feature request: sys.call_tracing(func, args) doesn't take kwargs, which would be great.

[gaogaotiantian]

I think the rule is - you can't do settrace in profiling function and you can't do setprofile in tracing function. Otherwise it's just too easy to create an infinite recursion - you profiling function will trigger tracing function and the triggered tracing function will trigger profilng function again.

[CAM-Gerlach]

If I can add a small feature request: sys.call_tracing(func, args) doesn't take kwargs, which would be great.

This would probably best as a separate issue, IMO, since it doesn't appear to be directly

I think the rule is - you can't do settrace in profiling function and you can't do setprofile in tracing function.

Is this documented anywhere? It might be worth adding a small note in the docs of the respective functions.

[impact27]

From what I can see, the rule is that if you need to call settrace or setprofile in a profiling / tracing function you need sys.call_tracing. There does not appear to be any fundamental difference between settrace and setprofile in that regard. This is the approach spyder uses to profile while debugging or to do recursive debugging.

[CAM-Gerlach]

In that case, perhaps we should add a note to that effect. Are you interested in submitting a PR? Happy to help guide you in that since I'm one of the docs team members here.

[impact27]

I opened #102806

[hugovk]

Thanks!