fix(rhai): stop disclosing Rhai internals and router function errors to clients

.changesets/fix_rohan_b99_redact_rhai_internals_from_client_errors.md

@@ -0,0 +1,32 @@
+### Stop disclosing Rhai internals in client-facing error responses ([PR #10004](https://github.com/apollographql/router/pull/10004))
+
+When a Rhai script failed, the router wrapped the failure in its own error text before returning it to the client, which exposed the fact that the router runs Rhai, the names of the script's callbacks, and the line and position where the failure happened:
+
+```json
+{
+  "errors": [
+    {
+      "message": "rhai execution error: 'Runtime error: Invalid request (line 25, position 39)\nin call to function 'process_router_request' @ 'process_router_request' (line 6, position 29)'"
+    }
+  ]
+}
+```
+
+Clients now receive only the message the script author chose. A thrown string is returned as written, with the Rhai wrapper stripped:
+
+```rhai
+throw "Invalid request";                          // client sees: Invalid request
+throw #{ status: 403, message: "Forbidden" };     // client sees: Forbidden
+throw #{ status: 403, body: #{ errors: [...] } }; // client sees the custom body
+```
+
+Anything the script did *not* choose is replaced with the status code's reason phrase, and the underlying error is logged at `ERROR` level instead. This covers failures raised by the Rhai engine itself (such as calling an undefined function or a type mismatch), a `throw` carrying only a status - `throw #{ status: 400 }` now reads `Bad Request` rather than dumping the thrown object - failures in the router's own Rhai functions that carry no message, such as reading a header that isn't present, and a `throw` the router cannot read as a message - a value that is not a string or an object map, such as `throw 42`, or a map with an unreadable field, such as `throw #{ status: "four hundred", message: "Invalid request" }`, which is discarded whole so the `message` beside the bad status goes with it.
+
+Failures in the router's own Rhai functions that *do* carry a message are only partly covered: the wrapper, the script line and position and the chain of callbacks are gone, but the function's own message still reaches the client. `env::get()` on a variable that isn't set still reports `could not expand variable: MY_VAR, environment variable not found`, and `json::decode()` on malformed input still reports the parse error. A router function's error is indistinguishable from a script's own `throw`, so telling them apart would take recording which side raised it - the Rhai customization docs carry this as a documented limitation. If a script of yours calls those functions on a client-facing path, catch the error and throw your own.
+
+Two things to be aware of when upgrading:
+
+- Client-facing messages for a thrown string no longer include the `rhai execution error: 'Runtime error: ... (line N, position M)'` wrapper. Only the string you threw is returned. The full error is still in the logs.
+- Nothing changes for scripts themselves: a `catch` block receives exactly what it received before, and status codes are unchanged.
+
+By [@rohan-b99](https://github.com/rohan-b99) in https://github.com/apollographql/router/pull/10004

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

@@ -76,6 +76,25 @@ const CANNOT_ACCESS_STATUS_CODE_ON_A_DEFERRED_RESPONSE: &str =
 
 const CANNOT_GET_ENVIRONMENT_VARIABLE: &str = "environment variable not found";
 
+/// Raised by a router Rhai function that has nothing to tell a client - a lookup that found
+/// nothing, for instance.
+///
+/// A router function's error is indistinguishable from a script's own `throw "..."`: both arrive as
+/// `EvalAltResult::ErrorRuntime` carrying a string, with nothing recording which side raised it.
+/// `super::process_error` therefore discriminates on the value, not the origin - it redacts an
+/// empty message and returns any other verbatim - and this constant is that value. Two consequences
+/// worth knowing:
+///
+/// - Giving this text would disclose it, and the Rhai function it came from, in client-facing error
+///   responses. That is why the router functions above raise nothing rather than something helpful.
+/// - A script's own `throw ""` is redacted by the same branch, because nothing can tell it apart.
+///
+/// Router functions that *do* raise text (`env::get`, `json::decode`) therefore reach clients with
+/// that text. Redacting them as well would take provenance rather than a value check: a distinct
+/// thrown type, or a variant other than `ErrorRuntime`, so the two can be told apart without
+/// inspecting the message. The Rhai customization docs carry this as a documented limitation.
+pub(super) const NO_CLIENT_MESSAGE: &str = "";
+
 pub(crate) use types::OptionDance;
 pub(crate) use types::SharedMut;
 
@@ -278,7 +297,7 @@ mod router_header_map {
         x: &mut HeaderMap,
         key: &str,
     ) -> Result<String, Box<EvalAltResult>> {
-        Ok(String::from_utf8_lossy(x.remove(key).ok_or("")?.as_bytes()).to_string())
+        Ok(String::from_utf8_lossy(x.remove(key).ok_or(NO_CLIENT_MESSAGE)?.as_bytes()).to_string())
     }
 
     // Register a HeaderMap indexer so we can get/set headers
@@ -296,7 +315,10 @@ mod router_header_map {
     ) -> Result<String, Box<EvalAltResult>> {
         let search_name =
             HeaderName::from_str(key).map_err(|e: InvalidHeaderName| e.to_string())?;
-        Ok(String::from_utf8_lossy(x.get(search_name).ok_or("")?.as_bytes()).to_string())
+        Ok(
+            String::from_utf8_lossy(x.get(search_name).ok_or(NO_CLIENT_MESSAGE)?.as_bytes())
+                .to_string(),
+        )
     }
 
     #[rhai_fn(index_set, return_raw)]

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

@@ -389,7 +389,10 @@ macro_rules! gen_map_response {
                     if let Err(error) = result {
                         let error_details = process_error(error);
                         if error_details.body.is_none() {
-                            tracing::error!("map_request callback failed: {error_details:#?}");
+                            // The response macros run outside the span the request macros install,
+                            // so the stage has to be named on the event itself - it is all an
+                            // operator has to go on once the client message is redacted.
+                            tracing::error!(rhai.stage = %$stage, "map_response callback failed: {error_details:#?}");
                         }
                         let mut guard = shared_response.lock();
                         let response_opt = guard.take();
@@ -442,7 +445,7 @@ macro_rules! gen_map_router_deferred_response {
                     if let Err(error) = result {
                         let error_details = process_error(error);
                         if error_details.body.is_none() {
-                            tracing::error!("map_request callback failed: {error_details:#?}");
+                            tracing::error!(rhai.stage = %$stage, "map_response callback failed: {error_details:#?}");
                         }
                         let response_opt = shared_response.lock().take();
                         return Ok($base::response_failure(
@@ -537,10 +540,20 @@ macro_rules! gen_map_deferred_response {
                     if first.is_none() {
                         let error_details = ErrorDetails {
                             status: StatusCode::INTERNAL_SERVER_ERROR,
-                            message: Some("rhai execution error: empty response".to_string()),
+                            message: Some(redacted_message(StatusCode::INTERNAL_SERVER_ERROR)),
                             position: None,
-                            body: None
+                            body: None,
+                            // No Rhai error to redact, since no callback ran. The
+                            // `rhai execution error` prefix is still the marker every cause behind
+                            // a redacted client response is logged under, so keep it here too -
+                            // one log query has to find the whole class.
+                            internal_detail: Some(
+                                "rhai execution error: the response stream ended before a primary response was available".to_string()
+                            ),
                         };
+                        // Not a callback failure: the response stream ended before there was a
+                        // primary response to hand the map_response callback, so it never ran.
+                        tracing::error!(rhai.stage = %$stage, "map_response was not called: {error_details:#?}");
                         return Ok($base::response_failure(
                             context,
                             error_details
@@ -567,7 +580,7 @@ macro_rules! gen_map_deferred_response {
                     if let Err(error) = result {
                         let error_details = process_error(error);
                         if error_details.body.is_none() {
-                            tracing::error!("map_request callback failed: {error_details:#?}");
+                            tracing::error!(rhai.stage = %$stage, "map_response callback failed: {error_details:#?}");
                         }
                         let mut guard = shared_response.lock();
                         let response_opt = guard.take();
@@ -605,7 +618,7 @@ macro_rules! gen_map_deferred_response {
                             if let Err(error) = result {
                                 let error_details = process_error(error);
                                 if error_details.body.is_none() {
-                                    tracing::error!("map_request callback failed: {error_details:#?}");
+                                    tracing::error!(rhai.stage = %$stage, "map_response callback failed: {error_details:#?}");
                                 }
                                 let mut guard = shared_response.lock();
                                 let response_opt = guard.take();
@@ -759,31 +772,91 @@ struct ErrorDetails {
     message: Option<String>,
     position: Option<Position>,
     body: Option<crate::graphql::Response>,
+    /// The unredacted Rhai error, kept for server-side logging only.
+    ///
+    /// This holds Rhai implementation details - the engine's error text, script line numbers and
+    /// the names of the callbacks involved - so it must never be copied into `message` or into a
+    /// client-facing response. It is skipped by serde so that a value deserialized from a script's
+    /// `throw` can never set it either.
+    ///
+    /// Outside of tests this is read only through the `Debug` impl, which is how every call site
+    /// logs the whole struct - dead code analysis does not count that, hence the `allow`.
+    #[serde(skip)]
+    #[allow(dead_code)]
+    internal_detail: Option<String>,
 }
 
 fn default_thrown_status_code() -> StatusCode {
     StatusCode::INTERNAL_SERVER_ERROR
 }
 
+/// The client-facing message for a failure the script author did not choose, i.e. anything the
+/// script did not explicitly `throw`.
+///
+/// Returning the Rhai error itself discloses that the router runs Rhai, which script functions are
+/// registered, and where in the script the failure happened, so clients get the status code's
+/// reason phrase instead and the real error is logged.
+fn redacted_message(status: StatusCode) -> String {
+    // A script is free to throw a status code that has no reason phrase - `throw #{ status: 599 }`
+    // - so there has to be a fallback. It is deliberately as vague as the status is: saying
+    // "Internal Server Error" alongside a 599 would be a lie. Kept local to the redaction rather
+    // than shared with the other reason-phrase call sites: this wording is chosen for what a client
+    // sees instead of a Rhai error, and should be free to change without moving anything else.
+    status
+        .canonical_reason()
+        .unwrap_or("Unknown Error")
+        .to_string()
+}
+
 fn process_error(error: Box<EvalAltResult>) -> ErrorDetails {
     let mut error_details = ErrorDetails {
         status: StatusCode::INTERNAL_SERVER_ERROR,
-        message: Some(format!("rhai execution error: '{error}'")),
+        message: None,
         position: None,
         body: None,
+        // Rendered before `error` is taken apart below: this is the only place the whole Rhai
+        // error is available, including the chain of script callbacks it came up through.
+        internal_detail: Some(format!("rhai execution error: '{error}'")),
     };
 
     let inner_error = error.unwrap_inner();
-    // We only want to process runtime errors
-    if let EvalAltResult::ErrorRuntime(obj, pos) = inner_error {
-        if let Ok(temp_error_details) = rhai::serde::from_dynamic::<ErrorDetails>(obj) {
-            if temp_error_details.message.is_some() || temp_error_details.body.is_some() {
-                error_details = temp_error_details;
-            } else {
-                error_details.status = temp_error_details.status;
+    // A script's `throw` is the only source of a message the author chose to show a client, and it
+    // always arrives as `ErrorRuntime`. Every other variant is an engine failure - unknown
+    // function, type mismatch, script recursion limit - whose text describes the script's
+    // internals, so those keep the redacted message set below.
+    if let EvalAltResult::ErrorRuntime(thrown, pos) = inner_error {
+        error_details.position = Some(pos.into());
+
+        if let Ok(thrown_message) = thrown.as_immutable_string_ref() {
+            // `throw "some message"`. The author wrote this string, so it is theirs to return -
+            // but only the string itself, not the Rhai wrapper around it.
+            //
+            // The router's own Rhai functions raise their errors in this same shape, with nothing
+            // recording which side raised them, so this discriminates on the value rather than the
+            // origin: an empty message - `engine::NO_CLIENT_MESSAGE`, all the router functions
+            // raise - falls through to the redacted message below. A script's own `throw ""` is
+            // caught by the same branch, and router functions that raise text of their own are
+            // returned verbatim; see `NO_CLIENT_MESSAGE` for why and for what a real fix needs.
+            if thrown_message.as_str() != engine::NO_CLIENT_MESSAGE {
+                error_details.message = Some(thrown_message.to_string());
             }
+        } else if let Ok(thrown_details) = rhai::serde::from_dynamic::<ErrorDetails>(thrown) {
+            // `throw #{ status: ..., message: ..., body: ... }`.
+            //
+            // A throw carrying only a status - `throw #{ status: 400 }` - gets the status it asked
+            // for and, because there is no author-provided message, the redacted message below. An
+            // empty `message` is treated the same way as an empty thrown string.
+            error_details.status = thrown_details.status;
+            error_details.message = thrown_details.message.filter(|message| !message.is_empty());
+            error_details.body = thrown_details.body;
         }
-        error_details.position = Some(pos.into());
+        // Anything else a script can `throw` - an integer, an array, a map that does not
+        // deserialize - carries no message this code can return without also dumping the thrown
+        // value, so it keeps the redacted message below.
+    }
+
+    if error_details.message.is_none() {
+        error_details.message = Some(redacted_message(error_details.status));
     }
     error_details
 }

apollo-router/src/plugins/rhai/snapshots/apollo_router__plugins__rhai__tests__execution_error_logging_without_body@logs.snap

@@ -4,7 +4,7 @@ expression: yaml
 ---
 - fields: {}
   level: ERROR
-  message: "map_request callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"rhai execution error: 'Runtime error: An error occurred without a body (line 22, position 5)'\",\n    ),\n    position: Some(\n        Position {\n            line: Some(\n                22,\n            ),\n            pos: Some(\n                5,\n            ),\n        },\n    ),\n    body: None,\n}"
+  message: "map_request callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"An error occurred without a body\",\n    ),\n    position: Some(\n        Position {\n            line: Some(\n                22,\n            ),\n            pos: Some(\n                5,\n            ),\n        },\n    ),\n    body: None,\n    internal_detail: Some(\n        \"rhai execution error: 'Runtime error: An error occurred without a body (line 22, position 5)'\",\n    ),\n}"
   span:
     name: rhai_plugin
     otel.kind: INTERNAL
@@ -13,6 +13,7 @@ expression: yaml
     - name: rhai_plugin
       otel.kind: INTERNAL
       rhai service: "execution :: Request"
-- fields: {}
+- fields:
+    rhai.stage: ExecutionResponse
   level: ERROR
-  message: "map_request callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"rhai execution error: 'Runtime error: An error occurred without a body (line 26, position 5)'\",\n    ),\n    position: Some(\n        Position {\n            line: Some(\n                26,\n            ),\n            pos: Some(\n                5,\n            ),\n        },\n    ),\n    body: None,\n}"
+  message: "map_response callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"An error occurred without a body\",\n    ),\n    position: Some(\n        Position {\n            line: Some(\n                26,\n            ),\n            pos: Some(\n                5,\n            ),\n        },\n    ),\n    body: None,\n    internal_detail: Some(\n        \"rhai execution error: 'Runtime error: An error occurred without a body (line 26, position 5)'\",\n    ),\n}"

apollo-router/src/plugins/rhai/snapshots/apollo_router__plugins__rhai__tests__it_redacts_a_binding_error_that_carries_no_message@logs.snap

@@ -0,0 +1,15 @@
+---
+source: apollo-router/src/plugins/rhai/tests.rs
+expression: yaml
+---
+- fields: {}
+  level: ERROR
+  message: "map_request callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"Internal Server Error\",\n    ),\n    position: Some(\n        Position {\n            line: Some(\n                15,\n            ),\n            pos: Some(\n                32,\n            ),\n        },\n    ),\n    body: None,\n    internal_detail: Some(\n        \"rhai execution error: 'Runtime error (line 15, position 32)'\",\n    ),\n}"
+  span:
+    name: rhai_plugin
+    otel.kind: INTERNAL
+    rhai service: "supergraph :: Request"
+  spans:
+    - name: rhai_plugin
+      otel.kind: INTERNAL
+      rhai service: "supergraph :: Request"

apollo-router/src/plugins/rhai/snapshots/apollo_router__plugins__rhai__tests__it_redacts_an_empty_response_stream@logs.snap

@@ -0,0 +1,8 @@
+---
+source: apollo-router/src/plugins/rhai/tests.rs
+expression: yaml
+---
+- fields:
+    rhai.stage: SupergraphResponse
+  level: ERROR
+  message: "map_response was not called: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"Internal Server Error\",\n    ),\n    position: None,\n    body: None,\n    internal_detail: Some(\n        \"rhai execution error: the response stream ended before a primary response was available\",\n    ),\n}"

apollo-router/src/plugins/rhai/snapshots/apollo_router__plugins__rhai__tests__it_redacts_engine_errors_from_client_responses@logs.snap

@@ -0,0 +1,15 @@
+---
+source: apollo-router/src/plugins/rhai/tests.rs
+expression: yaml
+---
+- fields: {}
+  level: ERROR
+  message: "map_request callback failed: ErrorDetails {\n    status: 500,\n    message: Some(\n        \"Internal Server Error\",\n    ),\n    position: None,\n    body: None,\n    internal_detail: Some(\n        \"rhai execution error: 'Function not found: this_function_does_not_exist () (line 14, position 5)'\",\n    ),\n}"
+  span:
+    name: rhai_plugin
+    otel.kind: INTERNAL
+    rhai service: "execution :: Request"
+  spans:
+    - name: rhai_plugin
+      otel.kind: INTERNAL
+      rhai service: "execution :: Request"