SinglePeriodTimeline.getPeriod assertion fails when manipulating playlist

[BrainCrumbz]

Before filing an issue:

• [✔] Search existing issues, including issues that are closed.
• [✔] Consult our FAQs, supported devices and supported formats pages. These can be
  found at https://google.github.io/ExoPlayer/.
• [✔] Rule out issues in your own code. A good way to do this is to try and
  reproduce the issue in the ExoPlayer demo app.
• [✔] This issue tracker is intended for bugs, feature requests and ExoPlayer
  specific questions. If you're asking a general Android development question,
  please do so on Stack Overflow.

When reporting a bug:

Issue description

We are manipulating a playlist of local MP4 files through ConcatenatingMediaSource. When we perform a particular sequence of actions on the list, we incur systematically into an IndexOutOfBoundsException when SinglePeriodTimeline.getPeriod checks index.

We've a sample project showing the issue. To the purpose of explanation, consider tracks named as C, D, E, F, G. Every action waits for enough time to let the previous one completed.
The sequence of actions is:

1. Add initial track (C).
   • Once completed, Tracklist is: [ C ]
2. C starts playing.
   • Tracklist is: [ _C_ ]
3. When C is playing, add second batch of tracks (D, E, F).
   • Once completed, Tracklist is: [ _C_ | D | E | F ]
4. While C is still playing, move F to become the next coming track (instead of D).
   • Once completed, Tracklist is: [ _C_ | F | D | E ]
5. F starts playing.
   • Tracklist is: [ C | _F_ | D | E ]
6. When F starts playing, remove the other tracks. First C, then D, then E. Each one waiting for completion of previous one
   • Once completed, Tracklist is: [ _F_ ]
7. Add third batch of tracks (only G).
   • Here exception is thrown, when traying to add media sources to playlist

There are other cases when another assertion fails, when we create a loop source after some playlist manipulation, but those are out of the current scope and we're not able yet to reproduce it systematically.

Reproduction steps

Build and run (on emulator or device) the project that will be sent by email. A few seconds after video F starts playing, app will crash with following:

09-26 13:09:36.235 9716-9716/com.braincrumbz.fatalgetperiod D/MainActivity: adding third batch...
    	Tracklist is: [ _F_ ]
09-26 13:09:36.238 9716-9716/com.braincrumbz.fatalgetperiod D/AndroidRuntime: Shutting down VM
    
    
    --------- beginning of crash
09-26 13:09:36.238 9716-9716/com.braincrumbz.fatalgetperiod E/AndroidRuntime: FATAL EXCEPTION: main
    Process: com.braincrumbz.fatalgetperiod, PID: 9716
    java.lang.IndexOutOfBoundsException
        at com.google.android.exoplayer2.util.Assertions.checkIndex(Assertions.java:68)
        at com.google.android.exoplayer2.source.SinglePeriodTimeline.getPeriod(SinglePeriodTimeline.java:186)
        at com.google.android.exoplayer2.source.ConcatenatingMediaSource$DeferredTimeline.getPeriod(ConcatenatingMediaSource.java:841)
        at com.google.android.exoplayer2.source.AbstractConcatenatedTimeline.getPeriod(AbstractConcatenatedTimeline.java:176)
        at com.google.android.exoplayer2.analytics.AnalyticsCollector$MediaPeriodQueueTracker.updateMediaPeriodToNewTimeline(AnalyticsCollector.java:778)
        at com.google.android.exoplayer2.analytics.AnalyticsCollector$MediaPeriodQueueTracker.onTimelineChanged(AnalyticsCollector.java:724)
        at com.google.android.exoplayer2.analytics.AnalyticsCollector.onTimelineChanged(AnalyticsCollector.java:424)
        at com.google.android.exoplayer2.ExoPlayerImpl$PlaybackInfoUpdate.notifyListeners(ExoPlayerImpl.java:746)
        at com.google.android.exoplayer2.ExoPlayerImpl.updatePlaybackInfo(ExoPlayerImpl.java:681)
        at com.google.android.exoplayer2.ExoPlayerImpl.handlePlaybackInfo(ExoPlayerImpl.java:622)
        at com.google.android.exoplayer2.ExoPlayerImpl.handleEvent(ExoPlayerImpl.java:567)
        at com.google.android.exoplayer2.ExoPlayerImpl$1.handleMessage(ExoPlayerImpl.java:109)
        at android.os.Handler.dispatchMessage(Handler.java:102)
        at android.os.Looper.loop(Looper.java:154)
        at android.app.ActivityThread.main(ActivityThread.java:6119)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)
09-26 13:09:38.752 9716-9806/com.braincrumbz.fatalgetperiod W/SoftwareRenderer: Surface::dequeueBuffer returned error -19

We tried several constructors signatures for ConcatenatingMediaSource (atomic or not, different ShuffleOrder) with no luck.

Link to test content

Please wait for link by email.

Version of ExoPlayer being used

'com.google.android.exoplayer:exoplayer-core:2.8.2'
'com.google.android.exoplayer:exoplayer-dash:2.8.2'
'com.google.android.exoplayer:exoplayer-ui:2.8.2'

Device(s) and version(s) of Android being used

Emulator, both Nexus 5 API 25 and Nexus 5X API 28.

A full bug report captured from the device

See bugreport-NYC-2018-09-26-13-19-45.zip here attached. There's also a logcat, just in case.

bugreport-NYC-2018-09-26-13-19-45.zip
logcat-2018-09-26-13-19-45.txt

Question is: are we doing something wrong? How to avoid this? Thanks!

[tonihei]

I think that's a duplicate of #4634 and should no longer occur on the dev-v2 branch (and the upcoming 2.9.0 release).

[BrainCrumbz]

