20.8. Instrumenting the Python Process for Your Structures

Some debugging problems can be solved by instrumenting your C extensions for the duration of the Python process and reporting what happened when the process terminates. The data could be: the number of times classes were instantiated, functions called, memory allocations/deallocations or anything else that you wish.

To take a simple case, suppose we have a class that implements a up/down counter and we want to count how often each inc() and dec() function is called during the entirety of the Python process. We will create a C extension that has a class that has a single member (an interger) and two functions that increment or decrement that number. If it was in Python it would look like this:

class Counter:
    def __init__(self, count=0):
        self.count = count

    def inc(self):
        self.count += 1

    def dec(self):
        self.count -= 1

What we would like to do is to count how many times inc() and dec() are called on all instances of these objects and summarise them when the Python process exits [1].

There is an interpreter hook Py_AtExit() that allows you to register C functions that will be executed as the Python interpreter exits. This allows you to dump information that you have gathered about your code execution.

20.8.1. An Implementation of a Counter

First here is the module pyatexit with the class pyatexit.Counter with no intrumentation (it is equivalent to the Python code above). We will add the instrumentation later:

  1#include <Python.h>
  2#include "structmember.h"
  3
  4#include <stdio.h>
  5
  6typedef struct {
  7    PyObject_HEAD int number;
  8} Py_Counter;
  9
 10static void Py_Counter_dealloc(Py_Counter* self) {
 11    Py_TYPE(self)->tp_free((PyObject*)self);
 12}
 13
 14static PyObject* Py_Counter_new(PyTypeObject* type, PyObject* args,
 15                                PyObject* kwds) {
 16    Py_Counter* self;
 17    self = (Py_Counter*)type->tp_alloc(type, 0);
 18    if (self != NULL) {
 19        self->number = 0;
 20    }
 21    return (PyObject*)self;
 22}
 23
 24static int Py_Counter_init(Py_Counter* self, PyObject* args, PyObject* kwds) {
 25    static char* kwlist[] = { "number", NULL };
 26    if (!PyArg_ParseTupleAndKeywords(args, kwds, "|i", kwlist, &self->number)) {
 27        return -1;
 28    }
 29    return 0;
 30}
 31
 32static PyMemberDef Py_Counter_members[] = {
 33    { "count", T_INT, offsetof(Py_Counter, number), 0, "count value" },
 34    { NULL, 0, 0, 0, NULL } /* Sentinel */
 35};
 36
 37static PyObject* Py_Counter_inc(Py_Counter* self) {
 38    self->number++;
 39    Py_RETURN_NONE;
 40}
 41
 42static PyObject* Py_Counter_dec(Py_Counter* self) {
 43    self->number--;
 44    Py_RETURN_NONE;
 45}
 46
 47static PyMethodDef Py_Counter_methods[] = {
 48    { "inc", (PyCFunction)Py_Counter_inc, METH_NOARGS, "Increments the counter" },
 49    { "dec", (PyCFunction)Py_Counter_dec, METH_NOARGS, "Decrements the counter" },
 50    { NULL, NULL, 0, NULL } /* Sentinel */
 51};
 52
 53static PyTypeObject Py_CounterType = {
 54    PyVarObject_HEAD_INIT(NULL, 0) "pyatexit.Counter", /* tp_name */
 55    sizeof(Py_Counter), /* tp_basicsize */
 56    0, /* tp_itemsize */
 57    (destructor)Py_Counter_dealloc, /* tp_dealloc */
 58    0, /* tp_print */
 59    0, /* tp_getattr */
 60    0, /* tp_setattr */
 61    0, /* tp_reserved */
 62    0, /* tp_repr */
 63    0, /* tp_as_number */
 64    0, /* tp_as_sequence */
 65    0, /* tp_as_mapping */
 66    0, /* tp_hash  */
 67    0, /* tp_call */
 68    0, /* tp_str */
 69    0, /* tp_getattro */
 70    0, /* tp_setattro */
 71    0, /* tp_as_buffer */
 72    Py_TPFLAGS_DEFAULT | Py_TPFLAGS_BASETYPE, /* tp_flags */
 73    "Py_Counter objects", /* tp_doc */
 74    0, /* tp_traverse */
 75    0, /* tp_clear */
 76    0, /* tp_richcompare */
 77    0, /* tp_weaklistoffset */
 78    0, /* tp_iter */
 79    0, /* tp_iternext */
 80    Py_Counter_methods, /* tp_methods */
 81    Py_Counter_members, /* tp_members */
 82    0, /* tp_getset */
 83    0, /* tp_base */
 84    0, /* tp_dict */
 85    0, /* tp_descr_get */
 86    0, /* tp_descr_set */
 87    0, /* tp_dictoffset */
 88    (initproc)Py_Counter_init, /* tp_init */
 89    0, /* tp_alloc */
 90    Py_Counter_new, /* tp_new */
 91    0, /* tp_free */
 92};
 93
 94static PyModuleDef pyexitmodule = {
 95    PyModuleDef_HEAD_INIT, "pyatexit",
 96    "Extension that demonstrates the use of Py_AtExit().",
 97    -1, NULL, NULL, NULL, NULL,
 98    NULL
 99};
