[BUG]: Missing calls from a cProfile profile when calling into a pybind11 extension
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 18k
- Forks
- 2.3k
- Avg merge
- 5d 17h
- Merged PRs (30d)
- 10
Description
Required prerequisites
- Make sure you've read the documentation. Your issue may be addressed there.
- Search the issue tracker and Discussions to verify that this hasn't already been reported. +1 or comment there if it has.
- Consider asking first in the Gitter chat room or in a Discussion.
What version (or hash if on master) of pybind11 are you using?
tried with both 2.13.6 and master
Problem description
Consider the following Python code using cProfile:
import cProfile
import sys
import ext
def call_me() -> None:
obj = ext.CppClass()
for _ in range(10):
obj.call_me()
def main() -> None:
print("Profiling...\n\n")
cProfile.run("call_me()")
if __name__ == "__main__":
main()
where ext is the following pybind11 extension:
#include <pybind11/pybind11.h>
namespace myspace {
class CppClass {};
} // namespace myspace
namespace py = pybind11;
PYBIND11_MODULE(ext, m) {
m.doc() = "Simple C++ Python extension using pybind11";
m.def("return_zero", []() { return 0; });
py::class_<myspace::CppClass>(m, "CppClass")
.def(py::init<>())
.def("call_me", [](myspace::CppClass& self) {
printf("hello!\n");
return 0;
});
}
Running this under Python 3.12.8 produces the following output:
Profiling...
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
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 {method 'disable' of '_lsprof.Profiler' objects}
Notably, the resulting profile doesn't include anything about the Python call to call_me(), nor the 10 calls to the pybind11 call_me() method on the obj instance. We can see from the "hello" prints in the output that the method was indeed called.
Interestingly, when changing the call inside the loop to ext.return_zero() instead, the profile produced is as expected:
Profiling...
14 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 repro.py:11(call_me)
1 0.000 0.000 0.000 0.000 {built-in method builtins.exec}
10 0.000 0.000 0.000 0.000 {built-in method ext.return_zero}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
Using Python 3.10 instead of 3.12, the second profile is identical, while the first one is still missing some calls, but it's not missing the initial Python call_me() call:
Profiling...
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
hello!
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 repro.py:11(call_me)
1 0.000 0.000 0.000 0.000 {built-in method builtins.exec}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
I think this is likely pybind11-specific, because I tried reproducing this with an equivalent C++ extension using hand crafted C-API, and couldn't observe the issue.
Reproducible example code
Is this a regression? Put the last known working version here if it is.
Not a regression
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with the Python cProfile example and the pybind11 extension definitions for CppClass.call_me and ext.return_zero, comparing their profiles on Python 3.10 and 3.12. Trace the pybind11 call path against the hand-crafted C-API comparison mentioned in the issue. Done means calls to call_me and its surrounding Python function appear correctly in the generated profile.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, python
- Domain
- backend
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100