Websocket connection fails sometimes with exception "ChannelPipeline does not contain an HttpRequestEncoder or HttpClientCodec"

[Scorpio1987]

Expected behavior

No exceptions

Actual behavior

2023-05-19 11:00:52 [nioEventLoopGroup-23-3] WARN io.netty.channel.DefaultChannelPipeline - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.lang.IllegalStateException: ChannelPipeline does not contain an HttpRequestEncoder or HttpClientCodec
at io.netty.handler.codec.http.websocketx.WebSocketClientHandshaker$1.operationComplete(WebSocketClientHandshaker.java:273) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.handler.codec.http.websocketx.WebSocketClientHandshaker$1.operationComplete(WebSocketClientHandshaker.java:263) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:604) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:104) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.channel.DelegatingChannelPromiseNotifier.operationComplete(DelegatingChannelPromiseNotifier.java:52) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.channel.DelegatingChannelPromiseNotifier.operationComplete(DelegatingChannelPromiseNotifier.java:31) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise.access$200(DefaultPromise.java:35) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.DefaultPromise$1.run(DefaultPromise.java:501) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [CMX-Cloud-Connector-1.0.jar:?]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [CMX-Cloud-Connector-1.0.jar:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_171]

One thing i observed is when this exception happens, the handler is getting HANDSHAKE_COMPLETE event without getting HANDSHAKE_ISSUED event.

Steps to reproduce

It happens sometimes not always

Minimal yet complete reproducer code (or URL to code)

Netty version

4.1.50-final

JVM version (e.g. java -version)

openjdk version "1.8.0_171"
OpenJDK Runtime Environment (build 1.8.0_171-b10)
OpenJDK 64-Bit Server VM (build 25.171-b10, mixed mode)

OS version (e.g. uname -a)

Linux 2d168e5cfdbe 5.13.2-1.el7.elrepo.x86_64 #1 SMP Wed Jul 14 12:18:11 EDT 2021 x86_64 x86_64 x86_64 GNU/Linux

[hyperxpro]

Upgrade to the latest version of Netty and see if the issue still persists.

[Scorpio1987]

The code that causing this exception hasn't changed in years and i see a problem with below code.

https://github.com/netty/netty/blob/4.1/codec-http/src/main/java/io/netty/handler/codec/http/websocketx/WebSocketClientHandshaker.java#LL325C9-L348C6

In above code we send handshake request and as part of the future listener callback we are trying to get HTTPClientCodec to insert WebsocketEncoder. But before the future listener function callback, the handshake is getting completed and HttpClientCodec is getting removed in the finishHandshake function.

https://github.com/netty/netty/blob/4.1/codec-http/src/main/java/io/netty/handler/codec/http/websocketx/WebSocketClientHandshaker.java#L425

This happens very rare and not seen always. As i mentioned before whenever i get the event HANDSHAKE_ISSUED before HANDSHAKE_COMPLETE event, i don't see this issue happening.

[normanmaurer]

@Scorpio1987 just to double-check... you are using the HttpClientCodec correct in your pipeline ?

[Scorpio1987]

Yes, i think so. Below is the code that is doing the initialization of HttpClientCodec

public class SocketChannelInitializer extends ChannelInitializer { .... @Override protected void initChannel(Channel channel) throws Exception { ChannelPipeline channelPipeline = channel.pipeline(); .... final HttpClientCodec codec = new HttpClientCodec(); channelPipeline.addLast("http", codec); .... WebSocketClientProtocolHandler handler = new WebSocketClientProtocolHandler(WebSocketClientHandshakerFactory.newHandshaker( socketUri, WebSocketVersion.V13, null, true, httpHeaders)){ @Override public void userEventTriggered(ChannelHandlerContext ctx, Object evt) throws Exception { if (evt instanceof SslHandshakeCompletionEvent) { SslHandshakeCompletionEvent event = (SslHandshakeCompletionEvent) evt; logger.info("Channel {} SSL status = {}", connectionId, "HANDSHAKE_COMPLETE"); } else if (evt instanceof WebSocketClientProtocolHandler.ClientHandshakeStateEvent) { WebSocketClientProtocolHandler.ClientHandshakeStateEvent event = (WebSocketClientProtocolHandler.ClientHandshakeStateEvent)evt; logger.info("Channel {} WS status = {}", connectionId, event.name()); } } }; channelPipeline.addLast("websocket", handler); ..... } }

So when the above exception happens, i see below logs

2023-05-19 11:00:47 [nioEventLoopGroup-23-1] INFO SocketChannelInitializer - Channel 5 SSL status = HANDSHAKE_COMPLETE
2023-05-19 11:00:47 [nioEventLoopGroup-23-1] INFO SocketChannelInitializer - Channel 5 WS status = HANDSHAKE_COMPLETE
2023-05-19 11:00:48 [nioEventLoopGroup-23-1] WARN io.netty.channel.DefaultChannelPipeline - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.lang.IllegalStateException: ChannelPipeline does not contain an HttpRequestEncoder or HttpClientCodec

But when i get HANDSHAKE_ISSUED followed by HANDSHAKE_COMPLETE, i don't see the exception. Again as i mentioned this doesn't always happen. I am trying to find the pattern but so far not able to.

2023-05-19 11:03:49 [nioEventLoopGroup-23-7] INFO SocketChannelInitializer - Channel 5 SSL status = HANDSHAKE_COMPLETE
2023-05-19 11:03:49 [nioEventLoopGroup-23-7] INFO SocketChannelInitializer - Channel 5 WS status = HANDSHAKE_ISSUED
2023-05-19 11:03:49 [nioEventLoopGroup-23-7] INFO SocketChannelInitializer - Channel 5 WS status = HANDSHAKE_COMPLETE