When invalid bidder, PBJS still waits for the timeout before continuing

robertrmartinez commented 6 years ago

Type of issue

BUG in 1.X Versions. Works as expected in legacy versions.

Description

When an invalid bidder is used in an auction. Prebid.js will wait for the invalid bidder to timeout before continuing with the auction and sending results to DFP.

PBJS correctly logs the console log error Adapter trying to be called which does not exist:, but then does not emit the auction end event until the invalid bidder's timeout event is triggered.

We should be removing the invalid bidder completely instead of waiting around for their timeout to trigger.

Using the same test page:

PBJS 1.13.0 Events Log:

PBJS 0.34.13 Events Log

Notice how in 1.13 we see a bidder timeout before the auction end event is fired. Which does not make sense since the invalid bidder is never actually requested!

The major issue here is that if a publisher has a lower timeout threshold for the pbjs auction than pbjs has for the bidders, we often see that the request for DFP will not go through with the other bidders targeting values.

Steps to reproduce

Test page with two bidders
One valid, one invalid

Expected results

When an invalid bidder is included in the auction, PBJS should remove that bidder completely from the auction and not ever emit a timeout for them!

Actual results

PBJS is waiting for the invalid bidder to return, and when it does not emits a timeout event.

Platform details

Any

Other information

headerbidding commented 6 years ago

Yes, I have noticed that also. Here is a test page with a prebid.js that does not include EBDR as a bidder: http://www.flixxy.com/prebid-test.htm?pbjs_debug=true

There is a "WARNING: Error calling onTimeout of ebdr" and no bids are returned.

jsnellbaker commented 6 years ago

Thanks for reporting this issue and providing the extra details; I'll investigate into this bug.

headerbidding commented 6 years ago

Here is another scenario that happened today: Temporary timeout by Rhythmone ad server resulting in no bids being returned: cid:image001.png@01D3FD77.262B64F0 cid:image002.png@01D3FD77.262B64F0 cid:image004.png@01D3FD77.262B64F0

jsnellbaker commented 6 years ago

Hi @headerbidding it seems like the image attachments didn't come through in your reply. Can you update the comment when you get the chance?

Additionally, rhythmone appears to be a valid bidder. My understanding for this issue is that unknown/invalid bidders are still being used when the request goes out, which results in the auction waiting on the expected timeout for that invalid bidder.

Can you expand on how rhythmone matches this issue?

headerbidding commented 6 years ago

The Rhythmone server had a temporary time-out this morning, which caused a: "server call to rhythmone failed. Continuing without bids" error.

jsnellbaker commented 6 years ago

I think you'd have to attach them directly into a comment in github; the footer in the comment box have different ways to include them (ie drag&drop, select them from menu, or paste via clipboard).

In regards to that type of error, I think that's separate from this issue. Unresponsiveness could happen at any point theoretically, and prebid wouldn't know upfront if the server wasn't available or experiencing issues until we made a request.

headerbidding commented 6 years ago

I understand. But the result was that no bids were returned even from the other bidders:

r13

r12

r11

At least I don't see any bid amounts.

jsnellbaker commented 6 years ago

@headerbidding I was looking at your test page further, and it seems there are several things at work/to note.

The current behavior where prebid waits for the 'invalid' bidder to respond is playing a factor.
The auction has a certain amount of time it can run waiting for all the bidders to come back with a response, before the auction gets timed out. You can see that happening in the console logs for your last screenshot. There is a Auction ... timedOut log line occur before the Bids Received for Auction... log line. If you notice in that same Bids Received for Auction log line, it has 3 objects listed that can be expanded; this indicates other bidders are successfully returning their bids despite one of the other bidders having an issue.
For me at least, the various bidders on the test page weren't returning any bids from the respective servers. It wasn't until I replaced one of the appnexusAst placementIds with a value we use the hello_world test page that I was able to see an ad naturally return.

The fix I've put together addresses the first item and indirectly part of the second; in that we're no longer including an invalid bidder in the request objects that get generated for the auction. This means prebid won't wait for that invalid bidder's timeout to expire and the auction can finish more ideally once all other bidders respond. When I swapped out the AppnexuAst placementId, removed the ebdrBidAdapter from the build (to replicate the bidder does not exist error on the test page) and ran the page -- I was seeing an ad return even with the error message from the new logic present in the log.

