Video player gets stuck when stating a video from pre-defined (known) position on video containing multiple mid breaks.

[nishantkp]

Issue description

Stating a video from pre-defined position on video with multiple mid-rolls will get stuck. Either it will not play content (or get stuck on content) or will get stuck on pod and doesn't resume content anymore.

Code used for stating a video from known position,

 player.prepare(mediaSource, false, false);
 player.seekTo(35000);

AdsLoader.AdsLoadedListener will fire CONTENT_RESUME_REQUESTED and CONTENT_PAUSE_REQUESTED events but it doesn't do anything. If player is playing an Ad and when all the ads are completed in pod CONTENT_RESUME_REQUESTED gets fired but content is not resuming. Same goes for Ads, CONTENT_PAUSE_REQUESTED gets fired and player will not play ads and it looks like player is frizzed.

Reproduction steps

Play a video for VMAP pre-roll single ad, mid-roll standard pods with 5 ads every 10 seconds

NOTE :

This happens only on video with multiple mid-rolls. Any video which has single mid-roll will be fine. You can check VMAP pre-roll single ad, mid-roll optimized pod with 3 ads, post-roll single ad and it will work just fine.

Link to test content

Reproducible on demo-app

A full bug report captured from the device

I/ExoPlayerImpl: Init b233575 [ExoPlayerLib/2.11.1] [gts210vewifi, SM-T813, samsung, 24]
2020-03-02 11:05:37.625 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: state [eventTime=0.00, mediaPos=0.00, window=0, true, BUFFERING]
2020-03-02 11:05:37.626 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: seekStarted [eventTime=0.01, mediaPos=0.00, window=0]
2020-03-02 11:05:37.626 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: positionDiscontinuity [eventTime=0.01, mediaPos=35.00, window=0, SEEK]
2020-03-02 11:05:37.652 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: ThreadedRenderer.create() translucent=false
2020-03-02 11:05:37.663 32452-32452/com.google.android.exoplayer2.demo D/InputTransport: Input channel constructed: fd=190
2020-03-02 11:05:37.664 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: setView = DecorView@8eb5d44[PlayerActivity] touchMode=true
2020-03-02 11:05:37.665 32452-32464/com.google.android.exoplayer2.demo I/art: Background sticky concurrent mark sweep GC freed 47690(3MB) AllocSpace objects, 1(20KB) LOS objects, 29% free, 9MB/13MB, paused 5.016ms total 35.756ms
2020-03-02 11:05:37.674 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: dispatchAttachedToWindow
2020-03-02 11:05:37.695 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: Relayout returned: oldFrame=[0,0][0,0] newFrame=[0,0][2048,1536] result=0x27 surface={isValid=true 547222286848} surfaceGenerationChanged=true
2020-03-02 11:05:37.696 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: mHardwareRenderer.initialize() mSurface={isValid=true 547222286848} hwInitialized=true
2020-03-02 11:05:37.719 32452-32452/com.google.android.exoplayer2.demo D/SurfaceView: Relayout returned: oldFrame=[0,0][0,0] newFrame=[0,48][2048,1536] result=0x7 surface={Surface(name=null)/@0x9399e2d isValid=true 547246427136}
2020-03-02 11:05:37.720 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: surfaceSize [eventTime=0.10, mediaPos=35.00, window=0, 2048, 1488]
2020-03-02 11:05:37.759 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: Relayout returned: oldFrame=[0,0][2048,1536] newFrame=[0,0][2048,1536] result=0x1 surface={isValid=true 547222286848} surfaceGenerationChanged=false
2020-03-02 11:05:37.778 32452-32452/com.google.android.exoplayer2.demo D/SurfaceView: Relayout returned: oldFrame=[0,48][2048,1536] newFrame=[0,48][2048,1536] result=0x1 surface={Surface(name=null)/@0x9399e2d isValid=true 547280787456}
2020-03-02 11:05:37.804 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: MSG_RESIZED_REPORT: frame=Rect(0, 0 - 2048, 1536) ci=Rect(0, 48 - 0, 0) vi=Rect(0, 48 - 0, 0) or=2
2020-03-02 11:05:37.804 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: MSG_WINDOW_FOCUS_CHANGED 1
2020-03-02 11:05:37.804 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@e14de57[PlayerActivity]: mHardwareRenderer.initializeIfNeeded()#2 mSurface={isValid=true 547222286848}
2020-03-02 11:05:37.805 32452-32452/com.google.android.exoplayer2.demo V/InputMethodManager: Starting input: tba=android.view.inputmethod.EditorInfo@e2eefae nm : com.google.android.exoplayer2.demo ic=null
2020-03-02 11:05:37.805 32452-32452/com.google.android.exoplayer2.demo I/InputMethodManager: [IMM] startInputInner - mService.startInputOrWindowGainedFocus
2020-03-02 11:05:37.825 32452-32452/com.google.android.exoplayer2.demo D/InputTransport: Input channel constructed: fd=188
2020-03-02 11:05:37.825 32452-32452/com.google.android.exoplayer2.demo D/InputTransport: Input channel destroyed: fd=151
2020-03-02 11:05:37.868 32452-32523/com.google.android.exoplayer2.demo D/OpenGLRenderer: endAllActiveAnimators on 0x7f70660000 (ExpandableListView) with handle 0x7f5a04dbe0
2020-03-02 11:05:37.868 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@46051f4[SampleChooserActivity]: mHardwareRenderer.destroy()#1
2020-03-02 11:05:37.873 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@46051f4[SampleChooserActivity]: Relayout returned: oldFrame=[0,0][2048,1536] newFrame=[0,0][2048,1536] result=0x5 surface={isValid=false 0} surfaceGenerationChanged=true
2020-03-02 11:05:38.266 32452-32452/com.google.android.exoplayer2.demo D/ViewRootImpl@46051f4[SampleChooserActivity]: Relayout returned: oldFrame=[0,0][2048,1536] newFrame=[0,0][2048,1536] result=0x5 surface={isValid=false 0} surfaceGenerationChanged=false
2020-03-02 11:05:38.291 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: timeline [eventTime=0.67, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=PREPARED
2020-03-02 11:05:38.291 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   period [?]
2020-03-02 11:05:38.291 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   window [?, false, false]
2020-03-02 11:05:38.291 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: ]
2020-03-02 11:05:38.293 32452-32452/com.google.android.exoplayer2.demo D/IMASDK: AdsManager.init -> Setting contentStartTime 35.0
2020-03-02 11:05:38.294 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: seekProcessed [eventTime=0.67, mediaPos=0.00, window=0]
2020-03-02 11:05:38.300 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: timeline [eventTime=0.68, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=DYNAMIC
2020-03-02 11:05:38.300 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   period [?]
2020-03-02 11:05:38.300 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   window [?, false, false]
2020-03-02 11:05:38.300 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: ]
2020-03-02 11:05:38.303 32452-32452/com.google.android.exoplayer2.demo W/IMASDK: Invalid internal message, ignoring. Please make sure the Google IMA SDK library is up to date. Message: gmsg://afma.google.com/activityMonitor?type=getPageSignals&sid=4b1a6c61-84af-4334-848c-adf48dc28e62&dt=1583165138298
2020-03-02 11:05:38.456 32452-32452/com.google.android.exoplayer2.demo W/ImaAdsLoader: Expected ad group index 3, actual ad group index 5
2020-03-02 11:05:38.457 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: timeline [eventTime=0.84, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=DYNAMIC
2020-03-02 11:05:38.457 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   period [?]
2020-03-02 11:05:38.457 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   window [?, false, false]
2020-03-02 11:05:38.457 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: ]
2020-03-02 11:05:38.508 32452-32452/com.google.android.exoplayer2.demo W/IMASDK: Invalid internal message, ignoring. Please make sure the Google IMA SDK library is up to date. Message: gmsg://afma.google.com/videoDisplay?type=activate&sid=4b1a6c61-84af-4334-848c-adf48dc28e62&dt=1583165138501
2020-03-02 11:05:38.515 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: timeline [eventTime=0.89, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=DYNAMIC
2020-03-02 11:05:38.515 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   period [?]
2020-03-02 11:05:38.515 32452-32452/com.google.android.exoplayer2.demo D/EventLogger:   window [?, false, false]
2020-03-02 11:05:38.515 32452-32452/com.google.android.exoplayer2.demo D/EventLogger: ]

