[Android] IMA 3.7.4 Errors not being propagated to listeners

[justin...@syncbak.com]

While playing an ad pod, I will receive the UI that states 1 of 2 ads are playing, which is correct.  The first ad will play, but then the second ad will have the following error occur:

10-19 08:54:07.051 12343-12343/com.s.qa.debug I/SDK_LOG:ima.vast.VideoAdEventTracker: dispatching event error
10-19 08:54:07.063 12343-12343/com.s.qa.debug I/SDK_LOG:ima.managers.VastVideoAdsManager: Ad error: null
10-19 08:54:07.068 12343-12343/com.s.qa.debug I/SDK_LOG:ima.managers.VastVideoAdsManager: Playback error: [object Object] AdError 400: There was an error playing the video ad.
10-19 08:54:07.077 12343-12343/com.s.qa.debug W/SDK_LOG:ima.common.ErrorUtils: Error play dispatched: AdError 400: There was an error playing the video ad.
10-19 08:54:07.082 12343-12343/com.s.qa.debug I/SDK_LOG:ima.adslist.AdBreak: Ad play error for playTime:0, error: AdError 400: There was an error playing the video ad.
10-19 08:54:07.087 12343-12343/com.s.qa.debug I/SDK_LOG:ima.adslist.AdBreak: Playing next item and waiting for time:0.
10-19 08:54:07.092 12343-12343/com.s.qa.debug I/SDK_LOG:ima.adslist.AdBreak: Done playing all ads for time: 0
10-19 08:54:07.132 12343-12343/com.s.qa.debug I/SDK_LOG:ima.adslist.AdBreak: Destroying the ad break, 0
10-19 08:54:07.163 12343-12343/com.s.qa.debug I/SDK_LOG:ima.managers.AdsListAdsManager: No next event in the event queue.

Sometimes both ads will play with no issues, other times I get the above.  The same ad tag url is being used in all cases, which I can PM to someone when this gets picked up.

Why isn't this error being passed through to the AdEvent.AdEventListener or AdErrorEvent.AdErrorListener callbacks?

[Deepika Uragayala (IMA SDK Team)]

Hello Justin,

It sounds like an implementation issue here where you might not be handling the event callbacks from the SDK properly. Can you check whether you are properly integrating this from our guidelines? Also, we highly recommend that you first try with our sample apps, which already integrates these callbacks, and see if this is still happening and then let us know.

Regards,
Deepika Uragayala
IMA SDK Team

[justin...@syncbak.com]

I did attempt to use it, your documentation points to a wrong version, but didn't have the same issue as the player didn't have the same issue playing the ads.  Yes, I'm using the built-in SDK player.

I printed all events from the onAdError and onAdEvent and this is the result:

LOADED occurred
CONTENT_PAUSE_REQUESTED occurred
STARTED occurred
FIRST_QUARTILE occurred
MIDPOINT occurred
THIRD_QUARTILE occurred
COMPLETED occurred
LOADED occurred
CONTENT_RESUME_REQUESTED occurred

Simple code being used (Kotlin):

 override fun onAdEvent(adEvent: AdEvent) {
    android.util.Log.d("@@@@", "${adEvent.type} occurred")
}


override fun onAdError(adErrorEvent: AdErrorEvent) {
    android.util.Log.d("@@@@", "${adErrorEvent.error.errorCodeNumber} : ${adErrorEvent.error.message}")
}

My event listeners are attached to the ads loader and ad manager the same way.  My understanding when using VMAP, is that the onAdError listener isn't meant to be called, and I should receive a Log event, which I don't.  Another interesting thing is that when a second break is crossed over, it will jump to playing ad "2 of 2" and completely skip the first one...

A separate issue is why is ad playback failing for me but not the test one, both using 3.7.4.  

[Deepika Uragayala (IMA SDK Team)]

Hi Justin,

We currently do not provide support for Kotlin for our SDK. This might be reason you are noticing these errors. Can you confirm if you are still noticing this with our sample apps? 

Regards,
Deepika Uragayala
IMA SDK Team

[justin...@syncbak.com]

Using your sample apps, with the player provided by your SDK, I have repeated this.

It requires a change to your current code to enable the use of the built-in player, comment out line 240 for the VideoPlayerController.java class.  The line should be:

mAdDisplayContainer.setPlayer(mVideoPlayerWithAdPlayback.getVideoAdPlayer());

The VMAP Pods example exhibits the same issue for the Midroll.  You will have to play it multiple times as it doesn't happen every time the pod is played.  Same in my case.

Take note how not AdError or ImaExample log tag is present, meaning nothing it being propagated to your listeners to write to the console.

10-20 14:23:55.745 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/ImaExample: Event: LOADED
/* Long ping-back url omitted */
10-20 14:23:55.828 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.vast.VideoAdEventTracker: dispatching event error

10-20 14:23:55.839 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.managers.VastVideoAdsManager: Ad error: null
10-20 14:23:55.844 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.managers.VastVideoAdsManager: Playback error: [object Object] AdError 400: There was an error playing the video ad.
10-20 14:23:55.853 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp W/SDK_LOG:ima.common.ErrorUtils: Error play dispatched: AdError 400: There was an error playing the video ad.
10-20 14:23:55.857 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.adslist.AdBreak: Ad play error for playTime:15, error: AdError 400: There was an error playing the video ad.
10-20 14:23:55.862 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.adslist.AdBreak: Playing next item and waiting for time:15.
10-20 14:23:55.877 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/SDK_LOG:ima.managers.AdsManagerFactory: createAdsManagerFromAds_, adType: video
10-20 14:23:55.884 11697-11697/com.google.ads.interactivemedia.v3.samples.videoplayerapp I/ImaExample: Event: LOADED

Your example app does not catch the Log ad event type for logging to the console, I would strongly suggest you add that to the actual application for future releases.

[Deepika Uragayala (IMA SDK Team)]

Hi there,

Thanks for getting back to us. The SDK would not treat this as an AdError Event since it will try to request and load the next ad in the pod. If it throws an error, then the client would destroy it and resume the content. For this reason, instead, if it's an pod where multiple ads are being played, then an AdError 400 would simply throw a LOG event and would continue with the remaining ads in the pod. Note that this will be treated as an AdError Event if the ad being requested is the only ad left from the AdResponse and Error 400 is thrown.

Let me know if you have any other questions.

Regards,

Deepika Uragayala

IMA SDK Team

[justin...@syncbak.com]

I understand.  The problem is that a LOG event ISN'T occurring!

This coupled with the fact that this condition is present in the built-in ad player implementation. This is telling me that something is wrong with the built-in player and needs to be corrected.

The error doesn't occur using the example as is, it uses the MediaPlayer.  When you attempt to use the built-in player, by not setting the player with the ad container, this error becomes present and nothing it emitted from the SDK to the listeners to notify them of this.  The SDK's player isn't working as intended.

[Chris Feldman (IMA SDK Team)]

Hi Justin,

Thank you for clarifying. If the LOG event is not firing, can you please share the ad tag so that I can attempt to reproduce the issue myself? If you're not comfortable posting a link on the forum, you can choose the option to reply privately.

Along with the ad tag, please also provide detailed steps for reproducing the issue - as well as information about any changes you made to our samples.

Thank you,

Chris Feldman

IMA SDK Team

[justin...@syncbak.com]

Chris,

I have forked the example app with the needed changes. 

To re-create:

1. Enter the app and select the VMAP Pods video
2. A pre-roll will play
3. After the pre-roll has played, seek past the half-way mark
4. If the issue occurs, you will see entries in the log that look similar to the follow:
• I/ImaExample: Event: LOADED
  I/SDK_LOG:ima.vast.VastAdServerReporter: Reporting urls for event : complete
  I/SDK_LOG:ima.vast.VastAdServerReporter: Pinging reporting URL: https://pubads.g.doubleclick.net/pagead/conversion/?ai=BBNPHLT_uWZ2ROcbZBY75gGjQr4_r....
  I/SDK_LOG:ima.vast.VastAdServerReporter: Pinging reporting URL: https://video-ad-stats.googlesyndication.com/video/client_events?event=3&web_propert....
  I/SDK_LOG:ima.vast.VideoAdEventTracker: dispatching event error.

• 
  I/SDK_LOG:ima.managers.VastVideoAdsManager: Ad error: null

