feat: add support for uprobes

per4m/giltracer.py

@@ -35,7 +35,7 @@ class PerfRecordSched(PerfRecord):
 class PerfRecordGIL(PerfRecord):
     def __init__(self, output='perf-gil.data', trace_output='giltracer.json', viztracer_input="viztracer.json", verbose=1):
         # TODO: check output of perf probe --list="python:*gil*"  to see if probes are set
-        super().__init__(output=output, verbose=verbose, args=["-e 'python:*gil*'"], stacktrace=False)
+        super().__init__(output=output, verbose=verbose, args=["-e 'python:*gil*'", "-e pytrace:function_entry", "-e pytrace:function_return"], stacktrace=False)
         # this is used to filter the giltracer data
         self.viztracer_input = viztracer_input
         self.trace_output = trace_output

per4m/perf2trace.py

@@ -128,6 +128,10 @@ def gil2trace(input, verbose=1, take_probe="python:take_gil$", take_probe_return
     wants_take_gil = {}
     wants_drop_gil = {}
     has_gil = {}
+    has_gil_stack = {}
+
+    pystack = defaultdict(list)
+    wait_for_stack = defaultdict(list)  # pid -> call
 
     parent_pid = None
     # to avoid printing out the same msg over and over
@@ -163,10 +167,36 @@ def gil2trace(input, verbose=1, take_probe="python:take_gil$", take_probe_return
             if time_first is None:
                 time_first = time
 
-            if re.match(take_probe, event):
+            function_entry_probe = 'pytrace:function_entry'
+            function_return_probe = 'pytrace:function_return'
+            if re.match(function_entry_probe, event):
+                values = parse_values(other, l=int, what=int)
+                call = (values['filename'], values['funcname'],
+                        values['l'], values['what'])
+                pystack[pid].append(call)
+                depth = len(pystack[pid])
+                if verbose >= 3:
+                    print(pid, "  " * depth, "→", call)
+            elif re.match(function_return_probe, event):
+                try:
+                    call = pystack[pid].pop()
+                    depth = len(pystack[pid])
+                    if verbose >= 3:
+                        print(pid, "  " * depth, "←", call)
+                except:
+                    pass  # we may have missed some calls
+            elif re.match(take_probe, event):
                 wants_take_gil[pid] = time
                 scope = "t"  # thread scope
                 yield header, {"pid": parent_pid, "tid": pid, "ts": time, "name": 'take', "ph": "i", "cat": "GIL state", 's': scope, 'cname': 'bad'}
+                if has_gil:
+                    for blocking_pid in has_gil:
+                        if pystack[blocking_pid]:
+                            call = pystack[blocking_pid][-1]
+                            wait_for_stack[pid].append((blocking_pid, call, None))
+                        else:
+                            call = ('cpython', 'cpython', -1)
+                            wait_for_stack[pid].append((blocking_pid, call, None))
             elif re.match(take_probe_return, event):
                 if has_gil:
                     for other_pid in has_gil:
@@ -185,7 +215,9 @@ def gil2trace(input, verbose=1, take_probe="python:take_gil$", take_probe_return
                             # yield header, {"pid": parent_pid, "tid": other_pid, "ts": wants_drop_gil[other_pid], "dur": overlap_relaxed, "name": 'GIL overlap2', "ph": "X", "cat": "process state"}
                             # yield header, {"pid": parent_pid, "tid": pid, "ts": wants_drop_gil[other_pid], "dur": overlap_relaxed, "name": 'GIL overlap2', "ph": "X", "cat": "process state"}
                 has_gil[pid] = time
-                time_wait_gil[pid] += time - max(t_min[pid], wants_take_gil[pid])
+                has_gil_stack[pid] = pystack[pid].copy()
+                time_wait = time - max(t_min[pid], wants_take_gil[pid])
+                time_wait_gil[pid] += time_wait
             elif re.match(drop_probe, event):
                 wants_drop_gil[pid] = time
                 scope = "t"  # thread scope

per4m/probes.cpp

@@ -0,0 +1,9 @@
+#include <stdio.h>
+
+extern "C" void pytrace_function_entry(const char *filename, const char *funcname, int lineno, int what) {
+    // do nothing, so we can attach a probe here
+}
+
+extern "C" void pytrace_function_return(const char *filename, const char *funcname, int lineno, int what) {
+    // do nothing
+}

per4m/pytrace.cpp

@@ -0,0 +1,76 @@
+#include <Python.h>
+#include <frameobject.h>
+
+extern "C" void pytrace_function_entry(const char *filename,
+                                       const char *funcname, int lineno,
+                                       int what);
+extern "C" void pytrace_function_return(const char *filename,
+                                        const char *funcname, int lineno,
+                                        int what);
+
+int pytrace_trace(PyObject *obj, PyFrameObject *frame, int what,
+                  PyObject *arg) {
+  if ((what == PyTrace_CALL) || (what == PyTrace_C_CALL)) {
+    // simular to https://github.com/python/cpython/blob/master/Python/ceval.c
+    // dtrace_function_entry
+    const char *filename;
+    const char *funcname;
+    int lineno;
+
+    PyCodeObject *code = frame->f_code;
+    filename = PyUnicode_AsUTF8(code->co_filename);
+    funcname = PyUnicode_AsUTF8(code->co_name);
+    lineno = PyCode_Addr2Line(code, frame->f_lasti);
+
+    pytrace_function_entry(filename, funcname, lineno, what);
+  }
+  if ((what == PyTrace_RETURN) || (what == PyTrace_C_RETURN)) {
+    const char *filename;
+    const char *funcname;
+    int lineno;
+
+    PyCodeObject *code = frame->f_code;
+    filename = PyUnicode_AsUTF8(code->co_filename);
+    funcname = PyUnicode_AsUTF8(code->co_name);
+    lineno = PyCode_Addr2Line(code, frame->f_lasti);
+
+    pytrace_function_return(filename, funcname, lineno, what);
+  }
+  return 0;
+}
+
+static PyObject *pytrace_start(PyObject *obj, PyObject *args) {
+  PyEval_SetProfile(pytrace_trace, NULL);
+  // PyObject *threading_module = PyImport_ImportModule("threading");
+  // PyObject *threading_setprofile =
+  //     PyObject_GetAttrString(threading_module, "setprofile");
+  // Py_INCREF(Py_None);
+  // PyObject *pytrace_cfunction = PyCFunction_New(pytrace_trace, Py_None);
+  // PyObject *args = Py_BuildValue("(N)", pytrace_cfunction);
+  // PyObject_CallObject(setprofile, args);
+  // Py_DECREF(args);
+  Py_RETURN_NONE;
+}
+
+static PyObject *pytrace_stop(PyObject *obj, PyObject *args) {
+  PyEval_SetProfile(NULL, NULL);
+  Py_RETURN_NONE;
+}
+
+static PyMethodDef pytrace_methods[] = {
+    {"start", (PyCFunction)pytrace_start, METH_VARARGS, "start tracing"},
+    {"stop", (PyCFunction)pytrace_stop, METH_VARARGS, "stop tracing"},
+    {NULL, NULL, 0, NULL}};
+
+static struct PyModuleDef pytrace_module = {
+    PyModuleDef_HEAD_INIT, "per4m.pytrace", NULL, -1, pytrace_methods};
+
+PyMODINIT_FUNC PyInit_pytrace(void) {
+  PyObject *m = PyModule_Create(&pytrace_module);
+
+  if (!m) {
+    return NULL;
+  }
+
+  return m;
+}

setup.py

@@ -1,20 +1,25 @@
-from setuptools import setup, find_packages
+from setuptools import setup, find_packages, Extension
 author = "Maarten A. Breddels"
 author_email = "maartenbreddels@gmail.com"
 license = 'MIT'
 url = 'https://www.github.com/maartenbreddels/per4m'
 
+# add debug, and use O1 to avoid inlining
+extra_compile_args = ["-g", "-O1"]
+
 setup(
     author=author,
     author_email=author_email,
     name='per4m',
-    description = "Profiling and tracing information for Python using viztracer and perf, the GIL exposed.",
+    description="Profiling and tracing information for Python using viztracer and perf, the GIL exposed.",
     # version='0.1',
     url=url,
     packages=['per4m'],
     license=license,
     use_scm_version=True,
     setup_requires=['setuptools_scm'],
+    ext_modules=[Extension("per4m.pytrace", ["per4m/pytrace.cpp", "per4m/probes.cpp"],
+                          extra_compile_args=extra_compile_args)],
     entry_points={
         'console_scripts': [
             'per4m = per4m.__main__:main',