ISSUE #315

* Improve logging strategy.

Author: Sergio García Prado

packages/plugins/minos-router-graphql/minos/plugins/graphql/handlers.py

@@ -6,6 +6,7 @@
 
 from graphql import (
     ExecutionResult,
+    GraphQLError,
     GraphQLSchema,
     graphql,
     print_schema,
@@ -53,30 +54,41 @@ async def _build_graphql_arguments(request: Request) -> dict[str, Any]:
 
         return {"source": source, "variable_values": variables}
 
-    @staticmethod
-    def _build_response_from_graphql(result: ExecutionResult) -> Response:
-        errors = result.errors
-        if errors is None:
-            errors = list()
-
-        status = 200
+    def _build_response_from_graphql(self, result: ExecutionResult) -> Response:
+        content = {"data": result.data}
+        if result.errors is not None:
+            content["errors"] = [err.message for err in result.errors]
+            self._log_errors(result.errors)
 
-        if len(errors):
-            status = 500
-            for error in errors:
-                if error.original_error is None:
-                    logger.error(f"Raised an graphql exception:\n {error.formatted}")
-                else:
+        status = self._get_status(result)
 
-                    if isinstance(error.original_error, ResponseException):
-                        status = error.original_error.status
-
-                    error_trace = "".join(traceback.format_tb(error.original_error.__traceback__))
-                    logger.exception(f"Raised a system exception:\n {error_trace}")
+        return Response(content, status=status)
 
-        content = {"data": result.data, "errors": [err.message for err in errors]}
+    @staticmethod
+    def _get_status(result: ExecutionResult) -> int:
+        status = 200
+        for error in result.errors or []:
+            if error.original_error is None:
+                current = 400
+            elif isinstance(error.original_error, ResponseException):
+                current = error.original_error.status
+            else:
+                current = 500
+            status = max(status, current)
+        return status
 
-        return Response(content, status=status)
+    @staticmethod
+    def _log_errors(errors: list[GraphQLError]) -> None:
+        for error in errors:
+            if error.original_error is None:
+                tb = repr(error)
+            else:
+                tb = "".join(traceback.format_tb(error.__traceback__))
+
+            if error.original_error is None or isinstance(error.original_error, ResponseException):
+                logger.error(f"Raised an application exception:\n {tb}")
+            else:
+                logger.exception(f"Raised a system exception:\n {tb}")
 
     async def get_schema(self, request: Request) -> Response:
         """Get schema

packages/plugins/minos-router-graphql/tests/test_graphql/test_handlers.py

@@ -47,6 +47,10 @@ async def resolve_ticket_raises(request: Request):
     raise ResponseException("Some error.", status=403)
 
 
+async def resolve_ticket_raises_system(request: Request):
+    raise ValueError()
+
+
 class TestGraphQlHandler(unittest.IsolatedAsyncioTestCase):
     CONFIG_FILE_PATH = BASE_PATH / "test_config.yml"
     _config = Config(CONFIG_FILE_PATH)
@@ -66,7 +70,8 @@ async def test_execute_operation(self):
         result = await handler.execute_operation(request)
 
         self.assertEqual(200, result.status)
-        self.assertDictEqual(await result.content(), {"data": {"order_query": "ticket #4"}, "errors": []})
+        expected_content = {"data": {"order_query": "ticket #4"}}
+        self.assertDictEqual(expected_content, await result.content())
 
     async def test_execute_operation_raises(self):
         routes = {
@@ -83,6 +88,21 @@ async def test_execute_operation_raises(self):
 
         self.assertEqual(403, result.status)
 
+    async def test_execute_operation_raises_system(self):
+        routes = {
+            GraphQlQueryEnrouteDecorator(name="ticket_query", output=GraphQLString): resolve_ticket_raises_system,
+        }
+
+        schema = GraphQLSchemaBuilder.build(routes=routes)
+
+        handler = GraphQlHandler(schema)
+
+        request = InMemoryRequest(content="{ ticket_query }")
+
+        result = await handler.execute_operation(request)
+
+        self.assertEqual(500, result.status)
+
     async def test_execute_wrong_operation(self):
         routes = {
             GraphQlQueryEnrouteDecorator(name="order_query", output=GraphQLString): callback_fn,
@@ -99,8 +119,8 @@ async def test_execute_wrong_operation(self):
 
         content = await result.content()
 
-        self.assertEqual(500, result.status)
-        self.assertNotEqual(content["errors"], [])
+        self.assertEqual(400, result.status)
+        self.assertEqual(1, len(content["errors"]))
 
     async def test_schema(self):
         routes = {
@@ -148,8 +168,8 @@ async def test_query_with_variables(self):
         content = await result.content()
 
         self.assertEqual(200, result.status)
-        self.assertDictEqual({"order_query": 3}, content["data"])
-        self.assertEqual([], content["errors"])
+        expected_content = {"data": {"order_query": 3}}
+        self.assertDictEqual(expected_content, content)
 
     async def test_simple_query(self):
         routes = {GraphQlQueryEnrouteDecorator(name="SimpleQuery", output=GraphQLString): resolve_simple_query}
@@ -171,8 +191,8 @@ async def test_simple_query(self):
         content = await result.content()
 
         self.assertEqual(200, result.status)
-        self.assertDictEqual({"SimpleQuery": "ABCD"}, content["data"])
-        self.assertEqual([], content["errors"])
+        expected_content = {"data": {"SimpleQuery": "ABCD"}}
+        self.assertDictEqual(expected_content, content)
 
     async def test_query_with_variables_return_user(self):
         routes = {GraphQlQueryEnrouteDecorator(name="order_query", argument=GraphQLInt, output=user_type): resolve_user}
@@ -204,11 +224,12 @@ async def test_query_with_variables_return_user(self):
         content = await result.content()
 
         self.assertEqual(200, result.status)
-        self.assertDictEqual(
-            {"order_query": {"id": "3", "firstName": "Jack", "lastName": "Johnson", "tweets": 563, "verified": True}},
-            content["data"],
-        )
-        self.assertEqual([], content["errors"])
+        expected_content = {
+            "data": {
+                "order_query": {"id": "3", "firstName": "Jack", "lastName": "Johnson", "tweets": 563, "verified": True}
+            }
+        }
+        self.assertDictEqual(expected_content, content)
 
     async def test_mutation(self):
         routes = {
@@ -240,19 +261,18 @@ async def test_mutation(self):
         content = await result.content()
 
         self.assertEqual(200, result.status)
-        self.assertDictEqual(
-            {
+        expected_content = {
+            "data": {
                 "createUser": {
                     "id": "4kjjj43-l23k4l3-325kgaa2",
                     "firstName": "John",
                     "lastName": "Doe",
                     "tweets": 42,
                     "verified": True,
                 }
-            },
-            content["data"],
-        )
-        self.assertEqual([], content["errors"])
+            }
+        }
+        self.assertDictEqual(expected_content, content)
 
 
 if __name__ == "__main__":