Exoplayer: MediaCodecRenderer bypass does not handle empty streams correctly

[AlienAsRoger]

In our code we had this part

new AdsMediaSource(SilenceMediaSource(0), sourceFactory, adsLoader, playerView);

which was working fine with ExoPlayer version 2.11.8

In order to launch standalone IMA preroll and then when it finishes launch another player which might not be ExoPlayer. So we relied on correct callback which is called

Steps to reproduce

1. Modify media.exolist.json

        "name": "TuneIn sample",
        "uri": "https://storage.googleapis.com/exoplayer-test-media-1/mkv/android-screens-lavf-56.36.100-aac-avc-main-1280x720.mkv",
        "ad_tag_uri": "https://pubads.g.doubleclick.net/gampad/ads?iu=/15480783/Mobile-Preroll-Video/Android&correlator=1608131292462&env=vp&impl=s&url=tunein.player&gdfp_req=1&output=vast&unviewed_position_start=1&ciu_szs=300x250&description_url=https%3A%2F%2Ftunein.com%2Fdesc%2Fs250018%2F&sz=1x1%7C400x300%7C640x360%7C640x480&us_privacy=1YNY&gdpr=0&gdpr_consent=&cust_params=useragent%3DTuneIn+Radio-25.8+%28Android-30%3B+Pixel+3%3B+Java%29%26partnerId%3DxwhZkVKi%26ListingId%3Ds250018%26genre_id%3Dg4136%26class%3Dmusic%26stationId%3Ds250018%26is_mature%3Dfalse%26is_family%3Dfalse%26is_event%3Dfalse%26is_ondemand%3Dfalse%26language%3Den_US%26version%3D25.8%26persona%3DMusic%26is_new_user%3Dfalse%26device%3Dphone%26country_region_id%3D100436%26videoEnabled%3Dtrue%26audioEnabled%3Dtrue%26station_language%3DEnglish%26categoryId%3Dhome%26screen%3Dnowplaying%26isFirstInSession%3Dtrue%26videoPrerollPlayed%3Dfalse%26unlockEnabled%3Dtrue%26nflUnlocks%3D0%26isUnlocked%3Dfalse%26lotamesegments%3DVP1%2CW12%2CPHY%2CBLK%2CW07%2CVM3%2CVB3%2CVM1%2CVB1%2C890%2CVC1%2CW17%2CVJ2%2CVF3%2CW09%2Cx740x%2CW05%2CPYT%2CVF4%2CVE3%2Cx1x%2CxAMx%2CVNG%2CW14%2CVF2%2CPHIF%2CVA2%2CW22%2Cx848x%2CVN4%2Cx620x%2CVF6%2CW02%2CW21%2CW08%2CVN6%2CBE%2Cx809x%2C492%2CVP6%26premium%3Dfalse%26msid%3Dtunein.player"

1. Replace this part in the ExoPlayer Demo project

    return new AdsMediaSource(
        new SilenceMediaSource(1), // instead   of  mediaSource,
        new DataSpec(adTagUri),
        /* adMediaSourceFactory= */ this,
        adsLoader,
        adViewProvider);
  }

1. Select build variant with extensions
2. Enable debugging logging for ImaAdsLoader
3. Launch new added IMA sample tag and wait till the end.
4. Observe logs. ExoPlayer throws onPlayerError() called with: error = [com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error]" and ImaAdsLoader receives PAUSE callback instead of COMPLETED

2020-12-18 17:01:50.561 20546-20546/com.google.android.exoplayer2.demo D/ImaAdsLoader: Ad progress: 28406 ms of 28952 ms
2020-12-18 17:01:50.663 20546-20546/com.google.android.exoplayer2.demo D/ImaAdsLoader: Ad progress: 28507 ms of 28952 ms
2020-12-18 17:01:50.747 20546-20546/com.google.android.exoplayer2.demo D/ImaAdsLoader: pauseAd AdMediaInfo[https://cdn-cms.tunein.com/ads/Lizzie/INTEL%20_%20MADE%20120120.mp3, (0, 0)]
2020-12-18 17:01:50.777 20546-20546/com.google.android.exoplayer2.demo D/ImaAdsLoader: Ad progress: 28578 ms of 28952 ms
2020-12-18 17:01:50.811 20546-20546/com.google.android.exoplayer2.demo D/ImaAdsLoader: onAdEvent: PAUSED

• ExoPlayer version number = 2.12.2
• IMA SDK = 3.21.4
• Android version = 11
• Android device = Pixel 3

UPDATE:

Passing new SilenceMediaSource(TimeUnit.SECONDS.toMicros(1)) solves the problem.

Proposed solution:

throw an error if duration of SilenceMediaSource isn't enough for player to actually play it.

[ojw28]

Thanks for reporting this, and for the detailed reproduction steps. Please do take care to include all of the requested information when filing future issues though! In this particular instance, including a bug report (or even logcat output) would have shown the root cause, which is unrelated to ads:

EventLogger:   com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
EventLogger:       at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:595)
EventLogger:       at android.os.Handler.dispatchMessage(Handler.java:102)
EventLogger:       at android.os.Looper.loop(Looper.java:246)
EventLogger:       at android.os.HandlerThread.run(HandlerThread.java:67)
EventLogger:   Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.nio.ByteBuffer java.nio.ByteBuffer.order(java.nio.ByteOrder)' on a null object reference
EventLogger:       at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.bypassRender(MediaCodecRenderer.java:2199)
EventLogger:       at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:801)
EventLogger:       at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:953)
EventLogger:       at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:482)
EventLogger:       ... 3 more
EventLogger: ]

