1

Intro

I'm writing a python application which uses a library written in C. When some event occurred at C level a Python callback is used to be called.

Here is a part of my python callback definition:

def callback(str1, str2, cdata, flag):
  print("PYTHON HANDLER")
  ...
  print(">>EXIT<<")

Before passing callback to C it is converted using this code:

FuncType = ctypes.CFUNCTYPE(None, ctypes.c_char_p, ctypes.c_char_p,
                            ctypes.c_void_p, ctypes.c_bool)

ctype_function_wrapper = FuncType(callback)
cfunction_pointer = ctypes.cast(ctype_function_wrapper, ctypes.c_void_p)
py_callback_ptr = cfunction_pointer.value

After that py_callback_ptr is passed to C library and saved there as a (void *) pointer.

When an event occurs C level py_callback_ptr is called. Here is a piece of code which does this at C level:

...
printf("Acquire GIL\r\n");
PyGILState_STATE gstate;
gstate = PyGILState_Ensure();
printf("Callback()\r\n");
((void (*)(char*, char*, DataStructure*, bool))py_callback_ptr)(
    str1, str2, value, bool_flag);
printf("Callback return\r\n");
PyGILState_Release(gstate);
printf("Release GIL\r\n");
...

Most of the time it works as expected and callback is called. I get this output in stdout:

...
Acquire GIL
Callback()
PYTHON HANDLER
>>EXIT<<
Callback return
Release GIL
...

But some times I get this output mixed with stderr output. It shows me that C code around callback executed normally but callback itself didn't executed:

...
Acquire GIL
Callback()
SystemError: null argument to internal routine      # from stderr
Callback return
Release GIL
...

Research

I have looked for SystemError in Python and found the explanation

Raised when the interpreter finds an internal error, but the situation does not look so serious to cause it to abandon all hope. The associated value is a string indicating what went wrong (in low-level terms).

So this is error caught in interpreter code which writes to stderr some string. I decided to catch that call and investigate it.

Debugging

I have tried to catch this error in gdb. I have set up a breakpoint which stops program execution on stderr output using this command:

(gdb) b write if 2==$rdi

Also a have caught backtrace of normal callback execution. Here they are.

Part of normal backtrace:

