Debug disable feature implementation:

[VeronikaSolovei9]

• Added Bidder level debug variable
• Added Account level debug variable

[VeronikaSolovei9]

@jmaynardxandr @camrice Guys please review debug disable feature PR.

@camrice Cam, can you please pay attention to this commit: 4c7d53a
This is possible cache fix, mostly about adding response to logs in case of bids returned and not.

[camrice]

The failure message here should mention true instead of false

[VeronikaSolovei9]

Fixed, thank you!

[camrice]

Same as above, just need to change failure message to true

[VeronikaSolovei9]

Fixed

[camrice]

This block can be removed

[VeronikaSolovei9]

Yes, removed

[SyntaxNode]

I think the comment block is till here.

[camrice]

Should this be removed? Are the request and header fields added elsewhere?

[VeronikaSolovei9]

Yes, this commented block of code is moved to line 160. It's not removed.

[camrice]

I think this would cause two calls to the cache in a no-bid case. In video_auction.go, there is a check around line 306 for if the adpod length is 0, and then it calls the PutDebugLogError() function. This also adds the cache key to the response. I think this PutJson call is not needed.

[VeronikaSolovei9]

You are right! We only need to build response and put it to debugLog. Fixed. Great great great catch!

[SyntaxNode]

The json must be json:"-" xml:"-" to play nicely with the /info/bidders endpoint.

[VeronikaSolovei9]

Right, didn't know about this, fixed

[SyntaxNode]

Would calling it Debug instead of DebugInfo cause a naming conflict?

[VeronikaSolovei9]

Renamed, no conflicts

[SyntaxNode]

Let's call the JSON debug_allowed to match the other naming conventions.

[VeronikaSolovei9]

Modified!

[SyntaxNode]

I really don't like the context. Is there a way we can do without this?

[VeronikaSolovei9]

Refactored. We have this variable in account. To have this in bidder -> requestBid I passed it through function param from HoldAuction

[hhhjort]

The default in Go for a boolean is false, but this is okay since it is inside of a pointer to an object that will be empty if not specified. This does result in this DebugInfo object in the Bidder infos to be optional, which does look a bit strange as server generated info output. Maybe we want to consider a DebugRestricted field instead of DebugInfo.Allow, or even just a pointer to a bool so we can detect the difference to a missing setting vs. and explicit false value.

Do we need to advertise this in the bidder info data? You can hide this in the bidder config, which seems a more logical place to house this data, and avoids the issue of the bidder infos being inconsistent on if they include an "optional" parameter. Also this is a setting that a PBS host would be expected to set, are there any other parameters in the bidder info that a PBS host might touch? That would argue that it goes in the bidder config if not.

[VeronikaSolovei9]

@SyntaxNode please advice if we want to have DebugRestricted instead of DebugInfo.Allow

[VeronikaSolovei9]

Yes, moved to adapters/info.go, good catch!

[hhhjort]

I think you missed my point. I was thinking of moving this flag out of the BidderInfo struct, and thus out of the bidder/info endpoint, and into the actual server configuration in the Adapter struct, where we actually do sever level configuration of the adapter. I am not aware of anything in the /static/bidder-info/ directory that a PBS host should touch, all configuration should be driven by the config file and/or environment variables. Spreading configuration out across multiple files will just lead to confusion.

[VeronikaSolovei9]

I'm confused.
We want to have bidder level debug flag and store it in static/bidder-info/{bidder}.yaml files. The only place where we load it is in adapters/info.go -> func ParseBidderInfos. We Unmarshal file data to BidderInfo struct.
Unless I miss something...
Do you mean I need to move it to config/adapter.go -> Adapter struct after loading?
What is "the actual server configuration in the Adapter struct"?

[SyntaxNode]

@SyntaxNode please advice if we want to have DebugRestricted instead of DebugInfo.Allow

I don't have a strong opinion. Bret introduced this config as debug allow and that makes sense to me, but yes - it does play against the boolean zero value. We'd need to ask in the GitHub issues to swap it to something like restricted.

I was thinking of moving this flag out of the BidderInfo struct, and thus out of the bidder/info endpoint, and into the actual server configuration in the Adapter struct,

I think both have valid arguments. I had spec'd it for the bidder yaml since I didn't expect a host to override this value. I thought if the bidder knows its url will include sensitive information, then it could specify such here for all hosts to follow.

We've also had discussions about in the future using bidder yaml as the base config for each adapter as is done in PBS-Java and then using the config system to override those values if needed. This would work well for reducing the code length of config.go, making it easier to port adapters to PBS-Java, and would provide a nice way to override yaml information for aliases.

[hhhjort]

Oh, if PBS-Java is already using it for config, then it is not such a big change to for us to do the same. I have no opinion on if this struct should be in config/config.go or adapters/info.go