If it can help, we'd just like to point out that this happens at the time when adding the third batch. It does not happen if we do not perform that step. And it does not happen if previously we don't move tracks around.

Are there instructions on how to try the dev-v2 branch? Nevermind, here they are https://github.com/google/ExoPlayer/tree/dev-v2-r2.9.0#locally

Thanks for quick reply, BTW

[tonihei]

Yes, thanks for the reproduction steps. The issue was produced by changing the indices in the playlist before some events were reported which still had the old index. That totally messed up the event tracking. We prevented the whole issue from happening by switching to unique ids which are independent of the index in the playlist.

[BrainCrumbz]

Tried adding dev-v2-r2.9.0 locally to the project, and exception is gone. 💯

We also experienced a similar situation with following stacktrace:

09-13 13:57:32.525 2374-2406/com.hypexvideo.marveldemoapp E/ExoPlayerImplInternal: Internal runtime error.
    java.lang.IllegalArgumentException
        at com.google.android.exoplayer2.util.Assertions.checkArgument(Assertions.java:39)
        at com.google.android.exoplayer2.source.ExtractorMediaSource.createPeriod(ExtractorMediaSource.java:358)
        at com.google.android.exoplayer2.source.LoopingMediaSource.createPeriod(LoopingMediaSource.java:73)
        at com.google.android.exoplayer2.source.DeferredMediaPeriod.createPeriod(DeferredMediaPeriod.java:105)
        at com.google.android.exoplayer2.source.MMPlaylistMediaSource.createPeriod(MMPlaylistMediaSource.java:467)
        at com.google.android.exoplayer2.MediaPeriodHolder.<init>(MediaPeriodHolder.java:84)
        at com.google.android.exoplayer2.MediaPeriodQueue.enqueueNextMediaPeriod(MediaPeriodQueue.java:151)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.maybeUpdateLoadingPeriod(ExoPlayerImplInternal.java:1488)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.updatePeriods(ExoPlayerImplInternal.java:1367)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:495)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:301)
        at android.os.Handler.dispatchMessage(Handler.java:101)
        at android.os.Looper.loop(Looper.java:156)
        at android.os.HandlerThread.run(HandlerThread.java:61)

Is that the same root cause, or should we open a new issue? (MMPlaylistMediaSource is a copy of the improved ConcatenatingMediaSource that we helped creating with PR #4564, the one with removeMediaSourceRange API).

[tonihei]

Could be, but also maybe not. :)

Do I understand it correctly that you are using a ConcatenatingMediaSource with a LoopingMediaSource of a ExtractorMediaSource?
And is the LoopingMediaSource using a non-infinite loop count? If so, it was probably fixed by 656c217.

[BrainCrumbz]

In that mentioned scenario, we are using a ConcatenatingMediaSource. At some point, after playlist manipulation (add/ remove/ move), we add a LoopingMediaSource. That one is built out of a regular, single MediaSource, which in turn is created through the following snippet:

final RawResourceDataSource rawResourceDataSource = new RawResourceDataSource(context);

DataSource.Factory dataSourceFactory = new DataSource.Factory() {
    @Override
    public DataSource createDataSource() {
        return rawResourceDataSource;
    }
};

ExtractorMediaSource.Factory mediaSourceFactory = new ExtractorMediaSource.Factory(dataSourceFactory);

DataSpec dataSpec = new DataSpec(RawResourceDataSource.buildRawResourceUri(resourceId));

try {
    rawResourceDataSource.open(dataSpec);
} catch (RawResourceDataSource.RawResourceDataSourceException e) {
    e.printStackTrace();

    return null;
}

MediaSource source = mediaSourceFactory.createMediaSource(rawResourceDataSource.getUri());

The loop does use an infinite loop count.

[tonihei]

Thanks! It seems that may still be a problem.

I think this is what's happening:

1. Player message queue: [doSomeWork]
2. ConcatenatingMediaSource.removeMediaSource is called -> a message is enqueued to remove the media source. New queue: [doSomeWork, removeMediaSource]
3. doSomeWork queues another doSomeWork for the next cycle. New queue: [removeMediaSource, doSomeWork]
4. removeMediaSource updates the internal state of ConcatenatingMediaSource and tells the player to update it's timeline. New queue: [doSomeWork, updateTimeline]
5. doSomeWork checks if a new period needs to be created (e.g. because the previous one finished loading). If that happens, it calls mediaSource.createPeriod. Note that at this point the player still has a timeline including the media source we just removed. So it may call ConcatenatingMediaSource.createPeriod for a period which no longer is part of the playlist.
6. If this period is the last one in the timeline, it forwards the wrong index to the new last period in the timeline. That's the exception you are seeing.

Note that this is the combination of three unlikely events: 1. a doSomeWork message which sneaks in between the playlist and the timeline update, 2. a fully buffered media period exactly in this moment, 3. a situation where the player attempts to re-buffer the last period in the timeline (that's why it happens for the LoopingMediaSource).

We changed the code for 2.9.0 but the problem still exists. You will most likely receive a null pointer exception now.

[BrainCrumbz]

Thanks for explanation, although now we got a little bit lost.

Q1: With respect to the error being described in detail at the top (IndexOutOfBoundsException from SinglePeriodTimeline.getPeriod), it seems to me that 2.9.0 would solve that. Is that right?

Q2: With respect to the other error scenario I mentioned afterwards (IllegalArgumentException from ExtractorMediaSource.createPeriod), is your explanation here above related to that? If so, maybe we better create a dedicated issue for that, so not to mix up things.

[tonihei]

Yes, sorry. The issue reported at the top is fixed in 2.9.0.
The second issue reported here still persists and will be fixed. Fine to leave as it is. I already fixed it ;)