IMA ImaAdsLoader not resuming content/finishing when preroll and postroll/midroll Ads are empty

[fpittersacc]

Issue description

When getting an Ad playlist compose of Preroll + Midroll (or Preroll + Postroll), after an empty Preroll, when reaching the Midroll (or Postroll) it gets stuck, like paused, without any further events.

Reproduction steps

On IMA Demo replace Tag URL below.

Link to test content

// Real Ad, currently giving empty Preroll and Postroll (not sure how long it will work)
https://pubads.g.doubleclick.net/gampad/ads?correlator=%5Btimestamp%5D&custom_params=assetid%253D1302548%2526assettype%253Depisode%2526categoryid%253D604008862%2526categorytitle%253DKort%252Ber%252Bgodt%2526dfpduration%253D7%2526duration%253D1352%2526free%253Dfalse%2526livechannel%253Dfalse&description_url=http%3A%2F%2Fwww.tv2.no%2Fv%2F1302548&duration=1352&env=vp&gdfp_req=1&hl=no&impl=s&iu=%2F5374%2FTV2video%2Fsumo%2Fprogrammer%2Funderholdning%2Fbragodt&output=vast&sz=640x480&unviewed_position_start=1&url=%5Breferrer_url%5D

// Alternative: from VMAP Pre-, Mid-, and Post-rolls, Single Ads
https://pubads.g.doubleclick.net/gampad/ads?sz=640x480&iu=/124319096/external/ad_rule_samples&ciu_szs=300x250&ad_rule=1&impl=s&gdfp_req=1&env=vp&output=vmap&unviewed_position_start=1&cust_params=deployment%3Ddevsite%26sample_ar%3Dpremidpost&cmsid=496&vid=short_onecue&correlator=

And block the specific Ad requests with Charles: https://pubads.g.doubleclick.net/gampad/ads?slotname=

Version of ExoPlayer being used

2.7.0

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

Nexus 5, Nexus 5X (Not device specific)

Useful logcat

