search

google / ExoPlayer

This project is deprecated and stale. The latest ExoPlayer code is available in https://github.com/androidx/media
https://developer.android.com/media/media3/exoplayer
Apache License 2.0
21.71k stars 6.02k forks source link

Sporadic ANR in MediaDrm.openSession() #6730

Closed GouravSna closed 4 years ago

GouravSna commented 4 years ago

[REQUIRED] Issue description

We are seeing potential ANR in the application. It is coming when we are calling openSession()

[REQUIRED] Reproduction steps

When we are calling mediaDrm.openSession() then in FrameworkMediaDrm class, following method looks like waiting for the response from jni.

@Override
  public byte[] openSession() throws MediaDrmException {
    return mediaDrm.openSession();
  }

[REQUIRED] A full bug report captured from the device

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x754a5650 self=0xb3004400
  | sysTid=3300 nice=0 cgrp=bg_non_interactive sched=0/0 handle=0xb5c2c534
  | state=S schedstat=( 157239541 61332131 169 ) utm=10 stm=5 core=5 HZ=100
  | stack=0xbe26e000-0xbe270000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000048598  /system/lib/libc.so (__ioctl+8)
  #01  pc 000000000001ad03  /system/lib/libc.so (ioctl+38)
  #02  pc 000000000003cc55  /system/lib/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+168)
  #03  pc 000000000003d62f  /system/lib/libbinder.so (_ZN7android14IPCThreadState15waitForResponseEPNS_6ParcelEPi+238)
  #04  pc 000000000003655d  /system/lib/libbinder.so (_ZN7android8BpBinder8transactEjRKNS_6ParcelEPS1_j+36)
  #05  pc 0000000000086e83  /system/lib/libmedia.so (???)
  #06  pc 0000000000025731  /system/lib/libmedia_jni.so (_ZN7android4JDrm7MakeDrmEv+76)
  #07  pc 0000000000025435  /system/lib/libmedia_jni.so (_ZN7android4JDrm7MakeDrmEPKh+20)
  #08  pc 000000000002550f  /system/lib/libmedia_jni.so (_ZN7android4JDrmC1EP7_JNIEnvP8_jobjectPKh+134)
  #09  pc 00000000000263d3  /system/lib/libmedia_jni.so (???)
  #10  pc 00000000004766a1  /system/framework/arm/boot-framework.oat (Java_android_media_MediaDrm_native_1setup__Ljava_lang_Object_2_3B+116)
  at android.media.MediaDrm.native_setup (Native method)
  at android.media.MediaDrm.<init> (MediaDrm.java:215)
  at com.google.android.exoplayer2.drm.FrameworkMediaDrm.<init> (FrameworkMediaDrm.java:73)
  at com.google.android.exoplayer2.drm.FrameworkMediaDrm.newInstance (FrameworkMediaDrm.java:61)
  at com.google.android.exoplayer2.drm.DefaultDrmSessionManager.newFrameworkInstance (DefaultDrmSessionManager.java:221)
  at com.google.android.exoplayer2.drm.DefaultDrmSessionManager.newWidevineInstance (DefaultDrmSessionManager.java:143)

[REQUIRED] Version of ExoPlayer being used

ExoPlayer version: 2.10.6

[REQUIRED] Device(s) and version(s) of Android being used

Affected Android OS : 9, 8.1, 10, 5.1 etc Device name: Redmi Note 7 Pro(violet), Mi A1(tissot_sprout), Redmi 5A(riva), Realme 2 Pro(RMX1801)

kim-vde commented 4 years ago

Can you provide the media file and the necessary information to play it as described here?

GouravSna commented 4 years ago

Hi @kim-vde , I have replied you privately over the email.

kim-vde commented 4 years ago

I can't play the content you provided but I get a different stack trace:

