python: stream callback crash with segfault.

[bpinsard]

Describe the bug I tried setting a stream callback as a python function, following examples in C.

def stream_cb(user_data, type, buffer):
    if type == Aravis.StreamCallbackType.INIT:
        if not Aravis.make_thread_realtime(10) and \
            not Aravis.make_thread_high_priority(-10):
            print("Failed to make stream thread high priority")

and passing it to the stream as

stream=cam.create_stream(stream_cb, None)

However, my code crashes with segfault. I suppose this is due to the stream thread accessing to some of the main thread memory but I am not sure how to properly separate these. Thanks in advance for your help.

To Reproduce see above

Camera description:

• Manufacturer Fake
• Model Fake
• Interface [e.g. USB3] Ethernet

Platform description:

• Aravis version 0.8.5
• OS: Ubuntu 20
• Hardware x86_64

[EmmanuelP]

Could you attach a crash trace ?

[bpinsard]

The crash produce files in cysignals_crash_logs/ such as that one: crash_3rb4oas6.log Is it what you meant?

[EmmanuelP]

Is it what you meant?

Yes, thanks.

Unfortunately, it is mostly gibberish for me, I'm not used to debug crashes from python code.

If I'm not mistaken, make_thread_realtime and make_thread_high_priority should be thread safe.

Did you try to test with just make_thread_realtime, then just make_thread_high_priority ?

[EmmanuelP]

Oups, I did not meant to close this issue.

[bpinsard]

I even tried a function that does nothing (just return) and it crashes the same, so it is likely due to python.

[bpinsard]

If you want to reproduce here is what to run in python:

import gi 
gi.require_version('Aravis', '0.8') 
from gi.repository import Aravis 
uid="Aravis-Fake-GV01" 
cam = Aravis.Camera.new(uid) 
def cb(user_data, cb_type, buffer): 
    print(user_data, cb_type, buffer) 
stream=cam.create_stream(cb, None) 
payload = cam.get_payload() 
stream.push_buffer(Aravis.Buffer.new_allocate(payload)) 
cam.start_acquisition()                                                         

Which should produce the following output and crash, it crashes when pushing a buffer or sometimes when starting the acquisition.

[GvStream::stream_new] Destination stream port = 53532
[GvStream::stream_new] Source stream port = 0
[GvStream::stream_thread] Packet timeout = 40 ms
[GvStream::stream_thread] Frame retention = 200 ms
[GvStream::loop] Standard socket method

Segmentation fault (core dumped)  

[bpinsard]

Here is gdb info after crash:

(gdb) info threads 
  Id   Target Id                                          Frame 
  1    Thread 0x7ffff7bdb740 (LWP 601197) "python3"       0x00007ffff7ebf12b in __GI___select (nfds=nfds@entry=0, readfds=readfds@entry=0x0, 
    writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7fffffffd370) at ../sysdeps/unix/sysv/linux/select.c:41
  2    Thread 0x7ffff42cc700 (LWP 601201) "python3"       0x00007ffff7ebcaff in __GI___poll (fds=0x7ffff42cbec0, nfds=2, timeout=-1)
    at ../sysdeps/unix/sysv/linux/poll.c:29
  3    Thread 0x7ffff3a9d700 (LWP 601202) "python3"       0x00007ffff7e873bf in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, 
    req=0x7ffff3a9ce50, rem=0x7ffff3a9ce60) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
* 4    Thread 0x7ffff329c700 (LWP 601203) "arv_gv_stream" 0x00007ffff71eefc8 in g_base_info_get_name ()
   from /usr/lib/x86_64-linux-gnu/libgirepository-1.0.so.1
(gdb) bt
#0  0x00007ffff71eefc8 in g_base_info_get_name () at /usr/lib/x86_64-linux-gnu/libgirepository-1.0.so.1
#1  0x00007ffff73f6d3f in  () at /usr/lib/python3/dist-packages/gi/_gi.cpython-38-x86_64-linux-gnu.so
#2  0x00007ffff71dfe06 in  () at /usr/lib/x86_64-linux-gnu/libffi.so.7
#3  0x00007ffff71e0188 in  () at /usr/lib/x86_64-linux-gnu/libffi.so.7
#4  0x00007ffff6414e30 in _find_frame_data
    (thread_data=0xb5f9a0, packet=0x7fffe4000c70, packet_size=40, frame_id=6502, packet_id=0, extended_ids=0, read_count=40, time_us=369630818997)
    at ../src/arvgvstream.c:431