Version of ExoPlayer being used

2.10.7 and onwards (did not check previous ones)

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

api 21 and above (did not check older ones)

[donato]

Thank you @nishantkp this is verified and I'm working on a fix now.

[donato]

The fix is in a canary, which is being served at 1% traffic. We hope to launch it on Monday morning EST.

[nishantkp]

Thats great @donato.

[nishantkp]

Hi @donato,

Any updates on this one?

[donato]

Release is rolling out now.

This is a bugfix to behavior for AdsRenderingSettings.playAdsAfterTime and may impact some players more than others, depending on their usage of that setting.

Overall results looked good in our analysis.

On Mon, Mar 9, 2020 at 4:00 PM Nishant Patel notifications@github.com wrote:

Hi @donato https://github.com/donato,

Any updates on this one?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/ExoPlayer/issues/7038?email_source=notifications&email_token=AAHFOAUMLASEKJVLGHOLWP3RGVKILA5CNFSM4K7XV7X2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEOI3DWA#issuecomment-596750808, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAHFOAVTAABKHSTQ5BMORFTRGVKILANCNFSM4K7XV7XQ .

[nishantkp]

Hi @donato,

Still have this issue (still able to reproduce in demo app). Is it a server side release or SDK update? Meanwhile, is there anything we can do on client side?