Stack trace ```` 2019-12-11 11:42:33.688 620-624/? E/QC-time-services: Receive Passed == base = 13, unit = 1, operation = 2, result = 0 2019-12-11 11:42:33.688 729-737/? E/QC-time-services: Daemon: Time-services: Waiting to acceptconnection 2019-12-11 11:42:33.688 729-737/? E/QC-time-services: Daemon: Time-services: Waiting to acceptconnection 2019-12-11 11:42:33.697 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.697 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.697 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.698 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.698 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.698 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.706 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.706 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.706 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.715 834-13135/? E/DrmWidevineDash: Error: input length 0 is less than 32. 2019-12-11 11:42:33.830 620-624/? E/QC-time-services: Receive Passed == base = 13, unit = 1, operation = 2, result = 0 2019-12-11 11:42:33.830 729-737/? E/QC-time-services: Daemon: Time-services: Waiting to acceptconnection 2019-12-11 11:42:33.830 729-737/? E/QC-time-services: Daemon: Time-services: Waiting to acceptconnection 2019-12-11 11:42:33.834 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.834 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.834 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.835 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.835 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.835 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.842 834-13135/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.842 834-13135/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.842 834-13135/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.853 834-13102/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.853 834-13102/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.853 834-13102/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.855 834-13102/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.855 834-13102/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.855 834-13102/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.856 834-13102/? E/DrmWidevineDash: hlos api version = 15 2019-12-11 11:42:33.856 834-13102/? E/DrmWidevineDash: tz api version = 15 2019-12-11 11:42:33.856 834-13102/? E/DrmWidevineDash: OEMCrypto_APIVersion: ends! returns version 15 2019-12-11 11:42:33.961 1236-13167/? E/OMX-VDEC-1080P: OMX_QcomIndexParamVideoMetaBufferMode not supported for port: 0 2019-12-11 11:42:33.961 1236-13167/? E/OMX-VDEC-1080P: set_parameter: Error: 0x80001019, setting param 0x7f00001c 2019-12-11 11:42:33.961 1236-13167/? E/OMXNodeInstance: setParameter(0xefd99f44:qcom.decoder.avc.secure, OMX.google.android.index.storeMetaDataInBuffers(0x7f00001c): Input:0 en=0 type=1) ERROR: UnsupportedSetting(0x80001019) 2019-12-11 11:42:33.961 1236-13167/? E/OMX-VDEC-1080P: Enable/Disable android-native-buffers allowed only on output port! 2019-12-11 11:42:33.961 1236-13167/? E/OMX-VDEC-1080P: set_parameter: Error: 0x80001019, setting param 0x7f000017 2019-12-11 11:42:33.961 1236-13167/? E/OMXNodeInstance: setParameter(0xefd99f44:qcom.decoder.avc.secure, OMX.google.android.index.enableAndroidNativeBuffers(0x7f000017): Input:0 en=0) ERROR: UnsupportedSetting(0x80001019) 2019-12-11 11:42:33.962 1236-13167/? E/OMX-VDEC-1080P: Enable/Disable allocate-native-handle allowed only on input port! 2019-12-11 11:42:33.962 1236-13167/? E/OMX-VDEC-1080P: set_parameter: Error: 0x80001019, setting param 0x7f00005d 2019-12-11 11:42:33.962 1236-13167/? E/OMXNodeInstance: setParameter(0xefd99f44:qcom.decoder.avc.secure, OMX.google.android.index.allocateNativeHandle(0x7f00005d): Output:1 en=0) ERROR: UnsupportedSetting(0x80001019) 2019-12-11 11:42:33.972 1236-29365/? E/OMXNodeInstance: getConfig(0xefd99f44:qcom.decoder.avc.secure, ??(0x7f000062)) ERROR: UnsupportedSetting(0x80001019) 2019-12-11 11:42:34.197 31150-31525/com.google.android.exoplayer2.demo E/ion: ioctl c0044901 failed with code -1: Invalid argument 2019-12-11 11:42:39.653 31150-31150/com.google.android.exoplayer2.demo E/EventLogger: internalError [9.92, 0.00, window=0, period=0, drmSessionManagerError] com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.upstream.DefaultHttpDataSource.open(DefaultHttpDataSource.java:311) at com.google.android.exoplayer2.upstream.DataSourceInputStream.checkOpened(DataSourceInputStream.java:102) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:82) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:76) at com.google.android.exoplayer2.util.Util.toByteArray(Util.java:157) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executePost(HttpMediaDrmCallback.java:165) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executeKeyRequest(HttpMediaDrmCallback.java:136) at com.google.android.exoplayer2.drm.DefaultDrmSession$PostRequestHandler.handleMessage(DefaultDrmSession.java:513) at android.os.Handler.dispatchMessage(Handler.java:107) at android.os.Looper.loop(Looper.java:214) at android.os.HandlerThread.run(HandlerThread.java:67) 2019-12-11 11:42:39.660 31150-31496/com.google.android.exoplayer2.demo E/ExoPlayerImplInternal: Playback error. com.google.android.exoplayer2.ExoPlaybackException: com.google.android.exoplayer2.drm.DrmSession$DrmSessionException: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.shouldWaitForKeys(MediaCodecRenderer.java:1137) at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.feedInputBuffer(MediaCodecRenderer.java:1088) at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:658) at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:575) at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:326) at android.os.Handler.dispatchMessage(Handler.java:103) at android.os.Looper.loop(Looper.java:214) at android.os.HandlerThread.run(HandlerThread.java:67) Caused by: com.google.android.exoplayer2.drm.DrmSession$DrmSessionException: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.drm.DefaultDrmSession.onError(DefaultDrmSession.java:446) at com.google.android.exoplayer2.drm.DefaultDrmSession.onKeysError(DefaultDrmSession.java:441) at com.google.android.exoplayer2.drm.DefaultDrmSession.onKeyResponse(DefaultDrmSession.java:406) at com.google.android.exoplayer2.drm.DefaultDrmSession.access$100(DefaultDrmSession.java:49) at com.google.android.exoplayer2.drm.DefaultDrmSession$PostResponseHandler.handleMessage(DefaultDrmSession.java:479) at android.os.Handler.dispatchMessage(Handler.java:107) at android.os.Looper.loop(Looper.java:214)  at android.os.HandlerThread.run(HandlerThread.java:67)  Caused by: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.upstream.DefaultHttpDataSource.open(DefaultHttpDataSource.java:311) at com.google.android.exoplayer2.upstream.DataSourceInputStream.checkOpened(DataSourceInputStream.java:102) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:82) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:76) at com.google.android.exoplayer2.util.Util.toByteArray(Util.java:157) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executePost(HttpMediaDrmCallback.java:165) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executeKeyRequest(HttpMediaDrmCallback.java:136) at com.google.android.exoplayer2.drm.DefaultDrmSession$PostRequestHandler.handleMessage(DefaultDrmSession.java:513) at android.os.Handler.dispatchMessage(Handler.java:107)  at android.os.Looper.loop(Looper.java:214)  at android.os.HandlerThread.run(HandlerThread.java:67)  2019-12-11 11:42:39.665 31150-31150/com.google.android.exoplayer2.demo E/EventLogger: playerFailed [9.94, 0.00, window=0, period=0] com.google.android.exoplayer2.ExoPlaybackException: com.google.android.exoplayer2.drm.DrmSession$DrmSessionException: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.shouldWaitForKeys(MediaCodecRenderer.java:1137) at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.feedInputBuffer(MediaCodecRenderer.java:1088) at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:658) at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:575) at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:326) at android.os.Handler.dispatchMessage(Handler.java:103) at android.os.Looper.loop(Looper.java:214) at android.os.HandlerThread.run(HandlerThread.java:67) Caused by: com.google.android.exoplayer2.drm.DrmSession$DrmSessionException: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.drm.DefaultDrmSession.onError(DefaultDrmSession.java:446) at com.google.android.exoplayer2.drm.DefaultDrmSession.onKeysError(DefaultDrmSession.java:441) at com.google.android.exoplayer2.drm.DefaultDrmSession.onKeyResponse(DefaultDrmSession.java:406) at com.google.android.exoplayer2.drm.DefaultDrmSession.access$100(DefaultDrmSession.java:49) at com.google.android.exoplayer2.drm.DefaultDrmSession$PostResponseHandler.handleMessage(DefaultDrmSession.java:479) at android.os.Handler.dispatchMessage(Handler.java:107) at android.os.Looper.loop(Looper.java:214)  at android.os.HandlerThread.run(HandlerThread.java:67)  Caused by: com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeException: Response code: 500 at com.google.android.exoplayer2.upstream.DefaultHttpDataSource.open(DefaultHttpDataSource.java:311) at com.google.android.exoplayer2.upstream.DataSourceInputStream.checkOpened(DataSourceInputStream.java:102) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:82) at com.google.android.exoplayer2.upstream.DataSourceInputStream.read(DataSourceInputStream.java:76) at com.google.android.exoplayer2.util.Util.toByteArray(Util.java:157) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executePost(HttpMediaDrmCallback.java:165) at com.google.android.exoplayer2.drm.HttpMediaDrmCallback.executeKeyRequest(HttpMediaDrmCallback.java:136) at com.google.android.exoplayer2.drm.DefaultDrmSession$PostRequestHandler.handleMessage(DefaultDrmSession.java:513) at android.os.Handler.dispatchMessage(Handler.java:107)  at android.os.Looper.loop(Looper.java:214)  at android.os.HandlerThread.run(HandlerThread.java:67)  ````

