github.com/prebid/prebid-server/v2@v2.18.0/exchange/bidder.go (about) 1 package exchange 2 3 import ( 4 "bytes" 5 "compress/gzip" 6 "context" 7 "crypto/tls" 8 "encoding/json" 9 "errors" 10 "fmt" 11 "io" 12 "net/http" 13 "net/http/httptrace" 14 "regexp" 15 "strings" 16 "sync" 17 "time" 18 19 "github.com/golang/glog" 20 "github.com/prebid/prebid-server/v2/bidadjustment" 21 "github.com/prebid/prebid-server/v2/config/util" 22 "github.com/prebid/prebid-server/v2/currency" 23 "github.com/prebid/prebid-server/v2/exchange/entities" 24 "github.com/prebid/prebid-server/v2/experiment/adscert" 25 "github.com/prebid/prebid-server/v2/hooks/hookexecution" 26 "github.com/prebid/prebid-server/v2/version" 27 28 "github.com/prebid/openrtb/v20/adcom1" 29 nativeRequests "github.com/prebid/openrtb/v20/native1/request" 30 nativeResponse "github.com/prebid/openrtb/v20/native1/response" 31 "github.com/prebid/openrtb/v20/openrtb2" 32 "github.com/prebid/prebid-server/v2/adapters" 33 "github.com/prebid/prebid-server/v2/config" 34 "github.com/prebid/prebid-server/v2/errortypes" 35 "github.com/prebid/prebid-server/v2/metrics" 36 "github.com/prebid/prebid-server/v2/openrtb_ext" 37 "github.com/prebid/prebid-server/v2/util/jsonutil" 38 "golang.org/x/net/context/ctxhttp" 39 ) 40 41 // AdaptedBidder defines the contract needed to participate in an Auction within an Exchange. 42 // 43 // This interface exists to help segregate core auction logic. 44 // 45 // Any logic which can be done _within a single Seat_ goes inside one of these. 46 // Any logic which _requires responses from all Seats_ goes inside the Exchange. 47 // 48 // This interface differs from adapters.Bidder to help minimize code duplication across the 49 // adapters.Bidder implementations. 50 type AdaptedBidder interface { 51 // requestBid fetches bids for the given request. 52 // 53 // An AdaptedBidder *may* return two non-nil values here. Errors should describe situations which 54 // make the bid (or no-bid) "less than ideal." Common examples include: 55 // 56 // 1. Connection issues. 57 // 2. Imps with Media Types which this Bidder doesn't support. 58 // 3. The Context timeout expired before all expected bids were returned. 59 // 4. The Server sent back an unexpected Response, so some bids were ignored. 60 // 61 // Any errors will be user-facing in the API. 62 // Error messages should help publishers understand what might account for "bad" bids. 63 requestBid(ctx context.Context, bidderRequest BidderRequest, conversions currency.Conversions, reqInfo *adapters.ExtraRequestInfo, adsCertSigner adscert.Signer, bidRequestOptions bidRequestOptions, alternateBidderCodes openrtb_ext.ExtAlternateBidderCodes, hookExecutor hookexecution.StageExecutor, ruleToAdjustments openrtb_ext.AdjustmentsByDealID) ([]*entities.PbsOrtbSeatBid, extraBidderRespInfo, []error) 64 } 65 66 // bidRequestOptions holds additional options for bid request execution to maintain clean code and reasonable number of parameters 67 type bidRequestOptions struct { 68 accountDebugAllowed bool 69 headerDebugAllowed bool 70 addCallSignHeader bool 71 bidAdjustments map[string]float64 72 tmaxAdjustments *TmaxAdjustmentsPreprocessed 73 bidderRequestStartTime time.Time 74 responseDebugAllowed bool 75 } 76 77 type extraBidderRespInfo struct { 78 respProcessingStartTime time.Time 79 } 80 81 type extraAuctionResponseInfo struct { 82 fledge *openrtb_ext.Fledge 83 bidsFound bool 84 bidderResponseStartTime time.Time 85 } 86 87 const ImpIdReqBody = "Stored bid response for impression id: " 88 89 // Possible values of compression types Prebid Server can support for bidder compression 90 const ( 91 Gzip string = "GZIP" 92 ) 93 94 // AdaptBidder converts an adapters.Bidder into an exchange.AdaptedBidder. 95 // 96 // The name refers to the "Adapter" architecture pattern, and should not be confused with a Prebid "Adapter" 97 // (which is being phased out and replaced by Bidder for OpenRTB auctions) 98 func AdaptBidder(bidder adapters.Bidder, client *http.Client, cfg *config.Configuration, me metrics.MetricsEngine, name openrtb_ext.BidderName, debugInfo *config.DebugInfo, endpointCompression string) AdaptedBidder { 99 return &bidderAdapter{ 100 Bidder: bidder, 101 BidderName: name, 102 Client: client, 103 me: me, 104 config: bidderAdapterConfig{ 105 Debug: cfg.Debug, 106 DisableConnMetrics: cfg.Metrics.Disabled.AdapterConnectionMetrics, 107 DebugInfo: config.DebugInfo{Allow: parseDebugInfo(debugInfo)}, 108 EndpointCompression: endpointCompression, 109 }, 110 } 111 } 112 113 func parseDebugInfo(info *config.DebugInfo) bool { 114 if info == nil { 115 return true 116 } 117 return info.Allow 118 } 119 120 type bidderAdapter struct { 121 Bidder adapters.Bidder 122 BidderName openrtb_ext.BidderName 123 Client *http.Client 124 me metrics.MetricsEngine 125 config bidderAdapterConfig 126 } 127 128 type bidderAdapterConfig struct { 129 Debug config.Debug 130 DisableConnMetrics bool 131 DebugInfo config.DebugInfo 132 EndpointCompression string 133 } 134 135 func (bidder *bidderAdapter) requestBid(ctx context.Context, bidderRequest BidderRequest, conversions currency.Conversions, reqInfo *adapters.ExtraRequestInfo, adsCertSigner adscert.Signer, bidRequestOptions bidRequestOptions, alternateBidderCodes openrtb_ext.ExtAlternateBidderCodes, hookExecutor hookexecution.StageExecutor, ruleToAdjustments openrtb_ext.AdjustmentsByDealID) ([]*entities.PbsOrtbSeatBid, extraBidderRespInfo, []error) { 136 request := openrtb_ext.RequestWrapper{BidRequest: bidderRequest.BidRequest} 137 reject := hookExecutor.ExecuteBidderRequestStage(&request, string(bidderRequest.BidderName)) 138 if reject != nil { 139 return nil, extraBidderRespInfo{}, []error{reject} 140 } 141 142 var ( 143 reqData []*adapters.RequestData 144 errs []error 145 responseChannel chan *httpCallInfo 146 extraRespInfo extraBidderRespInfo 147 ) 148 149 // rebuild request after modules execution 150 request.RebuildRequest() 151 bidderRequest.BidRequest = request.BidRequest 152 153 //check if real request exists for this bidder or it only has stored responses 154 dataLen := 0 155 if len(bidderRequest.BidRequest.Imp) > 0 { 156 // Reducing the amount of time bidders have to compensate for the processing time used by PBS to fetch a stored request (if needed), validate the OpenRTB request and split it into multiple requests sanitized for each bidder 157 // As well as for the time needed by PBS to prepare the auction response 158 if bidRequestOptions.tmaxAdjustments != nil && bidRequestOptions.tmaxAdjustments.IsEnforced { 159 bidderRequest.BidRequest.TMax = getBidderTmax(&bidderTmaxCtx{ctx}, bidderRequest.BidRequest.TMax, *bidRequestOptions.tmaxAdjustments) 160 } 161 reqData, errs = bidder.Bidder.MakeRequests(bidderRequest.BidRequest, reqInfo) 162 163 if len(reqData) == 0 { 164 // If the adapter failed to generate both requests and errors, this is an error. 165 if len(errs) == 0 { 166 errs = append(errs, &errortypes.FailedToRequestBids{Message: "The adapter failed to generate any bid requests, but also failed to generate an error explaining why"}) 167 } 168 return nil, extraBidderRespInfo{}, errs 169 } 170 xPrebidHeader := version.BuildXPrebidHeaderForRequest(bidderRequest.BidRequest, version.Ver) 171 172 for i := 0; i < len(reqData); i++ { 173 if reqData[i].Headers != nil { 174 reqData[i].Headers = reqData[i].Headers.Clone() 175 } else { 176 reqData[i].Headers = http.Header{} 177 } 178 reqData[i].Headers.Add("X-Prebid", xPrebidHeader) 179 if reqInfo.GlobalPrivacyControlHeader == "1" { 180 reqData[i].Headers.Add("Sec-GPC", reqInfo.GlobalPrivacyControlHeader) 181 } 182 if bidRequestOptions.addCallSignHeader { 183 startSignRequestTime := time.Now() 184 signatureMessage, err := adsCertSigner.Sign(reqData[i].Uri, reqData[i].Body) 185 bidder.me.RecordAdsCertSignTime(time.Since(startSignRequestTime)) 186 if err != nil { 187 bidder.me.RecordAdsCertReq(false) 188 errs = append(errs, &errortypes.Warning{Message: fmt.Sprintf("AdsCert signer is enabled but cannot sign the request: %s", err.Error())}) 189 } 190 if err == nil && len(signatureMessage) > 0 { 191 reqData[i].Headers.Add(adscert.SignHeader, signatureMessage) 192 bidder.me.RecordAdsCertReq(true) 193 } 194 } 195 196 } 197 // Make any HTTP requests in parallel. 198 // If the bidder only needs to make one, save some cycles by just using the current one. 199 dataLen = len(reqData) + len(bidderRequest.BidderStoredResponses) 200 responseChannel = make(chan *httpCallInfo, dataLen) 201 if len(reqData) == 1 { 202 responseChannel <- bidder.doRequest(ctx, reqData[0], bidRequestOptions.bidderRequestStartTime, bidRequestOptions.tmaxAdjustments) 203 } else { 204 for _, oneReqData := range reqData { 205 go func(data *adapters.RequestData) { 206 responseChannel <- bidder.doRequest(ctx, data, bidRequestOptions.bidderRequestStartTime, bidRequestOptions.tmaxAdjustments) 207 }(oneReqData) // Method arg avoids a race condition on oneReqData 208 } 209 } 210 } 211 if len(bidderRequest.BidderStoredResponses) > 0 { 212 //if stored bid responses are present - replace impIds and add them as is to responseChannel <- stored responses 213 if responseChannel == nil { 214 dataLen = dataLen + len(bidderRequest.BidderStoredResponses) 215 responseChannel = make(chan *httpCallInfo, dataLen) 216 } 217 for impId, bidResp := range bidderRequest.BidderStoredResponses { 218 go func(id string, resp json.RawMessage) { 219 responseChannel <- prepareStoredResponse(id, resp) 220 }(impId, bidResp) 221 } 222 } 223 224 defaultCurrency := "USD" 225 seatBidMap := map[openrtb_ext.BidderName]*entities.PbsOrtbSeatBid{ 226 bidderRequest.BidderName: { 227 Bids: make([]*entities.PbsOrtbBid, 0, dataLen), 228 Currency: defaultCurrency, 229 HttpCalls: make([]*openrtb_ext.ExtHttpCall, 0, dataLen), 230 Seat: string(bidderRequest.BidderName), 231 }, 232 } 233 234 // If the bidder made multiple requests, we still want them to enter as many bids as possible... 235 // even if the timeout occurs sometime halfway through. 236 for i := 0; i < dataLen; i++ { 237 httpInfo := <-responseChannel 238 // If this is a test bid, capture debugging info from the requests. 239 // Write debug data to ext in case if: 240 // - headerDebugAllowed (debug override header specified correct) - it overrides all other debug restrictions 241 // - account debug is allowed 242 // - bidder debug is allowed 243 if bidRequestOptions.headerDebugAllowed { 244 seatBidMap[bidderRequest.BidderName].HttpCalls = append(seatBidMap[bidderRequest.BidderName].HttpCalls, makeExt(httpInfo)) 245 } else { 246 if bidRequestOptions.accountDebugAllowed { 247 if bidder.config.DebugInfo.Allow { 248 seatBidMap[bidderRequest.BidderName].HttpCalls = append(seatBidMap[bidderRequest.BidderName].HttpCalls, makeExt(httpInfo)) 249 } else { 250 debugDisabledWarning := errortypes.Warning{ 251 WarningCode: errortypes.BidderLevelDebugDisabledWarningCode, 252 Message: "debug turned off for bidder", 253 } 254 errs = append(errs, &debugDisabledWarning) 255 } 256 } 257 } 258 259 if httpInfo.err == nil { 260 extraRespInfo.respProcessingStartTime = time.Now() 261 bidResponse, moreErrs := bidder.Bidder.MakeBids(bidderRequest.BidRequest, httpInfo.request, httpInfo.response) 262 errs = append(errs, moreErrs...) 263 264 if bidResponse != nil { 265 reject := hookExecutor.ExecuteRawBidderResponseStage(bidResponse, string(bidder.BidderName)) 266 if reject != nil { 267 errs = append(errs, reject) 268 continue 269 } 270 // Setup default currency as `USD` is not set in bid request nor bid response 271 if bidResponse.Currency == "" { 272 bidResponse.Currency = defaultCurrency 273 } 274 if len(bidderRequest.BidRequest.Cur) == 0 { 275 bidderRequest.BidRequest.Cur = []string{defaultCurrency} 276 } 277 278 // Try to get a conversion rate 279 // Try to get the first currency from request.cur having a match in the rate converter, 280 // and use it as currency 281 var conversionRate float64 282 var err error 283 for _, bidReqCur := range bidderRequest.BidRequest.Cur { 284 if conversionRate, err = conversions.GetRate(bidResponse.Currency, bidReqCur); err == nil { 285 seatBidMap[bidderRequest.BidderName].Currency = bidReqCur 286 break 287 } 288 } 289 290 // Only do this for request from mobile app 291 if bidderRequest.BidRequest.App != nil { 292 for i := 0; i < len(bidResponse.Bids); i++ { 293 if bidResponse.Bids[i].BidType == openrtb_ext.BidTypeNative { 294 nativeMarkup, moreErrs := addNativeTypes(bidResponse.Bids[i].Bid, bidderRequest.BidRequest) 295 errs = append(errs, moreErrs...) 296 297 if nativeMarkup != nil { 298 markup, err := jsonutil.Marshal(*nativeMarkup) 299 if err != nil { 300 errs = append(errs, err) 301 } else { 302 bidResponse.Bids[i].Bid.AdM = string(markup) 303 } 304 } 305 } 306 } 307 } 308 309 // FLEDGE auctionconfig responses are sent separate from bids 310 if bidResponse.FledgeAuctionConfigs != nil { 311 if fledgeAuctionConfigs := seatBidMap[bidderRequest.BidderName].FledgeAuctionConfigs; fledgeAuctionConfigs != nil { 312 seatBidMap[bidderRequest.BidderName].FledgeAuctionConfigs = append(fledgeAuctionConfigs, bidResponse.FledgeAuctionConfigs...) 313 } else { 314 seatBidMap[bidderRequest.BidderName].FledgeAuctionConfigs = bidResponse.FledgeAuctionConfigs 315 } 316 } 317 318 if len(bidderRequest.BidderStoredResponses) > 0 { 319 //set imp ids back to response for bids with stored responses 320 for i := 0; i < len(bidResponse.Bids); i++ { 321 if httpInfo.request.Uri == "" { 322 reqBody := string(httpInfo.request.Body) 323 re := regexp.MustCompile(ImpIdReqBody) 324 reqBodySplit := re.Split(reqBody, -1) 325 reqImpId := reqBodySplit[1] 326 // replace impId if "replaceimpid" is true or not specified 327 if bidderRequest.ImpReplaceImpId[reqImpId] { 328 bidResponse.Bids[i].Bid.ImpID = reqImpId 329 } 330 } 331 } 332 } 333 334 if err == nil { 335 // Conversion rate found, using it for conversion 336 for i := 0; i < len(bidResponse.Bids); i++ { 337 338 bidderName := bidderRequest.BidderName 339 if bidResponse.Bids[i].Seat != "" { 340 bidderName = bidResponse.Bids[i].Seat 341 } 342 343 if valid, err := alternateBidderCodes.IsValidBidderCode(bidderRequest.BidderName.String(), bidderName.String()); !valid { 344 if err != nil { 345 err = &errortypes.Warning{ 346 WarningCode: errortypes.AlternateBidderCodeWarningCode, 347 Message: err.Error(), 348 } 349 errs = append(errs, err) 350 } 351 continue 352 } 353 354 adjustmentFactor := 1.0 355 if givenAdjustment, ok := bidRequestOptions.bidAdjustments[(strings.ToLower(bidderName.String()))]; ok { 356 adjustmentFactor = givenAdjustment 357 } else if givenAdjustment, ok := bidRequestOptions.bidAdjustments[(strings.ToLower(bidderRequest.BidderName.String()))]; ok { 358 adjustmentFactor = givenAdjustment 359 } 360 361 originalBidCpm := 0.0 362 currencyAfterAdjustments := "" 363 if bidResponse.Bids[i].Bid != nil { 364 originalBidCpm = bidResponse.Bids[i].Bid.Price 365 bidResponse.Bids[i].Bid.Price = bidResponse.Bids[i].Bid.Price * adjustmentFactor * conversionRate 366 367 bidType := getBidTypeForAdjustments(bidResponse.Bids[i].BidType, bidResponse.Bids[i].Bid.ImpID, bidderRequest.BidRequest.Imp) 368 bidResponse.Bids[i].Bid.Price, currencyAfterAdjustments = bidadjustment.Apply(ruleToAdjustments, bidResponse.Bids[i], bidderRequest.BidderName, seatBidMap[bidderRequest.BidderName].Currency, reqInfo, bidType) 369 } 370 371 if _, ok := seatBidMap[bidderName]; !ok { 372 // Initalize seatBidMap entry as this is first extra bid with seat bidderName 373 seatBidMap[bidderName] = &entities.PbsOrtbSeatBid{ 374 Bids: make([]*entities.PbsOrtbBid, 0, dataLen), 375 Currency: seatBidMap[bidderRequest.BidderName].Currency, 376 // Do we need to fill httpCalls for this?. Can we refer one from adaptercode for debugging? 377 HttpCalls: seatBidMap[bidderRequest.BidderName].HttpCalls, 378 Seat: bidderName.String(), 379 } 380 } 381 382 seatBidMap[bidderName].Bids = append(seatBidMap[bidderName].Bids, &entities.PbsOrtbBid{ 383 Bid: bidResponse.Bids[i].Bid, 384 BidMeta: bidResponse.Bids[i].BidMeta, 385 BidType: bidResponse.Bids[i].BidType, 386 BidVideo: bidResponse.Bids[i].BidVideo, 387 DealPriority: bidResponse.Bids[i].DealPriority, 388 OriginalBidCPM: originalBidCpm, 389 OriginalBidCur: bidResponse.Currency, 390 AdapterCode: bidderRequest.BidderCoreName, 391 }) 392 seatBidMap[bidderName].Currency = currencyAfterAdjustments 393 } 394 } else { 395 // If no conversions found, do not handle the bid 396 errs = append(errs, err) 397 } 398 } 399 } else { 400 errs = append(errs, httpInfo.err) 401 } 402 } 403 seatBids := make([]*entities.PbsOrtbSeatBid, 0, len(seatBidMap)) 404 for _, seatBid := range seatBidMap { 405 seatBids = append(seatBids, seatBid) 406 } 407 408 return seatBids, extraRespInfo, errs 409 } 410 411 func addNativeTypes(bid *openrtb2.Bid, request *openrtb2.BidRequest) (*nativeResponse.Response, []error) { 412 var errs []error 413 var nativeMarkup nativeResponse.Response 414 if err := jsonutil.UnmarshalValid(json.RawMessage(bid.AdM), &nativeMarkup); err != nil || len(nativeMarkup.Assets) == 0 { 415 // Some bidders are returning non-IAB compliant native markup. In this case Prebid server will not be able to add types. E.g Facebook 416 return nil, errs 417 } 418 419 nativeImp, err := getNativeImpByImpID(bid.ImpID, request) 420 if err != nil { 421 errs = append(errs, err) 422 return nil, errs 423 } 424 425 var nativePayload nativeRequests.Request 426 if err := jsonutil.UnmarshalValid(json.RawMessage((*nativeImp).Request), &nativePayload); err != nil { 427 errs = append(errs, err) 428 } 429 430 for _, asset := range nativeMarkup.Assets { 431 if err := setAssetTypes(asset, nativePayload); err != nil { 432 errs = append(errs, err) 433 } 434 } 435 436 return &nativeMarkup, errs 437 } 438 439 func setAssetTypes(asset nativeResponse.Asset, nativePayload nativeRequests.Request) error { 440 if asset.Img != nil { 441 if asset.ID == nil { 442 return errors.New("Response Image asset doesn't have an ID") 443 } 444 if tempAsset, err := getAssetByID(*asset.ID, nativePayload.Assets); err == nil { 445 if tempAsset.Img != nil { 446 if tempAsset.Img.Type != 0 { 447 asset.Img.Type = tempAsset.Img.Type 448 } 449 } else { 450 return fmt.Errorf("Response has an Image asset with ID:%d present that doesn't exist in the request", *asset.ID) 451 } 452 } else { 453 return err 454 } 455 } 456 457 if asset.Data != nil { 458 if asset.ID == nil { 459 return errors.New("Response Data asset doesn't have an ID") 460 } 461 if tempAsset, err := getAssetByID(*asset.ID, nativePayload.Assets); err == nil { 462 if tempAsset.Data != nil { 463 if tempAsset.Data.Type != 0 { 464 asset.Data.Type = tempAsset.Data.Type 465 } 466 } else { 467 return fmt.Errorf("Response has a Data asset with ID:%d present that doesn't exist in the request", *asset.ID) 468 } 469 } else { 470 return err 471 } 472 } 473 return nil 474 } 475 476 func getNativeImpByImpID(impID string, request *openrtb2.BidRequest) (*openrtb2.Native, error) { 477 for _, impInRequest := range request.Imp { 478 if impInRequest.ID == impID && impInRequest.Native != nil { 479 return impInRequest.Native, nil 480 } 481 } 482 return nil, errors.New("Could not find native imp") 483 } 484 485 func getAssetByID(id int64, assets []nativeRequests.Asset) (nativeRequests.Asset, error) { 486 for _, asset := range assets { 487 if id == asset.ID { 488 return asset, nil 489 } 490 } 491 return nativeRequests.Asset{}, fmt.Errorf("Unable to find asset with ID:%d in the request", id) 492 } 493 494 var authorizationHeader = http.CanonicalHeaderKey("authorization") 495 496 func filterHeader(h http.Header) http.Header { 497 clone := h.Clone() 498 clone.Del(authorizationHeader) 499 return clone 500 } 501 502 // makeExt transforms information about the HTTP call into the contract class for the PBS response. 503 func makeExt(httpInfo *httpCallInfo) *openrtb_ext.ExtHttpCall { 504 ext := &openrtb_ext.ExtHttpCall{} 505 506 if httpInfo != nil && httpInfo.request != nil { 507 ext.Uri = httpInfo.request.Uri 508 ext.RequestBody = string(httpInfo.request.Body) 509 ext.RequestHeaders = filterHeader(httpInfo.request.Headers) 510 511 if httpInfo.err == nil && httpInfo.response != nil { 512 ext.ResponseBody = string(httpInfo.response.Body) 513 ext.Status = httpInfo.response.StatusCode 514 } 515 } 516 517 return ext 518 } 519 520 // doRequest makes a request, handles the response, and returns the data needed by the 521 // Bidder interface. 522 func (bidder *bidderAdapter) doRequest(ctx context.Context, req *adapters.RequestData, bidderRequestStartTime time.Time, tmaxAdjustments *TmaxAdjustmentsPreprocessed) *httpCallInfo { 523 return bidder.doRequestImpl(ctx, req, glog.Warningf, bidderRequestStartTime, tmaxAdjustments) 524 } 525 526 func (bidder *bidderAdapter) doRequestImpl(ctx context.Context, req *adapters.RequestData, logger util.LogMsg, bidderRequestStartTime time.Time, tmaxAdjustments *TmaxAdjustmentsPreprocessed) *httpCallInfo { 527 requestBody, err := getRequestBody(req, bidder.config.EndpointCompression) 528 if err != nil { 529 return &httpCallInfo{ 530 request: req, 531 err: err, 532 } 533 } 534 httpReq, err := http.NewRequest(req.Method, req.Uri, requestBody) 535 if err != nil { 536 return &httpCallInfo{ 537 request: req, 538 err: err, 539 } 540 } 541 httpReq.Header = req.Headers 542 543 // If adapter connection metrics are not disabled, add the client trace 544 // to get complete connection info into our metrics 545 if !bidder.config.DisableConnMetrics { 546 ctx = bidder.addClientTrace(ctx) 547 } 548 bidder.me.RecordOverheadTime(metrics.PreBidder, time.Since(bidderRequestStartTime)) 549 550 if tmaxAdjustments != nil && tmaxAdjustments.IsEnforced { 551 if hasShorterDurationThanTmax(&bidderTmaxCtx{ctx}, *tmaxAdjustments) { 552 bidder.me.RecordTMaxTimeout() 553 return &httpCallInfo{ 554 request: req, 555 err: &errortypes.TmaxTimeout{Message: "exceeded tmax duration"}, 556 } 557 } 558 } 559 560 httpCallStart := time.Now() 561 httpResp, err := ctxhttp.Do(ctx, bidder.Client, httpReq) 562 if err != nil { 563 if err == context.DeadlineExceeded { 564 err = &errortypes.Timeout{Message: err.Error()} 565 var corebidder adapters.Bidder = bidder.Bidder 566 // The bidder adapter normally stores an info-aware bidder (a bidder wrapper) 567 // rather than the actual bidder. So we need to unpack that first. 568 if b, ok := corebidder.(*adapters.InfoAwareBidder); ok { 569 corebidder = b.Bidder 570 } 571 if tb, ok := corebidder.(adapters.TimeoutBidder); ok { 572 // Toss the timeout notification call into a go routine, as we are out of time' 573 // and cannot delay processing. We don't do anything result, as there is not much 574 // we can do about a timeout notification failure. We do not want to get stuck in 575 // a loop of trying to report timeouts to the timeout notifications. 576 go bidder.doTimeoutNotification(tb, req, logger) 577 } 578 579 } 580 return &httpCallInfo{ 581 request: req, 582 err: err, 583 } 584 } 585 586 respBody, err := io.ReadAll(httpResp.Body) 587 if err != nil { 588 return &httpCallInfo{ 589 request: req, 590 err: err, 591 } 592 } 593 defer httpResp.Body.Close() 594 595 if httpResp.StatusCode < 200 || httpResp.StatusCode >= 400 { 596 err = &errortypes.BadServerResponse{ 597 Message: fmt.Sprintf("Server responded with failure status: %d. Set request.test = 1 for debugging info.", httpResp.StatusCode), 598 } 599 } 600 601 bidder.me.RecordBidderServerResponseTime(time.Since(httpCallStart)) 602 return &httpCallInfo{ 603 request: req, 604 response: &adapters.ResponseData{ 605 StatusCode: httpResp.StatusCode, 606 Body: respBody, 607 Headers: httpResp.Header, 608 }, 609 err: err, 610 } 611 } 612 613 func (bidder *bidderAdapter) doTimeoutNotification(timeoutBidder adapters.TimeoutBidder, req *adapters.RequestData, logger util.LogMsg) { 614 ctx, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) 615 defer cancel() 616 toReq, errL := timeoutBidder.MakeTimeoutNotification(req) 617 if toReq != nil && len(errL) == 0 { 618 httpReq, err := http.NewRequest(toReq.Method, toReq.Uri, bytes.NewBuffer(toReq.Body)) 619 if err == nil { 620 httpReq.Header = req.Headers 621 httpResp, err := ctxhttp.Do(ctx, bidder.Client, httpReq) 622 success := (err == nil && httpResp.StatusCode >= 200 && httpResp.StatusCode < 300) 623 bidder.me.RecordTimeoutNotice(success) 624 if bidder.config.Debug.TimeoutNotification.Log && !(bidder.config.Debug.TimeoutNotification.FailOnly && success) { 625 var msg string 626 if err == nil { 627 msg = fmt.Sprintf("TimeoutNotification: status:(%d) body:%s", httpResp.StatusCode, string(toReq.Body)) 628 } else { 629 msg = fmt.Sprintf("TimeoutNotification: error:(%s) body:%s", err.Error(), string(toReq.Body)) 630 } 631 // If logging is turned on, and logging is not disallowed via FailOnly 632 util.LogRandomSample(msg, logger, bidder.config.Debug.TimeoutNotification.SamplingRate) 633 } 634 } else { 635 bidder.me.RecordTimeoutNotice(false) 636 if bidder.config.Debug.TimeoutNotification.Log { 637 msg := fmt.Sprintf("TimeoutNotification: Failed to make timeout request: method(%s), uri(%s), error(%s)", toReq.Method, toReq.Uri, err.Error()) 638 util.LogRandomSample(msg, logger, bidder.config.Debug.TimeoutNotification.SamplingRate) 639 } 640 } 641 } else if bidder.config.Debug.TimeoutNotification.Log { 642 reqJSON, err := jsonutil.Marshal(req) 643 var msg string 644 if err == nil { 645 msg = fmt.Sprintf("TimeoutNotification: Failed to generate timeout request: error(%s), bidder request(%s)", errL[0].Error(), string(reqJSON)) 646 } else { 647 msg = fmt.Sprintf("TimeoutNotification: Failed to generate timeout request: error(%s), bidder request marshal failed(%s)", errL[0].Error(), err.Error()) 648 } 649 util.LogRandomSample(msg, logger, bidder.config.Debug.TimeoutNotification.SamplingRate) 650 } 651 652 } 653 654 type httpCallInfo struct { 655 request *adapters.RequestData 656 response *adapters.ResponseData 657 err error 658 } 659 660 // This function adds an httptrace.ClientTrace object to the context so, if connection with the bidder 661 // endpoint is established, we can keep track of whether the connection was newly created, reused, and 662 // the time from the connection request, to the connection creation. 663 func (bidder *bidderAdapter) addClientTrace(ctx context.Context) context.Context { 664 var connStart, dnsStart, tlsStart time.Time 665 666 trace := &httptrace.ClientTrace{ 667 // GetConn is called before a connection is created or retrieved from an idle pool 668 GetConn: func(hostPort string) { 669 connStart = time.Now() 670 }, 671 // GotConn is called after a successful connection is obtained 672 GotConn: func(info httptrace.GotConnInfo) { 673 connWaitTime := time.Since(connStart) 674 675 bidder.me.RecordAdapterConnections(bidder.BidderName, info.Reused, connWaitTime) 676 }, 677 // DNSStart is called when a DNS lookup begins. 678 DNSStart: func(info httptrace.DNSStartInfo) { 679 dnsStart = time.Now() 680 }, 681 // DNSDone is called when a DNS lookup ends. 682 DNSDone: func(info httptrace.DNSDoneInfo) { 683 dnsLookupTime := time.Since(dnsStart) 684 685 bidder.me.RecordDNSTime(dnsLookupTime) 686 }, 687 688 TLSHandshakeStart: func() { 689 tlsStart = time.Now() 690 }, 691 692 TLSHandshakeDone: func(tls.ConnectionState, error) { 693 tlsHandshakeTime := time.Since(tlsStart) 694 695 bidder.me.RecordTLSHandshakeTime(tlsHandshakeTime) 696 }, 697 } 698 return httptrace.WithClientTrace(ctx, trace) 699 } 700 701 func prepareStoredResponse(impId string, bidResp json.RawMessage) *httpCallInfo { 702 //always one element in reqData because stored response is mapped to single imp 703 body := fmt.Sprintf("%s%s", ImpIdReqBody, impId) 704 reqDataForStoredResp := adapters.RequestData{ 705 Method: "POST", 706 Uri: "", 707 Body: []byte(body), //use it to pass imp id for stored resp 708 } 709 respData := &httpCallInfo{ 710 request: &reqDataForStoredResp, 711 response: &adapters.ResponseData{ 712 StatusCode: 200, 713 Body: bidResp, 714 }, 715 err: nil, 716 } 717 return respData 718 } 719 720 func getBidTypeForAdjustments(bidType openrtb_ext.BidType, impID string, imp []openrtb2.Imp) string { 721 if bidType == openrtb_ext.BidTypeVideo { 722 for _, imp := range imp { 723 if imp.ID == impID { 724 if imp.Video != nil && imp.Video.Plcmt == adcom1.VideoPlcmtAccompanyingContent { 725 return "video-outstream" 726 } 727 break 728 } 729 } 730 return "video-instream" 731 } 732 return string(bidType) 733 } 734 735 func hasShorterDurationThanTmax(ctx bidderTmaxContext, tmaxAdjustments TmaxAdjustmentsPreprocessed) bool { 736 if tmaxAdjustments.IsEnforced { 737 if deadline, ok := ctx.Deadline(); ok { 738 overheadNS := time.Duration(tmaxAdjustments.BidderNetworkLatencyBuffer+tmaxAdjustments.PBSResponsePreparationDuration) * time.Millisecond 739 bidderTmax := deadline.Add(-overheadNS) 740 741 remainingDuration := ctx.Until(bidderTmax).Milliseconds() 742 return remainingDuration < int64(tmaxAdjustments.BidderResponseDurationMin) 743 } 744 } 745 return false 746 } 747 748 func getRequestBody(req *adapters.RequestData, endpointCompression string) (*bytes.Buffer, error) { 749 switch strings.ToUpper(endpointCompression) { 750 case Gzip: 751 // Compress to GZIP 752 b := bytes.NewBuffer(make([]byte, 0, len(req.Body))) 753 754 w := gzipWriterPool.Get().(*gzip.Writer) 755 defer gzipWriterPool.Put(w) 756 757 w.Reset(b) 758 _, err := w.Write(req.Body) 759 if err != nil { 760 return nil, err 761 } 762 err = w.Close() 763 if err != nil { 764 return nil, err 765 } 766 767 // Set Header 768 req.Headers.Set("Content-Encoding", "gzip") 769 770 return b, nil 771 default: 772 return bytes.NewBuffer(req.Body), nil 773 } 774 } 775 776 var gzipWriterPool = sync.Pool{ 777 New: func() interface{} { 778 return gzip.NewWriter(nil) 779 }, 780 }