#0  write () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000000000437735 in _Py_write_impl (gil_held=1, count=4, buf=<optimized out>, fd=2) at Python/fileutils.c:1331
#2  _Py_write (fd=2, buf=0x961100, count=<optimized out>) at Python/fileutils.c:1393
#3  0x00000000005b73ce in _io_FileIO_write_impl (b=0x7ffff3916b00, b=0x7ffff3916b00, self=0x7ffff7f0c3a8) at ./Modules/_io/fileio.c:857
#4  _io_FileIO_write (self=0x7ffff7f0c3a8, arg=<optimized out>) at ./Modules/_io/clinic/fileio.c.h:251
#5  0x00000000004aa139 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9d828, args=args@entry=0x7ffff3916c40, nargs=nargs@entry=1, kwargs=kwargs@entry=0x0) at Objects/methodobject.c:209
#6  0x0000000000451b68 in _PyObject_FastCallDict (func=0x7ffff4f9d828, args=0x7ffff3916c40, nargs=1, kwargs=0x0) at Objects/abstract.c:2313
#7  0x0000000000452b86 in PyObject_CallMethodObjArgs (callable=0x7ffff4f9d828, name=<optimized out>) at Objects/abstract.c:2759
#8  0x00000000005bb24a in _bufferedwriter_raw_write (self=self@entry=0x7ffff7fd0b48, start=<optimized out>, len=4) at ./Modules/_io/bufferedio.c:1853
#9  0x00000000005bbd0f in _bufferedwriter_flush_unlocked (self=self@entry=0x7ffff7fd0b48) at ./Modules/_io/bufferedio.c:1898
#10 buffered_flush_and_rewind_unlocked (self=self@entry=0x7ffff7fd0b48) at ./Modules/_io/bufferedio.c:827
#11 0x00000000005bbf27 in buffered_flush (self=0x7ffff7fd0b48, args=<optimized out>) at ./Modules/_io/bufferedio.c:854
#12 0x00000000004aa1ff in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9d5a0, args=args@entry=0x7ffff3916f30, nargs=nargs@entry=0, kwargs=kwargs@entry=0x0) at Objects/methodobject.c:192
#13 0x0000000000451b68 in _PyObject_FastCallDict (func=0x7ffff4f9d5a0, args=0x7ffff3916f30, nargs=0, kwargs=0x0) at Objects/abstract.c:2313
#14 0x0000000000452b86 in PyObject_CallMethodObjArgs (callable=0x7ffff4f9d5a0, name=<optimized out>) at Objects/abstract.c:2759
#15 0x00000000005c1924 in _io_TextIOWrapper_write_impl (text=0x7ffff7f30a40, self=0x7ffff7f7d708) at ./Modules/_io/textio.c:1367
#16 _io_TextIOWrapper_write (self=0x7ffff7f7d708, arg=<optimized out>) at ./Modules/_io/clinic/textio.c.h:216
#17 0x00000000004aa139 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9d5e8, args=args@entry=0x7ffff3917148, nargs=nargs@entry=1, kwargs=kwargs@entry=0x0) at Objects/methodobject.c:209
#18 0x0000000000451b68 in _PyObject_FastCallDict (func=func@entry=0x7ffff4f9d5e8, args=args@entry=0x7ffff3917148, nargs=nargs@entry=1, kwargs=kwargs@entry=0x0) at Objects/abstract.c:2313
#19 0x000000000047a4cc in PyFile_WriteObject (flags=1, f=<optimized out>, v=0x7ffff7f30a40) at Objects/fileobject.c:150
#20 PyFile_WriteString (s=s@entry=0x5e4ac5 "\n", f=<optimized out>) at Objects/fileobject.c:174
#21 0x000000000053b103 in builtin_print (self=<optimized out>, args=0x7ffff65df748, kwds=<optimized out>) at Python/bltinmodule.c:1814
#22 0x00000000004aa3d9 in PyCFunction_Call (func=func@entry=0x7ffff7fcdf30, args=args@entry=0x7ffff65df748, kwds=kwds@entry=0x7ffff4f9d8b8) at Objects/methodobject.c:98
#23 0x0000000000548572 in do_call_core (kwdict=0x7ffff4f9d8b8, callargs=0x7ffff65df748, func=0x7ffff7fcdf30) at Python/ceval.c:5116
#24 _PyEval_EvalFrameDefault (f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3404
#25 0x000000000053f401 in PyEval_EvalFrameEx (throwflag=0, f=0x7ffff4fa1048) at Python/ceval.c:754
#26 _PyEval_EvalCodeWithName (_co=0x7ffff7f089c0, globals=globals@entry=0x7ffff7f4c360, locals=locals@entry=0x0, args=<optimized out>, argcount=1, kwnames=0x0, kwargs=kwargs@entry=0x7ffff7ed4d60, kwcount=0, kwstep=kwstep@entry=1, 
    defs=0x0, defcount=defcount@entry=0, kwdefs=0x0, closure=0x0, name=name@entry=0x7ffff7f0f3b0, qualname=0x7ffff7f0f3b0) at Python/ceval.c:4166
