From a846bfb64029efb3f13b011fb404097eb40d4a26 Mon Sep 17 00:00:00 2001 From: Andrew McGivery Date: Fri, 4 Oct 2024 15:30:07 -0400 Subject: [PATCH 1/2] Allow thrown rhai errors to opt out of logging in the Router --- apollo-router/src/plugins/rhai/mod.rs | 47 +++++++++++----- apollo-router/src/plugins/rhai/tests.rs | 54 ++++++++++++++++--- .../tests/fixtures/request_response_test.rhai | 23 ++++++++ docs/source/customizations/rhai-api.mdx | 25 +++++++++ 4 files changed, 129 insertions(+), 20 deletions(-) diff --git a/apollo-router/src/plugins/rhai/mod.rs b/apollo-router/src/plugins/rhai/mod.rs index 8ef1e61e8f..703d3db263 100644 --- a/apollo-router/src/plugins/rhai/mod.rs +++ b/apollo-router/src/plugins/rhai/mod.rs @@ -333,8 +333,10 @@ macro_rules! gen_map_request { let result: Result> = execute(&$rhai_service, &$callback, (shared_request.clone(),)); if let Err(error) = result { - let error_details = process_error(error); - tracing::error!("map_request callback failed: {error_details:#?}"); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)) { + tracing::error!("map_request callback failed: {error:#?}"); + } let mut guard = shared_request.lock().unwrap(); let request_opt = guard.take(); return $base::request_failure(request_opt.unwrap().context, error_details); @@ -381,8 +383,10 @@ macro_rules! gen_map_router_deferred_request { let result = execute(&$rhai_service, &$callback, (shared_request.clone(),)); if let Err(error) = result { - tracing::error!("map_request callback failed: {error}"); - let error_details = process_error(error); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)){ + tracing::error!("map_request callback failed: {error:#?}"); + } let mut guard = shared_request.lock().unwrap(); let request_opt = guard.take(); return $base::request_failure(request_opt.unwrap().context, error_details); @@ -468,8 +472,10 @@ macro_rules! gen_map_response { execute(&$rhai_service, &$callback, (shared_response.clone(),)); if let Err(error) = result { - tracing::error!("map_response callback failed: {error}"); - let error_details = process_error(error); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)) { + tracing::error!("map_response callback failed: {error}"); + } let mut guard = shared_response.lock().unwrap(); let response_opt = guard.take(); return $base::response_failure( @@ -514,8 +520,10 @@ macro_rules! gen_map_router_deferred_response { let result = execute(&$rhai_service, &$callback, (shared_response.clone(),)); if let Err(error) = result { - tracing::error!("map_response callback failed: {error}"); - let error_details = process_error(error); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)) { + tracing::error!("map_response callback failed: {error}"); + } let response_opt = shared_response.lock().unwrap().take(); return Ok($base::response_failure( response_opt.unwrap().context, @@ -610,7 +618,8 @@ macro_rules! gen_map_deferred_response { status: StatusCode::INTERNAL_SERVER_ERROR, message: Some("rhai execution error: empty response".to_string()), position: None, - body: None + body: None, + log_error: None }; return Ok($base::response_failure( context, @@ -631,8 +640,10 @@ macro_rules! gen_map_deferred_response { let result = execute(&$rhai_service, &$callback, (shared_response.clone(),)); if let Err(error) = result { - tracing::error!("map_response callback failed: {error}"); - let error_details = process_error(error); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)) { + tracing::error!("map_response callback failed: {error}"); + } let mut guard = shared_response.lock().unwrap(); let response_opt = guard.take(); return Ok($base::response_failure( @@ -666,8 +677,10 @@ macro_rules! gen_map_deferred_response { (shared_response.clone(),), ); if let Err(error) = result { - tracing::error!("map_response callback failed: {error}"); - let error_details = process_error(error); + let error_details = process_error(&error); + if matches!(error_details.log_error, Some(true)) { + tracing::error!("map_response callback failed: {error}"); + } let mut guard = shared_response.lock().unwrap(); let response_opt = guard.take(); let $base::DeferredResponse { mut response, .. } = response_opt.unwrap(); @@ -778,18 +791,20 @@ struct ErrorDetails { message: Option, position: Option, body: Option, + log_error: Option, } fn default_thrown_status_code() -> StatusCode { StatusCode::INTERNAL_SERVER_ERROR } -fn process_error(error: Box) -> ErrorDetails { +fn process_error(error: &Box) -> ErrorDetails { let mut error_details = ErrorDetails { status: StatusCode::INTERNAL_SERVER_ERROR, message: Some(format!("rhai execution error: '{error}'")), position: None, body: None, + log_error: Some(true), }; let inner_error = error.unwrap_inner(); @@ -801,6 +816,10 @@ fn process_error(error: Box) -> ErrorDetails { } else { error_details.status = temp_error_details.status; } + + if error_details.log_error.is_none() { + error_details.log_error = Some(true); + } } error_details.position = Some(pos.into()); } diff --git a/apollo-router/src/plugins/rhai/tests.rs b/apollo-router/src/plugins/rhai/tests.rs index 11c4f3a03a..180b2804e8 100644 --- a/apollo-router/src/plugins/rhai/tests.rs +++ b/apollo-router/src/plugins/rhai/tests.rs @@ -583,7 +583,7 @@ async fn it_can_find_router_global_variables() { #[tokio::test] async fn it_can_process_om_subgraph_forbidden() { if let Err(error) = call_rhai_function("process_subgraph_response_om_forbidden").await { - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::FORBIDDEN); assert_eq!( processed_error.message, @@ -601,7 +601,7 @@ async fn it_can_process_om_subgraph_forbidden_with_graphql_payload() { .await .unwrap_err(); - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::FORBIDDEN); assert_eq!( processed_error.body, @@ -624,7 +624,7 @@ async fn it_can_process_om_subgraph_200_with_graphql_data() { .await .unwrap_err(); - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::OK); assert_eq!( processed_error.body, @@ -639,7 +639,7 @@ async fn it_can_process_om_subgraph_200_with_graphql_data() { #[tokio::test] async fn it_can_process_string_subgraph_forbidden() { if let Err(error) = call_rhai_function("process_subgraph_response_string").await { - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::INTERNAL_SERVER_ERROR); assert_eq!(processed_error.message, Some("rhai execution error: 'Runtime error: I have raised an error (line 223, position 5)'".to_string())); } else { @@ -653,7 +653,7 @@ async fn it_can_process_ok_subgraph_forbidden() { let error = call_rhai_function("process_subgraph_response_om_ok") .await .unwrap_err(); - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::OK); assert_eq!( processed_error.message, @@ -664,7 +664,7 @@ async fn it_can_process_ok_subgraph_forbidden() { #[tokio::test] async fn it_cannot_process_om_subgraph_missing_message_and_body() { if let Err(error) = call_rhai_function("process_subgraph_response_om_missing_message").await { - let processed_error = process_error(error); + let processed_error = process_error(&error); assert_eq!(processed_error.status, StatusCode::BAD_REQUEST); assert_eq!( processed_error.message, @@ -679,6 +679,48 @@ async fn it_cannot_process_om_subgraph_missing_message_and_body() { } } +#[tokio::test] +async fn it_can_process_subgraph_response_on_log_error_not_defined() { + let error = call_rhai_function("process_subgraph_response_on_log_error_not_defined") + .await + .unwrap_err(); + let processed_error = process_error(&error); + assert_eq!(processed_error.status, StatusCode::BAD_REQUEST); + assert_eq!( + processed_error.message, + Some("This is an error to be logged".to_string()) + ); + assert_eq!(processed_error.log_error, Some(true)); +} + +#[tokio::test] +async fn it_can_process_subgraph_response_on_log_error_true() { + let error = call_rhai_function("process_subgraph_response_on_log_error_true") + .await + .unwrap_err(); + let processed_error = process_error(&error); + assert_eq!(processed_error.status, StatusCode::BAD_REQUEST); + assert_eq!( + processed_error.message, + Some("This is an error to be logged".to_string()) + ); + assert_eq!(processed_error.log_error, Some(true)); +} + +#[tokio::test] +async fn it_can_process_subgraph_response_on_log_error_false() { + let error = call_rhai_function("process_subgraph_response_on_log_error_false") + .await + .unwrap_err(); + let processed_error = process_error(&error); + assert_eq!(processed_error.status, StatusCode::BAD_REQUEST); + assert_eq!( + processed_error.message, + Some("This is an error not to be logged".to_string()) + ); + assert_eq!(processed_error.log_error, Some(false)); +} + #[tokio::test] async fn it_mentions_source_when_syntax_error_occurs() { let err: Box = crate::plugin::plugins() diff --git a/apollo-router/tests/fixtures/request_response_test.rhai b/apollo-router/tests/fixtures/request_response_test.rhai index 4dc88d42ad..20b6d066ba 100644 --- a/apollo-router/tests/fixtures/request_response_test.rhai +++ b/apollo-router/tests/fixtures/request_response_test.rhai @@ -235,3 +235,26 @@ fn process_subgraph_response_om_missing_message(response) { status: 400, }; } + +fn process_subgraph_response_on_log_error_not_defined(response){ + throw #{ + message: "This is an error to be logged", + status: 400, + }; +} + +fn process_subgraph_response_on_log_error_true(response){ + throw #{ + message: "This is an error to be logged", + status: 400, + log_error: true, + }; +} + +fn process_subgraph_response_on_log_error_false(response){ + throw #{ + message: "This is an error not to be logged", + status: 400, + log_error: false, + }; +} \ No newline at end of file diff --git a/docs/source/customizations/rhai-api.mdx b/docs/source/customizations/rhai-api.mdx index b75824048d..0025caa1bb 100644 --- a/docs/source/customizations/rhai-api.mdx +++ b/docs/source/customizations/rhai-api.mdx @@ -121,6 +121,31 @@ Rhai throws at the `map_request` layer behave the same as `ControlFlow::Break`, If the supplied status code is not a valid HTTP status code, then a `500` response code will result. +### Disable logging of thrown errors + +By default, the Router will log an error when a Rhai script uses a `throw` to throw an error. You can opt out of this on an individual `throw` by specifying `log_error: false`: + +```rhai +fn supergraph_service(service) { + let f = |request| { + throw #{ + status: 403, + log_error: false, // Do not log this error + body: #{ + errors: [#{ + message: `I have raised a 403`, + extensions: #{ + code: "ACCESS_DENIED" + } + }] + } + }; + }; + // Map our request using our closure + service.map_request(f); +} +``` + ## Timing execution Your Rhai customization can use the global `Router.APOLLO_START` constant to calculate durations. This is similar to `Epoch` in Unix environments. From 6ebb01f19e9f02fb6b637043433cfaec6413cb9d Mon Sep 17 00:00:00 2001 From: Andrew McGivery Date: Fri, 4 Oct 2024 15:33:22 -0400 Subject: [PATCH 2/2] Add changeset --- .../feat_feature_disablerhaierrorlog.md | 25 +++++++++++++++++++ docs/source/customizations/rhai-api.mdx | 1 - 2 files changed, 25 insertions(+), 1 deletion(-) create mode 100644 .changesets/feat_feature_disablerhaierrorlog.md diff --git a/.changesets/feat_feature_disablerhaierrorlog.md b/.changesets/feat_feature_disablerhaierrorlog.md new file mode 100644 index 0000000000..b5e8b471d1 --- /dev/null +++ b/.changesets/feat_feature_disablerhaierrorlog.md @@ -0,0 +1,25 @@ +### Allow thrown rhai errors to opt out of logging in the Router ([PR #6124](https://github.com/apollographql/router/pull/6124)) + +By default, the Router will log an error when a Rhai script uses a `throw` to throw an error. You can opt out of this on an individual `throw` by specifying `log_error: false`: + +```rhai +fn supergraph_service(service) { + let f = |request| { + throw #{ + status: 403, + log_error: false, // Do not log this error + body: #{ + errors: [#{ + message: `I have raised a 403`, + extensions: #{ + code: "ACCESS_DENIED" + } + }] + } + }; + }; + service.map_request(f); +} +``` + +By [@andrewmcgivery](https://github.com/andrewmcgivery) in https://github.com/apollographql/router/pull/6124 diff --git a/docs/source/customizations/rhai-api.mdx b/docs/source/customizations/rhai-api.mdx index 0025caa1bb..e88051b905 100644 --- a/docs/source/customizations/rhai-api.mdx +++ b/docs/source/customizations/rhai-api.mdx @@ -141,7 +141,6 @@ fn supergraph_service(service) { } }; }; - // Map our request using our closure service.map_request(f); } ```