[hhhjort]

Minor point, but perhaps we just want to return the final boolean value here, rather than a full config.DebugInfo. Is there any benefit in keeping it packed inside of the the struct?

[VeronikaSolovei9]

Yes, fixed

[hhhjort]

Do we still have test coverage somewhere that httpcalls are included if debug is allowed?

[VeronikaSolovei9]

Yes, exchange_test.go, TestDebugBehaviour covers all the cases

[bsardo]

Should debug be allowed by default? If so, perhaps this should be a pointer so we can detect when it's missing or renamed (e.g. Disallow) so that the default value of false is appropriate when the field is missing?

Edit: I see @hhhjort mentioned this in another comment. Technically this is ok right now because Allow is the only field in DebugInfo so we could go with the implementation here where we rely on checking for the presence of Debug. However, it's possible we add additional fields to DebugInfo in the future, in which case we probably don't want to solely rely on checking for the presence of Debug to determine if we need to set Allow to the default. Maybe we don't care about that right now and will just refactor in the future if additional fields are added to DebugInfo.

[SyntaxNode]

Should debug be allowed by default?

Yes. The entire DebugInfo structure is a pointer currently. I think that's fine.

As you said, another option is to make the Debug field in BidderInfo not a pointer and add a pointer here. That would make it more future proof, but the current approach solves the problem at hand. tomato/tomato IMHO.

[bsardo]

Similar to my comment above in the bidder config, should debug be allowed by default? Perhaps a pointer or rename if the default should be to allow?

Edit: on second thought, this is ok since debug_allowed is set to true in the account defaults and that gets merged with any ingested account yaml.

[bsardo]

Maybe we should explicitly defined the composite keys here for readability?
adapters.DebugInfo{Allow: parseDebugInfo(debugInfo)}

[VeronikaSolovei9]

Done!

[bsardo]

It looks like we need debug enabled at both the bidder and the account level to see debug information. If that's the case, do we need the bidder level setting? Maybe we're requiring it as well as a safeguard...

[VeronikaSolovei9]

In case we bid more than one bidder in one request, some of those bidders may have debug.allowed=true and others may have debug.allowed=false. For this case we need to make 2 checks(account and bidder level) and write logs for those bidders where debug.allowed=true. Hope this make sense.

[VeronikaSolovei9]

Wait... did my comment disappear?
Correct. If account level debug disabled, we don't need to check bidder level config. We just skip it.
But if account debug is allowed, we need to check every bidder in request.

We may bid more than one bidder in one request and those bidders may have different debug options. To handle this case we need to check each of them and log data only for those bidders where debug.allow = true.

Hope this makes sense and answers your question.

[bsardo]

Why aren't we marshaling the ext and setting debugLog.Data.Response here if the debugLog is not nil and enabled?

[VeronikaSolovei9]

We do this earlier in code before doCache function, line 204.
If no bids returned we marshal it in else, line 230.

[hhhjort]

Looks good to me as long as everyone else is happy.

[SyntaxNode]

There is a guarantee that infos[bidderName.String()] will be found, but only because there's a check in buildBidders. I don't think that relationship is obvious enough. I recommend to add protections for the lookup here as well. Something like:

for bidderName, bidder := range bidders {
  info, infoFound := infos[string(bidderName)]
  if !infoFound {
    errs = append(errs, fmt.Errorf("%v: bidder info not found", bidder))
    continue
  }

  exchangeBidders[bidderName] = adaptBidder(bidder, client, cfg, me, bidderName, info.Debug)
}

return exchangeBidders, errs

[VeronikaSolovei9]

Done!

[SyntaxNode]

Could you combine the if clauses to improve readability?

if accountDebugAllowed && bidder.config.DebugInfo.Allow {

[VeronikaSolovei9]

Yes, was going to to this too, done! :)

[SyntaxNode]

debugLog can be nil. This needs a nil check, or perhaps incorporate the r.Account.DebugAllowed condition in line 203 and 228. Could you please add a unit test to cover when debugLog is nil, because that doesn't seem to have coverage.

[VeronikaSolovei9]

Good catch! Also modified existing test to make sure debugLog is properly handled in Auction function.

[SyntaxNode]

I think the comment block is till here.

[SyntaxNode]

Should be DebugAllow / debug_allow per the spec and to coordinate with debug.allow in the bidder info.

[VeronikaSolovei9]

Done

[guscarreon]

A couple of comments

[guscarreon]

If we can bear to pass an extra boolean argument to (e *exchange) getAllBids(...) then we might as well save us the extra performance the calls makeDebugContext(ctx context.Context, debugInfo bool) (line 333) and context.WithValue(ctx, DebugContextKey, debugInfo) (line 334) entail:

124   func (e *exchange) HoldAuction(ctx context.Context, r AuctionRequest, debugLog *DebugLog) (*openrtb.BidResponse, error) {
125       var err error
126       requestExt, err := extractBidRequestExt(r.BidRequest)
127       if err != nil {
128           return nil, err
129       }
130  
131       cacheInstructions := getExtCacheInstructions(requestExt)
132       targData := getExtTargetData(requestExt, &cacheInstructions)
133       if targData != nil {
134           _, targData.cacheHost, targData.cachePath = e.cache.GetExtCacheData()
135       }
136  
137       debugInfo := getDebugInfo(r.BidRequest, requestExt)
138  
139       debugInfo = debugInfo && r.Account.DebugAllowed
140       debugLog.Enabled = debugLog.Enabled && r.Account.DebugAllowed
141  
142 -     if debugInfo {
143 -         ctx = e.makeDebugContext(ctx, debugInfo)
144 -     }
145 -
146       bidAdjustmentFactors := getExtBidAdjustmentFactors(requestExt)
147  
148   *-- 20 lines: recordImpMetrics(r.BidRequest, e.me)---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
168  
169 -     adapterBids, adapterExtra, anyBidsReturned := e.getAllBids(auctionCtx, bidderRequests, bidAdjustmentFactors, conversions, r.Account.DebugAllowed)
    +     adapterBids, adapterExtra, anyBidsReturned := e.getAllBids(auctionCtx, bidderRequests, bidAdjustmentFactors, conversions, debugInfo)
170  
171       var auc *auction
172       var cacheErrs []error
173   *-- 66 lines: var bidResponseExt *openrtb_ext.ExtBidResponse-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
239       // Build the response
240       return e.buildBidResponse(ctx, liveAdapters, adapterBids, r.BidRequest, adapterExtra, auc, bidResponseExt, cacheInstructions.returnCreative, errs)
241   }
242  
243   *-- 89 lines: func (e *exchange) parseUsersyncIfAmbiguous(bidRequest *openrtb.BidRequest) bool {-----------------------------------------------------------------------------------------------------------------------------------
332  
333 - func (e *exchange) makeDebugContext(ctx context.Context, debugInfo bool) (debugCtx context.Context) {
334 -     debugCtx = context.WithValue(ctx, DebugContextKey, debugInfo)
335 -     return
336 - }
exchange/exchange.go

..as well as the extra performance the ctx.Value(DebugContextKey) call and the type assertion debugInfo.(bool) yield compared to plain boolean checks

131   func (bidder *bidderAdapter) requestBid(ctx context.Context, request *openrtb.BidRequest, name openrtb_ext.BidderName, bidAdjustment float64, conversions currency.Conversions, reqInfo *adapters.ExtraRequestInfo, accountDebugA
132       reqData, errs := bidder.Bidder.MakeRequests(request, reqInfo)
133  
134       if len(reqData) == 0 {
135           // If the adapter failed to generate both requests and errors, this is an error.
136           if len(errs) == 0 {
137               errs = append(errs, &errortypes.FailedToRequestBids{Message: "The adapter failed to generate any bid requests, but also failed to generate an error explaining why"})
138   *-- 23 lines: }------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
161  
162       // If the bidder made multiple requests, we still want them to enter as many bids as possible...
163       // even if the timeout occurs sometime halfway through.
164       for i := 0; i < len(reqData); i++ {
165           httpInfo := <-responseChannel
166           // If this is a test bid, capture debugging info from the requests.
167           // Write debug data to ext in case if:
168           // - debugContextKey (url param) in true
169           // - account debug is allowed
170           // - bidder debug is allowed
171 -         if debugInfo := ctx.Value(DebugContextKey); debugInfo != nil && debugInfo.(bool) {
172               if accountDebugAllowed {
173                   if bidder.config.DebugInfo.Allow {
174                       seatBid.httpCalls = append(seatBid.httpCalls, makeExt(httpInfo))
175                   }
176               }
177 -         }
178  
exchange/bidder.go [+]

Doubled-check these modifications with the test case we agreed with @VeronikaSolovei9 to add offline and test cases still pass

[VeronikaSolovei9]

Makes sense. Will push it shortly.

[SyntaxNode]

I think this is veering out of scope of this work. I don't feel this needs to be included in this PR. If you already did it, great. Otherwise I think this comment can be worked on separately.

[guscarreon]

Let me know if I overlooked something: could those 3 executions of bidResponseExt := e.makeExtBidResponse(adapterBids, adapterExtra, r, debugInfo, errs) (lines 202, 224, and 226) be rollbacked to just one call as the master branch had them? The modification shown below passes current package and system-wide tests

171       var auc *auction
172       var cacheErrs []error
173 -     var bidResponseExt *openrtb_ext.ExtBidResponse
174       if anyBidsReturned {
175  
176           var bidCategory map[string]string
177           //If includebrandcategory is present in ext then CE feature is on.
178           if requestExt.Prebid.Targeting != nil && requestExt.Prebid.Targeting.IncludeBrandCategory != nil {
179               var rejections []string
180               bidCategory, adapterBids, rejections, err = applyCategoryMapping(ctx, requestExt, adapterBids, e.categoriesFetcher, targData)
181               if err != nil {
182                   return nil, fmt.Errorf("Error in category mapping : %s", err.Error())
183               }
184               for _, message := range rejections {
185                   errs = append(errs, errors.New(message))
186               }
187           }
188  
189           evTracking := getEventTracking(&requestExt.Prebid, r.StartTime, &r.Account, e.bidderInfo, e.externalURL)
190           adapterBids = evTracking.modifyBidsForEvents(adapterBids)
191  
192           if targData != nil {
193               // A non-nil auction is only needed if targeting is active. (It is used below this block to extract cache keys)
194               auc = newAuction(adapterBids, len(r.BidRequest.Imp), targData.preferDeals)
195               auc.setRoundedPrices(targData.priceGranularity)
196  
197               if requestExt.Prebid.SupportDeals {
198                   dealErrs := applyDealSupport(r.BidRequest, auc, bidCategory)
199                   errs = append(errs, dealErrs...)
200               }
201  
202 -             bidResponseExt = e.makeExtBidResponse(adapterBids, adapterExtra, r, debugInfo, errs)
203 -             if debugLog != nil && debugLog.Enabled {
204 -                 if bidRespExtBytes, err := json.Marshal(bidResponseExt); err == nil {
205 -                     debugLog.Data.Response = string(bidRespExtBytes)
206 -                 } else {
207 -                     debugLog.Data.Response = "Unable to marshal response ext for debugging"
208 -                     errs = append(errs, err)
209 -                 }
210 -             }
211 -
212               cacheErrs = auc.doCache(ctx, e.cache, targData, evTracking, r.BidRequest, 60, &r.Account.CacheTTL, bidCategory, debugLog)
213               if len(cacheErrs) > 0 {
214                   errs = append(errs, cacheErrs...)
215               }
216 -             /*// Ensure caching errors are added in case auc.doCache was called and errors were returned
217 -             if len(cacheErrs) > 0 {
218 -                 bidderCacheErrs := errsToBidderErrors(cacheErrs)
219 -                 bidResponseExt.Errors[openrtb_ext.PrebidExtKey] = append(bidResponseExt.Errors[openrtb_ext.PrebidExtKey], bidderCacheErrs...)
220 -             }*/
221               targData.setTargeting(auc, r.BidRequest.App != nil, bidCategory)
222  
223           }
224 -         bidResponseExt = e.makeExtBidResponse(adapterBids, adapterExtra, r, debugInfo, errs)
225 -     } else {
226           bidResponseExt = e.makeExtBidResponse(adapterBids, adapterExtra, r, debugInfo, errs)
    +
    +     // Ensure caching errors are added in case auc.doCache was called and errors were returned
    +     if len(cacheErrs) > 0 {
    +         bidderCacheErrs := errsToBidderErrors(cacheErrs)
    +         bidResponseExt.Errors[openrtb_ext.PrebidExtKey] = append(bidResponseExt.Errors[openrtb_ext.PrebidExtKey], bidderCacheErrs...)
    +     }
227  
228           if debugLog != nil && debugLog.Enabled {
229  
230               if bidRespExtBytes, err := json.Marshal(bidResponseExt); err == nil {
231                   debugLog.Data.Response = string(bidRespExtBytes)
232               } else {
233                   debugLog.Data.Response = "Unable to marshal response ext for debugging"
234                   errs = append(errs, err)
235               }
    +             if !anyBidsReturned {
    +                 if rawUUID, err := uuid.NewV4(); err == nil {
    +                     debugLog.CacheKey = rawUUID.String()
    +                 } else {
    +                     errs = append(errs, err)
    +                 }
    +             }
236           }
237       }
238  
239       // Build the response
240       return e.buildBidResponse(ctx, liveAdapters, adapterBids, r.BidRequest, adapterExtra, auc, bidResponseExt, cacheInstructions.returnCreative, errs)
241   }
exchange/exchange.go

[VeronikaSolovei9]

I need to test it more before pushing. Working on it...

[VeronikaSolovei9]

This is a fix for a problem we had before - when we put data in cache in case everything is ok - there is no response data in debug logs. We don't have explicit test for this, we only check we put "something" in cache.

I understand your concern, but cannot come up with better solution.

[guscarreon]

Can we rename error to err instead? Just so it doesn't get confused with golang's error interface.

[VeronikaSolovei9]

Renamed