Allow thrown rhai errors to opt out of logging in the Router

.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

apollo-router/src/plugins/rhai/mod.rs

@@ -333,8 +333,10 @@ macro_rules! gen_map_request {
                     let result: Result<Dynamic, Box<EvalAltResult>> =
                         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<String>,
     position: Option<Position>,
     body: Option<crate::graphql::Response>,
+    log_error: Option<bool>,
 }
 
 fn default_thrown_status_code() -> StatusCode {
     StatusCode::INTERNAL_SERVER_ERROR
 }
 
-fn process_error(error: Box<EvalAltResult>) -> ErrorDetails {
+fn process_error(error: &Box<EvalAltResult>) -> 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<EvalAltResult>) -> 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());
     }

apollo-router/src/plugins/rhai/tests.rs

@@ -599,7 +599,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,
@@ -617,7 +617,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,
@@ -640,7 +640,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,
@@ -655,7 +655,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 229, position 5)'".to_string()));
     } else {
@@ -669,7 +669,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,
@@ -680,7 +680,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,
@@ -695,6 +695,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<dyn std::error::Error> = crate::plugin::plugins()

apollo-router/tests/fixtures/request_response_test.rhai

@@ -240,4 +240,27 @@ fn process_subgraph_response_om_missing_message(response) {
     throw #{
         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,
+    };
 }

docs/source/customizations/rhai-api.mdx

@@ -121,6 +121,30 @@ 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"
+                    }
+                }]
+            }
+        };
+    };
+    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.