exception traceback is not readable

[yanghao]

Recently realized that when calling python code from c++ code, and if there is an exception in python code, the resulting callback trace is difficult to read, something looks like this below. is there any better way to handle those kinds of situations?

cppyy version: 2.3.1 os: ubuntu 20.04

 0x00007f9772f1c01a in <unknown function>
 0x00007f977539280e in <unknown> from /home/yanghao/.local/lib/python3.10/site-packages/cppyy_backend/lib/libcppyy_backend.so
 0x00007f9775392f56 in Cppyy::CallI(long, void*, unsigned long, void*) at /tmp/pip-install-3ao4nili/cppyy-backend_42275ed3a4264c37a131855a602247fc/src/clingwrapper.cxx:883 from /home/yanghao/.local/lib/python3.10/site-packages/cppyy_backend/lib/libcppyy_backend.so
 0x00007f97730f1a14 in <unknown> from /home/yanghao/.local/lib/python3.10/site-packages/libcppyy.cpython-310-x86_64-linux-gnu.so
 0x00007f97730c5909 in CPyCppyy::CPPMethod::ExecuteFast(void*, long, CPyCppyy::CallContext*) at /tmp/pip-install-j77oxc6s/cpycppyy_b68a51eb46c747c392a0fad26a49ce1e/src/CPPMethod.cxx:187 from /home/yanghao/.local/lib/python3.10/site-packages/libcppyy.cpython-310-x86_64-linux-gnu.so
 0x00007f97730c4225 in CPyCppyy::CPPMethod::Execute(void*, long, CPyCppyy::CallContext*) at /tmp/pip-install-j77oxc6s/cpycppyy_b68a51eb46c747c392a0fad26a49ce1e/src/CPPMethod.cxx:858 from /home/yanghao/.local/lib/python3.10/site-packages/libcppyy.cpython-310-x86_64-linux-gnu.so
 0x00007f97730befbf in CPyCppyy::CPPFunction::Call(CPyCppyy::CPPInstance*&, _object* const*, unsigned long, _object*, CPyCppyy::CallContext*) at /tmp/pip-install-j77oxc6s/cpycppyy_b68a51eb46c747c392a0fad26a49ce1e/src/CPPFunction.cxx:89 from /home/yanghao/.local/lib/python3.10/site-packages/libcppyy.cpython-310-x86_64-linux-gnu.so
 0x00007f97730c96ff in <unknown> from /home/yanghao/.local/lib/python3.10/site-packages/libcppyy.cpython-310-x86_64-linux-gnu.so
 0x000055cdd165691d in _PyEval_EvalFrameDefault + 0x33d from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd1740a84 in <unknown> from python3
 0x000055cdd16a49de in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd1656c5f in _PyEval_EvalFrameDefault + 0x67f from python3
 0x000055cdd16555d6 in <unknown> from python3
 0x000055cdd165691d in _PyEval_EvalFrameDefault + 0x33d from python3
 0x000055cdd1654f04 in <unknown> from python3
 0x000055cdd16f54af in PyEval_EvalCode + 0x8f from python3
 0x000055cdd1709b39 in <unknown> from python3
 0x000055cdd1709ac4 in <unknown> from python3
 0x000055cdd1575d16 in <unknown> from python3
 0x000055cdd170a1b4 in _PyRun_SimpleFileObject + 0x1b4 from python3
 0x000055cdd1709fe7 in _PyRun_AnyFileObject + 0x47 from python3
 0x000055cdd16c88ba in Py_RunMain + 0x39a from python3
 0x000055cdd16c839d in Py_BytesMain + 0x3d from python3
 0x00007f977a6a80b3 in __libc_start_main + 0xf3 from /lib/x86_64-linux-gnu/libc.so.6
 0x000055cdd16c829e in _start + 0x2e from python3

[wlav]

That doesn't look like a Python exception coming from Python code called from C++ code, but more like a segfault in said C++ code. You can try enabling the debug flag: export EXTRA_CLING_ARGS=-g, but debug symbols (and thus traceback) don't play nice with the JIT yet (WIP). The upshot being that resolving symbols from JITted code isn't possible, so the traceback doesn't show the actual C++ function called.

