evaluateMediaItemTransitionReason - IllegalStateException

[Tolriq]

ExoPlayer Version

2.17.1

Devices that reproduce the issue

There does not seem to have specific devices from Play Console crashs.
Android 12/11/9 - Samsung/OnPlus/..

Devices that do not reproduce the issue

No response

Reproducible in the demo app?

No

Reproduction steps

Don't know :(

The crash is not reproducible here and seems rare, all calls are properly made on the same thread.

The crash does not give any useful information about the possible causes so I have no clue what to do next.

The stack trace also does not make sense since it seems it should only called for ads and I never queue or use ads in the app, it's music files played. What could trigger this check to be true?
Some users maybe playing transcoded media in strange formats, is there something I can do to avoid false classification as ads ?

Expected result

No crash, or something that we can catch.

Actual result

Crash with:

java.lang.IllegalStateException:
  at com.google.android.exoplayer2.ExoPlayerImpl.evaluateMediaItemTransitionReason (ExoPlayerImpl.java:2089)
  at com.google.android.exoplayer2.ExoPlayerImpl.updatePlaybackInfo (ExoPlayerImpl.java:1805)
  at com.google.android.exoplayer2.ExoPlayerImpl.handlePlaybackInfo (ExoPlayerImpl.java:1774)
  at com.google.android.exoplayer2.ExoPlayerImpl.lambda$new$1 (ExoPlayerImpl.java:306)
  at androidx.profileinstaller.ProfileInstallerInitializer$$InternalSyntheticLambda$1$0f795b3312dc1da540aed76dfe7be9153bc2dd822b10dd31dcd76fb9862960b5$0.run$bridge (ProfileInstallerInitializer.java:0)
  at android.os.Handler.handleCallback (Handler.java:873)
  at android.os.Handler.dispatchMessage (Handler.java:99)
  at android.os.Looper.loop (Looper.java:214)
  at android.app.ActivityThread.main (ActivityThread.java:7073)
  at java.lang.reflect.Method.invoke (Native Method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:494)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:965)

Media

N/A

Bug Report

N/A

[ojw28]

@marcbaechinger - Please take a look!

[Tolriq]

Bump on this one still occurs and no idea what I can do about it.

[marcbaechinger]

Yeah, not sure where this is coming from I'm afraid. We had a similar complaint in #8639 where it was resolved by reviewing the app and not calling the player from different threads. From your post I see you say you are doing this already?

That's actually everything I can say with the information available as I'm also not able to repro this.

How many percentage of your users are seeing this? Are all using the same app version and ExoPlayer 2.17.1 that see the crash?

[Tolriq]

Yes every calls are on the mainthread ensured via couroutines.

The only case I don't enforce is inside the listener callbacks but the player is initialized with

        exoPlayer = ExoPlayer.Builder(applicationContext, AudioOnlyRendererFactory(applicationContext, allowMpeg, replayGainProcessor))
            .setTrackSelector(trackSelector)
            .setLooper(mainLooper)
            .build()
        exoPlayer.addListener(exoPlayerEventListener)

So from my understanding the mainLooper will be used for the listener callbacks no? Or I should ensure that the listener is applied on the wanted thread?

The percentage is very small but that app is new and just starts so it's hard to properly calculate it. They are all using ExoPlayer 2.17.1.

[Tolriq]

So even with adding the listener on the proper thread the issue still occurs.

Can you please at least add a proper message to the exception for debug purpose?

[Tolriq]

@marcbaechinger Bump on this one to be able to progress.
Now that 6043739 is merged I can use a custom build that does not throw and log something to analytics to be able to gather some data.

Can you please tell me exactly what I should gather from evaluateMediaItemTransitionReason when reaching the issue so you may have necessary info to figure out the root cause?

[marcbaechinger]

Interesting would be the values of the arguments of the method specifically positionDiscontinuity and positionDiscontinuityReason. Also the playbackState, positionUs, playbackError!=null of the arguments playbackInfo and oldPlaybackInfo. That would help to understand what kind of API call or playback event has originated the change of the window UID.

Further the oldWindowIndex and newWindowIndex and the number of windows in the old and the new timeline.

[Tolriq]

Thanks.

For the moment I've only logged
positionDiscontinuity = false
positionDiscontinuityReason = 0
And the oldWindowUid / newWindowUid = java.lang.Object@8d4a4fb/java.lang.Object@102901d that are different.

I'll try to add the others.

As a test I also return transitionReason = MEDIA_ITEM_TRANSITION_REASON_PLAYLIST_CHANGED;

And it leads to new crash that may help understand? (Those calls do happen on the proper mainthread)