100
101PyMODINIT_FUNC PyInit_pyatexit(void) {
102    PyObject* m;
103
104    if (PyType_Ready(&Py_CounterType) < 0) {
105        return NULL;
106    }
107    m = PyModule_Create(&pyexitmodule);
108    if (m == NULL) {
109        return NULL;
110    }
111    Py_INCREF(&Py_CounterType);
112    PyModule_AddObject(m, "Counter", (PyObject*)&Py_CounterType);
113    return m;
114}

If this was a file Py_AtExitDemo.c then a Python setup.py file might look like this:

from distutils.core import setup, Extension
setup(
    ext_modules=[
        Extension("pyatexit", sources=['Py_AtExitDemo.c']),
    ]
)

Building this with python3 setup.py build_ext --inplace we can check everything works as expected:

 1>>> import pyatexit
 2>>> c = pyatexit.Counter(8)
 3>>> c.inc()
 4>>> c.inc()
 5>>> c.dec()
 6>>> c.count
 79
 8>>> d = pyatexit.Counter()
 9>>> d.dec()
10>>> d.dec()
11>>> d.count
12-2
13>>> ^D

20.8.2. Instrumenting the Counter

To add the instrumentation we will declare a macro COUNT_ALL_DEC_INC to control whether the compilation includes instrumentation.

#define COUNT_ALL_DEC_INC

In the global area of the file declare some global counters and a function to write them out on exit. This must be a void function taking no arguments:

 1#ifdef COUNT_ALL_DEC_INC
 2/* Counters for operations and a function to dump them at Python process end. */
 3static size_t count_inc = 0;
 4static size_t count_dec = 0;
 5
 6static void dump_inc_dec_count(void) {
 7    fprintf(stdout, "==== dump_inc_dec_count() ====\n");
 8    fprintf(stdout, "Increments: %" PY_FORMAT_SIZE_T "d\n", count_inc);
 9    fprintf(stdout, "Decrements: %" PY_FORMAT_SIZE_T "d\n", count_dec);
10    fprintf(stdout, "== dump_inc_dec_count() END ==\n");
11}
12#endif

In the Py_Counter_new function we add some code to register this function. This must be only done once so we use the static has_registered_exit_function to guard this:

 1static PyObject* Py_Counter_new(PyTypeObject* type, PyObject* args,
 2                                PyObject* kwds) {
 3    Py_Counter* self;
 4#ifdef COUNT_ALL_DEC_INC
 5    static int has_registered_exit_function = 0;
 6    if (! has_registered_exit_function) {
 7        if (Py_AtExit(dump_inc_dec_count)) {
 8            return NULL;
 9        }
10        has_registered_exit_function = 1;
11    }
12#endif
13    self = (Py_Counter*)type->tp_alloc(type, 0);
14    if (self != NULL) {
15        self->number = 0;
16    }
17    return (PyObject*)self;
18}

Note

Py_AtExit can take, at most, 32 functions. If the function can not be registered then Py_AtExit will return -1.

Warning

Since Python’s internal finalization will have completed before the cleanup function, no Python APIs should be called by any registered function.

Now we modify the inc() and dec() functions thus:

 1static PyObject* Py_Counter_inc(Py_Counter* self) {
 2    self->number++;
 3#ifdef COUNT_ALL_DEC_INC
 4    count_inc++;
 5#endif
 6    Py_RETURN_NONE;
 7}
 8
 9static PyObject* Py_Counter_dec(Py_Counter* self) {
10    self->number--;
11#ifdef COUNT_ALL_DEC_INC
12    count_dec++;
13#endif
14    Py_RETURN_NONE;
15}

Now when we build this extension and run it we see the following:

 1>>> import pyatexit
 2>>> c = pyatexit.Counter(8)
 3>>> c.inc()
 4>>> c.inc()
 5>>> c.dec()
 6>>> c.count
 79
 8>>> d = pyatexit.Counter()
 9>>> d.dec()
10>>> d.dec()
11>>> d.count
12-2
13>>> ^D
14==== dump_inc_dec_count() ====
15Increments: 2
16Decrements: 3
17== dump_inc_dec_count() END ==

Footnotes