Prior to version r151034, the Python versions shipped with OmniOS included a patch which added support for a small number of dtrace probes around function entry and exit, and also a dtrace ustack helper. A ustack helper allows a stack trace examined in the context of a dtrace probe to be annotated with useful information; in the case of python, information about the python program stack.

When dtrace support was integrated into the official cpython release of Python, in version 3.6, the ustack helper was omitted. This meant that when OmniOS upgraded to Python 3.7 along with the move to using the built-in dtrace support, the ustack helper was no longer available. We recently revisited this and have just completed restoring the feature to Python 3.10 in OmniOS bloody, which will be the basis for the next stable release in May 2022. This is mostly derived from the original Solaris patch for python 3.5. The python patch for OmniOS is being maintained in a github branch.

We have opted to include this in a separate debug variant of the package since there are some performance overheads in providing the helper, even if it is not used. For it to work reliably, python itself needs to be built without optimisations, every loaded module needs to have a second copy of the line number information stored in a format that is usable by dtrace, and every function call needs to go through another stack frame to ensure that the necessary information ends up on the stack in a place that dtrace can find it. There’s a little more on this in John Levon’s blog post on the original python dtrace implementation.

As an example, I was recently debugging a problem with the OmniOS packaging system unexpectedly removing a directory. Reaching for dtrace to check when the rmdir system call is used is not particularly helpful since you only see the stack trace from the cpython process.

% pfexec dtrace -n 'syscall::rmdir:entry{trace(copyinstr(arg0));jstack()}' \
    -c 'pkg image-create -f /tmp/testimg'

  1  246  rmdir:entry   /tmp/testimg/.org.opensolaris,pkg/publisher`_syscall6+0x1b`os_rmdir+0x102`cfunction_vectorcall_FASTCALL_KEYWORDS+0x61`_PyEval_EvalFrameDefault+0x57b4`_PyEval_Vector+0x45`_PyEval_EvalFrameDefault+0x57b4`_PyEval_Vector+0x45`method_vectorcall+0x8c`_PyEval_EvalFrameDefault+0x1663`_PyEval_Vector+0x45`_PyObject_FastCallDictTstate+0x108`_PyObject_Call_Prepend+0x73`slot_tp_init+0x89`type_call+0x10b`_PyObject_MakeTpCall+0x126`_PyEval_EvalFrameDefault+0x6030`_PyEval_Vector+0x45`_PyEval_EvalFrameDefault+0x1663`_PyEval_Vector+0x45`_PyEval_EvalFrameDefault+0x3ef`_PyEval_Vector+0x45`_PyEval_EvalFrameDefault+0x30b0`_PyEval_Vector+0x45`_PyEval_EvalFrameDefault+0x3ef`_PyEval_Vector+0x45`PyEval_EvalCode+0x96`run_eval_code_obj+0x56`run_mod+0x6d`pyrun_file+0x81`_PyRun_SimpleFileObject+0x395`_PyRun_AnyFileObject+0x8b`Py_RunMain+0x3d6`Py_BytesMain+0x3c

With this new update, the debug python variant with the ustack helper can easily be switched in.

% pfexec pkg change-variant debug.python=true
            Packages to change:  1
     Variants/Facets to change:  1
       Create boot environment: No
Create backup boot environment: No

DOWNLOAD                                PKGS         FILES    XFER (MB)   SPEED
Completed                                1/1     2556/2556    14.5/14.5      --

PHASE                                          ITEMS
Installing new actions                           2/2
Updating modified actions                  2554/2554
Updating package state database                 Done
Updating package cache                           0/0
Updating image state                            Done
Creating fast lookup database                   Done
Reading search index                            Done
Building new search index                    689/689

and now the same stack trace is annotated with the python program information (the indented parts shown in square brackets).

 10  246  rmdir:entry   /tmp/testimg/.org.opensolaris,pkg/publisher`_syscall6+0x1b`os_rmdir+0x282`cfunction_vectorcall_FASTCALL_KEYWORDS+0x5b`_PyEval_EvalFrameDefaultReal+0xaf11
     [ /usr/lib/python3.10/ (rmtree) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyEval_EvalFrameDefaultReal+0xaf11
     [ /usr/lib/python3.10/vendor-packages/pkg/client/ (__set_dirs) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`method_vectorcall+0x185`_PyEval_EvalFrameDefaultReal+0x6dd2
     [ /usr/lib/python3.10/vendor-packages/pkg/client/ (__init__) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyObject_FastCallDictTstate+0xfa`_PyObject_Call_Prepend+0x112`slot_tp_init+0xd9`type_call+0x8f`_PyObject_MakeTpCall+0xa1`_PyEval_EvalFrameDefaultReal+0x9db5
     [ /usr/lib/python3.10/vendor-packages/pkg/client/ (image_create) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyEval_EvalFrameDefaultReal+0x6dd2
     [ /usr/bin/pkg:6284 (image_create) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyEval_EvalFrameDefaultReal+0x756f
     [ /usr/bin/pkg:8042 (main_func) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyEval_EvalFrameDefaultReal+0x5326
     [ /usr/bin/pkg:6191 (handle_errors) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`_PyEval_EvalFrameDefaultReal+0x756f
     [ /usr/bin/pkg:8182 (<module>) ]`_PyEval_EvalFrameDefault+0x1c`_PyEval_Vector+0x48`PyEval_EvalCode+0x91`run_eval_code_obj+0x54`run_mod+0x6c`pyrun_file+0x80`_PyRun_SimpleFileObject+0x124`_PyRun_AnyFileObject+0x44`Py_RunMain+0x451`Py_BytesMain+0x57

Here are those lines extracted, and it’s easy to see that the place to start looking is around line 1971 in the __set_dirs function of

[ /usr/lib/python3.10/ (rmtree) ]
[ /usr/lib/python3.10/vendor-packages/pkg/client/ (__set_dirs) ]
[ /usr/lib/python3.10/vendor-packages/pkg/client/ (__init__) ]
[ /usr/lib/python3.10/vendor-packages/pkg/client/ (image_create) ]
[ /usr/bin/pkg:6284 (image_create) ]
[ /usr/bin/pkg:8042 (main_func) ]
[ /usr/bin/pkg:6191 (handle_errors) ]
[ /usr/bin/pkg:8182 (<module>) ]

To switch back to the production version of python:

% pfexec pkg change-variant debug.python=false