Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] Occasional crash/video failure when using DeviceManager #1537

Open
3 tasks done
JasonWeinzierl opened this issue Mar 6, 2024 · 1 comment
Open
3 tasks done

[BUG] Occasional crash/video failure when using DeviceManager #1537

JasonWeinzierl opened this issue Mar 6, 2024 · 1 comment
Labels
customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-triage This is a new issue that needs to be triaged to the appropriate team. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that

Comments

@JasonWeinzierl
Copy link

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

  1. Create a CallClient and get its DeviceManager
  2. Get the list of cameras from the DeviceManager. The app may crash somewhere around this point.
  3. Create a LocalVideoStream, VideoStreamRenderer, and VideoStreamRendererView with the camera.
  4. 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

  • Bug Description Added
  • Repro Steps Added
  • Setup information Added
@github-actions github-actions bot added customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-triage This is a new issue that needs to be triaged to the appropriate team. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that labels Mar 6, 2024
@lucianopa-msft
Copy link

Tracking: ADO Bug 3732687

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-triage This is a new issue that needs to be triaged to the appropriate team. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@JasonWeinzierl @lucianopa-msft