Can you play the Widevine contents from the ExoPlayer demo app?

GouravSna commented 4 years ago

From which location you are trying to play the media ? May be it is geo blocked. Yes, I can play the widevine content on demo app.

kim-vde commented 4 years ago

I am trying to play the media from the UK.

Did you try to

GouravSna commented 4 years ago

I have shared another media set. I tested on Exo-Demo as well. It works fine there.

kim-vde commented 4 years ago

I can indeed play the media you provided with the ExoPlayer demo app. This means that the issue does not come from the media.

You should compare the code of your app with the one of the demo app to see what are the differences and what causes the ANR.

GouravSna commented 4 years ago

But I have shared you the adb logs. if you can possibly drill down and see. Because this error is intermittent.

kim-vde commented 4 years ago

The error is thrown by the Android Framework, when calling new MediaDrm(adjustUuid(uuid)) in class FrameworkMediaDrm.

What is the UUID passed to this constructor? Does it correspond to C.WIDEVINE_UUID or to C.CLEARKEY_UUID? What is the API level in your test device?

GouravSna commented 4 years ago

Yes C.WIDEVINE_UUID

API level 28

kim-vde commented 4 years ago

I'm afraid we don't have the resources to help on this issue as there isn't enough information to reproduce, so you'll need to put some time into debugging this yourself.

