prebid / Prebid.js

Setup and manage header bidding advertising partners without writing code or confusing line items. Prebid.js is open source and free.
https://docs.prebid.org
Apache License 2.0
1.28k stars 2.05k forks source link

Error executing callback in loadScript() in adloader.js #704

Closed eyedar closed 7 years ago

eyedar commented 7 years ago

We're seeing the error message Error executing callback coming from loadScript() in adloader.js at a significant rate from our production site.

Some background:

With that background, we're seeing this Error executing callback error about 30 times per minute. It just so happened that I got this error myself one time this morning. The content on the page rendered but all of the ad slots were empty. All subsequent page views successfully rendered ads.

We're using version 0.13.0 of prebid.js. We upgraded from prebid.js version 0.8.1 to 0.13.0 on September 29th. Prior to September 29th, this error was not in our logs (nor were there any other errors occurring at this rate). We have seen a drop off of a few hundred thousand impressions per day since we upgraded (traffic has been flat). Now that we have evidence of the effect of this error and the rate at which it is occurring, we believe the drop off is caused by this issue. We have therefore reverted back to 0.8.1.

mkendall07 commented 7 years ago

@eyedar Can you list which bidders are are using? Do you know which bidder is throwing callback error?

eyedar commented 7 years ago

Here are my bidders right out of adapters.json:

[ "aol", "appnexus", "indexExchange", "conversant", "pulsepoint", "sovrn", { "appnexus": { "alias": "brealtime" } }, { "appnexus": { "alias": "districtm" } } ]

I can't tell which bidder is throwing the callback error. The error message out of the box doesn't provide any info (I typically just get Error executing callback and nothing else). I tried adding a dump of the call stack to the error message but that didn't help much either. The call stacks all looked something like this:

utils.js:logError adloader.js:loadScript HTMLScriptElement.t.function.n.readyState.n.onload

(I'm paraphrasing here. Since we're using minified js in production, the stacks were actually much more convoluted. But I stepped through the js to confirm that this was the stack.)

Based on your question I'm guessing that this is being caused by a fault in one of the adapters. Is that true? Thanks.

mkendall07 commented 7 years ago

@eyedar Yes right it would be triggered by a bidder that invoked loadScript() - possibly caused by passing a param that is not a function.

Any chance you could put up a test page that I could look at running 0.13.0?

mkendall07 commented 7 years ago

@eyedar Any update here?

cbledsoe commented 7 years ago

We're also seeing the same symptoms as @eyedar but unfortunately don't have error logging in place to see if its the same exact issue. Turning off prebid fixed our issue where all of the ad slots were empty but we'd love to get this fixed so we can get prebid back on our site. Thanks!

cbledsoe commented 7 years ago

@eyedar - how did you modify prebid to catch these errors?

mkendall07 commented 7 years ago

@cbledsoe There is no standard functionality for error event handling (but it sounds like a great idea). @eyedar Most likely modified source to report on the errors. Not sure exactly what he did.

cbledsoe commented 7 years ago

Sorry, put the wrong person. While I have you @mkendall07 is there any word on this bug?

mkendall07 commented 7 years ago

Haven't been able to dig into anymore. Can you post the bidders you have configured to try and narrow down the list further?

cbledsoe commented 7 years ago

brealtime, sonobi, districtm, rubicon. openx is outside the wrapper.

mkendall07 commented 7 years ago

That's weird, the only adapter in common is AppNexus but AN adapter does not use this functionality. The path for this error is for scripts that can be cached, so that's a clue. I'll look further into that

cbledsoe commented 7 years ago

Thanks!!

cbledsoe commented 7 years ago

@mkendall07 - Was this missed being fixed for 0.15.0? We've had to turn prebid off until the issues are resolved.

eyedar commented 7 years ago

@mkendall07 sorry I went dark on this issue...

For a bunch of business reasons, I have to now upgrade to the latest release. I'm anticipating that I'm going to get this issue again. This time I'm going to take a different tact to track down the offending adapter. Assuming I get the error at the same rate as before, I will start to remove adapters one at a time to see where the error message goes away.

I will keep you posted as to which adapter is the winner (the one with the bug in this case) -- or perhaps the issue has worked itself out through subsequent releases.

fyi @cbledsoe