#27 0x000000000053f6ff in fast_function (kwnames=0x0, nargs=<optimized out>, stack=<optimized out>, func=0x7ffff7f36e18) at Python/ceval.c:4992
#28 call_function (pp_stack=pp_stack@entry=0x7ffff3917550, oparg=<optimized out>, kwnames=kwnames@entry=0x0) at Python/ceval.c:4872
#29 0x000000000054138b in _PyEval_EvalFrameDefault (f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3335
#30 0x000000000053e791 in PyEval_EvalFrameEx (throwflag=0, f=0x7ffff7ed4bb8) at Python/ceval.c:754
#31 _PyFunction_FastCall (co=<optimized out>, args=<optimized out>, nargs=4, globals=globals@entry=0x7ffff7f4c360) at Python/ceval.c:4933
#32 0x000000000053f927 in fast_function (kwnames=0x0, nargs=<optimized out>, stack=<optimized out>, func=0x7ffff4f9ed08) at Python/ceval.c:4968
#33 call_function (pp_stack=pp_stack@entry=0x7ffff3917770, oparg=<optimized out>, kwnames=kwnames@entry=0x0) at Python/ceval.c:4872
#34 0x000000000054138b in _PyEval_EvalFrameDefault (f=<optimized out>, throwflag=<optimized out>) at Python/ceval.c:3335
#35 0x000000000053f401 in PyEval_EvalFrameEx (throwflag=0, f=0x7ffff4fa0048) at Python/ceval.c:754
#36 _PyEval_EvalCodeWithName (_co=0x7ffff65d0810, globals=<optimized out>, locals=locals@entry=0x0, args=args@entry=0x7ffff6569330, argcount=4, kwnames=kwnames@entry=0x0, kwargs=kwargs@entry=0x0, kwcount=kwcount@entry=0, 
    kwstep=kwstep@entry=2, defs=defs@entry=0x0, defcount=defcount@entry=0, kwdefs=kwdefs@entry=0x0, closure=closure@entry=0x7ffff7e9e208, name=name@entry=0x0, qualname=qualname@entry=0x0) at Python/ceval.c:4166
#37 0x00000000005401dd in PyEval_EvalCodeEx (_co=<optimized out>, globals=<optimized out>, locals=locals@entry=0x0, args=args@entry=0x7ffff6569330, argcount=<optimized out>, kws=kws@entry=0x0, kwcount=kwcount@entry=0, 
    defs=defs@entry=0x0, defcount=defcount@entry=0, kwdefs=0x0, closure=0x7ffff7e9e208) at Python/ceval.c:4187
#38 0x000000000048101c in function_call (func=0x7ffff4f9eea0, arg=0x7ffff6569318, kw=0x0) at Objects/funcobject.c:604
#39 0x0000000000451820 in PyObject_Call (func=0x7ffff4f9eea0, args=args@entry=0x7ffff6569318, kwargs=<optimized out>) at Objects/abstract.c:2261
#40 0x0000000000540696 in PyEval_CallObjectWithKeywords (func=func@entry=0x7ffff4f9eea0, args=args@entry=0x7ffff6569318, kwargs=kwargs@entry=0x0) at Python/ceval.c:4771
#41 0x00000000004516e7 in PyObject_CallObject (o=o@entry=0x7ffff4f9eea0, a=a@entry=0x7ffff6569318) at Objects/abstract.c:2187
#42 0x00007ffff4d54d2c in _CallPythonObject (pArgs=<optimized out>, flags=257, converters=0x7ffff656a908, callable=0x7ffff4f9eea0, setfunc=0x0, restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20)
    at /home/ns-sergeev/.pythons/src/Python-3.6.8/Modules/_ctypes/callbacks.c:234
#43 closure_fcn (cif=<optimized out>, resp=0x7ffff3917c20, args=0x7ffff3917a80, userdata=<optimized out>) at /home/ns-sergeev/.pythons/src/Python-3.6.8/Modules/_ctypes/callbacks.c:296
#44 0x00007ffff4b42a6b in ffi_closure_unix64_inner (closure=0x7ffff7ff2010, rvalue=0x7ffff3917c20, reg_args=0x7ffff3917b70, argp=0x7ffff3917c40 "P\r") at ../src/x86/ffi64.c:667
#45 0x00007ffff4b42de4 in ffi_closure_unix64 () at ../src/x86/unix64.S:229
...
C-library frames are omitted

Backtrace with callback call error:

#0  write () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000000000437735 in _Py_write_impl (gil_held=1, count=47, buf=<optimized out>, fd=2) at Python/fileutils.c:1331
#2  _Py_write (fd=2, buf=0x961100, count=<optimized out>) at Python/fileutils.c:1393
#3  0x00000000005b73ce in _io_FileIO_write_impl (b=0x7ffff3916e80, b=0x7ffff3916e80, self=0x7ffff7f0c3a8) at ./Modules/_io/fileio.c:857
#4  _io_FileIO_write (self=0x7ffff7f0c3a8, arg=<optimized out>) at ./Modules/_io/clinic/fileio.c.h:251
#5  0x00000000004aa139 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9e7e0, args=args@entry=0x7ffff3916fc0, nargs=nargs@entry=1, 
    kwargs=kwargs@entry=0x0) at Objects/methodobject.c:209
#6  0x0000000000451b68 in _PyObject_FastCallDict (func=0x7ffff4f9e7e0, args=0x7ffff3916fc0, nargs=1, kwargs=0x0) at Objects/abstract.c:2313
#7  0x0000000000452b86 in PyObject_CallMethodObjArgs (callable=0x7ffff4f9e7e0, name=<optimized out>) at Objects/abstract.c:2759
#8  0x00000000005bb24a in _bufferedwriter_raw_write (self=self@entry=0x7ffff7fd0b48, start=<optimized out>, len=47) at ./Modules/_io/bufferedio.c:1853
#9  0x00000000005bbd0f in _bufferedwriter_flush_unlocked (self=self@entry=0x7ffff7fd0b48) at ./Modules/_io/bufferedio.c:1898
#10 buffered_flush_and_rewind_unlocked (self=self@entry=0x7ffff7fd0b48) at ./Modules/_io/bufferedio.c:827
#11 0x00000000005bbf27 in buffered_flush (self=0x7ffff7fd0b48, args=<optimized out>) at ./Modules/_io/bufferedio.c:854
#12 0x00000000004aa1ff in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9e558, args=args@entry=0x7ffff39172b0, nargs=nargs@entry=0, 
    kwargs=kwargs@entry=0x0) at Objects/methodobject.c:192
#13 0x0000000000451b68 in _PyObject_FastCallDict (func=0x7ffff4f9e558, args=0x7ffff39172b0, nargs=0, kwargs=0x0) at Objects/abstract.c:2313
#14 0x0000000000452b86 in PyObject_CallMethodObjArgs (callable=0x7ffff4f9e558, name=<optimized out>) at Objects/abstract.c:2759
#15 0x00000000005c1924 in _io_TextIOWrapper_write_impl (text=0x7ffff7f30a40, self=0x7ffff7f7d708) at ./Modules/_io/textio.c:1367
#16 _io_TextIOWrapper_write (self=0x7ffff7f7d708, arg=<optimized out>) at ./Modules/_io/clinic/textio.c.h:216
#17 0x00000000004aa139 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff4f9e5a0, args=args@entry=0x7ffff39174c8, nargs=nargs@entry=1, 
    kwargs=kwargs@entry=0x0) at Objects/methodobject.c:209
#18 0x0000000000451b68 in _PyObject_FastCallDict (func=func@entry=0x7ffff4f9e5a0, args=args@entry=0x7ffff39174c8, nargs=nargs@entry=1, 
    kwargs=kwargs@entry=0x0) at Objects/abstract.c:2313
#19 0x000000000047a4cc in PyFile_WriteObject (flags=1, f=0x7ffff7f30a40, v=0x7ffff7f30a40) at Objects/fileobject.c:150
#20 PyFile_WriteString (s=s@entry=0x5e4ac5 "\n", f=f@entry=0x7ffff7f7d708) at Objects/fileobject.c:174
#21 0x0000000000425790 in print_exception (value=<optimized out>, f=0x7ffff7f7d708) at Python/pythonrun.c:819
#22 print_exception_recursive (f=f@entry=0x7ffff7f7d708, value=value@entry=0x7ffff4f9a1a8, seen=seen@entry=0x7ffff650ee48) at Python/pythonrun.c:891
---Type <return> to continue, or q <return> to quit---
#23 0x0000000000426683 in PyErr_Display (exception=<optimized out>, value=0x7ffff4f9a1a8, tb=<optimized out>) at Python/pythonrun.c:925
#24 0x000000000043199a in sys_excepthook (self=<optimized out>, args=<optimized out>) at ./Python/sysmodule.c:230
#25 0x00000000004aa1ac in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7ffff7f61f78, args=args@entry=0x7ffff39176c0, nargs=nargs@entry=3, 
    kwargs=kwargs@entry=0x0) at Objects/methodobject.c:234