In terms of the second item, there are some aspects here that we'll look into further. There are measures in place to handle when the bidder's server is having issues (as via the one error message you saw Server call for ... failed. Continuing without bids.), but how its interacting with the overall timeout could be reviewed.

As an additional note, I saw the test page had a page-level setTimeout set for 700ms. The auction's internal timeout is using 3000ms. I would suggest to alter the page-level timeout to match the auction's value so that it's consistent and give the auction a more reasonable chance to finish.

headerbidding commented 6 years ago

Thank you! Can you please explain "The auction's internal timeout is using 3000ms"

jsnellbaker commented 6 years ago

When prebid creates an auction instance, it pulls in a specific timeout value to use for that auction. If the auction doesn't finish before that amount of time expires, then the auction cancels its current work and exits with a timeout error.

The value for the timeout is decided here: https://github.com/prebid/Prebid.js/blob/master/src/prebid.js#L315

The backup timeout value (ie the config.getConfig('bidderTimeout');) equates to 3000ms. The primary timeout value would be read from the pbjs.requestBids function's call in the prebid tag. To set this value in the call, you would add another parameter like timeout: 2500 after the bidsBackHandler property in the requestBids's arguments.

headerbidding commented 6 years ago

I just noticed that when browsing from Europe (by setting my Hola VPN to France for example), I get an “in response for AppnexusAST adapter: blacklist” error - if the GDPR module is not loaded. It seems (but I am not 100% positive) that this also causes the other bidders to be ignored - as above. Fixing the bug will resolve this also. I opened a separate thread on this issue: https://github.com/prebid/Prebid.js/issues/2712

headerbidding commented 6 years ago

@jsnellbaker: May I ask why this was closed? It is still not fixed in 1.15:

robertrmartinez commented 6 years ago

@headerbidding

The fix was to make it remove the request objects for invalid bidders.

Invalid bidders is a mis-match on the bid adapters alias names, or if the prebid.js code loaded does not include a bid adapter module you are trying to request for.

I can see in your test page you are attempting to call Appnexus, AOL, Sovrn, edbr, pulsepoint, rythome, conversant, sonobi.

But in your prebid.js library which is loaded, it looks like it only includes the modules for bid adapters for Appnexus, Sovrn, and Pulsepoint. Which would explain the console log warnings associate with the other bidders.

What are the commands you used to build the prebid.js library being lodaed on this page? The resource located here: http://www.flixxy.com/prebid.js

robertrmartinez commented 6 years ago

I built prebid.js using 1.15.0 and included all adapters in your test page and do not get the console log errors you are reporting.

headerbidding commented 6 years ago

I omitted some adapters intentionally to demonstrate that when adapters are omitted, prebid will not return ANY bids, even from the adapters that are included (appnexus, sovrn, sonobi). This was not the case in Version 0.xx I know, because I would just remove adapters from prebid.js to disable some ad networks for testing. This method no longer works in version 1.xx

jsnellbaker commented 6 years ago

@headerbidding Sorry for the radio silence on this issue.

Are you still seeing this issue with the latest version of Prebid.js? When I checked your test page (https://www.flixxy.com/prebid-test.htm) - it looked to be using Prebid.js 1.15. The fix I put together and referenced in this issue was included in Prebid.js 1.16.

While I was testing the page with a local build of the latest Prebid, any bidders that weren't included in the build got properly flagged with the new earlier check and didn't get a request object made (as was the old logic). The only issue I saw on the page was that your bidders didn't appear to be providing any bids in return; even when all bidders were enabled - they each seemed to be giving a nobid type of response. If they were test ads dedicated for this page, perhaps they expired?

Please let me know when you have the chance.

headerbidding commented 6 years ago

I haven't tested with 1.16 yet. I'm waiting for it to become available on http://prebid.org/download.html

Yes - I have noticed the "nobid" response, and this is what I am really concerned about.

No - my bidders haven't expired.

jsnellbaker commented 6 years ago

@headerbidding The download page has been updated for 1.16.

I'm not sure the nobid responses are a result of this behavior, because I was seeing the same thing when all bidders were enabled in the build. That's why I asked if the placements/information used in the bidder fields of the adunit objects were still active/live.

headerbidding commented 6 years ago

I just upgraded to 1.16. The issue of no bids being returned, when some adapters were missing, is now resolved. Thank you!!!

prebid / Prebid.js