03-23 19:04:28.303 2350-2350/com.google.android.exoplayer2.imademo I/InstantRun: starting instant run server: is main process
03-23 19:04:28.773 2350-2350/com.google.android.exoplayer2.imademo I/WebViewFactory: Loading com.google.android.webview version 65.0.3325.109 (code 332510900)
03-23 19:04:29.071 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.TokenBindingManagerAdapter>
03-23 19:04:29.071 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.TokenBindingManagerAdapter>
03-23 19:04:29.082 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.ServiceWorkerControllerAdapter>
03-23 19:04:29.083 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.ServiceWorkerControllerAdapter>
03-23 19:04:29.120 2350-2350/com.google.android.exoplayer2.imademo I/cr_LibraryLoader: Time to load native libraries: 1 ms (timestamps 4534-4535)
03-23 19:04:29.181 2350-2350/com.google.android.exoplayer2.imademo I/chromium: [INFO:library_loader_hooks.cc(36)] Chromium logging enabled: level = 0, default verbosity = 0
03-23 19:04:29.181 2350-2350/com.google.android.exoplayer2.imademo I/cr_LibraryLoader: Expected native library version number "65.0.3325.109", actual native library version number "65.0.3325.109"
03-23 19:04:29.260 2350-2350/com.google.android.exoplayer2.imademo I/cr_BrowserStartup: Initializing chromium process, singleProcess=true
03-23 19:04:29.261 2350-2350/com.google.android.exoplayer2.imademo I/cr_base: Android Locale: en_US requires .pak files: []
03-23 19:04:29.423 2350-2350/com.google.android.exoplayer2.imademo I/Adreno-EGL: <qeglDrvAPI_eglInitialize:379>: QUALCOMM Build: 10/21/15, 369a2ea, I96aee987eb
03-23 19:04:29.654 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.WebViewContentsClientAdapter$7>
03-23 19:04:29.654 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.WebViewContentsClientAdapter$7>
03-23 19:04:29.656 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.WebViewContentsClientAdapter$3>
03-23 19:04:29.656 2350-2350/com.google.android.exoplayer2.imademo I/art: Rejecting re-init on previously-failed class java.lang.Class<com.android.webview.chromium.WebViewContentsClientAdapter$3>
03-23 19:04:29.803 2350-2590/com.google.android.exoplayer2.imademo E/libEGL: validate_display:255 error 3008 (EGL_BAD_DISPLAY)
03-23 19:04:29.878 2350-2549/com.google.android.exoplayer2.imademo W/cr_media: Requires BLUETOOTH permission
03-23 19:04:30.001 2350-2590/com.google.android.exoplayer2.imademo W/VideoCapabilities: Unrecognized profile 2130706433 for video/avc
03-23 19:04:30.060 2350-2590/com.google.android.exoplayer2.imademo I/VideoCapabilities: Unsupported profile 4 for video/mp4v-es
03-23 19:04:30.091 2350-2350/com.google.android.exoplayer2.imademo I/ExoPlayerImpl: Init db575f4 [ExoPlayerLib/2.7.0] [hammerhead, Nexus 5, LGE, 23]
03-23 19:04:30.177 2350-2605/com.google.android.exoplayer2.imademo D/OpenGLRenderer: Use EGL_SWAP_BEHAVIOR_PRESERVED: true
03-23 19:04:30.314 2350-2350/com.google.android.exoplayer2.imademo I/ExoPlayerImpl: Release db575f4 [ExoPlayerLib/2.7.0] [hammerhead, Nexus 5, LGE, 23] [goog.exo.core, goog.exo.ui, goog.exo.ima]
03-23 19:04:30.366 2350-2605/com.google.android.exoplayer2.imademo I/OpenGLRenderer: Initialized EGL, version 1.4
03-23 19:04:30.454 2350-2608/com.google.android.exoplayer2.imademo W/art: Verification of void com.google.obf.ii.k(android.content.Context) took 118.536ms
03-23 19:04:31.448 2350-2645/com.google.android.exoplayer2.imademo W/cr_CrashFileManager: /data/user/0/com.google.android.exoplayer2.imademo/cache/WebView/Crash Reports does not exist or is not a directory
03-23 19:04:31.585 2350-2350/com.google.android.exoplayer2.imademo W/IMASDK: Invalid internal message, ignoring. Please make sure the Google IMA SDK library is up to date. Message: gmsg://afma.google.com/omid?type=omidUnavailable&sid=*&dt=1521828271398
03-23 19:04:31.662 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:04:31.990 2350-2350/com.google.android.exoplayer2.imademo 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=b1b38c76-45f5-4b80-8de8-b71156b0ac7e&dt=1521828271980
03-23 19:04:32.008 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:21.461 2350-2350/com.google.android.exoplayer2.imademo I/ExoPlayerImpl: Init af96081 [ExoPlayerLib/2.7.0] [hammerhead, Nexus 5, LGE, 23]
03-23 19:05:21.509 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: Initialized with ads rendering settings: AdsRenderingSettings [bitrate=-1, mimeTypes=[application/dash+xml, application/x-mpegURL, video/mp4, video/webm, video/3gpp, video/mpeg, audio/mp4, audio/mpeg], uiElements=null, enablePreloading=true, playAdsAfterTime=-1.0]
03-23 19:05:21.602 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:21.968 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: LOG
03-23 19:05:21.969 2350-2350/com.google.android.exoplayer2.imademo I/ImaAdsLoader: Log AdEvent: {type=adLoadError, errorCode=1009, errorMessage=The response does not contain any valid ads.}
03-23 19:05:21.969 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: Removing ad 0 in ad group 0
03-23 19:05:21.973 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: VideoAdPlayerCallback.onEnded in onTimelineChanged/onPositionDiscontinuity
03-23 19:05:21.974 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: LOG
03-23 19:05:21.974 2350-2350/com.google.android.exoplayer2.imademo I/ImaAdsLoader: Log AdEvent: {type=adLoadError, errorCode=1009, errorMessage=The response does not contain any valid ads.}
03-23 19:05:21.976 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: CONTENT_RESUME_REQUESTED
03-23 19:05:21.977 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:21.982 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:23.314 2350-3086/com.google.android.exoplayer2.imademo I/OMXClient: Using client-side OMX mux.
03-23 19:05:23.391 2350-3085/com.google.android.exoplayer2.imademo I/MediaCodec: [OMX.qcom.video.decoder.avc] setting surface generation to 2406401
03-23 19:05:23.423 2350-3086/com.google.android.exoplayer2.imademo D/SurfaceUtils: set up nativeWindow 0x9c294d08 for 640x360, color 0x7fa30c04, rotation 0, usage 0x42002900
03-23 19:05:23.438 2350-3103/com.google.android.exoplayer2.imademo I/OMXClient: Using client-side OMX mux.
03-23 19:05:23.454 2350-3086/com.google.android.exoplayer2.imademo D/SurfaceUtils: set up nativeWindow 0x9c294d08 for 640x368, color 0x7fa30c04, rotation 0, usage 0x42002900
03-23 19:05:23.462 2350-3103/com.google.android.exoplayer2.imademo E/OMXMaster: A component of name 'OMX.qcom.audio.decoder.aac' already exists, ignoring this one.
03-23 19:05:23.478 2350-3103/com.google.android.exoplayer2.imademo E/OMXNodeInstance: setConfig(1:google.aac.decoder, ConfigPriority(0x6f800002)) ERROR: Undefined(0x80001001)
03-23 19:05:23.478 2350-3103/com.google.android.exoplayer2.imademo I/ACodec: codec does not support config priority (err -2147483648)
03-23 19:05:23.482 2350-3107/com.google.android.exoplayer2.imademo I/SoftAAC2: Reconfiguring decoder: 0->44100 Hz, 0->2 channels
03-23 19:05:58.613 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: adsLoader.contentComplete
03-23 19:05:59.235 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: LOG
03-23 19:05:59.235 2350-2350/com.google.android.exoplayer2.imademo I/ImaAdsLoader: Log AdEvent: {type=adLoadError, errorCode=1009, errorMessage=The response does not contain any valid ads.}
03-23 19:05:59.238 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:59.240 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: LOG
03-23 19:05:59.240 2350-2350/com.google.android.exoplayer2.imademo I/ImaAdsLoader: Log AdEvent: {type=adLoadError, errorCode=1009, errorMessage=The response does not contain any valid ads.}
03-23 19:05:59.244 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:59.249 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:59.253 2350-2350/com.google.android.exoplayer2.imademo D/SDK_DEBUG: Destroying NativeVideoDisplay
03-23 19:05:59.253 2350-2350/com.google.android.exoplayer2.imademo D/ImaAdsLoader: onAdEvent: ALL_ADS_COMPLETED
03-23 19:05:59.259 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:05:59.265 2350-2350/com.google.android.exoplayer2.imademo E/IMASDK: Received displayContainer message: hide for invalid session id: b1b38c76-45f5-4b80-8de8-b71156b0ac7e
03-23 19:05:59.268 2350-2350/com.google.android.exoplayer2.imademo W/chromium: [WARNING:render_frame_host_impl.cc(2750)] OnDidStopLoading was called twice.
03-23 19:06:13.617 2350-2355/com.google.android.exoplayer2.imademo I/art: Thread[2,tid=2355,WaitingInMainSignalCatcherLoop,Thread*=0xaeeb9000,peer=0x12c540a0,"Signal Catcher"]: reacting to signal 3