• 
  I/SDK_LOG:ima.managers.VastVideoAdsManager: Playback error: [object Object] AdError 400: There was an error playing the video ad.

• 
  W/SDK_LOG:ima.common.ErrorUtils: Error play dispatched: AdError 400: There was an error playing the video ad.

• 
  I/SDK_LOG:ima.adslist.AdBreak: Ad play error for playTime:15, error: AdError 400: There was an error playing the video ad.

• 
  I/SDK_LOG:ima.adslist.AdBreak: Playing next item and waiting for time:15.

• 
  I/SDK_LOG:ima.adslist.AdBreak: Done playing all ads for time: 15
  I/ImaExample: Event: CONTENT_RESUME_REQUESTED
• You may need to repeat the process several times for it to occur
• It is most obvious when the UI state ad X of N is playing and it doesn't reach N

This issue seems to only occur when using the built-in video ad player with ad pods.  When using the example as-is, the issue doesn't occur.

I see two bugs with this:

1. The SDK isn't emitting a LOG event, as it should, when there is an issue with ad video playback
2. The SDK's built-in ad video player isn't working as intended as it failed to properly playback the ad when the system player works fine

Thank you for looking into this!

[Chris Feldman (IMA SDK Team)]

Hi Justin,

What device/Android version are you testing with? I'm not seeing the behavior that you describe when I test with my Nexus 6P on Android 8.0. I'd like to try and replicate your test environment exactly so any more details you can provide would be helpful. Issues like these are sometimes device specific.

Regards,

Chris Feldman

IMA SDK Team

[justin...@syncbak.com]

Chris,

I have been able to replicate this issue on a Nexus 7 Android 5.0.1 and a Droid Turbo Android 6.0.1.

I have created a video of the issue here.  You will notice if gets to ad 2 of 3, states an ad is loaded, but skips to content resume without any LOG events being shown.

[Chris Feldman (IMA SDK Team)]

Hi Justin,

Thank you for sending the video, but even with the devices in question, I've still not been able to reproduce this issue. It's possible that this may specific to your device or network. Can you please try another network and see if you have similar results? 

Thank you,

Chris Feldman

IMA SDK Team

[justin...@syncbak.com]

Chris,

The same issue occurred when I am on my Mobile network, Verizon, and WiFi shutoff.  I have recorded another example, this time it skipped two with no LOG event being emitted.

Are you using the forked repo I provided earlier?  This issue only seems to occur when using the built-in ad video player.  Your examples DON'T use it.  The repo I created changes that to use it.

[Chris Feldman (IMA SDK Team)]

Hi Justin,

I am using the forked repo that you've shared that includes the appropriate changes. That being said, I've still not been able to reproduce the issue. I'm going to continue working on this and I will let you know as soon as I have any updates. If you have any other information that you feel could be helpful, please follow-up and share that.

Regards,

Chris Feldman

IMA SDK Team

[Justin Thomas]

You are specifically using the VMAP Pods video as well, correct?  It seems to be the combination of Ad Pods and the ad player that causes this condition.

--
You received this message because you are subscribed to a topic in the Google Groups "Interactive Media Ads SDK" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/ima-sdk/70BjLpjWcg4/unsubscribe.
To unsubscribe from this group and all its topics, send an email to ima-sdk+unsubscribe@googlegroups.com.
To post to this group, send email to ima...@googlegroups.com.
Visit this group at https://groups.google.com/group/ima-sdk.
For more options, visit https://groups.google.com/d/optout.

--

Justin Thomas

[Chris Feldman (IMA SDK Team)]

Hi Justin,

After many more attempts, I was able to see the issue you've described a small handful of times. I'm going to share this with the rest of our team to investigate further. I will follow-up on this thread as soon as I have an update. Do keep in mind, that with the low reproducibility rate that I've seen, this may be difficult for us to diagnose. 

Regards,

Chris Feldman

IMA SDK Team

[justin...@syncbak.com]

Chris,

I really appricate you keeping on this and letting me know.

----

I just finished a simple test batch after gathering additional devices for testing and my results are below.

The below cases were looking for two specific issues:

1. When an ad playback error occurred, the logcat showed an error with a code of 400
2. When the above condition was met, that an appropriate LOG event was sent to the AdEventListener