Now, if there were a Python exception it should trace through the C++ code back into Python just fine. Example:

import cppyy

cppyy.cppdef("""
void callit(void (*f)()) {
   std::cerr << "in C++" << std::endl;
   f();
}""")

def raises():
    print("in Python")
    raise RuntimeError("failed")

cppyy.gbl.callit(raises)

which for me results in:

in C++
in Python
Traceback (most recent call last):
  File "pyexc.py", line 13, in <module>
    cppyy.gbl.callit(raises)
RuntimeError: void ::callit(void(*)() f) =>
    RuntimeError: failed

[yanghao]

Thanks for the quick response.

The C++ code used in my case is pre-compiled, so I guess that's the reason why the extra flag of "-g" does not make a difference in my case. I am sure the exception is not in C++ code but in python is that I intentionally injected a "raise Exception("...")" statement. So the calling flow is something like this:

1. python register c++ callback, the callback is a python function. the python function had a raise Exception() statement.
2. python triggers c++ code to run
3. python callback is invoked from c++ code
4. unreadable traceback displayed.

Let me try to work out a small enough example that can produce similar things and share it with you.

[yanghao]

@wlav I tried to replicate the flow in a simple program but failed to reproduce the issue, still getting nice readable trackbacks all the time. I also did a few experiments and it looks like whenever you have an exception in python, the next line of the C code is not reached. All I did to reproduce the issue in my full-blown program is to add a simple raise Exception("") in the python callback code. However I do see something like this preceeding the non-readable-traceback:

*** Break *** abort

So I converted my program to a C++ program and used a try-catch to handle all exceptions in C++ and voila, can reproduce the problem.

So now the question is: if I got some C++ library as a black-box and I cannot change it, would there be a better way to debug it ? Is there any way for not letting C++ catch python exceptions, so cppyy can handle it properly? If those are not possible, what can be done in the C++ exception handling code that could let the python exception to propogate through back to python/cppyy?

Attaching the code below.

test.cpp:

#include <cstdio>
int (*gf)(int, int);

void add(int (*func)(int, int))
{
    gf = func;
}

int f(void)
{
    int r;
    try {
        r = gf(5, 8);
    } catch (...) {
        printf("can still be reached!\n");
        int x = *((int *)0);
    }
    return r;
}

test.h

int add(int (*func)(int, int));
int f(void);

Makefile:

all:
        g++ -shared -fPIC -o test.so test.c
        strip --strip-all test.so

run:
        python3 test.py

test.py:

from cppyy import gbl as cpp
from cppyy import cppdef, load_library, include

def func(a, b):
    raise Exception("wrong ...")
    return a + b

load_library("./test.so")
include("test.h")

cpp.add(func)
r = cpp.f()
print("result:", r)

[wlav]

I'm not 100% sure I'm following you ... If you add in the above -g to command g++ -shared -fPIC -o test.so test.c, don't you get the C++ function:

#9  0x00007fca404f11de in f() () from /home/wlav/cppyy-dev/test.so

so that's working as it should?

Is there any way for not letting C++ catch python exceptions, so cppyy can handle it properly?

Just to be sure we're talking about the same thing: Python exceptions are a thread-local state, not a rollback mechanism like C++ exceptions, hence there is no such thing as C++ handling Python exceptions. What happens is that on exceptional return from the callback, CPyCppyy will raise a "magic" C++ exception to do the necessary rollbacks to reach the outermost layer before returning to Python, then report the Python exception.

From the description I get so far, it is then during that rollback that there is a crash? E.g. the destructor of an object on the stack? Note that if there is a segfault because of that reason, technically all bets are off: the program is now in a corrupted state and maybe something will work, maybe not.