java.lang.ArrayIndexOutOfBoundsException:
  at com.google.android.exoplayer2.PlaylistTimeline.getTimelineByChildIndex (PlaylistTimeline.java:86)
  at com.google.android.exoplayer2.AbstractConcatenatedTimeline.getNextWindowIndex (AbstractConcatenatedTimeline.java:98)
  at com.google.android.exoplayer2.BasePlayer.getNextMediaItemIndex (BasePlayer.java:301)
  at com.google.android.exoplayer2.BasePlayer.hasNextMediaItem (BasePlayer.java:231)
  at com.google.android.exoplayer2.util.Util.getAvailableCommands (Util.java:2554)
  at com.google.android.exoplayer2.ExoPlayerImpl.updateAvailableCommands (ExoPlayerImpl.java:2111)
  at com.google.android.exoplayer2.ExoPlayerImpl.updatePlaybackInfo (ExoPlayerImpl.java:1951)
  at com.google.android.exoplayer2.ExoPlayerImpl.addMediaSources (ExoPlayerImpl.java:637)
  at com.google.android.exoplayer2.ExoPlayerImpl.addMediaSources (ExoPlayerImpl.java:620)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistInsert$2.invokeSuspend (MusicPlayer.kt:441)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistInsert$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistInsert$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invokeSuspend (MusicPlayer.kt:99)
  at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith (ContinuationImpl.kt:33)
  at kotlinx.coroutines.DispatchedTask.run (DispatchedTask.kt:106)
  at android.os.Handler.handleCallback (Handler.java:873)
  at android.os.Handler.dispatchMessage (Handler.java:99)
  at android.os.Looper.loop (Looper.java:214)
  at android.app.ActivityThread.main (ActivityThread.java:7094)
  at java.lang.reflect.Method.invoke (Native Method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:494)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:975)

Reading code it might be caused by #9889 (Well that PR may fix it not be the cause) as I do use a customshuffleorder in this app that have this issue and not in another app that does not have this issue.

I'll improve the gathered logs to be sure that they are more useful, I'll soon release an update rebased on 2.18.1 to see (Waiting for a compose fix)

[Tolriq]

Ok so was able to catch another error that confirm some issues with shuffle order.

The stack trace is large due to the coroutines withContext without context switch to ensure the main thread access so only the last 5 lines are important.

@marcbaechinger and ping @tonihei as he helped me build the customShuffle order.

This error is mostly expected and possible due to

    int firstChildIndex = shuffleModeEnabled ? shuffleOrder.getFirstIndex() : 0;
    while (getTimelineByChildIndex(firstChildIndex).isEmpty()) {

getFirstIndex() can return C.INDEX_UNSET that will then break the getTimelineByChildIndex it should be checked and directly return C.INDEX_UNSET

java.lang.ArrayIndexOutOfBoundsException:
  at com.google.android.exoplayer2.PlaylistTimeline.getTimelineByChildIndex (PlaylistTimeline.java:86)
  at com.google.android.exoplayer2.AbstractConcatenatedTimeline.getFirstWindowIndex (AbstractConcatenatedTimeline.java:180)
  at com.google.android.exoplayer2.Timeline.equals (Timeline.java:1346)
  at com.google.android.exoplayer2.ExoPlayerImpl.updatePlaybackInfo (ExoPlayerImpl.java:1823)
  at com.google.android.exoplayer2.ExoPlayerImpl.setShuffleOrder (ExoPlayerImpl.java:712)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistUpdated$2.invokeSuspend (MusicPlayer.kt:417)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistUpdated$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$playlistUpdated$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invokeSuspend (MusicPlayer.kt:99)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invoke (MusicPlayer.kt:0)
  at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn (Undispatched.kt:89)
  at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext (BuildersKt__Builders_common.kt:169)
  at kotlinx.coroutines.BuildersKt.withContext (Builders.kt:1)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer.withExoPlayer (MusicPlayer.kt:98)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer.playlistUpdated (MusicPlayer.kt:417)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$setShuffled$1$1.invokeSuspend (MusicPlayer.kt:569)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$setShuffled$1$1.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$setShuffled$1$1.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invokeSuspend (MusicPlayer.kt:99)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invoke (MusicPlayer.kt:0)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$withExoPlayer$2.invoke (MusicPlayer.kt:0)
  at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn (Undispatched.kt:89)
  at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext (BuildersKt__Builders_common.kt:169)
  at kotlinx.coroutines.BuildersKt.withContext (Builders.kt:1)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer.withExoPlayer (MusicPlayer.kt:98)
  at app.symfonik.renderer.localdevice.exoplayer.MusicPlayer$setShuffled$1.invokeSuspend (MusicPlayer.kt:567)
  at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith (ContinuationImpl.kt:33)
  at kotlinx.coroutines.DispatchedTask.run (DispatchedTask.kt:106)
  at android.os.Handler.handleCallback (Handler.java:938)
  at android.os.Handler.dispatchMessage (Handler.java:99)
  at android.os.Looper.loopOnce (Looper.java:226)
  at android.os.Looper.loop (Looper.java:313)
  at android.app.ActivityThread.main (ActivityThread.java:8663)
  at java.lang.reflect.Method.invoke (Native Method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:567)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1135)

