quarkus-smallrye-graphql: NPE when connecting with websocat #28190

carueda · 2022-09-25T19:36:51Z

Describe the bug

NPE in SmallRyeGraphQLOverWebSocketHandler.java when connecting with websocat. Stack trace in additional info below.

Please note: My app functionality seems unaffected, but I sometimes use the handy websocat tool for some basic monitoring and I thought I'd enter this ticket in case it's actually exposing some unknown bug in Quarkus. I explored the documentation in case it could be related with some websocket protocol variation or something like that but was not able to find anything specific. It could also be a some websocat issue... in any case, there's an NPE lurking there that should probably be handled more gracefully.

Thanks!

Expected behavior

No exceptions.

Actual behavior

NPE in SmallRyeGraphQLOverWebSocketHandler.java

How to Reproduce?

Have a Quarkus app with graphql capability running. I discovered the issue with an actual deployed app involving dockerization and Apache proxy-pass, a setup that I thought might had been part of the problem BUT then noted that it also simply happens in development mode: quarkus dev
in a separate terminal, run websocat ws://localhost:8080/graphql. The NPE is thrown.

Output of `uname -a` or `ver`

Darwin Kernel Version 19.6.0: Tue Jan 12 22:13:05 PST 2021; root:xnu-6153.141.16~1/RELEASE_X86_64 x86_64

Output of `java -version`

openjdk version "17.0.3" 2022-04-19 OpenJDK Runtime Environment GraalVM CE 22.1.0 (build 17.0.3+7-jvmci-22.1-b06) OpenJDK 64-Bit Server VM GraalVM CE 22.1.0 (build 17.0.3+7-jvmci-22.1-b06, mixed mode, sharing)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

CLI 2.12.1.Final. BUT my pom.xml with 2.12.3.Final

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

Apache Maven 3.8.6 (84538c9988a25aec085021c365c560670ad80f63)

Additional information

