Crash in libARController with the new SDK


#1

Product: [Bebop/Bebop2]
SDK version: [3.10.1]
Use of libARController: [YES]
SDK platform: [iOS]
Reproductible with the official app: [Not tried]

Hi !

Since I upgraded my code to the new 3.10.1 SDK I get crashes in my iOS App when trying to reconnect too quickly to the drone. If I wait a little bit before reconnecting the crash don’t occur.
Here is the stack of the crashing thread :

#0 0x0000000100376458 in ARSAL_Mutex_Lock at /Users/d.bertrand/Documents/github/packages/libARSAL/Sources/ARSAL_Mutex.c:88
#1 0x00000001001ce450 in ARCOMMANDS_Decoder_SetARDrone3MediaRecordStatePictureStateChangedCb at /Users/d.bertrand/Documents/github/out/arsdk-ios/build/libARCommands/gen/Sources/ARCOMMANDS_Decoder.c:2562
#2 0x0000000100247d58 in ARCONTROLLER_FEATURE_ARDrone3_UnregisterARCommands at /Users/d.bertrand/Documents/github/out/arsdk-ios/build/libARController/gen/Sources/ARCONTROLLER_Feature.c:1168
#3 0x0000000100221728 in ARCONTROLLER_Device_StopNetwork at /Users/d.bertrand/Documents/github/out/arsdk-ios/build/libARController/gen/Sources/ARCONTROLLER_Device.c:5285
#4 0x000000010021fda4 in ARCONTROLLER_Device_StopRun at /Users/d.bertrand/Documents/github/out/arsdk-ios/build/libARController/gen/Sources/ARCONTROLLER_Device.c:4855
#5 0x000000010021f954 in ARCONTROLLER_Device_StartRun at /Users/d.bertrand/Documents/github/out/arsdk-ios/build/libARController/gen/Sources/ARCONTROLLER_Device.c:4817

And the logs :

2016-10-30 10:40:03.773049 BebopPad[1185:503346] newState: 4
2016-10-30 10:40:03.773256 BebopPad[1185:503346] - wait new state …
2016-10-30 10:40:03.808893 BebopPad[1185:503289] Service found : DreamBop, _arsdk-090c._udp.
2016-10-30 10:40:04.815039 BebopPad[1185:503714] newState: 0
2016-10-30 10:40:05.586229 BebopPad[1185:503289] PilotingViewController viewDidLoad …
2016-10-30 10:40:05.592049 BebopPad[1185:503289] PilotingViewController viewWillAppear…
2016-10-30 10:40:05.651915 BebopPad[1185:503289] PilotingViewController viewDidAppear…
2016-10-30 10:40:05.679119 BebopPad[1185:503349] - init discovery device …
2016-10-30 10:40:05.793443 BebopPad[1185:503349] Resolved:DreamBop.local.–>192.168.42.1:44444
2016-10-30 10:40:05.793642 BebopPad[1185:503349] Resolved:DreamBop.local.–>192.168.42.1:44444
2016-10-30 10:40:05.793708 BebopPad[1185:503349] - ARCONTROLLER_Device_New …
2016-10-30 10:40:05.793772 BebopPad[1185:503349] - ARCONTROLLER_Device_AddStateChangedCallback …
2016-10-30 10:40:05.793792 BebopPad[1185:503349] - ARCONTROLLER_Device_AddCommandRecievedCallback …
2016-10-30 10:40:05.793811 BebopPad[1185:503349] - ARCONTROLLER_Device_SetVideoStreamMP4Compliant …
2016-10-30 10:40:05.794449 BebopPad[1185:503349] - ARCONTROLLER_Device_SetVideoReceiveCallback …
2016-10-30 10:40:05.794489 BebopPad[1185:503349] - ARCONTROLLER_Device_Start …
2016-10-30 10:40:05.794514 BebopPad[1185:503349] newState: 1
[INF] ARCONTROLLER_Network | 10:40:05:795 | ARCONTROLLER_Network_GetAvailableSocketPort:108 - d2c_port port: 57451
[INF] ARCONTROLLER_Stream2 | 10:40:05:795 | ARCONTROLLER_Stream2_Open_Socket:122 - udp local port stream: 52642
[INF] ARCONTROLLER_Stream2 | 10:40:05:812 | ARCONTROLLER_Stream2_Open_Socket:122 - udp local port control: 55466
[ERR] ARNETWORKAL_WifiNetwork | 10:40:06:342 | ARNETWORKAL_WifiNetwork_GetAvailableSendSize:1214 - [0x174139dc0] Error during ioctl 6 (Device not configured)
[INF] ARNETWORKAL_WifiNetwork | 10:40:06:342 | ARNETWORKAL_WifiNetwork_GetAvailableSendSize:1219 - [0x174139dc0] ioctl failed with error ENXIO, stop trying to get available socket buffer size
[ERR] ARNETWORK_Sender | 10:40:06:863 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:06:864 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:07:383 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:07:383 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:07:901 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:07:902 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:08:423 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[WNG] ARNETWORK_Sender | 10:40:08:424 | ARNETWORK_Sender_TimeOutCallback:651 - [0x1742f6d80] Did timeout sending command : project = 0 | class = 4 | command = 1 - 0
[ERR] ARNETWORK_Sender | 10:40:08:945 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:08:946 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:09:468 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:09:468 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:09:994 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:09:994 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[ERR] ARNETWORK_Sender | 10:40:10:511 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[WNG] ARNETWORK_Sender | 10:40:10:511 | ARNETWORK_Sender_TimeOutCallback:651 - [0x1742f6d80] Did timeout sending command : project = 0 | class = 4 | command = 2 - 0
[ERR] ARNETWORK_Sender | 10:40:11:030 | ARNETWORK_Sender_ProcessBufferToSend:401 - [0x1742f6d80] Timeout waiting for ack in buffer 11
[ERR] ARNETWORK_Sender | 10:40:11:030 | ARNETWORK_Sender_ProcessBufferToSend:417 - [0x1742f6d80] Will retry sending data of buffer 11
[INF] ARNETWORKAL_WifiNetwork | 10:40:11:337 | ARNETWORKAL_WifiNetwork_Receive:890 - [0x174139dc0] connection lost (too long time without reception)
2016-10-30 10:40:11.338208 BebopPad[1185:503754] newState: 4
[INF] ARCONTROLLER_Device | 10:40:11:339 | ARCONTROLLER_Device_StartRun:4815 - Start failed or canceled.
2016-10-30 10:40:11.339394 BebopPad[1185:503751] newState: 4
2016-10-30 10:40:12.343497 BebopPad[1185:503751] newState: 0
2016-10-30 10:40:12.350477 BebopPad[1185:503289] - ARCONTROLLER_Device_Start …
2016-10-30 10:40:12.350616 BebopPad[1185:503289] newState: 1
[ERR] ARCONTROLLER_Device | 10:40:12:355 | ARCONTROLLER_Device_StartRun:4823 - Start fail error :start canceled
[INF] ARCONTROLLER_Device | 10:40:12:367 | ARCONTROLLER_Device_StartRun:4815 - Start failed or canceled.
2016-10-30 10:40:12.367333 BebopPad[1185:503789] newState: 4

