micronaut-core icon indicating copy to clipboard operation
micronaut-core copied to clipboard

WebSocketClient throws Nullpointer when wrong domain is set, when @OnClose method is getting any arguments

Open domi-nika60 opened this issue 1 year ago • 2 comments

Expected Behavior

Hi,

most probably I've found a bug. Please advice.

In my Micronaut project of Websocket Client with use of Rx3WebSocketClient (io.micronaut.rxjava3.http.client.websockets) I'm getting NullPointer Exception when the client is trying to connect to wrong domain and onOpen event is not executed.

To connect with the client I'm using Single<MyWSClient> .

The error indicates that there is problem with onClose method (not seeing session). The error is with stacktrace:

ERROR i.m.h.c.n.w.NettyWebSocketClientHandler - Error invoking @OnClose handler for WebSocket bean [com.example.MyWSClient$Intercepted@4b191512]: Cannot invoke "io.micronaut.websocket.WebSocketSession.getUriVariables()" because the return value of "io.micronaut.websocket.bind.WebSocketState.getSession()" is null
java.lang.NullPointerException: Cannot invoke "io.micronaut.websocket.WebSocketSession.getUriVariables()" because the return value of "io.micronaut.websocket.bind.WebSocketState.getSession()" is null
	at io.micronaut.websocket.bind.WebSocketStateBinderRegistry.findArgumentBinder(WebSocketStateBinderRegistry.java:84)
	at io.micronaut.websocket.bind.WebSocketStateBinderRegistry.findArgumentBinder(WebSocketStateBinderRegistry.java:42)
	at io.micronaut.core.bind.DefaultExecutableBinder.bind(DefaultExecutableBinder.java:70)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.bindMethod(AbstractNettyWebSocketHandler.java:626)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.handleCloseReason(AbstractNettyWebSocketHandler.java:566)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.handlerRemoved(AbstractNettyWebSocketHandler.java:317)
	at io.netty.channel.AbstractChannelHandlerContext.callHandlerRemoved(AbstractChannelHandlerContext.java:946)
	at io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:637)
	at io.netty.channel.DefaultChannelPipeline.destroyDown(DefaultChannelPipeline.java:876)
	at io.netty.channel.DefaultChannelPipeline.destroyUp(DefaultChannelPipeline.java:844)
	at io.netty.channel.DefaultChannelPipeline.destroy(DefaultChannelPipeline.java:836)
	at io.netty.channel.DefaultChannelPipeline.access$700(DefaultChannelPipeline.java:46)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelUnregistered(DefaultChannelPipeline.java:1392)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelUnregistered(AbstractChannelHandlerContext.java:198)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelUnregistered(AbstractChannelHandlerContext.java:184)
	at io.netty.channel.DefaultChannelPipeline.fireChannelUnregistered(DefaultChannelPipeline.java:821)
	at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:839)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	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)

After investigation, it turned out, that this error is being thrown only if the method onClose with @OnClose decorator is taking any arguments (if not, the application is closing normally, only with error printed in throwable).

That means that, application is failing on OnClose method although it does not open at all.

I’ve reproduced it on the clear environment with one Websocket Client:

Class with WebSocketClient:

@ClientWebSocket("/chat")
public abstract class MyWSClient implements AutoCloseable {

    private static final Logger LOG = LoggerFactory.getLogger(MyWSClient.class);
    private WebSocketSession session;

    @OnOpen
    void onOpen(
            WebSocketSession session,
            String anyVariab
    ) {
        this.session = session;
        LOG.info("On Open state");
    }

    @OnMessage
    void onMessage(String anyVariab) {
        LOG.info("On Message state");
    }

    @OnClose
    void onClose(String anyVariab) {
        LOG.info("Log which will never be executed.");
    }

    @OnError
    void onError() {
        LOG.info("in error");
    }

}

RunClient:

@Singleton
public class RunClient {
    private static final Logger LOG = LoggerFactory.getLogger(RunClient.class);
    @Inject
    @Client("http://nosuchdomaintest")
    Rx3WebSocketClient wsClient;

    @Scheduled(initialDelay = "1s")
    void connectToClient() {

        Single<MyWSClient> speechClient = wsClient.connect(MyWSClient.class, "/").lastOrError();
        speechClient.subscribe(
            success -> LOG.info("The connection is opened"),
            throwable -> {
                LOG.error("Problem with connection: {}", throwable.toString());
            }
        );
    }
}

Actual Behaviour

The application should print out that there is issue with connecting to websocekt client, the LOG.error("Problem with connection: {}", throwable.toString()) from throwable should be executed and program should stop.