2022-09-25 12:11:55,509 ERROR [io.qua.ver.cor.run.VertxCoreRecorder] (vert.x-eventloop-thread-1) Uncaught exception received by Vert.x: java.lang.NullPointerException: Cannot invoke "String.hashCode()" because "<local5>" is null
	at io.quarkus.smallrye.graphql.runtime.SmallRyeGraphQLOverWebSocketHandler.lambda$doHandle$4(SmallRyeGraphQLOverWebSocketHandler.java:38)
	at io.vertx.ext.web.impl.HttpServerRequestWrapper.lambda$toWebSocket$0(HttpServerRequestWrapper.java:355)
	at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
	at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
	at io.vertx.core.impl.future.Mapping.onSuccess(Mapping.java:40)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
	at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
	at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23)
	at io.vertx.core.Promise.complete(Promise.java:66)
	at io.vertx.core.http.impl.Http1xServerConnection.lambda$createWebSocket$2(Http1xServerConnection.java:299)
	at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:86)
	at io.vertx.core.impl.ContextBase.execute(ContextBase.java:225)
	at io.vertx.core.http.impl.Http1xServerConnection.createWebSocket(Http1xServerConnection.java:272)
	at io.vertx.core.http.impl.Http1xServerRequest.lambda$webSocket$4(Http1xServerRequest.java:467)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:246)
	at io.vertx.core.http.impl.HttpEventHandler.handleEnd(HttpEventHandler.java:76)
	at io.vertx.core.http.impl.Http1xServerRequest.onEnd(Http1xServerRequest.java:581)
	at io.vertx.core.http.impl.Http1xServerRequest.lambda$pendingQueue$1(Http1xServerRequest.java:130)
	at io.vertx.core.streams.impl.InboundBuffer.handleEvent(InboundBuffer.java:239)
	at io.vertx.core.streams.impl.InboundBuffer.drain(InboundBuffer.java:226)
	at io.vertx.core.streams.impl.InboundBuffer.lambda$fetch$0(InboundBuffer.java:279)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:246)
	at io.vertx.core.impl.EventLoopContext.lambda$runOnContext$0(EventLoopContext.java:43)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)```

The text was updated successfully, but these errors were encountered:

quarkus-bot · 2022-09-25T19:36:54Z

/cc @Ladicek, @jmartisk, @phillip-kruger, @radcortez

phillip-kruger · 2022-09-25T23:31:30Z

@carueda - can you share a reproducer ?

carueda · 2022-09-26T02:16:31Z

@phillip-kruger oh, sorry about that.

Here it is: https://github.com/carueda/microprofile-graphql-quickstart

it is a direct copy of https://github.com/quarkusio/quarkus-quickstarts/tree/main/microprofile-graphql-quickstart (as of a couple months ago)
with only change being the use of latest Quarkus release at this moment, 2.12.3.Final

Thanks.

2022-09-25 19:18:31,163 ERROR [io.qua.ver.cor.run.VertxCoreRecorder] (vert.x-eventloop-thread-1) Uncaught exception received by Vert.x: java.lang.NullPointerException: Cannot invoke "String.hashCode()" because "<local5>" is null
	at io.quarkus.smallrye.graphql.runtime.SmallRyeGraphQLOverWebSocketHandler.lambda$doHandle$4(SmallRyeGraphQLOverWebSocketHandler.java:38)
	at io.vertx.ext.web.impl.HttpServerRequestWrapper.lambda$toWebSocket$0(HttpServerRequestWrapper.java:355)
	at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
	at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
	at io.vertx.core.impl.future.Mapping.onSuccess(Mapping.java:40)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
	at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
	at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23)
	at io.vertx.core.Promise.complete(Promise.java:66)
	at io.vertx.core.http.impl.Http1xServerConnection.lambda$createWebSocket$2(Http1xServerConnection.java:299)
	at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:86)
	at io.vertx.core.impl.ContextBase.execute(ContextBase.java:225)
	at io.vertx.core.http.impl.Http1xServerConnection.createWebSocket(Http1xServerConnection.java:272)
	at io.vertx.core.http.impl.Http1xServerRequest.lambda$webSocket$4(Http1xServerRequest.java:467)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:246)
	at io.vertx.core.http.impl.HttpEventHandler.handleEnd(HttpEventHandler.java:76)
	at io.vertx.core.http.impl.Http1xServerRequest.onEnd(Http1xServerRequest.java:581)
	at io.vertx.core.http.impl.Http1xServerRequest.lambda$pendingQueue$1(Http1xServerRequest.java:130)
	at io.vertx.core.streams.impl.InboundBuffer.handleEvent(InboundBuffer.java:239)
	at io.vertx.core.streams.impl.InboundBuffer.drain(InboundBuffer.java:226)
	at io.vertx.core.streams.impl.InboundBuffer.lambda$fetch$0(InboundBuffer.java:279)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:246)
	at io.vertx.core.impl.EventLoopContext.lambda$runOnContext$0(EventLoopContext.java:43)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

phillip-kruger · 2022-09-26T05:22:49Z

Hi @carueda
Thanks for the info.

I am following your instructions to recreate the issue, but I can not seem to.

a few questions:

what is websocat and what are you trying to achieve with it ?
When do you get the error ? When you run websocat ws://localhost:8080/graphql

I get no error in my Quarkus log, but I get

websocat: WebSocketError: I/O failure
websocat: error running

Let me know. Thanks

carueda · 2022-09-26T16:15:19Z

Hi @phillip-kruger, thanks for the fast replies!

what is websocat and what are you trying to achieve with it ?

https://github.com/vi/websocat is a handy tool that I sometimes use to monitor traffic in websocket-enabled applications. It is not critical at all for me, but, as already said, I entered this ticket because its use seems to be exposing an issue in Quarkus.

When do you get the error ? When you run websocat ws://localhost:8080/graphql

Yes.

Interesting that in your case websocat is not even able (apparently) to hit the quarkus grapqhl endpoint.

To double check my repro, I just tried it fresh on a Linux machine and with the very latest websocat version available at https://github.com/vi/websocat/releases , 1.11.0 :

(note, using port 9090 here because I have one other app on 8080)

When I enter the websocat command, it immediately triggers the NPE on the Quarkus side:

Hope that helps clarify things. Thanks again.

phillip-kruger · 2022-09-27T01:29:31Z

Ok, I managed to recreate the issue ! Thanks. I ran into vi/websocat#23, so when I change to use 127.0.0.1 is works. I'll look into this a.s.a.p
Thanks

yesunch · 2022-09-28T19:34:09Z

Hi, @carueda , @phillip-kruger

I recreated the issue as well. It seems that the problem is caused by the subprotocol of the opened websocket which is null.
I've committed a fix and tested against the reproducer provided by @carueda . No exception is thrown.
I opened a PR for this issue, but since it's my first time to contribute to Quarkus, please, any remark and comment is welcomed.

Hope that may help things
Thanks

phillip-kruger · 2022-09-28T21:07:36Z

Is there no way to set the subprotocol in websocat?

carueda · 2022-09-28T22:27:54Z

Thanks @yesunch !

@phillip-kruger Good point and I should have done a bit more research.

Though the output of websocat --help=long doesn't say much about "protocols" I just learned from vi/websocat#140 that --protocol graphql-ws option should probably be the correct usage; in fact, I can run websocat against Quarkus with it with no exception:

$ websocat -v --protocol graphql-ws ws://127.0.0.1:8080/graphql
[INFO  websocat::lints] Auto-inserting the line mode
[INFO  websocat::stdio_threaded_peer] get_stdio_peer (threaded)
[INFO  websocat::ws_client_peer] get_ws_client_peer
[INFO  websocat::ws_client_peer] Connected to ws
{"type":"ka"}
{"type":"ka"}
{"type":"ka"}
{"type":"ka"}
{"type":"ka"}
...

phillip-kruger · 2022-09-29T00:55:55Z

Thanks @carueda @yesunch , I think @yesunch fix that print a better error message is the right fix.

carueda added the kind/bug Something isn't working label Sep 25, 2022

quarkus-bot bot added area/graphql area/smallrye labels Sep 25, 2022

yesunch mentioned this issue Sep 28, 2022

Fix NPE when the subprotocol of websocket is null #28268

Merged

gsmet closed this as completed in #28268 Sep 29, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

quarkus-smallrye-graphql: NPE when connecting with websocat #28190

quarkus-smallrye-graphql: NPE when connecting with websocat #28190

carueda commented Sep 25, 2022

quarkus-bot bot commented Sep 25, 2022

phillip-kruger commented Sep 25, 2022

carueda commented Sep 26, 2022 •

edited

Loading

phillip-kruger commented Sep 26, 2022

carueda commented Sep 26, 2022 •

edited

Loading

phillip-kruger commented Sep 27, 2022

yesunch commented Sep 28, 2022

phillip-kruger commented Sep 28, 2022

carueda commented Sep 28, 2022 •

edited

Loading

phillip-kruger commented Sep 29, 2022

quarkus-smallrye-graphql: NPE when connecting with websocat #28190

quarkus-smallrye-graphql: NPE when connecting with websocat #28190

Comments

carueda commented Sep 25, 2022

Describe the bug

Expected behavior

Actual behavior

How to Reproduce?

Output of uname -a or ver

Output of java -version

GraalVM version (if different from Java)

Quarkus version or git rev

Build tool (ie. output of mvnw --version or gradlew --version)

Additional information

quarkus-bot bot commented Sep 25, 2022

phillip-kruger commented Sep 25, 2022

carueda commented Sep 26, 2022 • edited Loading

phillip-kruger commented Sep 26, 2022

carueda commented Sep 26, 2022 • edited Loading

phillip-kruger commented Sep 27, 2022

yesunch commented Sep 28, 2022

phillip-kruger commented Sep 28, 2022

carueda commented Sep 28, 2022 • edited Loading

phillip-kruger commented Sep 29, 2022

Output of `uname -a` or `ver`

Output of `java -version`

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

carueda commented Sep 26, 2022 •

edited

Loading

carueda commented Sep 26, 2022 •

edited

Loading

carueda commented Sep 28, 2022 •

edited

Loading