graphql-java-kickstart/graphql-java-servlet

graphql.kickstart.servlet.HttpRequestHandlerImpl doesn't reponse error with detail

dioscoreae opened this issue · 11 comments

Hi,

The execute method in graphql.kickstart.servlet.HttpRequestHandlerImpl simply set reponse status to ERROR but doesn't fill any exception details, neither write error log. So that debug is not easy. Can it be improved ?

  private void execute(GraphQLInvocationInput invocationInput, HttpServletRequest request,
      HttpServletResponse response) {
    try {
      GraphQLQueryResult queryResult = invoke(invocationInput, request, response);

      QueryResponseWriter queryResponseWriter = QueryResponseWriter.createWriter(queryResult, configuration.getObjectMapper(),
          configuration.getSubscriptionTimeout());
      queryResponseWriter.write(request, response);
    } catch (Throwable t) {
      **response.setStatus(STATUS_BAD_REQUEST);**
      log.info("Bad GET request: path was not \"/schema.json\" or no query variable named \"query\" given");
      log.debug("Possibly due to exception: ", t);
    }
  }

@dioscoreae It's logging the stack-trace in the last statement of the catch statement with debug level, which contains all the exception details. So when you switch your logging level for these packages to debug you should be seeing them.

@oliemansm could you please clarify is this just a stub implementation or a prod-ready?

  1. It erroneously responds with 400 status if server-side error occurred, e.g. exception in resolver
  2. It doesn't allow error handling customization to be used, e.g. propagate exception to Spring MVC to be correctly translated by ExceptionHandler

@oefimov It is production ready, and it is used in production by a lot of projects. What are you basing these two assumptions on?

  1. If the GraphQL request itself is valid but an exception occurs in a resolver it does not return 400, but follow the GraphQL specification. Default it will translate any exception into a GraphQLError with message "Internal server error", but...
  2. The graphql-spring-boot project adds support for Spring style ExceptionHandler methods that return GraphQLError or a List<GraphQLError>. You have to enable exception-handling-enabled as described in the README of that project.

@oliemansm I'm trying to make it work with Spring MVC without Spring Boot, and I see behaviour described above. Is there any way to provide desired error handling in plain Spring?

@oefimov You are using graphql-java-tools or are you wiring the schema manually? The catch block referred to above should only kick in when the GraphQL request itself is invalid. If that request is valid and it can be handled by the resolvers then this catch block should not be triggered but instead a regular GraphQL response with the errors field should be returned. So it depends on what triggered the server-side error you're referring too in your item (1).

Without anything to go on to reproduce or knowledge about your setup it's not possible to say anything more sensible about it tbh. The whole idea of the servlet and the graphql-java library it wraps is that it handles errors in line with the specification. The graphql-spring-boot-starter only adds some tricks to customize the GraphQLErrors returned, but not the overall exception handling (which is what you currently seem to have a problem with).

It would be better if you can share a small repo and instructions on how to run and reproduce the issue.

@oliemansm here's the reproducer repo
https://github.com/oefimov/graphql-java-servlet-250
you may run mvn test to see that one test is failing

@oefimov Thanks for sharing the example, that helps a lot! It actually looks like you're running into this bug graphql-java/graphql-java#1652. Although apparently that doesn't just happen for custom exceptions implementing GraphQLError, but basically for any exception thrown that way.

@oliemansm thank you for your help!

BTW Are there any docs on integrating with Spring transactions (this is how I faced this issue)?

I've tried tx-ing ExecutionStrategy as per https://blog.akquinet.de/2020/04/16/part-2-graphql-with-spring-boot-jpa-and-kotlin/ but there were rollback-only exceptions from Spring interceptor causing 400 / empty response from HttpRequestHandlerImpl.

Tx-ing via Instrumentation (https://spectrum.chat/graphql/general/transactional-queries-with-spring~47749680-3bb7-4508-8935-1d20d04d0c6a) worked better for me.

@oefimov There aren't unfortunately. And I don't have any experience with that either, since I always separate the GraphQL layer from the domain model.

Judging by the amount of open issues, open PRs and their release cycle it might take a while before a fix is in for this particular problem btw...

Hi,

I have the same behavior with a StackOverflowError in my domain layer.

And clues given by the library to investigate are inexact.

  1. The log Bad GET request: path was not "schema.json" or no query variable named "query" given is inexact.

  2. The HTTP code is 400 but the client request is valid.
    It is a server error and I expect to have a HTTP code 500.

graphql.kickstart.servletHttpRequestHandlerImpl#handle method

@Slf4j
class HttpRequestHandlerImpl implements HttpRequestHandler {
@Override
  public void handle(HttpServletRequest request, HttpServletResponse response) throws IOException {
    try {
      GraphQLInvocationInputParser invocationInputParser = GraphQLInvocationInputParser.create(
          request,
          configuration.getInvocationInputFactory(),
          configuration.getObjectMapper(),
          configuration.getContextSetting()
      );
      GraphQLInvocationInput invocationInput = invocationInputParser.getGraphQLInvocationInput(request, response);
      execute(invocationInput, request, response);
    } catch (GraphQLException e) {
      response.setStatus(STATUS_BAD_REQUEST);
      log.info("Bad request: cannot create invocation input parser", e);
      throw e;
    } catch (Throwable t) {
      response.setStatus(500);
      log.info("Bad request: cannot create invocation input parser", t);
      throw t;
    }
  }
}

Logs Bad request: cannot create invocation input parser seems to be only valid on a exception thrown by invocationInputParser.getGraphQLInvocationInput(request, response).
The invocationInputParser.getGraphQLInvocationInput method seems to valid if a query is valid (cf. graphql.kickstart.servlet.GraphQLGetInvocationInputParser).
It checks in the case of a GET request, if it is a request for the schema or if the query request param is define.

The catch(Throwable t) clause give two incompatible information.

  • a HTTP status code 500 that indicate it is a server error
  • a log that indicate it is a client error

graphql.kickstart.servletHttpRequestHandlerImpl#execute

    private void execute(GraphQLInvocationInput invocationInput, HttpServletRequest request,
      HttpServletResponse response) {
    try {
      GraphQLQueryResult queryResult = invoke(invocationInput, request, response);

      QueryResponseWriter queryResponseWriter = QueryResponseWriter.createWriter(queryResult, configuration.getObjectMapper(),
          configuration.getSubscriptionTimeout());
      queryResponseWriter.write(request, response);
    } catch (Throwable t) {
      response.setStatus(STATUS_BAD_REQUEST);
      log.info("Bad GET request: path was not \"/schema.json\" or no query variable named \"query\" given");
      log.debug("Possibly due to exception: ", t);
    }
  }

I don't have all cases where the catch(Throwable t) is reached, but when a Throwable is catch (eg. StackOverflowError, OutOfMemoryError), it seems that a internal servor error log with a HTTP code 500 are more adequate.

Error handling and logging has been improved in 10.1.0. The original reported issue is not an issue with this library, but with graphql-java unfortunately. There's an open issue in that project already.