#26 0x0000000000451b68 in _PyObject_FastCallDict (func=0x7ffff7f61f78, args=args@entry=0x7ffff39176c0, nargs=nargs@entry=3, kwargs=kwargs@entry=0x0)
    at Objects/abstract.c:2313
#27 0x00000000004267f5 in PyErr_PrintEx (set_sys_last_vars=set_sys_last_vars@entry=1) at Python/pythonrun.c:669
#28 0x0000000000426a9a in PyErr_Print () at Python/pythonrun.c:532
#29 0x00007ffff4d54b78 in PrintError (msg=msg@entry=0x7ffff4d5bc7a "BUG: PySequence_Length")
    at /home/ns-sergeev/.pythons/src/Python-3.6.8/Modules/_ctypes/callbacks.c:91
#30 0x00007ffff4d54e8e in _CallPythonObject (pArgs=0x7ffff3917a80, flags=4353, converters=0x0, callable=0x0, setfunc=0x0, 
    restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20) at /home/ns-sergeev/.pythons/src/Python-3.6.8/Modules/_ctypes/callbacks.c:149
#31 closure_fcn (cif=<optimized out>, resp=0x7ffff3917c20, args=0x7ffff3917a80, userdata=<optimized out>)
    at /home/ns-sergeev/.pythons/src/Python-3.6.8/Modules/_ctypes/callbacks.c:296
#32 0x00007ffff4b42a6b in ffi_closure_unix64_inner (closure=0x7ffff7ff0cc0, rvalue=0x7ffff3917c20, reg_args=0x7ffff3917b70, 
    argp=0x7ffff3917c40 "\240\021\243") at ../src/x86/ffi64.c:667
#33 0x00007ffff4b42de4 in ffi_closure_unix64 () at ../src/x86/unix64.S:229
...
C-library frames are omitted

Preliminary findings

It seems like arguments converters and callable of _CallPythonObject are not Ok (changed or corrupted by some reason).

frame 42 from normal backtrace. Normal values and callback called.

#42 0x00007ffff4d54d2c in _CallPythonObject (pArgs=<optimized out>, flags=257,
    converters=0x7ffff656a908, callable=0x7ffff4f9eea0, setfunc=0x0,
    restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20)

frame 30 from error backtrace. Zero values and callback abandoned.

#30 0x00007ffff4d54e8e in _CallPythonObject (pArgs=0x7ffff3917a80, flags=4353, 
    converters=0x0, callable=0x0, setfunc=0x0,
    restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20)

Can someone help with solving this issue or suggest a way to further dig and debug it?