#5  0x00007ffff6415802 in _process_packet (thread_data=0xb5f9a0, packet=0x7fffe4000c70, packet_size=40, time_us=369630818997) at ../src/arvgvstream.c:691
#6  0x00007ffff6415bc9 in _loop (thread_data=0xb5f9a0) at ../src/arvgvstream.c:799
#7  0x00007ffff64166d1 in arv_gv_stream_thread (data=0xb5f9a0) at ../src/arvgvstream.c:1040
#8  0x00007ffff72f8931 in  () at /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0
#9  0x00007ffff7d8d609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007ffff7ec9293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

[lostcontrol]

Same issue here. Get a segfault when using callbacks. My callback is called once with ARV_STREAM_CALLBACK_TYPE_INIT but then the application crashes.

@bpinsard did you manage to workaround the issue?

[bpinsard]

@lostcontrol I think the only workaround I found was modifying Aravis sources to call a callback coded in C/C++ by default. and recompiled it. However, I didn't end up using that version in production nor did I run extensive tests of performance impacts.

[zhouzhou2088]

Same issue here. About the Segmentation fault, I made the same mistake on windows! Has this problem been solved?

[14:24:29.547] device> [GvDevice::new] Interface address = 192.168.1.11 [14:24:29.547] device> [GvDevice::new] Device address = 192.168.1.15 [14:24:29.548] device> [GvDevice::load_genicam] xml url = 'Local:GigE_Vision_1_V3_2_0.zip;100000;146b6' at 0x200 [14:24:29.548] device> [GvDevice::load_genicam] Xml address = 0x100000 - size = 0x146b6 - GigE_Vision_1_V3_2_0.zip [14:24:29.652] device> [GvDevice::load_genicam] Zipped xml data [14:24:29.709] device> [GvDevice::new] Device endianness = big [14:24:29.709] device> [GvDevice::new] Packet resend = yes [14:24:29.709] device> [GvDevice::new] Write memory = yes [14:24:29.709] device> [GvDevice::new] Legacy endianness handling = yes [14:24:30.708] device> [GvDevice::Heartbeat] Ack value = 2 [14:24:31.427] device> [GvDevice::create_stream] Number of stream channels = 1 [14:24:31.480] device> [GvDevice::auto_packet_size] Try packet size = 1500 [14:24:31.531] device> [GvDevice::auto_packet_size] Try packet size = 860 [14:24:31.581] device> [GvDevice::auto_packet_size] Try packet size = 540 [14:24:31.632] device> [GvDevice::auto_packet_size] Try packet size = 380 [14:24:31.685] device> [GvDevice::auto_packet_size] Try packet size = 300 [14:24:31.710] device> [GvDevice::Heartbeat] Ack value = 2 [14:24:31.740] device> [GvDevice::auto_packet_size] Try packet size = 260 [14:24:31.794] device> [GvDevice::auto_packet_size] Try packet size = 240 [14:24:31.847] device> [GvDevice::auto_packet_size] Try packet size = 232 [14:24:31.902] device> [GvDevice::auto_packet_size] Packet size set to 1500 bytes [14:24:31.908] device> [GvStream::stream_new] Packet size = 1500 byte(s) [14:24:31.911] stream> [GvStream::stream_new] Destination stream port = 54591 [14:24:31.911] stream> [GvStream::stream_new] Source stream port = 9001 [14:24:31.912] stream> [GvStream::loop] Standard socket method Segmentation fault

[zhouzhou2088]

@lostcontrol @bpinsard Hi gays, has this problem been solved at last? @EmmanuelP How to deal with Segmentation fault? Please help to answer it

[EmmanuelP]

Hi,

The crash is probably due to the fact the callback is called from the stream receiving thread. I have done some research in other projects to see how they handle this case, but did not find anything relevant.

An workaround is to not use the callback, but instead poll for incoming buffers, like what is done in tests/python/arv-camera-test.py. Polling could also happen in a worker thread.

Cheers.

[bpinsard]

It's not a callback to process buffers that cause the problem, but one to set the priority of the stream receiving thread which can only be done through a callback if I am correct. I have never used non-polling (callback) method to access buffers.

