diff --git a/README.md b/README.md index ff73d2b..b484ab2 100644 --- a/README.md +++ b/README.md @@ -61,6 +61,9 @@ Use `--json` for machine-readable output and `--verbose` for request diagnostics. Do not include credentials or other sensitive data when sharing verbose output. +For inherited Apps Platform trace context and failure correlation, see +[Apps operation correlation](docs/apps-operation-correlation.md). + ## Local development Install the repository tools and git hooks once: diff --git a/docs/apps-operation-correlation.md b/docs/apps-operation-correlation.md new file mode 100644 index 0000000..f723743 --- /dev/null +++ b/docs/apps-operation-correlation.md @@ -0,0 +1,66 @@ +# Apps operation correlation + +`bl apps` forwards valid inherited `TRACEPARENT` as a +[W3C `traceparent`](https://www.w3.org/TR/trace-context/#traceparent-header) +header on Compose requests, including uploads. It preserves sampling flags, +ignores malformed context, and adds no trace headers to authentication requests. +The CLI doesn't create spans or generate fallback IDs. + +## Returned IDs + +The server's valid `X-Hotpod-Trace-Id` header takes precedence over structured +`trace_id` (top-level or `error.trace_id`). IDs must be nonzero 32-character +hexadecimal values and are normalized to lowercase. Missing response IDs are +never replaced with the inherited ID: the server may have started another trace. + +Successful JSON objects expose `trace_id`. Failures include `trace_id=` in +text and `error.trace_id` with `--json`. Header IDs survive unreadable or +oversized bodies and CLI validation/recovery errors. Body-only IDs require +complete JSON within the existing 2 MiB limit. Responses must be JSON objects. +Authentication, exit codes, and retry behavior are unchanged. + +Use `deployment_trace_id` to investigate the original deployment. Later `ready` +or `debug` requests have their own `trace_id`, which identifies the inspection +request rather than the deployment. + +Create preserves IDs within its `plan`, `reservation`, and `initialize` results. +For a reconciled reservation, `reservation.trace_id` identifies the confirming +inspection; `reservation.reserve_trace_id` retains the original reserve response +ID when available. Unknown-outcome errors prefer the reserve ID, falling back to +the inspection ID. + +## Rollout and remaining work + +This needs Compose to return IDs and persist deployment context through +asynchronous work. Ingress must preserve the tracing headers. End-to-end log +correlation and restart recovery still need staging verification. + +`bl apps deploy` uploads a prebuilt artifact. Blox builds that fail before deploy +have no Compose deployment trace. BuilderLab's command runner still needs to +persist operation context, export `TRACEPARENT` into local and remote commands, +return failure IDs, and provide references to saved stdout/stderr. Keep task, +command, and deployment selectors alongside the ID when an operation spans +multiple commands. + +## Staging verification + +After the Compose dependency is deployed, authenticate with `bl auth` and read +`bl apps contract --base-url --json`. Follow the current +contract and command help, and test each staging environment separately. + +1. Run `bl apps get --base-url --json` + with `TRACEPARENT=00-1234567890abcdef1234567890abcdef-1234567890abcdef-00`. + Confirm `error.trace_id` matches the admitted trace and is searchable in + ingress/Compose logs even when APM doesn't retain the unsampled trace. +2. Deploy a freshly built artifact to an approved disposable app using fixed + version and deployment IDs. Save its correlation IDs and confirm validation, + reconciliation, and runtime events share the deployment trace. +3. Request `ready` and `debug` for that exact version under a different trace. + Confirm the request ID changes while `deployment_trace_id` stays the same. + Repeat after an approved restart test resumes asynchronous work. +4. Repeat with sampled (`01`) and malformed context. Malformed context must not + break the command; the server should return its own ID. + +Once runner support exists, separately fail a pre-deploy Blox build and follow +its ID to command logs and saved output. A deploy that never ran should have no +Compose deployment event. diff --git a/src/bl/apps.rs b/src/bl/apps.rs index 38eb059..53e26e8 100644 --- a/src/bl/apps.rs +++ b/src/bl/apps.rs @@ -35,7 +35,7 @@ use super::display::{print_json, terminal_safe_text, Style}; use super::runner; #[cfg(test)] use super::skills_api::failure_info; -use super::skills_api::{exit_codes, failure, CliFailure}; +use super::skills_api::{exit_codes, failure, failure_trace_id, with_failure_trace_id, CliFailure}; use super::skills_config::SkillsConfig; const APPS_BASE_URL_ENV_VAR: &str = "BL_APPS_CONTROL_PLANE_URL"; @@ -50,6 +50,7 @@ const APPS_CONTRACT_PATH: &str = "/v1/agent/contract"; const APPS_PLAN_PATH: &str = "/v1/agent/apps/plan"; const MAX_DEBUG_TAIL_LINES: u16 = 1000; const HOTPOD_AGENT_CLIENT_VERSION_HEADER: &str = "X-Hotpod-Agent-Client-Version"; +const HOTPOD_TRACE_ID_HEADER: &str = "X-Hotpod-Trace-Id"; // Compose may synchronously wait up to two minutes for an initialize or // deploy rollout. Leave enough headroom for the response to traverse ingress. const CONTROL_PLANE_REQUEST_TIMEOUT: Duration = Duration::from_secs(3 * 60); @@ -566,20 +567,23 @@ fn run_create(config: &SkillsConfig, matches: &ArgMatches) -> Result<()> { let plan = client.plan(&credential, &request)?; let app_id = required_response_string(&plan, "app_id", "Apps Platform plan")?.to_string(); if let Some(requested_app_id) = requested_app_id { - require_exact_app_id("plan", requested_app_id, &app_id)?; + require_exact_app_id("plan", requested_app_id, &app_id) + .map_err(|error| correlate_response_error(error, &plan))?; } let initialize_required = plan .pointer("/initialize/required") .and_then(Value::as_bool) .context( "Apps Platform plan response did not include boolean initialize.required; refusing to reserve the app", - )?; + ) + .map_err(|error| correlate_response_error(error, &plan))?; let initialize_recommended = plan .pointer("/initialize/recommended") .and_then(Value::as_bool) .context( "Apps Platform plan response did not include boolean initialize.recommended; refusing to reserve the app", - )?; + ) + .map_err(|error| correlate_response_error(error, &plan))?; let plan_requests_initialize = initialize_required || initialize_recommended; let mutation_request = mutation_request_from_plan(&plan); let (reservation, reservation_reconciled) = @@ -594,7 +598,8 @@ fn run_create(config: &SkillsConfig, matches: &ArgMatches) -> Result<()> { })?; let initialized_app_id = required_response_string(&response, "app_id", "Apps Platform initialize")?; - require_exact_app_id("initialize", &app_id, initialized_app_id)?; + require_exact_app_id("initialize", &app_id, initialized_app_id) + .map_err(|error| correlate_response_error(error, &response))?; Some(response) } else { None @@ -633,7 +638,8 @@ fn reconcile_create_reservation( Ok(reservation) => { let reserved_app_id = required_response_string(&reservation, "app_id", "Apps Platform reserve")?; - require_exact_app_id("reserve", app_id, reserved_app_id)?; + require_exact_app_id("reserve", app_id, reserved_app_id) + .map_err(|error| correlate_response_error(error, &reservation))?; Ok((reservation, false)) } Err(reserve_error) => { @@ -642,20 +648,28 @@ fn reconcile_create_reservation( Ok(existing) if is_matching_incomplete_reservation(&existing, app_id, mutation_request) => { - Ok(( - json!({ - "ok": true, - "app_id": app_id, - "external_url": plan.get("external_url").cloned().unwrap_or(Value::Null), - "reconciled": true, - "app": existing.get("app").cloned().unwrap_or(Value::Null), - }), - true, - )) + let mut reservation = json!({ + "ok": true, + "app_id": app_id, + "external_url": plan.get("external_url").cloned().unwrap_or(Value::Null), + "reconciled": true, + "app": existing.get("app").cloned().unwrap_or(Value::Null), + }); + retain_response_trace_id( + &mut reservation, + response_value_trace_id(&existing).as_deref(), + ); + if let Some(trace_id) = failure_trace_id(&reserve_error) { + reservation["reserve_trace_id"] = json!(trace_id); + } + Ok((reservation, true)) } - Ok(_) if reservation_outcome_is_unknown(&reserve_error) => { - let mismatch = anyhow::anyhow!( - "the inspected app was not the same caller-owned, incomplete reservation" + Ok(existing) if reservation_outcome_is_unknown(&reserve_error) => { + let mismatch = correlate_response_error( + anyhow::anyhow!( + "the inspected app was not the same caller-owned, incomplete reservation" + ), + &existing, ); Err(reservation_outcome_unknown( app_id, @@ -741,7 +755,7 @@ fn reservation_outcome_unknown( let environment_argument = environment .map(|value| format!(" --environment {value}")) .unwrap_or_default(); - failure( + let error = failure( exit_codes::NETWORK, "reservation_outcome_unknown", format!( @@ -750,6 +764,10 @@ fn reservation_outcome_unknown( inspection_error: {inspect_error:#}\n\ next_action: Run `bl apps get {app_id}{environment_argument}`. If it reports a caller-owned app with route_status `idle`, retry the same `bl apps create` command; the retry will reconcile that reservation and continue initialization." ), + ); + with_failure_trace_id( + error, + failure_trace_id(reserve_error).or_else(|| failure_trace_id(inspect_error)), ) } @@ -881,17 +899,22 @@ fn run_share(config: &SkillsConfig, matches: &ArgMatches) -> Result<()> { }; if action == "grant" && current.get("visibility").and_then(Value::as_str) != Some("restricted") { - anyhow::bail!("workspace sharing requires restricted app visibility"); + return Err(correlate_response_error( + anyhow::anyhow!("workspace sharing requires restricted app visibility"), + ¤t, + )); } let lifecycle_id = current .get("lifecycle_id") .and_then(Value::as_str) .filter(|value| !value.is_empty()) - .context("app has no active sharing lifecycle")?; + .context("app has no active sharing lifecycle") + .map_err(|error| correlate_response_error(error, ¤t))?; let expected_revision = current .get("workspace_grant_revision") .and_then(Value::as_u64) - .context("app sharing response has no workspace grant revision")?; + .context("app sharing response has no workspace grant revision") + .map_err(|error| correlate_response_error(error, ¤t))?; let response = client.update_workspace_grant( &credential, app_id, @@ -1026,6 +1049,7 @@ fn required_response_string<'a>( .and_then(Value::as_str) .filter(|value| !value.is_empty()) .with_context(|| format!("{description} response did not include {field}")) + .map_err(|error| correlate_response_error(error, value)) } fn validate_artifact_path(path: &Path) -> Result<()> { @@ -1086,6 +1110,7 @@ struct ControlPlaneClient { base_url: String, client_version: HeaderValue, client_version_text: String, + traceparent: Option, style: Style, } @@ -1174,6 +1199,10 @@ impl ControlPlaneClient { base_url: base_url.to_string(), client_version, client_version_text, + traceparent: std::env::var("TRACEPARENT") + .ok() + .as_deref() + .and_then(inherited_traceparent), style, }) } @@ -1351,21 +1380,37 @@ impl ControlPlaneClient { .execute_request(http_request) .map_err(|_| delete_outcome_unknown())?; let status = response.status(); + let trace_id = response_header_trace_id(&response) + .filter(|trace_id| credential.redact(trace_id) == *trace_id); let body = read_limited_response_body( response, CONTROL_PLANE_RESPONSE_MAX_BYTES, "Apps Platform control-plane", ) - .map_err(|_| delete_outcome_unknown())?; + .map_err(|_| with_failure_trace_id(delete_outcome_unknown(), trace_id.as_deref()))?; + let trace_id = trace_id.or_else(|| { + response_body_trace_id(&body) + .filter(|trace_id| credential.redact(trace_id) == *trace_id) + }); self.style .verbose(&format!("DELETE {path} -> {status} ({} bytes)", body.len())); if !status.is_success() { - return Err(control_plane_http_failure( - "DELETE", &path, status, &body, credential, + return Err(with_failure_trace_id( + control_plane_http_failure("DELETE", &path, status, &body, credential), + trace_id.as_deref(), )); } - let mut value = serde_json::from_str(&body).map_err(|_| delete_outcome_unknown())?; - redact_json_value(&mut value, credential).map_err(|_| delete_outcome_unknown())?; + let mut value: Value = serde_json::from_str(&body) + .map_err(|_| with_failure_trace_id(delete_outcome_unknown(), trace_id.as_deref()))?; + if !value.is_object() { + return Err(with_failure_trace_id( + delete_outcome_unknown(), + trace_id.as_deref(), + )); + } + redact_json_value(&mut value, credential) + .map_err(|_| with_failure_trace_id(delete_outcome_unknown(), trace_id.as_deref()))?; + retain_response_trace_id(&mut value, trace_id.as_deref()); Ok(value) } @@ -1555,14 +1600,18 @@ impl ControlPlaneClient { request: RequestBuilder, authorization: HeaderValue, ) -> RequestBuilder { - request + let request = request .header(USER_AGENT, apps_user_agent()) .header(ACCEPT, "application/json") .header( HOTPOD_AGENT_CLIENT_VERSION_HEADER, self.client_version.clone(), ) - .header(AUTHORIZATION, authorization) + .header(AUTHORIZATION, authorization); + match &self.traceparent { + Some(traceparent) => request.header("traceparent", traceparent.clone()), + None => request, + } } fn authorized_json_request( @@ -1576,26 +1625,38 @@ impl ControlPlaneClient { F: Fn(HeaderValue) -> Result, { let authorization = credential.authorization_header(); - let (status, body) = self.request_response(method, path, &send, authorization)?; + let (status, body, trace_id) = + self.request_response(credential, method, path, &send, authorization)?; if !status.is_success() { - return Err(control_plane_http_failure( - method, path, status, &body, credential, + return Err(with_failure_trace_id( + control_plane_http_failure(method, path, status, &body, credential), + trace_id.as_deref(), + )); + } + let mut value: Value = serde_json::from_str(&body) + .with_context(|| format!("parse Apps Platform {method} {path} response")) + .map_err(|error| with_failure_trace_id(error, trace_id.as_deref()))?; + if !value.is_object() { + return Err(with_failure_trace_id( + anyhow::anyhow!("Apps Platform {method} {path} response was not a JSON object"), + trace_id.as_deref(), )); } - let mut value = serde_json::from_str(&body) - .with_context(|| format!("parse Apps Platform {method} {path} response"))?; redact_json_value(&mut value, credential) - .with_context(|| format!("sanitize Apps Platform {method} {path} response"))?; + .with_context(|| format!("sanitize Apps Platform {method} {path} response")) + .map_err(|error| with_failure_trace_id(error, trace_id.as_deref()))?; + retain_response_trace_id(&mut value, trace_id.as_deref()); Ok(value) } fn request_response( &self, + credential: &ComposeSessionCredential, method: &str, path: &str, send: &F, authorization: HeaderValue, - ) -> Result<(StatusCode, String)> + ) -> Result<(StatusCode, String, Option)> where F: Fn(HeaderValue) -> Result, { @@ -1605,16 +1666,24 @@ impl ControlPlaneClient { .execute_request(request) .map_err(|error| network_failure(method, path, error))?; let status = response.status(); + // Capture correlation before the bounded reader consumes the response. + let trace_id = response_header_trace_id(&response) + .filter(|trace_id| credential.redact(trace_id) == *trace_id); let body = read_limited_response_body( response, CONTROL_PLANE_RESPONSE_MAX_BYTES, "Apps Platform control-plane", - )?; + ) + .map_err(|error| with_failure_trace_id(error, trace_id.as_deref()))?; + let trace_id = trace_id.or_else(|| { + response_body_trace_id(&body) + .filter(|trace_id| credential.redact(trace_id) == *trace_id) + }); self.style.verbose(&format!( "{method} {path} -> {status} ({} bytes)", body.len() )); - Ok((status, body)) + Ok((status, body, trace_id)) } fn execute_request(&self, request: Request) -> reqwest::Result { @@ -1633,6 +1702,72 @@ fn request_path(url: &url::Url) -> String { } } +// Forward context without creating a CLI span or changing the caller's sampling +// decision. Future versions retain the known W3C prefix and opaque suffix. +fn inherited_traceparent(value: &str) -> Option { + let bytes = value.as_bytes(); + if !(55..=512).contains(&bytes.len()) + || !bytes.iter().all(|byte| (b'!'..=b'~').contains(byte)) + || bytes[2] != b'-' + || bytes[35] != b'-' + || bytes[52] != b'-' + || !lowercase_hex(&bytes[..2]) + || &bytes[..2] == b"ff" + || !lowercase_hex(&bytes[3..35]) + || bytes[3..35].iter().all(|byte| *byte == b'0') + || !lowercase_hex(&bytes[36..52]) + || bytes[36..52].iter().all(|byte| *byte == b'0') + || !lowercase_hex(&bytes[53..55]) + || (bytes.len() > 55 && (&bytes[..2] == b"00" || bytes[55] != b'-')) + { + return None; + } + HeaderValue::from_str(value).ok() +} + +fn lowercase_hex(bytes: &[u8]) -> bool { + bytes + .iter() + .all(|byte| byte.is_ascii_digit() || (b'a'..=b'f').contains(byte)) +} + +fn canonical_trace_id(value: &str) -> Option { + (value.len() == 32 + && value.bytes().all(|byte| byte.is_ascii_hexdigit()) + && value.bytes().any(|byte| byte != b'0')) + .then(|| value.to_ascii_lowercase()) +} + +fn response_header_trace_id(response: &Response) -> Option { + response + .headers() + .get(HOTPOD_TRACE_ID_HEADER) + .and_then(|value| value.to_str().ok()) + .and_then(canonical_trace_id) +} + +fn response_value_trace_id(value: &Value) -> Option { + [value.get("trace_id"), value.pointer("/error/trace_id")] + .into_iter() + .flatten() + .filter_map(Value::as_str) + .find_map(canonical_trace_id) +} + +fn response_body_trace_id(body: &str) -> Option { + response_value_trace_id(&serde_json::from_str::(body).ok()?) +} + +fn retain_response_trace_id(value: &mut Value, trace_id: Option<&str>) { + if let (Some(object), Some(trace_id)) = (value.as_object_mut(), trace_id) { + object.insert("trace_id".to_string(), json!(trace_id)); + } +} + +fn correlate_response_error(error: anyhow::Error, response: &Value) -> anyhow::Error { + with_failure_trace_id(error, response_value_trace_id(response).as_deref()) +} + fn build_control_plane_http_client(timeout: Duration) -> Result { Client::builder() .redirect(Policy::none()) @@ -1843,6 +1978,7 @@ mod tests { struct ProcessResponse { status: u16, body: String, + trace_id: Option, } impl ProcessResponse { @@ -1850,6 +1986,7 @@ mod tests { Self { status: 200, body: body.to_string(), + trace_id: None, } } @@ -1857,6 +1994,7 @@ mod tests { Self { status, body: body.to_string(), + trace_id: None, } } @@ -1864,8 +2002,14 @@ mod tests { Self { status, body: body.into(), + trace_id: None, } } + + fn with_trace_id(mut self, trace_id: &str) -> Self { + self.trace_id = Some(trace_id.to_string()); + self + } } #[derive(Clone)] @@ -1930,15 +2074,20 @@ mod tests { body, body_bytes, }); + let mut http_response = Response::from_string(response.body) + .with_status_code(response.status) + .with_header( + Header::from_bytes("Content-Type", "application/json") + .expect("build Apps process content type"), + ); + if let Some(trace_id) = response.trace_id { + http_response.add_header( + Header::from_bytes(HOTPOD_TRACE_ID_HEADER, trace_id) + .expect("build Apps process trace header"), + ); + } request - .respond( - Response::from_string(response.body) - .with_status_code(response.status) - .with_header( - Header::from_bytes("Content-Type", "application/json") - .expect("build Apps process content type"), - ), - ) + .respond(http_response) .expect("respond to Apps process request"); } }); @@ -2057,6 +2206,7 @@ mod tests { .env_remove("KGOOSE_BASE_URL") .env_remove("BL_SKILLS_PROFILE") .env_remove("KGOOSE_PLAYPEN"); + command.env_remove("TRACEPARENT"); command } @@ -3144,8 +3294,8 @@ mod tests { let auth_server = ProcessServer::start(vec![process_auth_response()]); let control_plane = ProcessServer::start(vec![ ProcessResponse::json(plan), - ProcessResponse::raw(201, "{"), - ProcessResponse::json(existing_reservation), + ProcessResponse::raw(201, "{").with_trace_id(DEPLOYMENT_TRACE_ID), + ProcessResponse::json(existing_reservation).with_trace_id(REQUEST_TRACE_ID), ProcessResponse::json(initialized), ]); let mut command = process_command( @@ -3178,6 +3328,11 @@ mod tests { let value = serde_json::from_str::(&process_stdout(&output)) .expect("parse reconciled create output"); assert_eq!(value["reservation_reconciled"], true); + assert_eq!(value["reservation"]["trace_id"], REQUEST_TRACE_ID); + assert_eq!( + value["reservation"]["reserve_trace_id"], + DEPLOYMENT_TRACE_ID + ); assert_eq!(value["initialized"], true); let auth_requests = auth_server.finish(); let requests = control_plane.finish(); @@ -3229,7 +3384,7 @@ mod tests { let control_plane = ProcessServer::start(vec![ ProcessResponse::json(plan), ProcessResponse::raw(201, "{"), - ProcessResponse::json(existing_reservation), + ProcessResponse::json(existing_reservation).with_trace_id(REQUEST_TRACE_ID), ]); let mut command = process_command( &auth_server, @@ -3263,6 +3418,7 @@ mod tests { let value = serde_json::from_str::(&process_stdout(&output)) .expect("parse reconciled reserve-only output"); assert_eq!(value["reservation_reconciled"], true); + assert_eq!(value["reservation"]["trace_id"], REQUEST_TRACE_ID); assert_eq!(value["initialized"], false); assert_eq!(value["initialize"], Value::Null); let auth_requests = auth_server.finish(); @@ -3336,6 +3492,64 @@ mod tests { } } + #[test] + fn bl_apps_create_retains_inspection_id_on_reservation_mismatch() { + for reserve_trace_id in [None, Some(DEPLOYMENT_TRACE_ID)] { + let auth_server = ProcessServer::start(vec![process_auth_response()]); + let mut reserve = ProcessResponse::raw(201, "{"); + if let Some(trace_id) = reserve_trace_id { + reserve = reserve.with_trace_id(trace_id); + } + let control_plane = ProcessServer::start(vec![ + ProcessResponse::json(json!({ + "app_id": "app", + "initialize": {"required": false, "recommended": false} + })), + reserve, + ProcessResponse::json(json!({ + "ok": true, + "app": {"app_id": "app", "role": "publisher"}, + "versions": [] + })) + .with_trace_id(REQUEST_TRACE_ID), + ]); + let output = process_command( + &auth_server, + &control_plane, + &[ + "apps", + "create", + "--app-id", + "app", + "--base-url", + APPROVED_TEST_BASE_URL, + "--client-version", + "0.2.0", + "--json", + ], + "apps-e2e-only.reservation-mismatch.trace", + ) + .output() + .expect("run create with mismatched inspected reservation"); + let payload = process_error(&output); + assert_eq!(payload["error"]["code"], "reservation_outcome_unknown"); + assert_eq!(payload["error"]["exit_code"], exit_codes::NETWORK); + assert_eq!( + payload["error"]["trace_id"], + reserve_trace_id.unwrap_or(REQUEST_TRACE_ID) + ); + let message = payload["error"]["message"].as_str().unwrap(); + assert!(message.contains(&format!("trace_id={REQUEST_TRACE_ID}"))); + assert!(message.contains("not the same caller-owned, incomplete reservation")); + auth_server.finish(); + assert_eq!( + control_plane.finish().len(), + 3, + "do not initialize a mismatched reservation" + ); + } + } + #[test] fn bl_apps_create_reports_unknown_reservation_outcome_when_inspection_fails() { let credential = "apps-e2e-only.reserve-outcome-unknown.session+credential"; @@ -3631,6 +3845,8 @@ mod tests { credential, ); + let traceparent = format!("00-{REQUEST_TRACE_ID}-1234567890abcdef-00"); + command.env("TRACEPARENT", &traceparent); let output = command.output().expect("run Apps deploy process command"); assert!(output.status.success()); assert_eq!( @@ -3648,6 +3864,8 @@ mod tests { "/v1/agent/apps/merchant-lookup/deploy", credential, ); + assert_eq!(requests[0].headers.get("traceparent"), Some(&traceparent)); + assert!(!auth_requests[0].headers.contains_key("traceparent")); let body = String::from_utf8_lossy(&requests[0].body_bytes); for expected in [ "test-hotpod-artifact-marker", @@ -4023,6 +4241,484 @@ mod tests { ComposeSessionCredential::new(secret.to_string()).expect("build test credential") } + const REQUEST_TRACE_ID: &str = "1234567890abcdef1234567890abcdef"; + const DEPLOYMENT_TRACE_ID: &str = "abcdef1234567890abcdef1234567890"; + + fn process_error(output: &std::process::Output) -> Value { + assert!(!output.status.success()); + String::from_utf8_lossy(&output.stderr) + .lines() + .find_map(|line| serde_json::from_str::(line).ok()) + .expect("structured CLI error on stderr") + } + + #[test] + fn bl_apps_process_preserves_inherited_context_only_on_compose_requests() { + for flags in ["00", "01"] { + let credential = "apps-e2e-only.trace-success.session+credential"; + let auth_server = ProcessServer::start(vec![process_auth_response()]); + let control_plane = ProcessServer::start(vec![ProcessResponse::json(json!({ + "ok": true, + "trace_id": DEPLOYMENT_TRACE_ID, + "deployment_trace_id": DEPLOYMENT_TRACE_ID, + "version_id": "ver-123" + })) + .with_trace_id(REQUEST_TRACE_ID)]); + let traceparent = format!("00-{REQUEST_TRACE_ID}-1234567890abcdef-{flags}"); + let output = process_command( + &auth_server, + &control_plane, + &[ + "apps", + "ready", + "app", + "--version-id", + "ver-123", + "--base-url", + APPROVED_TEST_BASE_URL, + "--client-version", + "0.2.0", + "--json", + ], + credential, + ) + .env("TRACEPARENT", &traceparent) + .output() + .expect("run correlated readiness command"); + assert!(output.status.success(), "{output:?}"); + let value: Value = serde_json::from_str(&process_stdout(&output)).unwrap(); + assert_eq!(value["trace_id"], REQUEST_TRACE_ID); + assert_eq!(value["deployment_trace_id"], DEPLOYMENT_TRACE_ID); + assert_eq!(value["version_id"], "ver-123"); + let auth_requests = auth_server.finish(); + assert_process_auth(&auth_requests[0], credential); + assert!(!auth_requests[0].headers.contains_key("traceparent")); + let requests = control_plane.finish(); + assert_process_control_plane( + &requests[0], + "GET", + "/v1/agent/apps/app/ready?version_id=ver-123", + credential, + ); + assert_eq!(requests[0].headers.get("traceparent"), Some(&traceparent)); + } + } + + #[test] + fn bl_apps_process_retains_header_and_body_error_ids_and_ignores_bad_context() { + let credential = "apps-e2e-only.trace-failure.session+credential"; + for (header, body, expected_id, expected_exit) in [ + ( + Some(REQUEST_TRACE_ID), + json!({"error":{"code":"not_found"}, "trace_id":DEPLOYMENT_TRACE_ID}), + Some(REQUEST_TRACE_ID), + exit_codes::GENERAL, + ), + ( + None, + json!({"error":{"code":"not_found"}, "trace_id":DEPLOYMENT_TRACE_ID}), + Some(DEPLOYMENT_TRACE_ID), + exit_codes::GENERAL, + ), + ( + Some("malformed"), + json!({"error":{"code":"not_found", "trace_id":REQUEST_TRACE_ID}}), + Some(REQUEST_TRACE_ID), + exit_codes::GENERAL, + ), + ( + Some("00000000000000000000000000000000"), + json!({"trace_id":"bad-id"}), + None, + exit_codes::GENERAL, + ), + ( + Some(REQUEST_TRACE_ID), + json!({"error":{"code":"session_expired"}}), + Some(REQUEST_TRACE_ID), + exit_codes::AUTH_REQUIRED, + ), + ] { + let status = if expected_exit == exit_codes::AUTH_REQUIRED { + 401 + } else { + 404 + }; + let auth_server = ProcessServer::start(vec![process_auth_response()]); + let mut response = ProcessResponse::json_status(status, body); + if let Some(header) = header { + response = response.with_trace_id(header); + } + let control_plane = ProcessServer::start(vec![response]); + let output = process_command( + &auth_server, + &control_plane, + &[ + "apps", + "get", + "app", + "--base-url", + APPROVED_TEST_BASE_URL, + "--client-version", + "0.2.0", + "--json", + ], + credential, + ) + .env("TRACEPARENT", "00-invalid-context") + .output() + .expect("run correlated failing command"); + let error = process_error(&output); + assert_eq!(error["error"]["exit_code"], expected_exit); + assert_eq!( + error["error"]["trace_id"], + expected_id.map(Value::from).unwrap_or(Value::Null) + ); + if let Some(id) = expected_id { + assert!(error["error"]["message"] + .as_str() + .unwrap() + .contains(&format!("trace_id={id}"))); + } + auth_server.finish(); + let requests = control_plane.finish(); + assert_eq!(requests.len(), 1, "no auth retry"); + assert!(!requests[0].headers.contains_key("traceparent")); + } + } + + #[test] + fn bl_apps_create_process_retains_ids_through_protocol_and_domain_errors() { + for body in [ + "not-json".to_string(), + "[]".to_string(), + json!({}).to_string(), + json!({"app_id":"replacement"}).to_string(), + json!({"app_id":"app", "initialize":{"required":false}}).to_string(), + ] { + let auth_server = ProcessServer::start(vec![process_auth_response()]); + let control_plane = ProcessServer::start(vec![ + ProcessResponse::raw(200, body).with_trace_id(REQUEST_TRACE_ID) + ]); + let output = process_command( + &auth_server, + &control_plane, + &[ + "apps", + "create", + "--app-id", + "app", + "--base-url", + APPROVED_TEST_BASE_URL, + "--client-version", + "0.2.0", + "--json", + ], + "apps-e2e-only.trace-protocol.session", + ) + .output() + .expect("run protocol failure command"); + let error = process_error(&output); + assert_eq!(error["error"]["trace_id"], REQUEST_TRACE_ID); + assert_eq!(error["error"]["exit_code"], exit_codes::GENERAL); + auth_server.finish(); + assert_eq!( + control_plane.finish().len(), + 1, + "never reserve invalid plan" + ); + } + } + + #[test] + fn bl_apps_share_process_retains_trace_on_validation_failures() { + for body in [ + json!({"visibility":"organization"}), + json!({"visibility":"restricted"}), + json!({"visibility":"restricted", "lifecycle_id":"life-123"}), + ] { + let auth_server = ProcessServer::start(vec![process_auth_response()]); + let control_plane = ProcessServer::start(vec![ + ProcessResponse::json(body).with_trace_id(REQUEST_TRACE_ID) + ]); + let output = process_command( + &auth_server, + &control_plane, + &[ + "apps", + "share", + "grant", + "app", + "test-workspace", + "--base-url", + APPROVED_TEST_BASE_URL, + "--client-version", + "0.2.0", + "--json", + ], + "apps-e2e-only.trace-share.session", + ) + .output() + .expect("run invalid share command"); + assert_eq!( + process_error(&output)["error"]["trace_id"], + REQUEST_TRACE_ID + ); + auth_server.finish(); + assert_eq!( + control_plane.finish().len(), + 1, + "never mutate invalid sharing state" + ); + } + } + + #[test] + fn delete_retains_response_id_through_http_and_unknown_outcome_failures() { + for (status, body, expected_code, expected_exit) in [ + ( + 200, + vec![b'x'; CONTROL_PLANE_RESPONSE_MAX_BYTES + 1], + "delete_outcome_unknown", + exit_codes::NETWORK, + ), + ( + 200, + b"[]".to_vec(), + "delete_outcome_unknown", + exit_codes::NETWORK, + ), + ( + 403, + json!({"error":{"code":"access_denied"}, "trace_id":DEPLOYMENT_TRACE_ID}) + .to_string() + .into_bytes(), + "access_denied", + exit_codes::FORBIDDEN, + ), + ] { + let server = Server::http("127.0.0.1:0").unwrap(); + let client = test_control_plane_client( + &format!("http://{}", server.server_addr()), + Duration::from_secs(2), + ); + let server_thread = thread::spawn(move || { + server + .recv() + .unwrap() + .respond( + Response::from_data(body) + .with_status_code(status) + .with_header( + Header::from_bytes(HOTPOD_TRACE_ID_HEADER, REQUEST_TRACE_ID) + .unwrap(), + ), + ) + .unwrap(); + }); + let error = client + .delete_app( + &test_credential("delete_trace_session_credential"), + "app", + &DeleteAppRequest { + environment: "staging", + }, + ) + .expect_err("delete failure"); + let (exit_code, payload) = failure_info(&error); + assert_eq!(exit_code, expected_exit); + assert_eq!(payload["error"]["code"], expected_code); + assert_eq!(payload["error"]["trace_id"], REQUEST_TRACE_ID); + server_thread.join().unwrap(); + } + } + + #[test] + fn response_correlation_cannot_echo_a_session_credential() { + let server = Server::http("127.0.0.1:0").unwrap(); + let client = test_control_plane_client( + &format!("http://{}", server.server_addr()), + Duration::from_secs(2), + ); + let server_thread = thread::spawn(move || { + server + .recv() + .unwrap() + .respond( + Response::from_string(json!({"trace_id":REQUEST_TRACE_ID}).to_string()) + .with_status_code(403) + .with_header( + Header::from_bytes(HOTPOD_TRACE_ID_HEADER, REQUEST_TRACE_ID).unwrap(), + ), + ) + .unwrap(); + }); + let error = client + .contract(&test_credential(REQUEST_TRACE_ID)) + .expect_err("request failure"); + let payload = failure_info(&error).1; + assert!(payload["error"].get("trace_id").is_none()); + assert!(!payload.to_string().contains(REQUEST_TRACE_ID)); + server_thread.join().unwrap(); + } + + #[test] + fn inherited_traceparent_validation_preserves_flags_and_rejects_invalid_headers() { + for flags in ["00", "01", "09", "ff"] { + let value = format!("00-{REQUEST_TRACE_ID}-1234567890abcdef-{flags}"); + assert_eq!( + inherited_traceparent(&value).unwrap().to_str().unwrap(), + value + ); + } + let valid = format!("00-{REQUEST_TRACE_ID}-1234567890abcdef-00"); + for value in [ + String::new(), + valid.to_uppercase(), + format!("{valid}-extra"), + valid.replace(REQUEST_TRACE_ID, "00000000000000000000000000000000"), + valid.replace("-1234567890abcdef-", "-0000000000000000-"), + valid.replacen("00-", "ff-", 1), + valid.replace("-00", "-gg"), + format!(" {valid}"), + format!("{valid}\r\nx-secret: value"), + valid.replace(REQUEST_TRACE_ID, "é234567890abcdef1234567890abcdef"), + ] { + assert!( + inherited_traceparent(&value).is_none(), + "accepted {value:?}" + ); + } + let future = valid.replacen("00-", "01-", 1) + "-opaque"; + assert_eq!( + inherited_traceparent(&future).unwrap().to_str().unwrap(), + future + ); + assert!(inherited_traceparent(&(future + &"a".repeat(512))).is_none()); + } + + #[test] + fn control_plane_retains_trace_id_on_bounded_decode_and_sanitize_failures() { + let credential = test_credential("trace_read_session_credential_123456"); + for (status, body, expected_message) in [ + ( + 200, + vec![b'x'; CONTROL_PLANE_RESPONSE_MAX_BYTES + 1], + "exceeded", + ), + ( + 503, + vec![b'x'; CONTROL_PLANE_RESPONSE_MAX_BYTES + 1], + "exceeded", + ), + (200, vec![0xff], "UTF-8"), + (200, b"not-json".to_vec(), "parse Apps Platform"), + ( + 200, + json!({"trace_read_session_credential_123456":"secret"}) + .to_string() + .into_bytes(), + "sanitize Apps Platform", + ), + ] { + let server = Server::http("127.0.0.1:0").unwrap(); + let client = test_control_plane_client( + &format!("http://{}", server.server_addr()), + Duration::from_secs(2), + ); + let server_thread = thread::spawn(move || { + server + .recv() + .unwrap() + .respond( + Response::from_data(body) + .with_status_code(status) + .with_header( + Header::from_bytes(HOTPOD_TRACE_ID_HEADER, REQUEST_TRACE_ID) + .unwrap(), + ), + ) + .unwrap(); + }); + let error = client + .contract(&credential) + .expect_err("reject unreadable response"); + let (exit_code, payload) = failure_info(&error); + assert_eq!(exit_code, exit_codes::GENERAL); + assert_eq!(payload["error"]["trace_id"], REQUEST_TRACE_ID); + assert!(format!("{error:#}").contains(expected_message)); + assert!(!payload.to_string().contains(&credential.secret)); + server_thread.join().unwrap(); + } + } + + #[test] + fn control_plane_retains_trace_id_after_response_body_connection_closes() { + use std::io::Write; + let listener = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let client = test_control_plane_client( + &format!("http://{}", listener.local_addr().unwrap()), + Duration::from_secs(2), + ); + let server_thread = thread::spawn(move || { + let (mut stream, _) = listener.accept().unwrap(); + let mut request = Vec::new(); + while !request.ends_with(b"\r\n\r\n") { + let mut byte = [0]; + stream.read_exact(&mut byte).unwrap(); + request.push(byte[0]); + assert!(request.len() <= 8192); + } + write!(stream, "HTTP/1.1 200 OK\r\nContent-Length: 100\r\n{HOTPOD_TRACE_ID_HEADER}: {REQUEST_TRACE_ID}\r\nConnection: close\r\n\r\n{{").unwrap(); + }); + let error = client + .contract(&test_credential("read_failure_session_credential")) + .expect_err("incomplete body fails"); + assert_eq!( + failure_info(&error).1["error"]["trace_id"], + REQUEST_TRACE_ID + ); + assert!(format!("{error:#}").contains("read Apps Platform")); + server_thread.join().unwrap(); + } + + #[test] + fn trace_context_does_not_change_failure_classification_or_wrapped_ids() { + let error = with_failure_trace_id( + failure(exit_codes::FORBIDDEN, "access_denied", "denied"), + Some(REQUEST_TRACE_ID), + ) + .context("initialization failed"); + let (exit_code, payload) = failure_info(&error); + assert_eq!(exit_code, exit_codes::FORBIDDEN); + assert_eq!(payload["error"]["code"], "access_denied"); + assert_eq!(payload["error"]["trace_id"], REQUEST_TRACE_ID); + assert!(payload["error"]["message"] + .as_str() + .unwrap() + .contains("initialization failed")); + assert!(!reservation_outcome_is_unknown(&error)); + let reserve_error = + with_failure_trace_id(anyhow::anyhow!("bad response"), Some(REQUEST_TRACE_ID)); + assert!(reservation_outcome_is_unknown(&reserve_error)); + let wrapped = reservation_outcome_unknown("app", None, &reserve_error, &error); + assert_eq!( + failure_info(&wrapped).1["error"]["trace_id"], + REQUEST_TRACE_ID + ); + assert_eq!( + canonical_trace_id(&REQUEST_TRACE_ID.to_uppercase()).as_deref(), + Some(REQUEST_TRACE_ID) + ); + for invalid in [ + "bad", + "00000000000000000000000000000000", + "1234567890abcdef1234567890abcde\n", + ] { + assert!(canonical_trace_id(invalid).is_none()); + } + } + #[test] fn compose_session_header_matches_kgoose_contract() { let secret = "opaque.session+credential/with=punctuation"; @@ -4511,7 +5207,9 @@ mod tests { let request = server.recv().expect("receive delete request"); assert_eq!(request.method().as_str(), "DELETE"); request - .respond(Response::from_string("not-json")) + .respond(Response::from_string("not-json").with_header( + Header::from_bytes(HOTPOD_TRACE_ID_HEADER, REQUEST_TRACE_ID).unwrap(), + )) .expect("respond with unreadable success body"); }); let client = test_control_plane_client(&base_url, Duration::from_secs(2)); @@ -4529,6 +5227,7 @@ mod tests { .expect_err("reject unreadable delete success response"); let (exit_code, payload) = failure_info(&error); assert_eq!(exit_code, exit_codes::NETWORK); + assert_eq!(payload["error"]["trace_id"], REQUEST_TRACE_ID); assert_eq!(payload["error"]["code"], "delete_outcome_unknown"); let message = payload["error"]["message"] .as_str() diff --git a/src/bl/skills_api.rs b/src/bl/skills_api.rs index cdeb505..840d499 100644 --- a/src/bl/skills_api.rs +++ b/src/bl/skills_api.rs @@ -90,6 +90,39 @@ impl std::error::Error for SilentJsonExit {} /// Finds the exit code and JSON payload for an error chain, defaulting to 1. pub fn failure_info(error: &anyhow::Error) -> (i32, Value) { + let (exit_code, mut payload) = uncorrelated_failure_info(error); + if let Some(trace_id) = failure_trace_id(error) { + payload["error"]["trace_id"] = json!(trace_id); + } + (exit_code, payload) +} + +pub fn failure_trace_id(error: &anyhow::Error) -> Option<&str> { + error + .downcast_ref::() + .map(|trace_id| trace_id.0.as_str()) +} + +/// Attach a server correlation ID without replacing an error's type or exit code. +pub fn with_failure_trace_id(error: anyhow::Error, trace_id: Option<&str>) -> anyhow::Error { + match trace_id { + Some(trace_id) => error.context(FailureTraceId(trace_id.to_string())), + None => error, + } +} + +#[derive(Debug)] +struct FailureTraceId(String); + +impl std::fmt::Display for FailureTraceId { + fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(formatter, "trace_id={}", self.0) + } +} + +impl std::error::Error for FailureTraceId {} + +fn uncorrelated_failure_info(error: &anyhow::Error) -> (i32, Value) { for cause in error.chain() { if let Some(cli) = cause.downcast_ref::() { let mut payload = cli.to_json();