-
Notifications
You must be signed in to change notification settings - Fork 8
Improve Prebid auction diagnostics #671
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -13,6 +13,26 @@ use super::config::AuctionConfig; | |
| use super::provider::AuctionProvider; | ||
| use super::types::{AuctionContext, AuctionRequest, AuctionResponse, Bid, BidStatus}; | ||
|
|
||
| const PROVIDER_ERROR_MESSAGE_CHARS: usize = 500; | ||
|
|
||
| fn provider_error_message(error: &Report<TrustedServerError>) -> String { | ||
| format!("{error:?}") | ||
| .chars() | ||
| .take(PROVIDER_ERROR_MESSAGE_CHARS) | ||
| .collect() | ||
| } | ||
|
|
||
| fn provider_error_response( | ||
| provider_name: &str, | ||
| response_time_ms: u64, | ||
| error_type: &str, | ||
| error: &Report<TrustedServerError>, | ||
| ) -> AuctionResponse { | ||
| AuctionResponse::error(provider_name, response_time_ms) | ||
| .with_metadata("error_type", serde_json::json!(error_type)) | ||
| .with_metadata("message", serde_json::json!(provider_error_message(error))) | ||
| } | ||
|
|
||
| /// Compute the remaining time budget from a deadline. | ||
| /// | ||
| /// Returns the number of milliseconds left before `timeout_ms` is exceeded, | ||
|
|
@@ -274,6 +294,7 @@ impl AuctionOrchestrator { | |
| let mut backend_to_provider: HashMap<String, (&str, Instant, &dyn AuctionProvider)> = | ||
| HashMap::new(); | ||
| let mut pending_requests: Vec<PlatformPendingRequest> = Vec::new(); | ||
| let mut responses = Vec::new(); | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🤔 thinking — Moving |
||
|
|
||
| for provider_name in provider_names { | ||
| let provider = match self.providers.get(provider_name) { | ||
|
|
@@ -353,11 +374,18 @@ impl AuctionOrchestrator { | |
| ); | ||
| } | ||
| Err(e) => { | ||
| let response_time_ms = start_time.elapsed().as_millis() as u64; | ||
| log::warn!( | ||
| "Provider '{}' failed to launch request: {:?}", | ||
| provider.provider_name(), | ||
| e | ||
| ); | ||
| responses.push(provider_error_response( | ||
| provider.provider_name(), | ||
| response_time_ms, | ||
| "launch_failed", | ||
| &e, | ||
| )); | ||
| } | ||
| } | ||
| } | ||
|
|
@@ -377,7 +405,6 @@ impl AuctionOrchestrator { | |
| // transport timeout fires). Hard deadline enforcement therefore depends | ||
| // on every backend's `first_byte_timeout` being set to at most the | ||
| // remaining auction budget — which Phase 1 above guarantees. | ||
| let mut responses = Vec::new(); | ||
| let mut remaining = pending_requests; | ||
|
|
||
| while !remaining.is_empty() { | ||
|
|
@@ -419,9 +446,11 @@ impl AuctionOrchestrator { | |
| provider_name, | ||
| e | ||
| ); | ||
| responses.push(AuctionResponse::error( | ||
| responses.push(provider_error_response( | ||
| provider_name, | ||
| response_time_ms, | ||
| "parse_response", | ||
| &e, | ||
| )); | ||
| } | ||
| } | ||
|
|
@@ -432,8 +461,12 @@ impl AuctionOrchestrator { | |
| provider_name, | ||
| e | ||
| ); | ||
| responses | ||
| .push(AuctionResponse::error(provider_name, response_time_ms)); | ||
| responses.push(provider_error_response( | ||
| provider_name, | ||
| response_time_ms, | ||
| "unsupported_response_body", | ||
| &e, | ||
| )); | ||
| } | ||
| } | ||
| } else { | ||
|
|
@@ -635,8 +668,9 @@ mod tests { | |
| use crate::auction::config::AuctionConfig; | ||
| use crate::auction::test_support::create_test_auction_context; | ||
| use crate::auction::types::{ | ||
| AdFormat, AdSlot, AuctionRequest, Bid, MediaType, PublisherInfo, UserInfo, | ||
| AdFormat, AdSlot, AuctionRequest, Bid, BidStatus, MediaType, PublisherInfo, UserInfo, | ||
| }; | ||
| use crate::error::TrustedServerError; | ||
|
|
||
| // All-None ClientInfo used across tests that don't need real IP/TLS data. | ||
| // Defined as a const so &EMPTY_CLIENT_INFO has 'static lifetime, avoiding | ||
|
|
@@ -648,6 +682,7 @@ mod tests { | |
| }; | ||
| use crate::platform::test_support::noop_services; | ||
| use crate::test_support::tests::crate_test_settings_str; | ||
| use error_stack::Report; | ||
| use fastly::Request; | ||
| use std::collections::{HashMap, HashSet}; | ||
|
|
||
|
|
@@ -700,6 +735,32 @@ mod tests { | |
| crate::settings::Settings::from_toml(&settings_str).expect("should parse test settings") | ||
| } | ||
|
|
||
| #[test] | ||
| fn provider_error_response_includes_diagnostic_metadata() { | ||
| let error = Report::new(TrustedServerError::Auction { | ||
| message: "parse failed".to_string(), | ||
| }); | ||
|
|
||
| let response = super::provider_error_response("prebid", 37, "parse_response", &error); | ||
|
|
||
| assert_eq!( | ||
| response.status, | ||
| BidStatus::Error, | ||
| "should mark diagnostic provider responses as errors" | ||
| ); | ||
| assert_eq!( | ||
| response.metadata["error_type"], | ||
| serde_json::json!("parse_response"), | ||
| "should include the provider error classification" | ||
| ); | ||
| assert!( | ||
| response.metadata["message"] | ||
| .as_str() | ||
| .is_some_and(|message| message.contains("parse failed")), | ||
| "should include capped diagnostic detail" | ||
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn filters_winning_bids_below_floor() { | ||
| let orchestrator = AuctionOrchestrator::new(AuctionConfig::default()); | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -37,6 +37,7 @@ const PREBID_INTEGRATION_ID: &str = "prebid"; | |
| const TRUSTED_SERVER_BIDDER: &str = "trustedServer"; | ||
| const BIDDER_PARAMS_KEY: &str = "bidderParams"; | ||
| const ZONE_KEY: &str = "zone"; | ||
| const PREBID_ERROR_BODY_PREVIEW_CHARS: usize = 1000; | ||
|
|
||
| /// Default currency for `OpenRTB` bid floors and responses. | ||
| const DEFAULT_CURRENCY: &str = "USD"; | ||
|
|
@@ -391,6 +392,13 @@ impl IntegrationHeadInjector for PrebidIntegration { | |
| } | ||
| } | ||
|
|
||
| fn prebid_body_preview(body: &[u8]) -> String { | ||
| String::from_utf8_lossy(body) | ||
| .chars() | ||
| .take(PREBID_ERROR_BODY_PREVIEW_CHARS) | ||
| .collect() | ||
| } | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. ⛏ nitpick — No tests pin the truncation behavior (>1000 chars) or non-UTF-8 input handling for |
||
|
|
||
| fn expand_trusted_server_bidders( | ||
| configured_bidders: &[String], | ||
| params: &Json, | ||
|
|
@@ -1093,27 +1101,45 @@ impl AuctionProvider for PrebidAuctionProvider { | |
| response_time_ms: u64, | ||
| ) -> Result<AuctionResponse, Report<TrustedServerError>> { | ||
| // Parse response | ||
| let status = response.get_status(); | ||
| let body_bytes = response.take_body_bytes(); | ||
|
|
||
| if !response.get_status().is_success() { | ||
| log::warn!( | ||
| "Prebid returned non-success status: {}", | ||
| response.get_status(), | ||
| ); | ||
| if log::log_enabled!(log::Level::Trace) { | ||
| let body_preview = String::from_utf8_lossy(&body_bytes); | ||
| log::trace!( | ||
| "Prebid error response body: {}", | ||
| &body_preview[..body_preview.floor_char_boundary(1000)] | ||
| ); | ||
| if !status.is_success() { | ||
| let body_preview = prebid_body_preview(&body_bytes); | ||
| if body_preview.is_empty() { | ||
| log::warn!("Prebid returned non-success status: {status} with empty body"); | ||
| } else { | ||
| log::warn!("Prebid returned non-success status: {status} body: {body_preview}"); | ||
| } | ||
|
|
||
| let mut auction_response = AuctionResponse::error("prebid", response_time_ms) | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. ♻️ refactor — Use |
||
| .with_metadata("error_type", serde_json::json!("http_status")) | ||
| .with_metadata("http_status", serde_json::json!(status.as_u16())); | ||
| if !body_preview.is_empty() { | ||
| auction_response = | ||
| auction_response.with_metadata("body_preview", serde_json::json!(body_preview)); | ||
| } | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🤔 thinking — The first 1000 chars of the upstream Prebid Server's error body are placed in The trace-level body logging at line 1146 is gated on |
||
| return Ok(AuctionResponse::error("prebid", response_time_ms)); | ||
|
|
||
| return Ok(auction_response); | ||
| } | ||
|
|
||
| let response_json: Json = | ||
| serde_json::from_slice(&body_bytes).change_context(TrustedServerError::Prebid { | ||
| message: "Failed to parse Prebid response".to_string(), | ||
| })?; | ||
| if body_bytes.is_empty() { | ||
| log::info!( | ||
| "Prebid returned successful empty response with status {status}; treating as no-bid" | ||
| ); | ||
| return Ok(AuctionResponse::no_bid("prebid", response_time_ms) | ||
| .with_metadata("reason", serde_json::json!("empty_response")) | ||
| .with_metadata("http_status", serde_json::json!(status.as_u16()))); | ||
| } | ||
|
|
||
| let response_json: Json = serde_json::from_slice(&body_bytes).map_err(|e| { | ||
| Report::new(TrustedServerError::Prebid { | ||
| message: format!( | ||
| "Failed to parse Prebid response JSON (status {status}, {} bytes): {e}", | ||
| body_bytes.len() | ||
| ), | ||
| }) | ||
| })?; | ||
|
|
||
| // Log the full response body when debug is enabled to surface | ||
| // ext.debug.httpcalls, resolvedrequest, bidstatus, errors, etc. | ||
|
|
@@ -1234,8 +1260,8 @@ mod tests { | |
| use crate::settings::Settings; | ||
| use crate::streaming_processor::{Compression, PipelineConfig, StreamingPipeline}; | ||
| use crate::test_support::tests::crate_test_settings_str; | ||
| use fastly::http::Method; | ||
| use fastly::Request; | ||
| use fastly::http::{Method, StatusCode}; | ||
| use fastly::{Request, Response}; | ||
| use serde_json::json; | ||
| use std::collections::HashMap; | ||
| use std::io::Cursor; | ||
|
|
@@ -2900,6 +2926,109 @@ fixed_bottom = {placementId = "_s2sBottom"} | |
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn parse_response_non_success_returns_error_with_http_metadata() { | ||
| let provider = PrebidAuctionProvider::new(base_config()); | ||
| let response = Response::from_status(StatusCode::BAD_REQUEST).with_body("invalid request"); | ||
|
|
||
| let auction_response = provider | ||
| .parse_response(response, 58) | ||
| .expect("should convert non-success status to provider error"); | ||
|
|
||
| assert_eq!( | ||
| auction_response.status, | ||
| crate::auction::types::BidStatus::Error, | ||
| "should mark non-success upstream responses as errors" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["error_type"], | ||
| json!("http_status"), | ||
| "should classify the error source" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["http_status"], | ||
| json!(400), | ||
| "should include upstream HTTP status" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["body_preview"], | ||
| json!("invalid request"), | ||
| "should include a capped upstream body preview" | ||
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn parse_response_no_content_returns_no_bid_with_reason() { | ||
| let provider = PrebidAuctionProvider::new(base_config()); | ||
| let response = Response::from_status(StatusCode::NO_CONTENT); | ||
|
|
||
| let auction_response = provider | ||
| .parse_response(response, 42) | ||
| .expect("should convert no-content status to no-bid"); | ||
|
|
||
| assert_eq!( | ||
| auction_response.status, | ||
| crate::auction::types::BidStatus::NoBid, | ||
| "should treat 204 as a no-bid response" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["reason"], | ||
| json!("empty_response"), | ||
| "should explain why the provider returned no bids" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["http_status"], | ||
| json!(204), | ||
| "should include upstream HTTP status" | ||
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn parse_response_ok_empty_body_returns_no_bid_with_reason() { | ||
| let provider = PrebidAuctionProvider::new(base_config()); | ||
| let response = Response::from_status(StatusCode::OK); | ||
|
|
||
| let auction_response = provider | ||
| .parse_response(response, 17) | ||
| .expect("should convert empty successful response to no-bid"); | ||
|
|
||
| assert_eq!( | ||
| auction_response.status, | ||
| crate::auction::types::BidStatus::NoBid, | ||
| "should treat empty 200 as a no-bid response" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["reason"], | ||
| json!("empty_response"), | ||
| "should explain why the provider returned no bids" | ||
| ); | ||
| assert_eq!( | ||
| auction_response.metadata["http_status"], | ||
| json!(200), | ||
| "should include upstream HTTP status" | ||
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn parse_response_valid_json_without_bids_returns_no_bid() { | ||
| let provider = PrebidAuctionProvider::new(base_config()); | ||
| let response = Response::from_status(StatusCode::OK).with_body(r#"{"seatbid":[]}"#); | ||
|
|
||
| let auction_response = provider | ||
| .parse_response(response, 23) | ||
| .expect("should parse valid no-bid JSON"); | ||
|
|
||
| assert_eq!( | ||
| auction_response.status, | ||
| crate::auction::types::BidStatus::NoBid, | ||
| "should preserve valid JSON no-bid behavior" | ||
| ); | ||
| assert!( | ||
| auction_response.metadata.is_empty(), | ||
| "should not add empty-response metadata for valid no-bid JSON" | ||
| ); | ||
| } | ||
|
|
||
| #[test] | ||
| fn enrich_response_metadata_attaches_always_on_fields() { | ||
| let provider = PrebidAuctionProvider::new(base_config()); | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🔧 wrench — Information disclosure:
format!("{error:?}")on aReport<TrustedServerError>emits error-stack's full Debug stack, which includesat <file>:<line>:<col>location entries (and backtrace frames if compiled with them). That string flows throughAuctionResponse.metadata["message"]→ProviderSummary.metadata→ public JSON body ofPOST /auction, exposing internal source paths to any caller.This contradicts the explicit policy in
error.rs:18-22("messagefield is included in client-facing HTTP responses … keep it free of internal implementation details") and theIntoHttpResponse::user_message()pattern ("Full error details are preserved in server logs").Fix — use Display on the current context so the user-safe
#[display(...)]text is preserved but file/line/stack info is dropped:The detailed
{error:?}is still emitted to logs via the existinglog::warn!("…: {:?}", e)calls.