However, the NullPointer Exception is being thrown with logs:

<tmp> [main] INFO  io.micronaut.runtime.Micronaut - Startup completed in 1526ms. Server Running: http://localhost:8080
<tmp> [default-nioEventLoopGroup-1-2] ERROR com.example.RunClient - Problem with connection: java.net.UnknownHostException: nosuchdomaintest: nodename nor servname provided, or not known
<tmp> [default-nioEventLoopGroup-1-2] ERROR i.m.h.c.n.w.NettyWebSocketClientHandler - Error invoking @OnClose handler for WebSocket bean [com.example.MyWSClient$Intercepted@5cca1509]: Cannot invoke "io.micronaut.websocket.WebSocketSession.getUriVariables()" because the return value of "io.micronaut.websocket.bind.WebSocketState.getSession()" is null
java.lang.NullPointerException: Cannot invoke "io.micronaut.websocket.WebSocketSession.getUriVariables()" because the return value of "io.micronaut.websocket.bind.WebSocketState.getSession()" is null
	at io.micronaut.websocket.bind.WebSocketStateBinderRegistry.findArgumentBinder(WebSocketStateBinderRegistry.java:84)
	at io.micronaut.websocket.bind.WebSocketStateBinderRegistry.findArgumentBinder(WebSocketStateBinderRegistry.java:42)
	at io.micronaut.core.bind.DefaultExecutableBinder.bind(DefaultExecutableBinder.java:70)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.bindMethod(AbstractNettyWebSocketHandler.java:626)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.handleCloseReason(AbstractNettyWebSocketHandler.java:566)
	at io.micronaut.http.netty.websocket.AbstractNettyWebSocketHandler.handlerRemoved(AbstractNettyWebSocketHandler.java:317)
	at io.netty.channel.AbstractChannelHandlerContext.callHandlerRemoved(AbstractChannelHandlerContext.java:946)
	at io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:637)
	at io.netty.channel.DefaultChannelPipeline.destroyDown(DefaultChannelPipeline.java:876)
	at io.netty.channel.DefaultChannelPipeline.destroyUp(DefaultChannelPipeline.java:844)
	at io.netty.channel.DefaultChannelPipeline.destroy(DefaultChannelPipeline.java:836)
	at io.netty.channel.DefaultChannelPipeline.access$700(DefaultChannelPipeline.java:46)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelUnregistered(DefaultChannelPipeline.java:1392)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelUnregistered(AbstractChannelHandlerContext.java:198)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelUnregistered(AbstractChannelHandlerContext.java:184)
	at io.netty.channel.DefaultChannelPipeline.fireChannelUnregistered(DefaultChannelPipeline.java:821)
	at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:839)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	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)

Additionally I noticed, that it is possible to define another @OnClose method. When it's without any arguments, the behavior is as expected. But, when the domain is correct, the application is also executing onClose without arguments. So it's not resolving the issue.

The question is, why Micronaut is even opening such connection in this situation (wrong domain)? Shouldn't it just end the application (with status 404) before @onOpen is executed?

Steps To Reproduce

  1. In clear Micronaut (with gradle) project add MyWSClient.java and RunClient,.java classes.
  2. Add dependencies for rxjava3 to build.gradle
    implementation 'io.micronaut.rxjava3:micronaut-rxjava3-http-client'
  1. Run application: ./gradlew :run

  2. See the error in logs.

Environment Information

  • Operating System: OSX M1
  • JDK: java 17

Example Application

No response

Version

3.2.6

domi-nika60 avatar Aug 30 '22 06:08 domi-nika60

does this still happen with 3.6?

yawkat avatar Aug 30 '22 16:08 yawkat

Yes, already checked. The behavior is the same for 3.6.1

domi-nika60 avatar Aug 30 '22 20:08 domi-nika60

hello, is there any update about this? thanks

domi-nika60 avatar Oct 06 '22 08:10 domi-nika60

hello, is this any ETA for this bug to be released? I saw, it was moved to another release, why so?

domi-nika60 avatar Nov 02 '22 10:11 domi-nika60

@domi-nika60 can you provide an example to reproduce the issue, also PRs welcome of course :)

graemerocher avatar Nov 02 '22 11:11 graemerocher

Sorry this took so long, I was waiting for the client refactor, and then went on vacation. Can you try with the PR #8300 applied?

yawkat avatar Nov 07 '22 11:11 yawkat

No problem :). Not sure if I test it correctly with your branch, but it seems that issue still exists. I will check again after merge and let you know.

domi-nika60 avatar Nov 09 '22 10:11 domi-nika60