A full bug report captured from the device

bugreport-bullhead-OPM3.171019.016-2018-03-23-19-17-08.zip

[YonathanLiang]

hi, has this issue been addressed?

[andrewlewis]

This isn't fixed yet I'm afraid. If I remember correctly, it only applies to the case of two empty ad breaks, one after the other.

[YonathanLiang]

i see, is there any chance that this issue is going to be work on in the near future?

[andrewlewis]

Yes, but maybe not for a while. Is this causing severe problems for your use case? It seems like it would be sufficient to ensure you aren't serving multiple empty ad breaks.

[YonathanLiang]

a bit, since we are using a third party ads provider that may or may not be serving ads, so we don't really have control over which ads will be served. sometimes all the ads will be filled and sometimes only some will be, it depends on said ads provider

[andrewlewis]

To fix this I think we need the IMA SDK to surface more information with adLoadErrors about exactly which ad/ad break is empty. I've filed [Internal: b/112349460] for this feature request and will update this issue when I have more information.

[ojw28]

Please give the latest dev-v2 branch a try, and let us know whether this is fixed. Thanks!

[sujitkumarjha]

have anyone found solution to this?

[andrewlewis]

@sujitkumarjha This issue should be fixed in release 2.9.1. Please file a new issue and provide all the information requested in the issue template if you still see the problem described here.