[C++-sig] Functions exposed using boost::python not reported by the python profiler

[Arnaud Espanel]

Hi --
When running a python program through the python profiler, calls to a
function exposed directly through C python api are reported, but not
the calls to a function exposed through boost::python. I'd like to see
boost::python calls reported on their own as well... but have not
managed to.
To demonstrate this, a simple "greet" fonction that returns a string
has been implemented in two versions. The first implementation ("cext"
module) has been exposed directly using python C api. The second
implementation ("bpyext" module)  has been exposed using boost::python
(the corresponding source code is at the end of this message).

When profiling these functions:

>>> import cProfile as profile
>>> profile.run('cext.greet()')
         3 function calls in 0.000 CPU 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 {cext.greet}
        1    0.000    0.000    0.000    0.000 {method 'disable' of
'_lsprof.Profiler' objects}


>>> profile.run('bpyext.greet()')
         2 function calls in 0.000 CPU 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 {method 'disable' of
'_lsprof.Profiler' objects}

We can see that the call to the C extension module (cext.greet) get
reported, but not the call to the boost::python extension
(bpyext.greet). Looking at how the profile module works, the profile
module is notified by the python interpreter on each function
call/return. This notification happens through the function set by
os.setprofile(function). Let's provide some simple "profiler" function
that just prints whenever it is called by the interpreter:

>>> import cext, bpyext, sys
>>> def profiler(frame,event,arg):
...     print 'PROF %r %r' % (event, arg)
...
>>> sys.setprofile(profiler)
PROF 'return' None
>>> cext.greet()
PROF 'call' None
PROF 'c_call' <built-in function greet>
PROF 'c_return' <built-in function greet>
'hello from C'
PROF 'return' None
>>> bpyext.greet()
PROF 'call' None
'Hello from boost::python'
PROF 'return' None

It works as expected for the C extension (we can see the
c_call/c_return events), but no events are triggered when the
boost::python function is called. Why is this the case? Is there
something that can be done in order to trigger these c_call/c_return
events for boost::python extensions?

Thanks,
Arnaud


For reference, here is the code of the C/boost::python modules. Tests
were done on Linux x86_64, using python 2.6.5 and boost 1.40.0
======================== cext.c ========================
include <Python.h>

static PyObject *
greet(PyObject *self, PyObject *args)
{
  return Py_BuildValue("s", "hello from C");
}

static PyMethodDef CextMethods[] = {
    {"greet",  greet, METH_VARARGS,
     "Say hi"},
    {NULL, NULL, 0, NULL}
};

PyMODINIT_FUNC
initcext(void)
{
  (void) Py_InitModule("cext", CextMethods);
}

======================= bpyext.cpp ======================
#include <string>
#include <boost/python.hpp>

std::string greet() {
    return "Hello from boost::python";
}

using namespace boost::python;

BOOST_PYTHON_MODULE(bpyext) {
    def("greet", &greet)
    ;
}