Best at that point, and solely for debugging purposes, is to jump out from the segfault handler back to the outermost layer. This then does not involve any exceptions (it's a longjmp). You can enable that with:

import cppyy.ll
cppyy.ll.set_signals_as_exception(True)

See: https://cppyy.readthedocs.io/en/latest/debugging.html .

However, that will replace the original Python exception, so the traceback only points to the place where the call started in Python (here: cpp.f()).

I've change the code in repo to now first check for Python exceptions outstanding and print them, if any, before setting the exception reporting the segfault. So now the report looks like this (with set_signals_as_exception(True) added):

can still be reached!
 *** Break *** segmentation violation
...
#9  0x00007f0787a7f1de in f() () from /home/wlav/cppyy-dev/test.so
...
#31 0x00000000005fa5ce in _start ()
Python exception outstanding during C++ longjmp:
Traceback (most recent call last):
  File "test.py", line 9, in func
    raise Exception("wrong ...")
Exception: wrong ...

Traceback (most recent call last):
  File "test.py", line 16, in <module>
    r = cpp.f()
cppyy.ll.SegmentationViolation: int ::f() =>
    SegmentationViolation: segfault in C++; program state was reset

Note that checking for a Python exception and printing it is not without pitfalls after a segfault.

With that, for me anyway, there is now the traceback through Python onto the point where C++ was entered, the C++ trace including the library function where the problem occurred, the fact that it was a segfault, and the last exception seen from Python before handling the segfault.

Aside, it is actually safe to always run with set_signals_as_exception(True), just that it incurs a performance penalty, which is why it's not enabled by default.

[yanghao]

Just to be sure we're talking about the same thing: Python exceptions are a thread-local state, not a rollback mechanism like C++ exceptions, hence there is no such thing as C++ handling Python exceptions. What happens is that on exceptional return from the callback, CPyCppyy will raise a "magic" C++ exception to do the necessary rollbacks to reach the outermost layer before returning to Python, then report the Python exception.

You are right, I do not really understands how C++ seemingly captured Python exceptions, but that for me is more a symptom rather than understanding how it actually works. But still, cppyy raises an C++ exception, and C++ captured that C++ exception. Thanks for clarifying on this.

I've change the code in repo to now first check for Python exceptions outstanding and print them, if any, before setting the exception reporting the segfault. So now the report looks like this (with set_signals_as_exception(True) added):

can still be reached!
 *** Break *** segmentation violation
...
#9  0x00007f0787a7f1de in f() () from /home/wlav/cppyy-dev/test.so
...
#31 0x00000000005fa5ce in _start ()
Python exception outstanding during C++ longjmp:
Traceback (most recent call last):
  File "test.py", line 9, in func
    raise Exception("wrong ...")
Exception: wrong ...

Traceback (most recent call last):
  File "test.py", line 16, in <module>
    r = cpp.f()
cppyy.ll.SegmentationViolation: int ::f() =>
    SegmentationViolation: segfault in C++; program state was reset

This is really wonderful! Thank you! I am looking forward to see it in the next release, maybe in 2.3.2? :-)

Aside, it is actually safe to always run with set_signals_as_exception(True), just that it incurs a performance penalty, which is why it's not enabled by default.

Noticed and thanks!

[wlav]

Yes, it'll appear in 2.3.2, but you can also build from source, see: https://cppyy.readthedocs.io/en/latest/repositories.html#building-from-source-1 where you only need to checkout CPyCppyy and build/install (see at the bottom of the linked text).

[yanghao]

@wlav , thanks. Which change/commit was it that enabled the python traceback prints? Also want to learn a bit of cppyy internals.

Nevermind, found it. :-)

[wlav]

Which change/commit was it that enabled the python traceback prints?

It's not a traceback: that one is always at the end. The extra printout is the outstanding exception when entering back into C++ the first time. It's probably possible to collect a traceback of the Python calls through several layers of C++ and Python, but not (currently) the C++ calls as these originate from JITed wrapper calls w/o debugging information (the wrapper calls themselves could be tracked and reported, but would be incomplete).

In any case, the commit is here: https://github.com/wlav/CPyCppyy/commit/ba831422388afde06d6a5fb33a7a5b865a5f050c

[yanghao]

Thanks for the explanation. the outstanding exception information is helping a lot to work with buggy shared libraries :-)