Assumptions:

1. The VMAP Pods example in the AdvancedExample project is being used
2. After the Pre-roll is played, the user seeks to after the Mid-roll to start it
3. The "forked" repo is found here
4. The "as-is" repo is found here
5. Each device will have the case ran 5 times

Refer to here for changes made to the "forked" repo.

Case: Testing Ad Pod playback with the "forked" repo

Note: The "foked" repo uses the IMA SDK's built-in Exoplayer for Ad Playback

• ASUS Nexus 7 @ 5.0
  
• 2/5 attempts worked
• In attempt 1, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 3, 3rd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 5, 2nd ad in Mid-roll pod failed, no LOG event emitted
• Mid-roll ads didn't honor orientation of device and rendered upside down
• Motorolla Droid Turbo @ 6.0.1
• 1/5 attempts worked
• In attempt 1, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 3, 3rd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 4, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 5, 2nd ad in Mid-roll pod failed, no LOG event emitted
• Got an AdSense Pre-roll only...very odd, disregarded attempt
• ASUS Nexus 7 @ 4.4.2
• All 5 Attempts worked
• Nvidia SHIELD Tablet K1 @ 7.0
• In attempt 1, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 2, 3rd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 3, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 4, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 5, 2nd ad in Mid-roll pod failed, no LOG event emitted
• LG Nexus 5X @ 8.0.0
• In attempt 1, 3rd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 2, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 3, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 4, 2nd ad in Mid-roll pod failed, no LOG event emitted
• In attempt 5, 2nd ad in Mid-roll pod failed, no LOG event emitted

Case: Testing Ad Pod playback with the "as-is" repo

Note: The "as-is" repo uses Android's Media Player for Ad Playback

• ASUS Nexus 7 @ 5.0
• All 5 attempts worked
• Motorolla Droid Turbo @ 6.0.1
• All 5 attempts worked
• ASUS Nexus 7 @ 4.4.2
• All 5 attempts failed with "AdError 400: There was an error playing the video ad." 
• No LOG events observed
• Locked the player
• Attempted example Pre-roll, linear not skippable, it failed with the same error, "AdError 400: There was an error playing the video ad.", but he appropriate LOG event was emitted allowing the player to resume
• Nvidia SHIELD Tablet K1 @ 7.0
• All 5 attempts worked
• LG Nexus 5X @ 8.0.0
• All 5 attempts worked

This leads me to believe that the built-in ad video player (Exoplayer) that comes packages with the SDK has issues handling Ad Pods.  As a side effect of Ad Pods implementation, AdErrorListener not being called so other ads in the pod can play, the SDK is failing to catch all player errors and pass them back on AdEventListener as a LOG event.

Hopefully this is useful information and better helps understand and step through the issues I'm seeing.  It is HIGHLY reproducible for me and even manifests itself in our production application.

To unsubscribe from this group and all its topics, send an email to ima-sdk+u...@googlegroups.com.

To post to this group, send email to ima...@googlegroups.com.
Visit this group at https://groups.google.com/group/ima-sdk.
For more options, visit https://groups.google.com/d/optout.

--

Justin Thomas

[Chris Feldman (IMA SDK Team)]

Hi Justin,

Thank you for the excellent breakdown of your testing process. I will make sure that we take note of this while we work through the issue.

Thank you,

Chris Feldman

IMA SDK Team

[ima-sdk-adv...@google.com]

Hi Justin,

The issue with the LOG events should now be resolved. Please let me know if yo continue to have issues.

Regards,

Chris Feldman

IMA SDK Team

=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~
Also find us on our blog and Google+ page:
    http://googleadsdeveloper.blogspot.com
    https://plus.google.com/115658573333388777174/
=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~

[justin...@syncbak.com]

Thanks Chris!

Do you happen to know the version this is corrected in?  It doesn't seem to be part of any of the recent release notes.

[ima-sdk-adv...@google.com]

Hi Justin, 

These changes are live now in v3.9 (link).

Regards,

Chris Feldman
IMA SDK Team

=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~
Also find us on our blog and Google+ page:
    http://googleadsdeveloper.blogspot.com
    https://plus.google.com/115658573333388777174/
=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~=~