diff --git a/Cargo.lock b/Cargo.lock index 8aa84f3b5..79e15fcd3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -198,6 +198,7 @@ dependencies = [ "serde_json", "serde_urlencoded", "tokio", + "tower", "trybuild", "url", ] diff --git a/crates/api-macros-impl/src/lib.rs b/crates/api-macros-impl/src/lib.rs index 8014ff556..1d65a073f 100644 --- a/crates/api-macros-impl/src/lib.rs +++ b/crates/api-macros-impl/src/lib.rs @@ -2077,7 +2077,7 @@ fn axum_adapter_tokens( status, rejection.body_text(), ); - return #api_crate::axum::json_response( + return #api_crate::axum::error_response( #api_crate::axum::status(status), error, ); @@ -2111,7 +2111,7 @@ fn axum_adapter_tokens( status, rejection.body_text(), ); - return #api_crate::axum::json_response( + return #api_crate::axum::error_response( #api_crate::axum::status(status), error, ); @@ -2188,7 +2188,7 @@ fn axum_adapter_tokens( let error = match operation.error_status { Some(_) => quote!({ let status = #api_crate::HttpError::status_code(&error); - #api_crate::axum::json_response(#api_crate::axum::status(status), error) + #api_crate::axum::error_response(#api_crate::axum::status(status), error) }), None => quote!({ let _ = error; #api_crate::axum::empty_response(#api_crate::axum::framework::StatusCode::INTERNAL_SERVER_ERROR) }), }; diff --git a/crates/api-macros/Cargo.toml b/crates/api-macros/Cargo.toml index a99fb7bde..b56e64eb8 100644 --- a/crates/api-macros/Cargo.toml +++ b/crates/api-macros/Cargo.toml @@ -35,4 +35,5 @@ oas3 = { version = "0.22", default-features = false } serde = { workspace = true, features = ["derive"] } serde_json = { workspace = true } tokio = { workspace = true, features = ["net"] } +tower = { workspace = true, features = ["util"] } trybuild = "1" diff --git a/crates/api-macros/src/axum.rs b/crates/api-macros/src/axum.rs index 8f8807277..a9a2e0c82 100644 --- a/crates/api-macros/src/axum.rs +++ b/crates/api-macros/src/axum.rs @@ -77,6 +77,26 @@ pub fn json_response(status: StatusCode, value: T) -> Response { (status, Json(value)).into_response() } +/// Serialize a public error and retain its typed value for outer application middleware. +/// +/// The extension is server-local (`Arc`); it is not another wire field. This lets observers +/// inspect the declared error without consuming the response body or requiring `T: Clone`. +/// Applications still choose which public fields are safe to log; the adapter does not log them. +pub fn error_response( + status: StatusCode, + error: T, +) -> Response { + let mut response = json_response(status, &error); + // JSON encoding failures are plain-text responses, including when the requested status is 500. + if response.status() == status + && response.headers().get(axum::http::header::CONTENT_TYPE) + == Some(&axum::http::HeaderValue::from_static("application/json")) + { + response.extensions_mut().insert(std::sync::Arc::new(error)); + } + response +} + /// Emit an empty response with the contract status. pub fn empty_response(status: StatusCode) -> Response { status.into_response() diff --git a/crates/api-macros/tests/error_metadata.rs b/crates/api-macros/tests/error_metadata.rs new file mode 100644 index 000000000..c70ea0197 --- /dev/null +++ b/crates/api-macros/tests/error_metadata.rs @@ -0,0 +1,176 @@ +#![cfg(feature = "axum")] + +use api_macros::api; +use axum::{ + body::{Body, to_bytes}, + http::{Request, StatusCode}, +}; +use serde::{Deserialize, Serialize}; +use std::sync::Arc; +use tower::ServiceExt; + +// No Clone requirement: retaining an error must not require duplicating its typed value. +#[derive(Debug, Serialize)] +pub struct PublicError { + message: String, + #[serde(skip)] + status: u16, +} + +impl api_macros::HttpError for PublicError { + fn status_code(&self) -> u16 { + self.status + } +} + +impl api_macros::HttpRequestError for PublicError { + fn from_request_rejection(status: u16, message: String) -> Self { + Self { status, message } + } +} + +#[derive(Deserialize)] +pub struct Input { + fail: bool, +} + +#[derive(Serialize)] +pub struct Output { + message: String, +} + +#[api(axum)] +pub trait ErrorMetadataApi { + #[post( + "/json", + status = 200, + error_status = 400, + normalize_body_errors = true + )] + async fn json(&self, #[body] input: Input) -> Result; + + #[post( + "/binary", + status = 200, + error_status = 400, + normalize_body_errors = true + )] + async fn binary(&self, #[binary] input: api_macros::BinaryBody) -> Result; +} + +pub struct Service; +impl ErrorMetadataApi for Service { + async fn json(&self, input: Input) -> Result { + if input.fail { + Err(PublicError { + status: 502, + message: "upstream rejected operation".to_string(), + }) + } else { + Ok(Output { + message: "ok".to_string(), + }) + } + } + async fn binary(&self, _input: api_macros::BinaryBody) -> Result { + Ok(Output { + message: "ok".to_string(), + }) + } +} + +#[tokio::test] +async fn generated_service_and_body_errors_retain_typed_metadata_without_changing_wire_body() { + let app = ErrorMetadataApiAxum::router(Service).layer(axum::extract::DefaultBodyLimit::max(32)); + for (path, content_type, input, status) in [ + ( + "/json", + "application/json", + "{\"fail\":true}".to_string(), + StatusCode::BAD_GATEWAY, + ), + ( + "/json", + "application/json", + "{".to_string(), + StatusCode::BAD_REQUEST, + ), + ( + "/binary", + "application/octet-stream", + "x".repeat(33), + StatusCode::PAYLOAD_TOO_LARGE, + ), + ] { + let response = app + .clone() + .oneshot( + Request::builder() + .method("POST") + .uri(path) + .header("content-type", content_type) + .body(Body::from(input)) + .unwrap(), + ) + .await + .unwrap(); + assert_eq!(response.status(), status); + assert_eq!(response.headers()["content-type"], "application/json"); + let error = response + .extensions() + .get::>() + .expect("typed error retained") + .clone(); + assert_eq!(error.status, status.as_u16()); + assert!(!error.message.is_empty()); + let body = to_bytes(response.into_body(), usize::MAX).await.unwrap(); + assert_eq!( + serde_json::from_slice::(&body).unwrap(), + serde_json::json!({"message": error.message}) + ); + } + let response = app + .oneshot( + Request::builder() + .method("POST") + .uri("/json") + .header("content-type", "application/json") + .body(Body::from("{\"fail\":false}")) + .unwrap(), + ) + .await + .unwrap(); + assert_eq!(response.status(), StatusCode::OK); + assert!(response.extensions().get::>().is_none()); + assert_eq!( + to_bytes(response.into_body(), usize::MAX) + .await + .unwrap() + .as_ref(), + b"{\"message\":\"ok\"}" + ); +} + +#[test] +fn error_encoding_failure_does_not_retain_misleading_original_metadata() { + struct UnencodableError; + impl Serialize for UnencodableError { + fn serialize(&self, _serializer: S) -> Result { + Err(serde::ser::Error::custom("cannot encode fixture error")) + } + } + for status in [StatusCode::BAD_GATEWAY, StatusCode::INTERNAL_SERVER_ERROR] { + let response = api_macros::axum::error_response(status, UnencodableError); + assert_eq!(response.status(), status); + assert_eq!( + response.headers()["content-type"], + "text/plain; charset=utf-8" + ); + assert!( + response + .extensions() + .get::>() + .is_none() + ); + } +} diff --git a/crates/workspace-server/src/server.rs b/crates/workspace-server/src/server.rs index 445a7566d..2ac1ef033 100644 --- a/crates/workspace-server/src/server.rs +++ b/crates/workspace-server/src/server.rs @@ -11422,7 +11422,15 @@ async fn log_failed_api_response(request: Request, next: Next) -> Response { let status = response.status(); if uri.path().starts_with("/api/") && (status.is_client_error() || status.is_server_error()) { - let error = response.extensions().get::(); + // Generated routes bypass ApiError::into_response; inspect their typed error, not the body. + let generated_error = response + .extensions() + .get::>() + .map(|error| ApiErrorLog::from_repository_error(error)); + let error = response + .extensions() + .get::() + .or(generated_error.as_ref()); let event = api_failure_log_event(&method, &uri, status, error); tracing::error!( target: "yoi::api", @@ -31785,6 +31793,32 @@ struct ApiErrorLog { diagnostics: Vec, } +impl ApiErrorLog { + fn from_repository_error(error: &server_api::RepositoryApiError) -> Self { + Self { + kind: error + .diagnostics + .first() + .map(|diagnostic| diagnostic.code.clone()) + .unwrap_or_else(|| error.error.to_ascii_lowercase().replace(' ', "_")), + message: sanitize_backend_error(&error.message), + diagnostics: error + .diagnostics + .iter() + .map(|diagnostic| RuntimeDiagnostic { + code: diagnostic.code.clone(), + severity: match diagnostic.severity { + server_api::DiagnosticSeverity::Info => HostDiagnosticSeverity::Info, + server_api::DiagnosticSeverity::Warning => HostDiagnosticSeverity::Warning, + server_api::DiagnosticSeverity::Error => HostDiagnosticSeverity::Error, + }, + message: sanitize_backend_error(&diagnostic.message), + }) + .collect(), + } + } +} + impl From for ApiError { fn from(error: merge_request::MergeRequestError) -> Self { Error::MergeRequest(error).into() @@ -32059,6 +32093,7 @@ impl IntoResponse for ApiError { #[cfg(test)] mod tests { + mod api_logging_tests; mod auth_logging_tests; mod subject_spawn_tests; mod subjektiv_jobs_tests; @@ -42163,6 +42198,7 @@ mod tests { materializer: worker_runtime::working_directory::RuntimeGitMaterializer, spawn_failure: std::sync::Mutex>, input_failure: std::sync::Mutex>, + cancel_failure: std::sync::Mutex>, input_hook: std::sync::Mutex< Option>, >, @@ -42197,6 +42233,7 @@ mod tests { ), spawn_failure: std::sync::Mutex::new(None), input_failure: std::sync::Mutex::new(None), + cancel_failure: std::sync::Mutex::new(None), input_hook: std::sync::Mutex::new(None), input_request_ids: std::sync::Mutex::new(Vec::new()), accept_restores: std::sync::atomic::AtomicBool::new(false), @@ -42523,6 +42560,12 @@ mod tests { &self, _worker_ref: &worker_runtime::identity::WorkerRef, ) -> worker_runtime::execution::WorkerExecutionResult { + if let Some(message) = self.cancel_failure.lock().unwrap().clone() { + return worker_runtime::execution::WorkerExecutionResult::rejected( + worker_runtime::execution::WorkerExecutionOperation::Cancel, + message, + ); + } worker_runtime::execution::WorkerExecutionResult::accepted( worker_runtime::execution::WorkerExecutionOperation::Cancel, ) diff --git a/crates/workspace-server/src/server/tests/api_logging_tests.rs b/crates/workspace-server/src/server/tests/api_logging_tests.rs new file mode 100644 index 000000000..6bdeabc3c --- /dev/null +++ b/crates/workspace-server/src/server/tests/api_logging_tests.rs @@ -0,0 +1,222 @@ +use super::*; +use std::io::Write; +use tracing::instrument::WithSubscriber; + +#[derive(Clone, Default)] +struct CapturedApiLog(Arc>>); + +impl Write for CapturedApiLog { + fn write(&mut self, bytes: &[u8]) -> std::io::Result { + self.0.lock().unwrap().extend_from_slice(bytes); + Ok(bytes.len()) + } + + fn flush(&mut self) -> std::io::Result<()> { + Ok(()) + } +} + +async fn request_with_logs(app: Router, request: Request) -> (StatusCode, Value, Vec) { + let logs = CapturedApiLog::default(); + let writer = logs.clone(); + let subscriber = tracing_subscriber::fmt() + .without_time() + .with_ansi(false) + .json() + .flatten_event(true) + .with_writer(move || writer.clone()) + .finish(); + let response = app + .oneshot(request) + .with_subscriber(subscriber) + .await + .unwrap(); + let status = response.status(); + assert_eq!(response.headers()[CONTENT_TYPE], "application/json"); + let body = to_bytes(response.into_body(), usize::MAX).await.unwrap(); + let body: Value = serde_json::from_slice(&body).unwrap(); + let text = String::from_utf8(logs.0.lock().unwrap().clone()).unwrap(); + for secret in ["query-secret", "bearer-secret", "body-secret"] { + assert!(!text.contains(secret), "log leaked request data: {text}"); + } + let events = text + .lines() + .map(|line| serde_json::from_str::(line).unwrap()) + .filter(|event| event["event"] == "api_error") + .collect(); + (status, body, events) +} + +#[tokio::test] +async fn generated_cancellation_errors_preserve_response_and_log_details() { + let dir = tempfile::tempdir().unwrap(); + let (api, execution) = test_api_with_recording_backend(dir.path()).await; + let worker = api + .runtime + .spawn_worker( + EMBEDDED_WORKER_RUNTIME_ID, + test_create_binding(), + WorkerSpawnRequest { + requested_worker_name: Some("logging-coder".to_string()), + intent: WorkerSpawnIntent::TicketRole { + ticket_id: "cancellation-logging".to_string(), + role: TicketWorkerRole::Coder, + }, + singleton_key: None, + acceptance: WorkerSpawnAcceptanceRequirement::RunAccepted { + expected_segments: 0, + }, + profile: ProfileSelector::Builtin("builtin:coder".to_string()), + ticket_assignment: None, + initial_submit: Vec::new(), + workdir_attachment_requests: Vec::new(), + resolved_workdir_attachment_requests: Vec::new(), + resolved_workdir_attachments: Vec::new(), + resolved_config_bundle: None, + resolved_worker_observation_enabled: false, + resolved_worker_observation_grants: Vec::new(), + resolved_workspace_api: Some(test_worker_workspace_api(EMBEDDED_WORKER_RUNTIME_ID)), + resolved_memory_settings: Some(test_worker_memory_settings()), + resolved_subjektiv_attached: false, + resolved_control_operation: None, + }, + ) + .unwrap() + .worker + .unwrap() + .worker; + let worker = RuntimeWorkerRef::new(EMBEDDED_WORKER_RUNTIME_ID, worker.worker_id); + api.store + .upsert_worker_registry(&WorkerRegistryRecord { + workspace_id: TEST_WORKSPACE_ID.to_string(), + worker: worker.clone(), + display_name: "Logging Coder".to_string(), + profile: Some("builtin:coder".to_string()), + retention_state: "normal".to_string(), + transcript_ref: None, + session_ref: None, + summary_ref: None, + diagnostics_ref: None, + created_at: TEST_CREATED_AT.to_string(), + updated_at: TEST_CREATED_AT.to_string(), + }) + .unwrap(); + let backend = browser_ticket_backend(&api).unwrap(); + let mut input = ticket::NewTicket::new("Cancellation logging"); + input.workflow_state = Some(TicketWorkflowState::InProgress); + let ticket = backend.create(input).unwrap(); + api.store + .set_current_ticket_coder_assignment( + &TicketCoderAssignmentRecord { + workspace_id: TEST_WORKSPACE_ID.to_string(), + ticket_id: ticket.id.clone(), + assignment_id: "logging-assignment".to_string(), + worker, + assigned_by: "test-user".to_string(), + assigned_at: TEST_CREATED_AT.to_string(), + }, + None, + "logging-assignment-event", + "logging-assignment-operation", + false, + ) + .unwrap(); + *execution.cancel_failure.lock().unwrap() = Some("fixture cancellation rejected".to_string()); + // The real generated route, service conversion, and logging middleware; no live Runtime needed. + let app = build_inner_router(api.clone()); + let path = format!( + "/api/w/{TEST_WORKSPACE_ID}/tickets/{}/implementation-cancellations", + ticket.id + ); + let request = |reason: &str| { + Request::builder() + .method(Method::POST) + .uri(format!("{path}?access_token=query-secret")) + .header(CONTENT_TYPE, "application/json") + .header(axum::http::header::AUTHORIZATION, "Bearer bearer-secret") + .body(Body::from( + serde_json::to_vec(&json!({ + "operation_id": "logging-cancel", + "assignment_id": "logging-assignment", + "reason": reason, + })) + .unwrap(), + )) + .unwrap() + }; + + let (status, body, events) = request_with_logs(app.clone(), request("body-secret")).await; + assert_eq!(status, StatusCode::BAD_GATEWAY, "{body}"); + assert_eq!(body["error"], "Bad Gateway"); + assert_eq!( + body["message"], + "workspace_ticket_implementation_cancel_rejected: Runtime did not cancel the assigned Coder Worker" + ); + assert!( + !body["diagnostics"].as_array().unwrap().is_empty(), + "{body}" + ); + assert_eq!(events.len(), 1, "{events:?}"); + assert_eq!(events[0]["method"], "POST"); + assert_eq!(events[0]["path"], path); + assert_eq!(events[0]["status"], 502); + assert_eq!(events[0]["message"], body["message"]); + assert_eq!(events[0]["kind"], body["diagnostics"][0]["code"]); + let diagnostics = events[0]["diagnostics"].as_str().unwrap(); + assert!( + diagnostics.contains("fixture cancellation rejected"), + "{diagnostics}" + ); + assert_eq!( + api.authority.ticket(&ticket.id).unwrap().state, + "inprogress" + ); + + // Errors without diagnostics still carry a useful kind and message. + let (status, body, events) = request_with_logs(app.clone(), request(&"r".repeat(513))).await; + assert_eq!(status, StatusCode::BAD_REQUEST, "{body}"); + assert_eq!(body["diagnostics"], json!([])); + assert_eq!(events.len(), 1, "{events:?}"); + assert_eq!(events[0]["kind"], "bad_request"); + assert_eq!(events[0]["message"], body["message"]); + assert!(!events[0]["message"].as_str().unwrap().is_empty()); + + *execution.cancel_failure.lock().unwrap() = None; + let (status, body, events) = request_with_logs(app, request("body-secret")).await; + assert_eq!(status, StatusCode::OK, "{body}"); + assert_eq!(body["state"], "ready"); + assert!( + events.is_empty(), + "successful cancellation logged as failure: {events:?}" + ); +} + +#[tokio::test] +async fn legacy_api_errors_keep_their_log_metadata() { + let app = Router::new() + .route( + "/api/legacy-error", + get(|| async { + ApiError::from(Error::InvalidInput("fixture invalid input".to_string())) + }), + ) + .layer(middleware::from_fn(log_failed_api_response)); + let (status, body, events) = request_with_logs( + app, + Request::builder() + .uri("/api/legacy-error?token=query-secret") + .body(Body::empty()) + .unwrap(), + ) + .await; + assert_eq!(status, StatusCode::BAD_REQUEST); + assert_eq!(events.len(), 1); + assert_eq!(events[0]["kind"], "bad_request"); + assert_eq!(events[0]["message"], body["message"]); + assert!( + body["message"] + .as_str() + .unwrap() + .contains("fixture invalid input") + ); +}