server: Log graphql panics

Author: leoyvens

graph/src/data/query/query.rs

@@ -133,4 +133,14 @@ impl Query {
             _force_use_of_new: (),
         }
     }
+
+    pub fn query_text(&self) -> String {
+        self.document
+            .format(&graphql_parser::Style::default().indent(0))
+            .replace('\n', " ")
+    }
+
+    pub fn variables_text(&self) -> String {
+        serde_json::to_string(&self.variables).unwrap_or_default()
+    }
 }

graphql/src/execution/query.rs

@@ -1,11 +1,11 @@
-use graphql_parser::{query as q, schema as s, Style};
+use graphql_parser::{query as q, schema as s};
 use std::collections::HashMap;
 use std::sync::Arc;
 
 use graph::data::graphql::ext::TypeExt;
 use graph::data::query::{Query as GraphDataQuery, QueryVariables};
 use graph::data::schema::Schema;
-use graph::prelude::{serde_json, QueryExecutionError};
+use graph::prelude::QueryExecutionError;
 
 use crate::execution::{get_field, get_named_type};
 use crate::introspection::introspection_schema;
@@ -45,8 +45,8 @@ pub struct Query {
 
     /// Used only for logging; if logging is configured off, these will
     /// have dummy values
-    pub(crate) query_text: Arc<String>,
-    pub(crate) variables_text: Arc<String>,
+    pub query_text: Arc<String>,
+    pub variables_text: Arc<String>,
     pub(crate) complexity: u64,
 }
 
@@ -60,16 +60,9 @@ impl Query {
         max_complexity: Option<u64>,
         max_depth: u8,
     ) -> Result<Arc<Self>, Vec<QueryExecutionError>> {
-        let (query_text, variables_text) = if *graph::log::LOG_GQL_TIMING {
-            (
-                query
-                    .document
-                    .format(&Style::default().indent(0))
-                    .replace('\n', " "),
-                serde_json::to_string(&query.variables).unwrap_or_default(),
-            )
-        } else {
-            ("(gql logging turned off)".to_owned(), "".to_owned())
+        let (query_text, variables_text) = match *graph::log::LOG_GQL_TIMING {
+            true => (query.query_text(), query.variables_text()),
+            false => ("(gql logging turned off)".to_owned(), "".to_owned()),
         };
         let query_text = Arc::new(query_text);
         let variables_text = Arc::new(variables_text);

server/http/src/service.rs

@@ -272,9 +272,41 @@ where
         let query = GraphQLRequest::new(body, schema, network).compat().await;
 
         let result = match query {
-            Ok(query) => graph::spawn_blocking_allow_panic(service.graphql_runner.run_query(query))
-                .await
-                .unwrap(),
+            Ok(query) => {
+                // Not great that we serialize the query here only for the panic case.
+                let query_text = query.query_text();
+                let variables_text = query.variables_text();
+
+                let result =
+                    graph::spawn_blocking_allow_panic(service.graphql_runner.run_query(query))
+                        .await;
+
+                match result {
+                    Ok(res) => res,
+
+                    // `JoinError` means a panic.
+                    Err(e) => {
+                        let e = e.into_panic();
+                        let e = match e
+                            .downcast_ref::<String>()
+                            .map(|s| s.as_str())
+                            .or(e.downcast_ref::<&'static str>().map(|&s| s))
+                        {
+                            Some(e) => e.to_string(),
+                            None => "panic is not a string".to_string(),
+                        };
+                        let err = QueryExecutionError::Panic(e);
+                        error!(
+                            self.logger,
+                            "panic when processing graphql query";
+                            "panic" => err.to_string(),
+                            "query" => query_text,
+                            "variables" => variables_text,
+                        );
+                        Arc::new(QueryResult::from(err))
+                    }
+                }
+            }
             Err(GraphQLServerError::QueryError(e)) => Arc::new(QueryResult::from(e)),
             Err(e) => return Err(e),
         };

server/index-node/src/service.rs

@@ -79,7 +79,6 @@ where
         &self,
         request_body: Body,
     ) -> Result<Response<Body>, GraphQLServerError> {
-        let logger = self.logger.clone();
         let store = self.store.clone();
         let graphql_runner = self.graphql_runner.clone();
 
@@ -91,28 +90,59 @@ where
             .await?;
 
         let query = IndexNodeRequest::new(body, schema).compat().await?;
+        let query = match PreparedQuery::new(query, None, 100) {
+            Ok(query) => query,
+            Err(e) => return Ok(QueryResult::from(e).as_http_response()),
+        };
 
-        let logger = logger.clone();
         let graphql_runner = graphql_runner.clone();
         let load_manager = graphql_runner.load_manager();
 
         // Run the query using the index node resolver
+        let query_clone = query.cheap_clone();
+        let logger = self.logger.cheap_clone();
         let result = tokio::task::spawn_blocking(move || {
             let options = QueryExecutionOptions {
-                logger: logger.clone(),
                 resolver: IndexNodeResolver::new(&logger, graphql_runner, store),
+                logger,
                 deadline: None,
                 max_first: std::u32::MAX,
                 load_manager,
             };
-            QueryResult::from(PreparedQuery::new(query, None, 100).map(|query| {
+            QueryResult::from(
                 // Index status queries are not cacheable, so we may unwrap this.
-                Arc::try_unwrap(execute_query(query, None, None, options)).unwrap()
-            }))
+                Arc::try_unwrap(execute_query(query_clone, None, None, options)).unwrap(),
+            )
         })
-        .await
-        .unwrap();
-        Ok(result.as_http_response())
+        .await;
+
+        let query_result = match result {
+            Ok(res) => res,
+
+            // `JoinError` means a panic.
+            Err(e) => {
+                let e = e.into_panic();
+                let e = match e
+                    .downcast_ref::<String>()
+                    .map(|s| s.as_str())
+                    .or(e.downcast_ref::<&'static str>().map(|&s| s))
+                {
+                    Some(e) => e.to_string(),
+                    None => "panic is not a string".to_string(),
+                };
+                let err = QueryExecutionError::Panic(e);
+                error!(
+                    self.logger,
+                    "panic when processing graphql query";
+                    "panic" => err.to_string(),
+                    "query" => &query.query_text,
+                    "variables" => &query.variables_text,
+                );
+                QueryResult::from(err)
+            }
+        };
+
+        Ok(query_result.as_http_response())
     }
 
     // Handles OPTIONS requests