Nick
  • 133
  • 1
  • 10
  • Maybe include how you are calling the callable? – Neijwiert Apr 19 '19 at 11:23
  • As in building the tuple/dictionary – Neijwiert Apr 19 '19 at 11:33
  • @Neijwiert I have added more code to explain how the callback is called. – Nick Apr 19 '19 at 12:30
  • @Neijwiert I can't understand your second commentary. Cound you explain it? – Nick Apr 19 '19 at 12:31
  • Ignore my second comment, I assumed wrongly how you were invoking the Python side of things. I don't really have knowledge about ctypes and callbacks, but I do know how you could call a function from your c code. Is there any particular reason why you are not getting an attribute (your python function) from the c side? – Neijwiert Apr 19 '19 at 12:40
  • @Neijwiert There must not be any reason because I have set callback at startup and just receiving events from C code. I'm not changing or updating the callback anyhow. – Nick Apr 19 '19 at 12:55
  • Let us [continue this discussion in chat](https://chat.stackoverflow.com/rooms/192107/discussion-between-nick-and-neijwiert). – Nick Apr 19 '19 at 13:01

1 Answers1

0

You should pass cfunction_pointer rather than py_callback_ptr = cfunction_pointer.value to your library.

Minimal working example:

cside.h:

#pragma once

#ifdef __cplusplus
extern "C" {
#endif

typedef struct DataStructure {
  int a;
} DataStructure;

typedef void (*callback)(char*, char*, DataStructure*, bool);

typedef void (*pcallback)(char*, char*, void*, bool);

int calc0(int, callback cb);

int calc1(int, pcallback cb);


#ifdef __cplusplus
}
#endif

Note, that you don't need to define the signature where DataStructure is replaced by void anywhere in the C code. I have included it anyway to use a cast like in your question.

cside.cpp:

#include "cside.h"
#include "Python.h"

const char cstring1[] = "foo";
const char cstring2[] = "bar";

const bool bool_flag = false;

char* str1 = const_cast<char*>(&cstring1[0]);
char* str2 = const_cast<char*>(&cstring2[0]);

int calc0(int k, callback cb) {
  printf("Acquire GIL\r\n");
  PyGILState_STATE gstate;
  gstate = PyGILState_Ensure();
  printf("Callback()\r\n");

  DataStructure s;

  // Execute callback with the signature known in C
  cb(str1, str2, &s, bool_flag);

  printf("Callback return\r\n");
  PyGILState_Release(gstate);
  printf("Release GIL\r\n");
  return k+2;
}

int calc1(int k, pcallback cb) {
  printf("Acquire GIL\r\n");
  PyGILState_STATE gstate;
  gstate = PyGILState_Ensure();
  printf("Callback()\r\n");

  DataStructure s;

  // Cast to correct signature
  ((void (*)(char*, char*, DataStructure*, bool))cb)(
      str1, str2, &s, bool_flag);

  printf("Callback return\r\n");
  PyGILState_Release(gstate);
  printf("Release GIL\r\n");
  return k+2;
}

To compile:

g++ -I. -fPIC -shared -o libcside.so cside.cpp -I/usr/include/python2.7 -lpython2.7

Test from within Python:

import ctypes

libc = ctypes.CDLL('libcside.so')

def callback(str1, str2, cdata, flag):
  print("PYTHON HANDLER")
  print(">>EXIT<<")

FuncType = ctypes.CFUNCTYPE(None, ctypes.c_char_p, ctypes.c_char_p,
                            ctypes.c_void_p, ctypes.c_bool)

ctype_function_wrapper = FuncType(callback)
cfunction_pointer = ctypes.cast(ctype_function_wrapper, ctypes.c_void_p)
py_callback_ptr = cfunction_pointer.value

libc.calc0(2, cfunction_pointer)
libc.calc1(2, cfunction_pointer)

#libc.calc(2, py_callback_ptr) # segfaults
Jens Munk
  • 4,627
  • 1
  • 25
  • 40
  • Thanks for your comprehensive answer! You said that you have segfaults when use py_callback_ptr. Do you always experience segfaults or just from time to time? – Nick Apr 22 '19 at 06:31
  • I can't use your example "as is" because SWIG wants me to pass to swig-wrapped-function parameters of exact types as they defined. So when I pass just cfunction_pointer to callback receiver function I see a message from SWIG "TypeError: in method 'CallbackSetter', argument 2 of type 'long'". I have tried to change callback parameter type to void* or to function declarartion (void (*)(char*, char*, DataStructure*, bool) but with no effect - SWIG always argues to "argument 2 doesn't match". while searching how to solve this issue I have found the "director" feature of SWIG. I'll try to use it. – Nick Apr 22 '19 at 07:10
  • With my setup, it always segfaults, but I can imagine you can have a situation, where it sometimes segfaults. I actually considered recommending you to use the `director` feature instead of `ctypes`. Another nice thing is to have SWIG generate an external runtime, you can use for converting objects to and from swig-wrapped objects. – Jens Munk Apr 22 '19 at 17:19