Best regards


#3

Hello!

I’m facing the same issue. My application often crashes while trying to reconnect to the drone (in case of connection loss for instance).
I’m using the latest C SDK (3.14.0)
According the gdb backtrace the issue is very similar:

#0 __GI___pthread_mutex_lock (mutex=0x0) at …/nptl/pthread_mutex_lock.c:67
#1 0x00007ffff6e06f2e in ARSAL_Mutex_Lock (mutex=mutex@entry=0x7fffbc003550)
at packages/libARSAL/Sources/ARSAL_Mutex.c:89
#2 0x00007ffff41683a7 in ARCOMMANDS_Decoder_SetGenericDroneSettingsChangedCb (decoder=0x7fffbc003550,
callback=callback@entry=0x0, custom=custom@entry=0x0)
at out/arsdk-native/build/libARCommands/gen/Sources/ARCOMMANDS_Decoder.c:1512
#3 0x00007ffff684508b in ARCONTROLLER_FEATURE_Generic_UnregisterARCommands (feature=)
at out/arsdk-native/build/libARController/gen/Sources/ARCONTROLLER_Feature.c:435
#4 0x00007ffff68303a4 in ARCONTROLLER_Device_StopNetwork (deviceController=deviceController@entry=0x6d4360)
at out/arsdk-native/build/libARController/gen/Sources/ARCONTROLLER_Device.c:7261
#5 0x00007ffff6834ecc in ARCONTROLLER_Device_StopRun (data=data@entry=0x6d4360)
at out/arsdk-native/build/libARController/gen/Sources/ARCONTROLLER_Device.c:5989
#6 0x00007ffff68350f0 in ARCONTROLLER_Device_StartRun (data=0x6d4360)
at out/arsdk-native/build/libARController/gen/Sources/ARCONTROLLER_Device.c:5951
#7 0x00007ffff46186ba in start_thread (arg=0x7fffd0bf8700) at pthread_create.c:333
#8 0x00007ffff711341d in clone () at …/sysdeps/unix/sysv/linux/x86_64/clone.S:109

It seems that the “mutex” property of the “ARCOMMANDS_Decoder_t” structure is NULL is some cases so the lock fails.
I tried to add ~10sec of delay between reconnection attempts but my program is still randomly crashing.

I would love to see this issue resolved. I’m ready to dump more backtraces or run some tests if needed.
Thanks a lot.