search

BelledonneCommunications / linphone-sdk

Mirror for linphone-sdk (https://gitlab.linphone.org/BC/public/linphone-sdk.git)
GNU Affero General Public License v3.0
104 stars 80 forks source link

Fatal crash when resuming call after pausing it, header_address parser error #303

Closed ypedegroot closed 1 year ago

ypedegroot commented 1 year ago

Context

The Linphone SDK is used in a native Android (Kotlin) app, targeting API 26 and above. A proprietary SIP registrar (Innovaphone PBX v13r2, behind a reverse proxy) is used.

General information

Expected behaviour

When resuming (unpausing) a call, after pausing it, expected behaviour would be to resume audiostreams. What actually happens is a fatal crash of my app. Please note that this only happens with a specific proprietary PBX. (Our development PBX does not induce this problem); however, I still want to understand this problem so I can prevent it from happening, as its should work with this proprietary PBX as well.

To Reproduce

Register a SIP account with the PBX. Place a call, pause it and then resume it.

Additional context

During testing, the Linphone SDK always generates this error message right after a register: [ERROR] header_address parser error for [sip:extension@realm.domain;gr=]

The app does not crash, the SDK behaves as expected, but yet, after every register this log entry can be seen. Then, when that account is used to place a call, pause the call after a few seconds and then resume it, the entire app crashes with a FATAL signal coming from libc.

I have attached here an unfiltered logcat log, starting with a debug message (coming from my ViewModel, this happens when the user resumes the call).

SDK logs from call resumption to fatal crash

2023-05-22 16:04:21.228  6490-6490  Timber                  com.apps.myapp                       D  [CallViewModel] Call in hold manually? false
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  Resuming MediaSession 0xb40000740f834a88
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  Stopping AudioStream.
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MediaStream[0xb40000749f821770] (MSAudio) with RtpSession[0xb40000751f8e93e0] summary:
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  send-ssrc = [dec:4201143622 hex:fa685d46]
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  recv-ssrc = [dec:3347912141 hex:c78d15cd]
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ===========================================================
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I                       RTP STATISTICS                          
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  -----------------------------------------------------------
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  sent                                       1119 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I                                                0 duplicated packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I                                           192468 bytes  
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  received                                   1138 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I                                                0 duplicated packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I                                           195736 bytes  
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  incoming delivered to the app            193156 bytes  
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  incoming cumulative lost                      0 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  incoming received too late                    0 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  incoming bad formatted                        0 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  incoming discarded (queue overflow)           0 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  sent rtcp                                    12 packets
2023-05-22 16:04:21.240  6490-6490  LinPhoneSdk             com.apps.myapp                       I  received rtcp                                 0 packets
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ===========================================================
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSFilePlayer:0xb40000741f880dc0,0-->MSResample:0xb40000741f87da90,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSResample:0xb40000741f87da90,0-->MSEqualizer:0xb40000741f8828c0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSEqualizer:0xb40000741f8828c0,0-->MSVolume:0xb40000741f87fe90,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSVolume:0xb40000741f87fe90,0-->MSAudioMixer:0xb40000741f8827a0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSAudioMixer:0xb40000741f8827a0,0-->MSUlawEnc:0xb40000741f880670,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSUlawEnc:0xb40000741f880670,0-->MSRtpSend:0xb40000741f87e390,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSRtpRecv:0xb40000741f87e300,0-->MSUlawDec:0xb40000741f8823b0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSUlawDec:0xb40000741f8823b0,0-->MSGenericPLC:0xb40000741f882200,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSGenericPLC:0xb40000741f882200,0-->MSAudioFlowControl:0xb40000741f881d80,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSAudioFlowControl:0xb40000741f881d80,0-->MSDtmfGen:0xb40000741f862730,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSDtmfGen:0xb40000741f862730,0-->MSVolume:0xb40000741f8824d0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSVolume:0xb40000741f8824d0,0-->MSEqualizer:0xb40000741f881900,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSEqualizer:0xb40000741f881900,0-->MSAudioMixer:0xb40000741f882cb0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSFilePlayer:0xb40000741f8829e0,0-->MSResample:0xb40000741f8820e0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSResample:0xb40000741f8820e0,0-->MSAudioMixer:0xb40000741f882cb0,1
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSAudioMixer:0xb40000741f882cb0,0-->MSResample:0xb40000741f87dc40,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ms_filter_unlink: MSResample:0xb40000741f87dc40,0-->MSFileRec:0xb40000741f882dd0,0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  =================================================================================
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I                           FILTER USAGE STATISTICS                                 
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  Name                          Count           Time/tick (ms)            CPU Usage
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I                                          min     mean    max     sd               
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  ---------------------------------------------------------------------------------
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSRtpRecv                     2713      0.02    0.07    0.96    0.05         58.2
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSRtpSend                     2713      0.00    0.03    1.51    0.16         26.2
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSFileRec                     99        0.00    0.00    0.01    0.00          4.3
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSAudioMixer                  5426      0.00    0.00    0.15    0.00          3.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSResample                    99        0.00    0.00    0.08    0.01          2.9
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSGenericPLC                  2713      0.00    0.00    0.10    0.00          2.3
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSDtmfGen                     2814      0.00    0.00    0.08    0.00          1.7
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSFilePlayer                  5527      0.00    0.00    0.15    0.00          1.4
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSAudioFlowControl            0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSEqualizer                   0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSVolume                      0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSUlawDec                     0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSUlawEnc                     0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSAAudioRecorder              0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSAAudioPlayer                0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  MSWebRTCAECM                  0         0.00    0.00    0.00    0.00          0.0
2023-05-22 16:04:21.241  6490-6490  LinPhoneSdk             com.apps.myapp                       I  =================================================================================
2023-05-22 16:04:21.243  6490-6490  libc                    com.apps.myapp                       A  Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 6490 (com.apps.myapp), pid 6490

SDK logs URL

No response

Viish commented 1 year ago

Hi,

Please attach the crash's symbolized stacktrace using adb logcat & ndk-stack tools.

Cheers,

ypedegroot commented 1 year ago

Hi Viish,

Thanks for your quick reply. I have attached a more detailed log with more stacktrace. I will try to get the full tombstone log attached here too shortly. It appears that the error originates from liblinphone.so, specifically from linphone_call_resume().

2023-05-22 17:30:01.260 23284-23284 libc                    com.apps.myapp                       A  Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 23284 (com.apps.myapp), pid 23284 (com.apps.myapp)
2023-05-22 17:30:01.267   972-23755 sensors-hal             and....sensors@2.0-service.multihal  E  handle_sns_client_event:74, prox_event: ts=279177705811477, raw_adc=311, near_far=0, distance=5.000000
2023-05-22 17:30:01.322 23895-23895 DEBUG                   pid-23895                            E  failed to readlink /proc/23284/fd/127: No such file or directory
2023-05-22 17:30:01.323 23895-23895 DEBUG                   pid-23895                            E  failed to readlink /proc/23284/fd/154: No such file or directory
2023-05-22 17:30:01.323 23895-23895 DEBUG                   pid-23895                            E  failed to readlink /proc/23284/fd/158: No such file or directory
2023-05-22 17:30:01.365 23895-23895 crash_dump64            pid-23895                            I  obtaining output fd from tombstoned, type: kDebuggerdTombstoneProto
2023-05-22 17:30:01.365   688-688   tombstoned              tombstoned                           I  received crash request for pid 23284
2023-05-22 17:30:01.370 23895-23895 crash_dump64            pid-23895                            I  performing dump of process 23284 (target tid = 23284)
2023-05-22 17:30:01.378   972-23755 sensors-hal             and....sensors@2.0-service.multihal  E  handle_sns_client_event:74, prox_event: ts=279177816907050, raw_adc=324, near_far=0, distance=5.000000
2023-05-22 17:30:01.490   972-23755 sensors-hal             and....sensors@2.0-service.multihal  E  handle_sns_client_event:74, prox_event: ts=279177928034185, raw_adc=324, near_far=0, distance=5.000000
2023-05-22 17:30:01.602   972-23755 sensors-hal             and....sensors@2.0-service.multihal  E  handle_sns_client_event:74, prox_event: ts=279178039129498, raw_adc=291, near_far=0, distance=5.000000
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Build fingerprint: 'Nokia/TheThing_00EEA/TTG_sprout:13/TKQ1.220807.001/00WW_3_28C:user/release-keys'
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Revision: '0'
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  ABI: 'arm64'
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Timestamp: 2023-05-22 17:30:01.379883136+0200
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Process uptime: 80s
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Cmdline: com.apps.myapp
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  pid: 23284, tid: 23284, name: com.apps.myapp  >>> com.apps.myapp <<<
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  uid: 10324
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0000000000000000
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  Cause: null pointer dereference
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x0  0000000000000000  x1  0000007fc2db4868  x2  0000000000000400  x3  0000007fc2db4860
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x4  0000007fc2db4c68  x5  0000000000000004  x6  736572206c6c6143  x7  676e696d75736572
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x8  69fd0d86f9520d8d  x9  69fd0d86f9520d8d  x10 0000000000018000  x11 0000000000000002
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x12 00000000cf8c3f18  x13 b4000073df85eb63  x14 00000000ffffffed  x15 0000000000000028
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x16 000000731d9bf630  x17 000000731d7f16e0  x18 00000076e9d86000  x19 0000000000000000
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x20 00000076e9057000  x21 b4000073cf851a20  x22 b4000073cf851a20  x23 00000076e9057000
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x24 b4000074cf837bc0  x25 0000007fc2db5098  x26 00000000183a0001  x27 0000000000000024
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      x28 0000007fc2db4f90  x29 0000007fc2db4810
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A      lr  000000731d565114  sp  0000007fc2db4810  pc  000000731d7f16f8  pst 0000000080001000
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A  backtrace:
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #00 pc 000000000088a6f8  /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!liblinphone.so (belle_sip_object_marshal+24) (BuildId: c1decffb3e804f373661e3f487430647d99c8340)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #01 pc 00000000005fe110  /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!liblinphone.so (sal_address_as_string+72) (BuildId: c1decffb3e804f373661e3f487430647d99c8340)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #02 pc 00000000007a071c  /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!liblinphone.so (LinphonePrivate::MediaSession::resume()+480) (BuildId: c1decffb3e804f373661e3f487430647d99c8340)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #03 pc 0000000000731970  /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!liblinphone.so (LinphonePrivate::Call::resume()+96) (BuildId: c1decffb3e804f373661e3f487430647d99c8340)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #04 pc 00000000007022f8  /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!liblinphone.so (linphone_call_resume+12) (BuildId: c1decffb3e804f373661e3f487430647d99c8340)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #05 pc 0000000000440554  /apex/com.android.art/lib64/libart.so (art_quick_generic_jni_trampoline+148) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #06 pc 000000000020a910  /apex/com.android.art/lib64/libart.so (nterp_helper+5648) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #07 pc 00000000001c1048  [anon:dalvik-classes19.dex extracted in memory from /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!classes19.dex] (org.linphone.core.CallImpl.resume+140)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #08 pc 000000000020b120  /apex/com.android.art/lib64/libart.so (nterp_helper+7712) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #09 pc 00000000000078dc  [anon:dalvik-classes17.dex extracted in memory from /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!classes17.dex] (com.apps.myapp.activities.call.CallViewModel.togglePauseCall+356)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #10 pc 000000000020a254  /apex/com.android.art/lib64/libart.so (nterp_helper+3924) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #11 pc 0000000000004dbe  [anon:dalvik-classes11.dex extracted in memory from /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!classes11.dex] (com.apps.myapp.activities.call.ongoing.CallOngoingFragment.onViewCreated$lambda$2+18)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #12 pc 0000000000209334  /apex/com.android.art/lib64/libart.so (nterp_helper+52) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #13 pc 0000000000004c30  [anon:dalvik-classes11.dex extracted in memory from /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!classes11.dex] (com.apps.myapp.activities.call.ongoing.CallOngoingFragment.$r8$lambda$1RkeoacHU22CY8Q9feF65fdW4DI+0)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #14 pc 0000000000209334  /apex/com.android.art/lib64/libart.so (nterp_helper+52) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #15 pc 0000000000004678  [anon:dalvik-classes11.dex extracted in memory from /data/app/~~BemB0waslOexeHbfK1-x0A==/com.apps.myapp-dsORErY7SVD0KHh4r5XM_g==/base.apk!classes11.dex] (com.apps.myapp.activities.call.ongoing.CallOngoingFragment$$ExternalSyntheticLambda2.onClick+4)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #16 pc 000000000020b074  /apex/com.android.art/lib64/libart.so (nterp_helper+7540) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #17 pc 00000000004d4242  /system/framework/framework.jar (android.view.View.performClick+218)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #18 pc 000000000020a254  /apex/com.android.art/lib64/libart.so (nterp_helper+3924) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #19 pc 00000000004d4272  /system/framework/framework.jar (android.view.View.performClickInternal+6)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #20 pc 000000000020a254  /apex/com.android.art/lib64/libart.so (nterp_helper+3924) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #21 pc 00000000004cf4ac  /system/framework/framework.jar (android.view.View.-$$Nest$mperformClickInternal+0)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #22 pc 0000000000209334  /apex/com.android.art/lib64/libart.so (nterp_helper+52) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #23 pc 00000000004aabf4  /system/framework/framework.jar (android.view.View$PerformClick.run+16)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #24 pc 000000000020b074  /apex/com.android.art/lib64/libart.so (nterp_helper+7540) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #25 pc 00000000001ca908  /system/framework/framework.jar (android.os.Handler.handleCallback+4)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #26 pc 0000000000209334  /apex/com.android.art/lib64/libart.so (nterp_helper+52) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #27 pc 00000000001ca754  /system/framework/framework.jar (android.os.Handler.dispatchMessage+8)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #28 pc 00000000020066e4  /memfd:jit-cache (deleted) (android.os.Looper.loopOnce+1444)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #29 pc 0000000000209a9c  /apex/com.android.art/lib64/libart.so (nterp_helper+1948) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #30 pc 00000000001ed4e8  /system/framework/framework.jar (android.os.Looper.loop+164)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #31 pc 0000000000209334  /apex/com.android.art/lib64/libart.so (nterp_helper+52) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #32 pc 00000000001c3a32  /system/framework/framework.jar (android.app.ActivityThread.main+202)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #33 pc 0000000000436e00  /apex/com.android.art/lib64/libart.so (art_quick_invoke_static_stub+576) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #34 pc 0000000000469534  /apex/com.android.art/lib64/libart.so (_jobject* art::InvokeMethod<(art::PointerSize)8>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jobject*, _jobject*, unsigned long)+1960) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #35 pc 0000000000468d64  /apex/com.android.art/lib64/libart.so (art::Method_invoke(_JNIEnv*, _jobject*, _jobject*, _jobjectArray*) (.__uniq.165753521025965369065708152063621506277)+48) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #36 pc 0000000000099148  /system/framework/arm64/boot.oat (art_jni_trampoline+120) (BuildId: c1e4535ad118667c012bcf950ce15dd7736d7b04)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #37 pc 000000000020a2b0  /apex/com.android.art/lib64/libart.so (nterp_helper+4016) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #38 pc 00000000003f9aa6  /system/framework/framework.jar (com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run+22)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #39 pc 00000000007bda2c  /system/framework/arm64/boot-framework.oat (com.android.internal.os.ZygoteInit.main+3228) (BuildId: 0d7cc491abca5a97ba1bd0b17a70f04cf4e7787c)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #40 pc 0000000000436e00  /apex/com.android.art/lib64/libart.so (art_quick_invoke_static_stub+576) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #41 pc 0000000000582718  /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeWithVarArgs<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, std::__va_list)+900) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #42 pc 00000000005f611c  /apex/com.android.art/lib64/libart.so (art::JNI<true>::CallStaticVoidMethodV(_JNIEnv*, _jclass*, _jmethodID*, std::__va_list)+160) (BuildId: d307dc6adc4105b5e392ad710770385d)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #43 pc 00000000000bdc04  /system/lib64/libandroid_runtime.so (_JNIEnv::CallStaticVoidMethod(_jclass*, _jmethodID*, ...)+124) (BuildId: 9e147c02bd5e272a2066aa88f77eee99)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #44 pc 00000000000ca68c  /system/lib64/libandroid_runtime.so (android::AndroidRuntime::start(char const*, android::Vector<android::String8> const&, bool)+844) (BuildId: 9e147c02bd5e272a2066aa88f77eee99)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #45 pc 0000000000002610  /system/bin/app_process64 (main+1464) (BuildId: 1c53153af285c7c41774632635266305)
2023-05-22 17:30:01.702 23895-23895 DEBUG                   pid-23895                            A        #46 pc 000000000004a948  /apex/com.android.runtime/lib64/bionic/libc.so (__libc_init+100) (BuildId: 2938f6235116cbc48464ee0f7622625e)
2023-05-22 17:30:01.713   972-23755 sensors-hal             and....sensors@2.0-service.multihal  E  handle_sns_client_event:74, prox_event: ts=279178150256373, raw_adc=322, near_far=0, distance=5.000000
2023-05-22 17:30:01.724   688-688   tombstoned              tombstoned                           E  Tombstone written to: tombstone_11
Viish commented 1 year ago

Seems to be related to SIP packets, probably due to a missing header or an invalid one. Can you please attach the full logs from the start of the Core to the moment it crashes?

ypedegroot commented 1 year ago

Hi Viish,

I have attached a TXT file containing the verbose log and LinphoneSdk Trace logs from the startup of my application (and hence, the start of the Linphone core). log_from_beginning_to_crash.txt

On line 973, the 200 OK response to the REGISTER is shown including all its headers. On line 3309, the Timber log entry is shown when the user chooses to resume ("unpause") the call. On line 3371, the fatal signal is received, coming from liblinphone.so, probably from the linphone_call_resume() method.

I have also added a TXT file containing the tombstone from the fatal crash, tombstone_12.txt. tombstone_12.txt

Do you think it will help if I run this app using the linphone-minimal-debug dependency? I am currently using org.linphone.minimal:linphone-sdk-android:5.2.61, together with androidx.media:media:1.6.0.

Let me know if I can provide you with more details if necessary.

ypedegroot commented 1 year ago

Hi Viish,

Do you have an update on this?

I traced two register attempts with two accounts. One account on the PBX that did not lead to a "header_address parser error" and another one on the "problematic" PBX that did lead to a "header_address parser error". Attached you find two screenshots of my capture.

If you want to inspect the .pcap files in more detail, I kindly ask you to reply with your e-mailaddress, so I can mail them to you. They contain information that I am not allowed to share publicly.

The 200 OK contact header that does not lead to a "header_address parser error":

3cx_register_200_ok

The 200 OK contact header that does lead to a "header_address parser error":

innovaphone_13r2_register_200_ok
AndreaGianarda commented 1 year ago

Hi,

The GRUU parameter must not be enclosed by <>.

Here is an example from RFC5627:

  SIP/2.0 200 OK
  Via: SIP/2.0/UDP 192.0.2.1;branch=z9hG4bKnashds7
  From: Callee <sip:callee@example.com>;tag=a73kszlfl
  To: Callee <sip:callee@example.com> ;tag=b88sn
  Call-ID: 1j9FpLxk3uxtm8tn@192.0.2.1
  CSeq: 1 REGISTER
  <allOneLine>
  Contact: <sip:callee@192.0.2.1>
  ;pub-gruu="sip:callee@example.com
  ;gr=urn:uuid:f81d4fae-7dec-11d0-a765-00a0c91e6bf6"
  ;temp-gruu="sip:tgruu.7hs==
  jd7vnzga5w7fajsc7-ajd6fabz0f8g5@example.com;gr"
  ;+sip.instance="<urn:uuid:f81d4fae-7dec-11d0-a765-00a0c91e6bf6>"
  ;expires=3600
  </allOneLine>
  Content-Length: 0

According to RFC 5627 (https://www.rfc-editor.org/rfc/rfc5627.html#page-23), the ABNF of the gr param is:

uri-parameter =/ gr-param gr-param = "gr" ["=" pvalue] ; defined in RFC 3261

In RFC3261, you find what a pvalue is:

  alphanum  =  ALPHA / DIGIT
  reserved    =  ";" / "/" / "?" / ":" / "@" / "&" / "=" / "+"
                 / "$" / ","
  unreserved  =  alphanum / mark
  mark        =  "-" / "_" / "." / "!" / "~" / "*" / "'"
                 / "(" / ")"
  escaped     =  "%" HEXDIG HEXDIG

  pvalue            =  1*paramchar
  paramchar         =  param-unreserved / unreserved / escaped
  param-unreserved  =  "[" / "]" / "/" / ":" / "&" / "+" / "$"

I'll make a fix for the crash, nonetheless if you want Linphone to behave correctly, please do fix your REGISTER response

Hope this helps,

Andrea

ypedegroot commented 1 year ago

Hi Andrea,

Thanks for your response. I have sent your feedback to the PBX manufacturer. In the meantime, can you let me know in which version the SDK crash will be fixed?

Kind regards

AndreaGianarda commented 1 year ago

You can either use the master branch or branch fix/chatroom_device_restart if you prefer developping on a stable version

ypedegroot commented 1 year ago

Hi Andrea (and @Viish),

Is there any update on the crash fix? Following issue #306 I have updated the SDK to version 5.2.69 (as there was another bug introduced in 5.2.61). Are there any foreseeable plans of merging the crash fix into the main release cycle?

Kind regards