IllegalStateException in DefaultDrmSession in ExoPlayer 2.12.2

[GouravSna]

• Steps to reproduce:

1. In demo app, open Widevine DASH H264(MP4)
2. Open Secure(cenc)
3. Let the content start and then go to Background and come to forground.
4. Try this couple of time, till you see the following warning in adb logs,

2020-12-08 17:32:36.633 2238-4296/com.google.android.exoplayer2.demo W/MessageQueue: Handler (com.google.android.exoplayer2.drm.DefaultDrmSession$ResponseHandler) {81d56cf} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (com.google.android.exoplayer2.drm.DefaultDrmSession$ResponseHandler) {81d56cf} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:548)
        at android.os.Handler.enqueueMessage(Handler.java:745)
        at android.os.Handler.sendMessageAtTime(Handler.java:697)
        at android.os.Handler.sendMessageDelayed(Handler.java:667)
        at android.os.Handler.sendMessage(Handler.java:604)
        at android.os.Message.sendToTarget(Message.java:436)
        at com.google.android.exoplayer2.drm.DefaultDrmSession$RequestHandler.handleMessage(DefaultDrmSession.java:610)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:193)
        at android.os.HandlerThread.run(HandlerThread.java:65)

• ExoPlayer version number : 2.12.2
• Android version : 10
• Android device : Moto G6 (India)

What I can think of that when we go in BG, drmSession is released. This warning comes when coming in FG, drmSession is being tried to acquire on dead thread.

[icbaker]

I can't reproduce this using the steps provided on 2.12.2 on a Pixel 3a XL running Android R. I back & foregrounded the demo app >10 times (home key to put it in background, then long-press home to bring up app switcher and tap demo app to bring it back to foreground)

What happens to playback when you see the warning in the logs?

---

I did accidentally manage to trigger the warning a different way:

1. Rapidly switch between two different widevine-protected entries.
   • i.e. tap one then while it's buffering/starting tap back and tap a different one.
2. Keep repeating, eventually events align to trigger the warning

I couldn't see any impact on playback - when the warning is triggered the current video keeps playing fine.

It's arguably a bug that we trigger this warning at all - but it's obviously higher priority if you're seeing an impact on playback.

[GouravSna]

Hi @icbaker , Thanks for trying hard to reproduce it finally.

I also don't see any issue with the playback but i was afraid if this is because of some potential issue which i am not aware of.

I can think of why you don't see in Pixel 3, it may be because of soc that it has. If device is capable enough to handle this DRM session acquisition in those frequent attempts then it is difficult to reproduce on such device.

I am using Moto G6 (India) variant. But it would be really helpful if you can see the underlying warning cause. Still I am afraid of an issue on DRM playbacks.

[icbaker]

I think i've worked out the sequence of operations that causes this exception to be logged:

When dealing with DRM playback using the DefaultDrmSession there are 2 looper threads used: The playback thread and the DRM request thread.

Roughly this happens when opening a new session:

• playback looper: openSession kicks off key request on DRM request looper (RequestHandler) then immediately returns.
• DRM request looper: Waits for server response, then posts response back to ResponseHandler on playback looper.

In my repro steps (repeatedly opening different DRM videos) the playback looper is killed each time we return to the sample selector screen (because the player is being released). If this happens fast enough after playback starts, it happens between the two bullets above (i.e. while waiting for a response from the server). The RequestHandler code doesn't check if the ResponseHandler looper (the playback looper) is alive before posting the response from the server, hence the exception.

DefaultDrmSession does quit the request looper thread during release, but I believe this doesn't halt execution immediately if a message is being handled at that moment - it allows the current message to execute to completion, and prevents the next message in the queue from being executed.

I'll have a play with some different ways we can avoid trying to schedule work on a dead thread in this case.

[GouravSna]

Thanks @icbaker for the in depth explanation. I can understand that it could be on a low priority due to bit unusual scenario but I will curiously wait for the solution.
I hope it is not harmful anyways !