GraphQL queries result in "java.io.IOException: UT000034: Stream is closed"

duncan-bayne commented 5 years ago

I've created a Luminus 3.25 app with the following invocation:

lein new luminus todo-list +postgres +re-frame +graphql +kibit

The app compiles, runs locally, and deploys to Heroku (with a tweak; see #231). However, the GraphQL API seems broken both locally, and in production.

If I POST a valid GraphQL query, the server returns a 500, while internally raising ERROR todo-list.middleware.exception - UT000034: Stream is closed. However, if I POST an invalid GraphQL query, it responds as expected.

For example:

$ curl 'http://localhost:3000/api/graphql' -X POST --data '{"query":"{ hero(id: \"1000\") }","variables":{},"operationName":null}'
{"type":"exception","class":"java.io.IOException"}%                                                                                                                       

$ curl 'http://localhost:3000/api/graphql' -X POST                                                                                
{"errors":[{"message":"Failed to parse GraphQL query.","errors":[{"location":{"line":1,"column":null},"parse-error":"no viable alternative at input '<EOF>'"}]}]}%

Relevant excerpt from the log:

2019-04-08 18:57:39,612 [XNIO-1 task-1] ERROR todo-list.middleware.exception - UT000034: Stream is closed
java.io.IOException: UT000034: Stream is closed
  at io.undertow.io.UndertowInputStream.read(UndertowInputStream.java:87) ~[undertow-core-1.4.14.Final.jar:1.4.14.Final]
  at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) ~[na:1.8.0_192]
  at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) ~[na:1.8.0_192]
  ... snip ...
  at immutant.web.internal.undertow$create_http_handler$reify__45945.handleRequest(undertow.clj:239) [na:na]
  at org.projectodd.wunderboss.web.undertow.async.websocket.UndertowWebsocket$2.handleRequest(UndertowWebsocket.java:109) [wunderboss-web-undertow-0.13.1.jar:na]
  at io.undertow.server.session.SessionAttachmentHandler.handleRequest(SessionAttachmentHandler.java:68) [undertow-core-1.4.14.Final.jar:1.4.14.Final]
  at io.undertow.server.Connectors.executeRootHandler(Connectors.java:211) [undertow-core-1.4.14.Final.jar:1.4.14.Final]
  at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:809) [undertow-core-1.4.14.Final.jar:1.4.14.Final]
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_192]
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_192]
  at java.lang.Thread.run(Thread.java:748) [na:1.8.0_192]

It's possible I'm doing something wrong and supplying an invalid or unexpected GraphQL query; this is my first time using GraphQL. Even so, I'd expect some sort of error to that effect (as is provided when no query at all is POSTed).

duncan-bayne commented 5 years ago

I wonder whether this is related to https://github.com/luminus-framework/luminus-template/issues/214? I don't think so, though, because it happens on a fresh run of lein run, and on a fresh production deployment.

yogthos commented 5 years ago

Hmm, have you tried using the built in test page http://localhost:3000/graphiql. I tried the following query from there:

query {
  hero {name}
}

and I see the following result as expected:

{
  "data": {
    "hero": {
      "name": "Luke"
    }
  }
}

As a note, there's an older version 0.28.0 of Lacinia packaged with the template, I've just bumped up to the latest `0.32.0.

duncan-bayne commented 5 years ago

Ah! Got it. Working back from your example, the cause was a missing header:

$ curl 'http://localhost:3000/api/graphql' -X POST --data '{"query":"{ hero(id: \"1000\") }","variables":{},"operationName":null}'                               
{"type":"exception","class":"java.io.IOException"}%    

$ curl 'http://localhost:3000/api/graphql' -X POST --data '{"query":"{ hero(id: \"1000\") }","variables":{},"operationName":null}' -H 'Content-Type: application/graphql'
{"errors":[{"message":"Failed to parse GraphQL query.","extensions":{"errors":[{"locations":[{"line":1,"column":null}],"message":"mismatched input '\"query\"' expecting {'query', 'mutation', 'subscription', '...', NameId}"},{"locations":[{"line":1,"column":null}],"message":"mismatched input '}' expecting {'query', 'mutation', 'subscription', '...', NameId}"},{"locations":[{"line":1,"column":null}],"message":"extraneous input '\"operationName\"' expecting {<EOF>, 'query', 'mutation', 'subscription', '{', 'fragment'}"}]}}]}%

If you don't specify -H 'Content-Type: application/graphql', you get the java.IO.IOException instead of a sensible error message.

Maybe another mention in the documentation somewhere? Or perhaps this is an upstream bug in lacinia?

yogthos commented 5 years ago

Yeah, that sounds like an upstream issue for lacinia, since it's ultimately handling the content type.

duncan-bayne commented 5 years ago

I'll raise an issue on lacinia, then, & close this one.

Thanks for all the help, and also, thanks for Luminus! :)

duncan-bayne commented 5 years ago

Raised as https://github.com/walmartlabs/lacinia/issues/279.

luminus-framework / luminus

GraphQL queries result in "java.io.IOException: UT000034: Stream is closed" #232