[ojw28]

This will be fixed shortly, and be eligible for the next minor release (although we don't have an ETA).

As you've noticed, passing a sufficiently large value as the durationUs argument when creating your SilenceMediaSource is a valid workaround. You should use the smallest value that fixes the issue, to avoid delaying the player transitioning to the ended state. The smallest value that fixes the issue is 23.

[AlienAsRoger]

Thank you so much for such a quick response @ojw28 !

For further requests I'll include more logs from EventLogger as well.

[amitav13]

I'm getting a similar stacktrace as well when trying to play these files through the ExoPlayer demo app:
https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+1.wav
https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+76.wav
media.exolist.json:

...
{
    "name": "User uploaded",
    "samples": [
      {
        "name": "Recording 80 - working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+80.wav"
      },
      {
        "name": "Recording 1 - not working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+1.wav"
      },
      {
        "name": "Recording 76 - not working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+76.wav"
      }
    ]
  }
...

For reference, I've got the same files working as expected when streaming them through the VLC Android app. (https://play.google.com/store/apps/details?id=org.videolan.vlc&hl=en_IN&gl=US)

Stacktrace:

2020-12-22 19:06:29.332 21782-25610/com.google.android.exoplayer2.demo E/ExoPlayerImplInternal: Playback error
      com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:564)
        at android.os.Handler.dispatchMessage(Handler.java:102)
        at android.os.Looper.loop(Looper.java:246)
        at android.os.HandlerThread.run(HandlerThread.java:67)
     Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.nio.ByteBuffer java.nio.ByteBuffer.order(java.nio.ByteOrder)' on a null object reference
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.bypassRender(MediaCodecRenderer.java:2206)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:852)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:892)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:467)
        at android.os.Handler.dispatchMessage(Handler.java:102) 
        at android.os.Looper.loop(Looper.java:246) 
        at android.os.HandlerThread.run(HandlerThread.java:67) 
2020-12-22 19:06:29.337 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: audioDisabled [eventTime=1.22, mediaPos=0.00, window=0, period=0]
2020-12-22 19:06:29.338 21782-21782/com.google.android.exoplayer2.demo E/EventLogger: playerFailed [eventTime=1.23, mediaPos=0.00, window=0, period=0
      com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:564)
        at android.os.Handler.dispatchMessage(Handler.java:102)
        at android.os.Looper.loop(Looper.java:246)
        at android.os.HandlerThread.run(HandlerThread.java:67)
     Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.nio.ByteBuffer java.nio.ByteBuffer.order(java.nio.ByteOrder)' on a null object reference
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.bypassRender(MediaCodecRenderer.java:2206)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:852)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:892)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:467)
        at android.os.Handler.dispatchMessage(Handler.java:102) 
        at android.os.Looper.loop(Looper.java:246) 
        at android.os.HandlerThread.run(HandlerThread.java:67) 
    ]

EventLogger events before the above stacktrace popped up:

2020-12-22 19:06:29.308 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: seekStarted [eventTime=1.19, mediaPos=0.01, window=0, period=0]
2020-12-22 19:06:29.308 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: positionDiscontinuity [eventTime=1.20, mediaPos=0.00, window=0, period=0, SEEK]
2020-12-22 19:06:29.312 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: state [eventTime=1.20, mediaPos=0.00, window=0, period=0, BUFFERING]
2020-12-22 19:06:29.315 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: positionDiscontinuity [eventTime=1.20, mediaPos=0.00, window=0, period=0, SEEK_ADJUSTMENT]
2020-12-22 19:06:29.317 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: loading [eventTime=1.20, mediaPos=0.00, window=0, period=0, true]
2020-12-22 19:06:29.320 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: audioInputFormat [eventTime=1.21, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=705600, channels=1, sample_rate=44100]
2020-12-22 19:06:29.321 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: loading [eventTime=1.21, mediaPos=0.00, window=0, period=0, false]
2020-12-22 19:06:29.321 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: state [eventTime=1.21, mediaPos=0.00, window=0, period=0, READY]
2020-12-22 19:06:29.324 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: isPlaying [eventTime=1.21, mediaPos=0.00, window=0, period=0, true]