[tonihei]

getFirstIndex() can return C.INDEX_UNSET that will then break the getTimelineByChildIndex it should be checked and directly return C.INDEX_UNSET

getFirstIndex() is only allowed to return C.INDEX_UNSET if the shuffle order (and the corresponding Timeline) is empty. Do you have empty Timelines somewhere? I think an empty Timeline created by one of the MediaSources could trigger this error.

[Tolriq]

It's possible to reach this state when clearing playlist yes.

[tonihei]

A completely empty playlist shouldn't cause problems because AbstractConcatenatedTimeline.getFirstWindowIndex checks childCount == 0 right at the beginning. I can only imagine having a MediaSource set that publishes an empty Timeline (e.g. Do you use ConcatenatingMediaSource?)

[Tolriq]

No I no more use that. It's possible that this is a side effect then of my change Tolriq@e6156fd to try to identify the root cause of the first issue and not a cause then :(

I hoped that the side crash would give enough clue, but I'm still pretty sure there's something wrong (or I do something wrong) with the customshuffle reason this only happens in this app.

[tonihei]

Reading code it might be caused by #9889 (Well that PR may fix it not be the cause) as I do use a customshuffleorder in this app that have this issue and not in another app that does not have this issue.

I can't explain how exactly, but this could potentially fix it because it ensures Timelines with different ShuffleOrder values are not equal and thus can't trigger the IllegalStateException. Worth giving it a try (and keep the additional logging, just in case).

[Tolriq]

Thanks it's blocked by Play Store review team because of the new Android 13 form to fill let's hope they don't take 15 days.

[Tolriq]

@tonihei Actually the last crash from setShuffleOrder was from an internal alpha tester with a recent build based on 2.18.1 already.
There's no Invalid transaction log in the analytics but the user may have disabled analytics :(

Any other possible reason that I should try to log to analytics?

The related code:

shuffleModeEnabled = shuffled
setShuffleOrder(ShuffleOrder.DefaultShuffleOrder(playlist.indices, randomSeed)

Edit1:
Could it actually be the opposite and the user somehow manage to clear the playlist and disable shuffle at the same time?
Leading to no shuffle and empty playlist and so the index error is because of the 0?

Edit2: Actually this is something like that I'm able to repro now and the error is
java.lang.ArrayIndexOutOfBoundsException: length=0; index=0

Exoplayer in shuffled mode with a playlist.
Exoplayer.stop()
Clear the playlist
setshuffled(false)
update customorder
crash.

So there's a state problem somewhere leading to that childCount not being 0 despite the stop and the clearplaylist.
Any idea what I need to debug?

[Tolriq]

Ok so the app was published and the original issue is effectively fixed, allowing to figure out the real issue.

#10244 (comment)

Was triggered because of a well hidden launch in my code that trigged a small possible race between the update of the shuffle and the next addition to the playlist.

Basically it sometimes reached setShuffleOrder(ShuffleOrder.DefaultShuffleOrder(playlist.indices, randomSeed)) with playlist.indices having 1 entry but the actual Exoplayer playlist having 0 entries.

@tonihei Don't know if this worth a check and a better error message to help to diagnose this kind of issues. If not then this issue can be closed.

[tonihei]

Basically it sometimes reached setShuffleOrder(ShuffleOrder.DefaultShuffleOrder(playlist.indices, randomSeed)) with playlist.indices having 1 entry but the actual Exoplayer playlist having 0 entries.

Did you reach this state purely by using ExoPlayer API calls to setShuffleOrder and other playlist manipulation methods like addMediaSource/Item? Or is the problem somewhere in your own custom code? Because if it's in ExoPlayer code, we definitely want fix the issue if there is a race condition that can trigger exceptions.

[Tolriq]

It's my code that had the small race, but before 2.18.1 fix impossible to debug.
And still hard to diagnose due to the complexity of timelines and everything in playlist and gapless.

So was hoping for some easy test that could be added on ExoPlayer side to help detecting such things if possible, if not then now I know a little more how to debug those :)

[tonihei]

I think throwing the exception already solves this issue by failing-fast as soon as we detect something doesn't match. It's unfortunately never easy to detect the root cause of threading race conditions, so I don't see what else we could provide in this case. I'll close the issue under this assumption. If you have a concrete documentation proposal for something you would have liked to read when writing your custom code, please let us know and we can add this.