azure-sdk-for-android
azure-sdk-for-android copied to clipboard
Published
20 hours ago •
Azure
Azure
[BUG] Occasional crash/video failure when using DeviceManager
Describe the bug
In the azure-communication-calling library, sometimes when getting cameras from the DeviceManager, the app crashes. Other times, we get the list of cameras just fine, but then the VideoStreamRenderer doesn't fire its onFirstFrameRendered() event and the VideoStreamRendererView doesn't show video.
This bug is tricky and doesn't always happen, but disposing and creating a new CallClient several times in a row usually triggers it (about 1 in 10 restarts).
Exception or Stack Trace
There's no exact exception, but adb logcat produces a variety of logs right when the crash happens or video fails to start.
App crash 1:
2024-03-06 10:20:37.874 14382-14506 RtcPalEnvironment com.azurecommunicationuidemoapp V file already exists /storage/emulated/0/Android/data/com.azurecommunicationuidemoapp/cache
2024-03-06 10:20:37.874 14382-14506 RtcPalEnvironment com.azurecommunicationuidemoapp I Pal initialization completed
2024-03-06 10:20:38.011 14382-15515 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:20:38.012 14382-15515 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:20:38.012 14382-15515 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:20:38.013 14382-15515 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:20:38.634 14382-14506 libc com.azurecommunicationuidemoapp A Fatal signal 7 (SIGBUS), code 1 (BUS_ADRALN), fault addr 0xecd000000078107 in tid 14506 (Thread-49), pid 14382 (cationuidemoapp)
App crash 2:
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I JNI_Pal_Init_Base: vm 0xb400007993b955d0 loader 0x43f6 loadMethod 0x70dcace8
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I JNI_Pal_Init: vm 0xb400007993b955d0 loader 0x43f6 loadMethod 0x70dcace8 GetEnv 0
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I findClass com/microsoft/media/RtcPalConfig loader 0x43f6
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I findClass com/microsoft/media/RtcPalEnvironment loader 0x43f6
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I findClass com/microsoft/media/NetworkPal loader 0x43f6
2024-03-06 10:38:36.402 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I findClass com/microsoft/media/ifaddrs loader 0x43f6
2024-03-06 10:38:36.403 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I findClass com/microsoft/media/RtcPalEnvironment loader 0x43f6
2024-03-06 10:38:36.403 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I JNI_Pal_Init: got init java class 0x69
2024-03-06 10:38:36.403 21042-21123 LYNC PAL com.azurecommunicationuidemoapp I JNI_Pal_Init: got init java class method 0x351
2024-03-06 10:38:36.403 21042-21055 System com.azurecommunicationuidemoapp W A resource failed to call release.
2024-03-06 10:38:36.404 21042-21055 System com.azurecommunicationuidemoapp W A resource failed to call release.
2024-03-06 10:38:36.406 21042-21055 System com.azurecommunicationuidemoapp W A resource failed to call release.
2024-03-06 10:38:36.416 21042-21123 RtcPalEnvironment com.azurecommunicationuidemoapp V file already exists /storage/emulated/0/Android/data/com.azurecommunicationuidemoapp/cache
2024-03-06 10:38:36.416 21042-21123 RtcPalEnvironment com.azurecommunicationuidemoapp I Pal initialization completed
2024-03-06 10:38:36.483 21042-21042 Thread-8 com.azurecommunicationuidemoapp I type=1400 audit(0.0:131924): avc: denied { open } for path="/proc/stat" dev="proc" ino=4026532101 scontext=u:r:untrusted_app:s0:c123,c256,c512,c768 tcontext=u:object_r:proc_stat:s0 tclass=file permissive=1 app=com.azurecommunicationuidemoapp
2024-03-06 10:38:36.523 21042-21959 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:38:36.524 21042-21959 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:38:36.524 21042-21959 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:38:36.524 21042-21959 AudioManager com.azurecommunicationuidemoapp I In isBluetoothScoOn(), calling application: com.azurecommunicationuidemoapp
2024-03-06 10:38:37.167 21042-21137 libc com.azurecommunicationuidemoapp A Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x80 in tid 21137 (Thread-12), pid 21042 (cationuidemoapp)
App crash 3:
024-03-06 14:19:33.221 9905-10313 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init_Base: vm 0xb400007993b955d0 loader 0x3c66 loadMethod 0x70dcace8
2024-03-06 14:19:33.221 9905-10313 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: vm 0xb400007993b955d0 loader 0x3c66 loadMethod 0x70dcace8 GetEnv 0
2024-03-06 14:19:33.221 9905-10313 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalConfig loader 0x3c66
2024-03-06 14:19:33.221 9905-10313 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalEnvironment loader 0x3c66
2024-03-06 14:19:33.222 9905-10313 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/NetworkPal loader 0x3c66
2024-03-06 14:19:33.222 9905-10313 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/ifaddrs loader 0x3c66
2024-03-06 14:19:33.222 9905-10313 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalEnvironment loader 0x3c66
2024-03-06 14:19:33.222 9905-10313 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: got init java class 0x69
2024-03-06 14:19:33.222 9905-10313 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: got init java class method 0x2fb
2024-03-06 14:19:33.229 9905-10313 RtcPalEnvironment com.example.videocallingquickstart V file already exists /storage/emulated/0/Android/data/com.example.videocallingquickstart/cache
2024-03-06 14:19:33.229 9905-10313 RtcPalEnvironment com.example.videocallingquickstart I Pal initialization completed
2024-03-06 14:19:33.342 9905-10839 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 14:19:33.343 9905-10839 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 14:19:33.343 9905-10839 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 14:19:33.343 9905-10839 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A Cmdline: com.example.videocallingquickstart
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A pid: 9905, tid: 10841, name: pool-2-thread-1 >>> com.example.videocallingquickstart <<<
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #00 pc 00000000006c3308 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libACSCallingShared.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #01 pc 00000000006c54fc /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libACSCallingShared.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #02 pc 00000000006c53ac /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libACSCallingShared.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #03 pc 00000000006c34a0 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libACSCallingShared.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #04 pc 00000000002a2738 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #05 pc 00000000002a2d64 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #06 pc 000000000029d704 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #07 pc 000000000029d62c /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #08 pc 000000000029d9ac /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #09 pc 00000000002a2738 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #10 pc 000000000029b554 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #11 pc 000000000029b2d0 /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
2024-03-06 14:19:34.553 10844-10844 DEBUG pid-10844 A #12 pc 00000000002385dc /data/app/~~LcXZSm1IiH-vm_0qmLQLxg==/com.example.videocallingquickstart-2KmxLOJ8vHCHoe0CxWCLQw==/base.apk!libskypert.so
App crash 4:
2024-03-06 15:49:09.117 7267-7267 MainActivity com.example.videocallingquickstart D Restarting ACS SDK
2024-03-06 15:49:09.117 7267-7267 MainActivity com.example.videocallingquickstart D Disposing CallAgent
2024-03-06 15:49:09.437 7267-7267 MainActivity com.example.videocallingquickstart D Disposing CallClient
2024-03-06 15:49:09.511 7267-7267 MainActivity com.example.videocallingquickstart D Creating new CallClient
2024-03-06 15:49:09.511 7267-7267 MainActivity com.example.videocallingquickstart D Starting ACS SDK
2024-03-06 15:49:09.513 7267-7267 MainActivity com.example.videocallingquickstart D Creating CallAgent
2024-03-06 15:49:09.513 7267-7267 pool-2-thread-1 com.example.videocallingquickstart I type=1400 audit(0.0:516782): avc: denied { read } for name="ostype" dev="proc" ino=609723 scontext=u:r:untrusted_app:s0:c122,c256,c512,c768 tcontext=u:object_r:proc:s0 tclass=file permissive=1 app=com.example.videocallingquickstart
2024-03-06 15:49:09.513 7267-7267 pool-2-thread-1 com.example.videocallingquickstart I type=1400 audit(0.0:516783): avc: denied { open } for path="/proc/sys/kernel/ostype" dev="proc" ino=609723 scontext=u:r:untrusted_app:s0:c122,c256,c512,c768 tcontext=u:object_r:proc:s0 tclass=file permissive=1 app=com.example.videocallingquickstart
2024-03-06 15:49:09.513 7267-7267 pool-2-thread-1 com.example.videocallingquickstart I type=1400 audit(0.0:516784): avc: denied { getattr } for path="/proc/sys/kernel/ostype" dev="proc" ino=609723 scontext=u:r:untrusted_app:s0:c122,c256,c512,c768 tcontext=u:object_r:proc:s0 tclass=file permissive=1 app=com.example.videocallingquickstart
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init_Base: vm 0xb400007993b955d0 loader 0x3c66 loadMethod 0x70dcace8
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: vm 0xb400007993b955d0 loader 0x3c66 loadMethod 0x70dcace8 GetEnv 0
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalConfig loader 0x3c66
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalEnvironment loader 0x3c66
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/NetworkPal loader 0x3c66
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/ifaddrs loader 0x3c66
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I findClass com/microsoft/media/RtcPalEnvironment loader 0x3c66
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: got init java class 0x69
2024-03-06 15:49:09.541 7267-7732 LYNC PAL com.example.videocallingquickstart I JNI_Pal_Init: got init java class method 0x2f7
2024-03-06 15:49:09.546 7267-7732 RtcPalEnvironment com.example.videocallingquickstart V file already exists /storage/emulated/0/Android/data/com.example.videocallingquickstart/cache
2024-03-06 15:49:09.546 7267-7732 RtcPalEnvironment com.example.videocallingquickstart I Pal initialization completed
2024-03-06 15:49:09.613 7267-7267 Thread-106 com.example.videocallingquickstart I type=1400 audit(0.0:516785): avc: denied { open } for path="/proc/stat" dev="proc" ino=4026532101 scontext=u:r:untrusted_app:s0:c122,c256,c512,c768 tcontext=u:object_r:proc_stat:s0 tclass=file permissive=1 app=com.example.videocallingquickstart
2024-03-06 15:49:09.648 7267-8572 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 15:49:09.648 7267-8572 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 15:49:09.649 7267-8572 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 15:49:09.649 7267-8572 AudioManager com.example.videocallingquickstart I In isBluetoothScoOn(), calling application: com.example.videocallingquickstart
2024-03-06 15:49:10.047 7267-7267 MainActivity com.example.videocallingquickstart D Getting DeviceManager
2024-03-06 15:49:10.052 7267-7267 MainActivity com.example.videocallingquickstart D Getting cameras from DeviceManager
2024-03-06 15:49:10.053 7267-7267 MainActivity com.example.videocallingquickstart D Finished starting ACS SDK
2024-03-06 15:49:10.054 7267-7267 Choreographer com.example.videocallingquickstart I Skipped 56 frames! The application may be doing too much work on its main thread.
2024-03-06 15:49:10.091 7267-7283 OpenGLRenderer com.example.videocallingquickstart I Davey! duration=951ms; Flags=0, FrameTimelineVsyncId=473404, IntendedVsync=23097317760446, Vsync=23098251093742, InputEventId=813588500, HandleInputStart=23098255554521, AnimationStart=23098255649313, PerformTraversalsStart=23098255683219, DrawStart=23098255818167, FrameDeadline=23097351093778, FrameInterval=23098255454052, FrameStartTime=16666666, SyncQueued=23098256816448, SyncStart=23098256879313, IssueDrawCommandsStart=23098256994313, SwapBuffers=23098258282542, FrameCompleted=23098269791396, DequeueBufferDuration=219479, QueueBufferDuration=885052, GpuCompleted=23098269791396, SwapBuffersCompleted=23098259574469, DisplayPresentTime=0,
2024-03-06 15:49:10.592 7267-8289 libc com.example.videocallingquickstart A Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xffffffffffffe8 in tid 8289 (Thread-165), pid 7267 (llingquickstart)
App doesn't crash but video fails to render 1:
2024-03-06 10:19:22.065 14382-14393 System com.azurecommunicationuidemoapp W A resource failed to call release.
2024-03-06 10:19:33.580 14382-14502 libEGL com.azurecommunicationuidemoapp E call to OpenGL ES API with no current context (logged once per thread)
App doesn't crash but video fails to render 2:
2024-03-06 10:23:12.323 16173-16518 OpenGLRenderer com.azurecommunicationuidemoapp I Davey! duration=9223368496353ms; Flags=0, FrameTimelineVsyncId=144143, IntendedVsync=3540501368154, Vsync=3540501368154, InputEventId=0, HandleInputStart=3540503413388, AnimationStart=3540503431721, PerformTraversalsStart=3540506497086, DrawStart=3540507285471, FrameDeadline=3540534701486, FrameInterval=3540503370888, FrameStartTime=16666666, SyncQueued=3540509561357, SyncStart=3540509645523, IssueDrawCommandsStart=3540510415940, SwapBuffers=3540513994742, FrameCompleted=9223372036854775807, DequeueBufferDuration=119166, QueueBufferDuration=2302136, GpuCompleted=9223372036854775807, SwapBuffersCompleted=3540517415107, DisplayPresentTime=45035996273704960,
2024-03-06 10:23:22.865 16173-16186 System com.azurecommunicationuidemoapp W A resource failed to call release.
App doesn't crash but video fails to render 3:
2024-03-06 10:36:30.077 20368-20482 libEGL com.azurecommunicationuidemoapp E call to OpenGL ES API with no current context (logged once per thread)
2024-03-06 10:36:31.377 20368-20382 System com.azurecommunicationuidemoapp W A resource failed to call release.
2024-03-06 10:36:31.379 20368-20382 System com.azurecommunicationuidemoapp W A resource failed to call release.
To Reproduce
- Create a CallClient and get its DeviceManager
- Get the list of cameras from the DeviceManager. The app may crash somewhere around this point.
- Create a LocalVideoStream, VideoStreamRenderer, and VideoStreamRendererView with the camera.
- Add the view to your UI. The video may not render (onFirstFrameRendered never fires).
Code Snippet
I forked the videoCallingQuickstart example, and I've modified it to have a button that easily lets me dispose and re-create the SDK (CallClient, CallAgent, DeviceManager, etc.). I also modified it to allow me to toggle video on and off without being inside a call. If you restart the SDK enough times and keep toggling video on and off, the app eventually crashes or video doesn't render. See the videoCallingQuickstart project here: https://github.com/JasonWeinzierl/communication-services-android-quickstarts
Expected behavior
Video should always render successfully.
Screenshots
N/A
Setup (please complete the following information):
- OS: Android 11 (API level 30)
- IDE : Android Studio Flamingo | 2022.2.1 Patch 2
- Version of the Library used: 2.6.0-beta.8
Additional context
N/A
Information Checklist Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report
- [X] Bug Description Added
- [X] Repro Steps Added
- [X] Setup information Added