[donato]

Thank you for following up. This was a server-side update, I will check again to look for other unexpected behaviors.

On Tue, Mar 10, 2020 at 10:05 AM Nishant Patel notifications@github.com wrote:

Hi @donato https://github.com/donato,

Still have this issue (still able to reproduce in demo app). Is it a server side release or SDK update? Meanwhile, is there anything we can do on client side?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/ExoPlayer/issues/7038?email_source=notifications&email_token=AAHFOAWACBIENAY5GUDJUY3RGZCKRA5CNFSM4K7XV7X2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEOLRLFI#issuecomment-597104021, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAHFOAQKFAS2WUCP64WXEW3RGZCKRANCNFSM4K7XV7XQ .

[TakuSemba]

This happened to me and still have this issue on v3.202.1.

[donato]

It looks like the ad break index for skipped ads was being calculated a little differently.

For example if we had an ad at [10, 20, 30], their ad pod index would be 1, 2, 3. When skipping ads, the old behavior would update the ad pod index, to reflect the new ordering. For example if skipping the first two ads, then the third ad would have an updated pod index of 1. This rewriting of the ad pod index was removed, which I believe is impacting ExoPlayer. I will work adding it back in today and hopefully release soon after.

On Tue, Mar 10, 2020 at 11:52 PM TakuSemba notifications@github.com wrote:

This happened to me and still have this issue on v3.202.1.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/ExoPlayer/issues/7038?email_source=notifications&email_token=AAHFOAS7XCKU4P3YHOIA5QLRG4DIDA5CNFSM4K7XV7X2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEOOBFJQ#issuecomment-597430950, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAHFOAXHI2A7EQDCVO4V533RG4DIDANCNFSM4K7XV7XQ .

[TakuSemba]

@donato Hi, Thank you for the fix, but unfortunately, it still happens to me on v3.203.1.

You can reproduce it easily just setting initial position 25 * 1000 for VMAP pre-roll single ad, mid-roll standard pods with 5 ads every 10 seconds for 1:40, post-roll single ad on ExoPlayer demo. You can see that ExoPlayer gets stuck whenever you try to play the ad.

It seems like it happens when an initial seek position is over the second mid-point.

private void initializePlayer() {
    ...
    player.prepare();
    player.seekTo(25 * 1000);
    ...
}

And I have a few requests. The first request is there any chance of making IMA-SDK open-source so that we can look into what is happening and what is wrong. Currently, what we can do is just waiting for the fix.

The second request is that is it possible to stop updating the internal js version? I want to change the behavior only when I changed com.google.ads.interactivemedia.v3 version on Gradle.

implementation 'com.google.ads.interactivemedia.v3:interactivemedia:x.xxx.x'

I hope you would consider my suggestions kindly. Thanks!

[nishantkp]

Hi @donato,

@TakuSemba is right. It is still happening. Thanks a bunch for quick release though.

[donato]

Thank you for the feedback!

I was testing part 2 of the fix overnight and results look promising. I'm rolling it out now, so let me know if you see any changes in behavior (I'd give it another 15 minutes to deploy completely).

[nishantkp]

Hi @donato,

Awesome, It looks good on demo app. I do not see any unexpected behaviour. If something goes wrong, i will keep you posted.

Once again, thanks a bunch! 👏

[TakuSemba]

Hi, @donato,

I also confirmed that it worked as expected! Thanks for the fix, and thanks for the consideration of my feedback.