I think the main problem is that the function to set priorities is declared in python and thus is "attached" to the main thread and cannot be called from another C++ thread as it is GIL locked. My knowledge about this is limited, but that's my guess. I had also tried to code the callback in C++ in Aravis, recompile, and pass it to the stream in python, but still the layers of GIR/pygobject bindings still cause the same problem.

Maybe an option would be to pass these priority parameters at stream init create_stream and then set priorities in the stream thread. Of course it is more limiting than what the callback can do, notably for buffers.

[tpwrules]

I ran into this problem too. I like the option of having a way to pre-set the requested realtime/priority level and a default callback which simply sets that.

[lostcontrol]

I looked at this issue a bit closer and managed to get the following script working:

import threading
import time

import gi
# autopep8: off
gi.require_version('Aravis', '0.8')
from gi.repository import Aravis  # noqa: E402
# autopep8: on

Aravis.enable_interface('Fake')


def callback(user_data, cb_type, buffer):
    print(f'Callback[{threading.get_native_id()}] {user_data=} {cb_type=} {buffer=}')


print(f'Main thread[{threading.get_native_id()}]')
cam = Aravis.Camera.new('Fake_1')
payload = cam.get_payload()
stream = cam.create_stream(callback, [1, 2, 3])
stream.push_buffer(Aravis.Buffer.new_allocate(payload))

cam.start_acquisition()
time.sleep(1)
cam.stop_acquisition()

dev@L-0267:/workspace/tests/python$ ARV_DEBUG=stream-thread:9 python3 arv-callback-segfault.py 
Main thread[87992]
[14:37:03.048] 🅳 stream-thread> [FakeStream::thread] Start
[14:37:03.048] 🅳 stream-thread> callback: 0x7f45a8918010
Callback[87996] user_data=[1, 2, 3] cb_type=<enum ARV_STREAM_CALLBACK_TYPE_INIT of type Aravis.StreamCallbackType> buffer=None
Callback[87996] user_data=[1, 2, 3] cb_type=<enum ARV_STREAM_CALLBACK_TYPE_START_BUFFER of type Aravis.StreamCallbackType> buffer=None
Callback[87996] user_data=[1, 2, 3] cb_type=<enum ARV_STREAM_CALLBACK_TYPE_BUFFER_DONE of type Aravis.StreamCallbackType> buffer=<Aravis.Buffer object at 0x7f45a834e300 (ArvBuffer at 0x557aba134430)>

By just applying this patch:

diff --git a/src/arvcamera.c b/src/arvcamera.c
index 4373abfb..12284ff7 100644
--- a/src/arvcamera.c
+++ b/src/arvcamera.c
@@ -139,7 +139,7 @@ enum
 /**
  * arv_camera_create_stream:
  * @camera: a #ArvCamera
- * @callback: (scope call) (allow-none): a frame processing callback
+ * @callback: (scope notified) (allow-none): a frame processing callback
  * @user_data: (closure) (allow-none): user data for @callback
  * @error: a #GError placeholder, %NULL to ignore
  *

Long story short, this issue is "just" a lifecycle problem between Aravis and the Python part (PyGObject I guess, my knowledge of GObject & co is close to zero). With (scope call), PyGObject assumes that callback will only be used for the lifetime of the call to create_stream. However, Aravis keeps track of the pointer and calls the callback in a separate thread, multiple times, way after the call to create_stream is over. This is what causes the crash. With (scope notified), PyGObject waits until the GDestroyNotify argument is called. With my simple patch, PyGObject just never deletes the callback since there is no GDestroyNotify. It works but of course, we leak memory.

I had a quick look at how to fix it properly but my knowledge of GObject and all the introspection stuff is too scarce and I'm stuck. Basically, the lifetime of callback should be bound to the lifetime of the returned stream. But I don't see how to do this correctly with a GDestroyNotify. Any help would be welcome here.

[EmmanuelP]

You have to:

• add a new CONSTRUCT_ONLY destroy_notify property to ArvStream
• call this function in arv_stream_finalize if not NULL
• create 2 new functions with a destroy parameter: arv _device_create_stream_full and arv_camera_create_stream_full
• a new ArvDevice::create_stream_full virtual function should also be added
• The existing arv_device_create_stream, arv_camera_create_stream and ArvDevice::create_stream should be implemented using the _full version with destroy set to NULL.

[lostcontrol]

Thank you @EmmanuelP. I think I just found out what was not working in my attempt at using GDestroyNotify.

[bpinsard]

Thanks @lostcontrol ! Will test that patch when it is finalized.