Intro
Я пишу приложение на Python, которое использует библиотеку, написанную на C. Когда происходит какое-то событие на уровне C, используется обратный вызов Python.
Вотчасть моего определения обратного вызова python:
def callback(str1, str2, cdata, flag):
print("PYTHON HANDLER")
...
print(">>EXIT<<")
Перед передачей обратного вызова в C он конвертируется с использованием этого кода:
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
После этого py_callback_ptr передается в библиотеку C и сохраняется там как указатель (void *).
Когда происходит событие C, вызывается уровень py_callback_ptr .Вот фрагмент кода, который делает это на уровне C:
...
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");
...
Большую часть времени он работает, как ожидалось, и вызывается обратный вызов.Я получаю этот вывод в stdout:
...
Acquire GIL
Callback()
PYTHON HANDLER
>>EXIT<<
Callback return
Release GIL
...
Но иногда я получаю этот вывод, смешанный с выводом stderr.Он показывает мне, что код C вокруг обратного вызова выполнялся нормально, но сам обратный вызов не выполнялся:
...
Acquire GIL
Callback()
SystemError: null argument to internal routine # from stderr
Callback return
Release GIL
...
Исследование
Я искал SystemError в Python и нашел объяснение
Возникает, когда переводчик обнаруживает внутреннюю ошибку, но ситуация не выглядит настолько серьезной, чтобы заставить его отказаться от всякой надежды.Связанное значение представляет собой строку, указывающую, что пошло не так (в терминах низкого уровня).
Так что это ошибка, обнаруженная в коде интерпретатора, который записывает в stderr некоторую строку.Я решил перехватить этот вызов и исследовать его.
Отладка
Я пытался отловить эту ошибку в GDB.Я установил точку останова, которая останавливает выполнение программы на выводе stderr с помощью этой команды:
(gdb) b write if 2==$rdi
Также обнаружен обратный след нормального выполнения обратного вызова.Вот они.
Часть обычной трассировки:
#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
Обратная трассировка с ошибкой обратного вызова:
#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
Предварительные выводы
Кажется, чтоАргументы преобразователи и вызываемые _CallPythonObject не в порядке (изменены или повреждены по какой-то причине).
кадр 42 от обычной обратной трассировки.Нормальные значения и обратный вызов вызваны.
#42 0x00007ffff4d54d2c in _CallPythonObject (pArgs=<optimized out>, flags=257,
converters=0x7ffff656a908, callable=0x7ffff4f9eea0, setfunc=0x0,
restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20)
кадр 30 от ошибки возврата.Нулевые значения и обратный вызов отменены.
#30 0x00007ffff4d54e8e in _CallPythonObject (pArgs=0x7ffff3917a80, flags=4353,
converters=0x0, callable=0x0, setfunc=0x0,
restype=0x7ffff4f631d0 <ffi_type_void>, mem=0x7ffff3917c20)
Может кто-нибудь помочь с решением этой проблемы или предложить способ дальнейшего поиска и отладки?