Immediate adapter response may end auction

[github-nilsson]

Type of issue

Robustness problem with bid response API.

Description

Immediate calls to bidmanager.addBidResponse may cause the auction to end. Since the same loop is used to call adapters and add requests to pbjs._bidsRequested, an immediate call to bidmanager.addBidResponse can cause the bidsBackAll to believe the auction has ended.

Steps to reproduce

Have the first adapter respond to all bid request by immediately calling bidmanager.addBidResponse. The auction will immediately end and any responses from other adapters will be ignored.

Solution

This can of course be fixed by asynchronously calling bidmanager.addBidResponse using setTimer, but I would like to avoid these kind of API traps. I propose to have the current loop only update pbjs._bidsRequested and then iterate over that array for calling the adapters like the following.

  $$PREBID_GLOBAL$$._bidsRequested.forEach(bidderRequest => {
    utils.logMessage(`CALLING BIDDER ======= ${bidderRequest.bidderCode}`);
    events.emit(CONSTANTS.EVENTS.BID_REQUESTED, bidderRequest);
    _bidderRegistry[bidderRequest.bidderCode].callBids(bidderRequest);
  });

[mkendall07]

@github-nilsson
is there any adapters doing this today? Each adapter would be making a async HTTP call, so addBidResponse would be async as well. Is this just a theoretical?

[github-nilsson]

The adapter we are developing can return a response right away in some cases, so this caused a few days of mysterious lowered revenue.

But then again, now that we've run into that mine we know how to work around it.

[mkendall07]

@jaiminpanchal27
please check this condition in the 1.0 branch.

[dugwood]

Just hit the same issue in 0.30.1. The first result forbids the next auction to be sent:

 Time Info
    2 leader AdUnit ready (1158px): [[728,90],[768,90],[970,90],[970,250],[1000,90],[1000,300]]
    2 leader Launching requests
    3 leader Request bid for rubicon
    5 leader Request bid for appnexusAst
   64 square AdUnit ready (579px): [[300,250],[300,600],[336,280]]
   64 square Launching requests
   66 leader rubicon (0x0):           0     (Time: 63)
  235 leader appnexusAst (970x250):   0.xxx (Time: 230) (ignored by local cpm floor)
  242 leader All bids are back, launching DFP with price bucket 0.20: 239ms
  253 square Request bid for rubicon
  254 square rubicon (0x0):           0     (Time: 1)
  256 square All bids are back, launching DFP with price bucket 0.20: 3ms
  261 square Request bid for appnexusAst
  424 square appnexusAst (300x250):   0.xxx (Time: 163)
  503 square DFP wins with price bucket 0.20
  626 leader DFP wins with price bucket 0.20

Here you can see that error returned by rubicon (no ad) will stop the auction, even if there's another bidder (appnexus) to wait for (timeout is set to 2000ms).

Really needs an urgent fix :-(

Edit: reformatted the example. It seems that one adUnit will impact the other. With only one adUnit, there's no issue.

[dugwood]

No same thing with only one adUnit:

   40 AdUnit ready (579px): [[300,250],[300,600],[336,280]]
   41 Launching requests
   42 Request bid for rubicon
   44 rubicon (0x0):           0     (Time: 1)
   53 All bids are back, launching DFP with price bucket 0.20: 11ms
   65 Request bid for appnexusAst
  270 appnexusAst (300x250):   0.xxx (Time: 205)
  442 DFP wins with price bucket 0.20

[dugwood]

0.27.1 is not impacted, didn't test any other (a lot of issues since then).

[github-nilsson]

Are you sure 0.27.1 isn't impacted? You would only get this bug if the synchronously responding adapter is called before any other. Since randomization of adapter order wasn't on by default then it would be easy to avoid the issue by having an always asynchronous adapter first in the list.

[dugwood]

My bad, seems to have the exact same issue. It's by providing a bad sizes parameter to Rubicon, it hangs on both 0.27.1 and 0.30.1.

[jaiminpanchal27]

@dugwood can you share test page ?
So to confirm, it only happens with Rubicon adapter when we pass bad sizes ?

[bretg]

So just to be clear, 0x0 isn't necessarily a 'bad' size, but it's not one that Rubicon Project currently knows what to do with, so we just immediately decline the auction (i.e. return "false" from isBidRequestValid).

[dugwood]

@bretg yes it's just my debug. I've sent by error the sizes with non-valid Rubicon sizes, and it just show the bug. I'll try to make a test page for this. You can test it with something like sizes: [[1000, 300]], which is wrong for Rubicon. The error ends the auction.
@jaiminpanchal27 I don't know if it only happens with Rubicon, but bad parameter shouldn't hang the whole auction. As the information isn't viewable, unless setting pbjs_debug and looking at the console.

[dugwood]

@jaiminpanchal27 it will be difficult to set a test page, as it means creating an error on a production page... I only test on local VM. Will you be able to reproduce with the wrong sizes parameter? Maybe other adapters are creating the same issue.

[github-nilsson]

You don't need a production page to demonstrate the bug, as it never connects to any server. You should be able to trigger this by giving a non-numeric accountId in the adapter params to rubicon adapter.