mkendall07 commented 7 years ago

Hey @eyedar thanks. Sorry this one got lost in the shuffle. Please do report back your findings. Thanks

eyedar commented 7 years ago

@mkendall07 I pushed prebid.js 0.17.0 to production this morning and I do have some significant findings. Unfortunately, I had to revert back to 0.8.1. Here are my findings.

I have a real-time graph where I track errors being logged by prebid.js. Here is what it looked like with 0.8.1 in production just before I pushed 0.17.0:

screen shot 2017-01-11 at 8 55 21 am

You can see the average is around 20 per minute. (Just to refresh your memory, I added code to prebid.js to log client side javascript errors on our own servers.) This is the rate of errors we've had for months now. Since we do 8-9M ad requests per day, we just call 20 per minute a wash and just deal with it.

Then I pushed 0.17.0 to production. Here is what happened to this graph:

screen shot 2017-01-11 at 9 03 17 am

As you can see, the errors emitted by 0.8.1 are a mere blip relative to those produced by 0.17.0. I immediately jumped in to see what errors were being reported. The biggest culprit was "Empty bid response" from the AOL adapter. So I removed AOL as a header bidder in production and watched the error rate come down, but NOT to the level I was seeing in 0.8.1:

screen shot 2017-01-11 at 10 03 01 am

9:26 am was the first full minute where AOL was no longer in production. You can see that the error rates went down by about a half but were still nowhere near the 20 per minute we were seeing with 0.8.1. So I looked at the remaining errors and here is what I was seeing along with the associated counts over a five minute period:

screen shot 2017-01-11 at 9 34 12 am

At our peak times we're doing thousands of ad requests per minute, but this is still too many errors. If we kept 0.17.0 in production it would cause a material detriment to our overall revenue. Therefore, I reverted. The whole experiment can be summarized here:

screen shot 2017-01-11 at 9 49 53 am

Those last few minutes are after reverting back to 0.8.1 and turning AOL back on.

I'm in a bit of a conundrum here. On one hand I can't go to 0.17.0 because of these errors. On the other hand I have new partners to integrate whose adapters are not backwards compatible with 0.8.1, therefore I can't work with them. Not being able to work with these additional partners is also lost revenue. These issues are really starting to hurt my business overall.

At the same time I'm wondering: "surely, I'm not the only publisher with this issue." It strikes me that publishers are blind to client side javascript errors and lost impressions as a result of these errors. It would be helpful to recruit other publishers to do the same to see if these results can be replicated. It would be ideal if there was a logging service build in to prebid, but I understand the server costs there make it unrealistic.

@mkendall07 you had asked earlier if I could put up a test page so that you can look at it...I can cobble one together if you think it will be helpful, however I suspect that you're really not going to see an issue yourself. These things manifest themselves in the wild and can only be seen when looking at the wild in aggregate. The chance of seeing this issue yourself, I believe, is small. That said, I'm happy to do it if you think it will move the ball forward. Happy to chat offline as well.

mkendall07 commented 7 years ago

Thank you for the info.

Could you let me know how you are capturing these errors? I don't think it's correct to assume automatically that a JS error = missing impression. Of course that might be the case, but it also might just be noise.

mkendall07 commented 7 years ago

Can you also see if you can capture user agent / browser info as it relates to those errors? That would be something that could help us investigate further. Also I do think it's worth while to look at your implementation. Feel free to email me directly your website details if you don't want to post here.

eyedar commented 7 years ago

@mkendall07 The reason why I make the connection between JS error and impression is because of why I created this issue in the first place. Back in September, I had upgraded to 0.13.0 then after a couple of weeks discovered that we were missing hundreds of thousands of impressions per day (as I detailed above). When I reverted back to 0.8.1, impression volumes immediately returned.

That said, you are correct that probably not all JS errors here = missing impression, but I can say based on experience that most are missing impression.

In terms of how I'm capturing these errors, that reveals our website details and I'd rather leave it off of here. I'll message you directly.

I did capture user agent back in October when I first saw this issue but didn't see any trend so I turned it off. I can always look at it again.

Thanks for your attention to this.

mkendall07 commented 7 years ago

@eyedar I know you found the root cause of this issue, however, I don't think you submitted the fix? Can your refresh my memory so I can put the fix into master?