graphql-core-legacy
graphql-core-legacy copied to clipboard
AsyncioExecutor produces hard to debug errors
When an async
resolver is raising an exception, this exception is not logged and its stack in lost and never printed. The only "report" is the error carried by the ExecutionResult
but we can only access its type and message, not the actual stack trace.
This is different for sync resolvers (even when using the AsyncioExecutor
): the exception is printed by graphql.execution.executor resolve_or_error
.
Below is an example to illustrate the issue:
from graphql.execution.executors.asyncio import AsyncioExecutor
from graphql import GraphQLObjectType, GraphQLField, GraphQLString, GraphQLSchema, graphql
def resolve_hello(root, args, context, info):
raise Exception("wololo")
async def resolve_hello_async(root, args, context, info):
raise Exception("wololo")
QueryType = GraphQLObjectType("Query", fields={
"hello": GraphQLField(GraphQLString, resolver=resolve_hello),
"helloAsync": GraphQLField(GraphQLString, resolver=resolve_hello_async),
})
schema = GraphQLSchema(query=QueryType)
print("Sync execution")
result = graphql(schema, '{ hello }', executor=AsyncioExecutor())
# This will log something like:
#
# An error occurred while resolving field Query.hello
# Traceback (most recent call last):
# File ".../site-packages/graphql/execution/executor.py", line 200, in resolve_or_error
# return executor.execute(resolve_fn, source, args, context, info)
# File ".../site-packages/graphql/execution/executors/asyncio.py", line 50, in execute
# result = fn(*args, **kwargs)
# File "test.py", line 11, in resolve_hello
# raise Exception("wololo")
# Exception: wololo
# As a side note, the produced error have a correct stack trace:
print(result.errors[0].stack) # <traceback object at 0x123456789>
print("=" * 10)
print("Async execution")
async_result = graphql(schema, '{ helloAsync }', executor=AsyncioExecutor())
# While producing the same result, it won't log anything, and good luck to know where
# the error comes from.
# This error has None as a stack trace:
print(async_result.errors[0].stack) # None
I am a beginner with python async stuff so I won't send a PR, but as a temporary solution I am replacing the AsyncioExecutor execute
method with something like that:
def execute(self, fn, *args, **kwargs):
result = fn(*args, **kwargs)
if isinstance(result, Future) or iscoroutine(result):
async def hop():
try:
awaited_result = await result
except Exception as e:
logger.exception("Exception in %s", fn)
raise
return awaited_result
future = ensure_future(hop(), loop=self.loop)
# future = ensure_future(result, loop=self.loop)
self.futures.append(future)
return Promise.resolve(future)
return result
EDIT: I am using graphene 1.4 and graphql 1.1
Same issue here
In graphql-core 2.0.dev20170801051721, you can do:
# (your sample code pasted here)
import traceback
ex = async_result.errors[0].original_error
traceback.print_exception(type(ex), ex, ex.__traceback__)
Traceback (most recent call last):
File "test_gql_ex.py", line 8, in resolve_hello_async
raise Exception("wololo")
Exception: wololo
And in general, when writing asyncio-based programs we need explicit exception handling at the top stack frame of each asyncio Task (for all unexpected errors). Without explicit handling, the errors are only reported when the task is deleted from the memory, which usually happens when the event loop shuts down.
Hm... I've also found that the code here
if hasattr(original_error, 'stack'):
stack = original_error.stack
should check original_error.__traceback__
instead, because original_error
may be just an arbitrary Python exceptions which might not have stack
property (which is the convention in graphql-core). But __traecback__
is only available in Python 3, so we need some other way to do the same for Python 2.
For those who are looking for a quick solution, this is how I resolved it in graphql 1.1:
import logging
from graphql.execution.executors.asyncio import AsyncioExecutor
from promise import Promise
logger = logging.getLogger(__name__)
class LoggingAsyncioExecutor(AsyncioExecutor):
def execute(self, fn, *args, **kwargs):
result = super().execute(fn, *args, **kwargs)
if isinstance(result, Promise):
def log_exception(ex):
logger.error(
"Unhandled error in %s:\n%s",
fn,
"".join(traceback.format_exception(type(ex), ex, ex.__traceback__))
)
raise ex
result = result.catch(log_exception)
return result
# Then use LoggingAsyncioExecutor in place of AsyncioExecutor
# Example with flask_graphql:
app.add_url_rule('/graphql', view_func=GraphQLView.as_view(
'graphql',
schema=schema,
graphiql=True,
executor=LoggingAsyncioExecutor(loop=loop)
))
Legend, this works wonderfully for now!