You said you could play the media wihout issue in the ExoPlayer demo app. You should compare the code of your app with the one of the demo app to see what are the differences and what causes the ANR.

ojw28 commented 4 years ago

I don't think we've been provided with a full bug report for this issue. Please capture one using adb bugreport shortly after encountering the problem, and either provide it by email or attach it here. A small snippet of log is not sufficient for debugging this type of issue.

If you're able to provide a full bug report, please do so. If you've already provided one and I just haven't found it, please let me know where I can locate it. Thanks!

GouravSna commented 4 years ago

Hi @ojw28 , I have shared the reports over email. Please let me know if it helps. I am also not able to reproduce on my end.

ojw28 commented 4 years ago

Unfortunately the provided information isn't much to go on. Do you see the ANR only on the 4 devices mentioned? What kind of volume of reports are you seeing? Thanks!

GouravSna commented 4 years ago

No, it is not like that the issue is only in these 4 devices. These are the most frequent ones. Redmi Note 7 Pro(violet) is 5000 device affected, it has android-9

google-oss-bot commented 4 years ago

Hey @GouravSna. We need more information to resolve this issue but there hasn't been an update in 14 days. I'm marking the issue as stale and if there are no new updates in the next 7 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

GouravSna commented 4 years ago

@ojw28 , I also don't have more info than this. If possible please check this or else close it.

ojw28 commented 4 years ago

Closing for now because there's not enough information to go on.