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