ConnectionWatchdog throw "IllegalStateException: cannot be started once stopped" on shutdown process

weixsun commented 3 months ago

Bug Report

Current Behavior

Stack trace

```java [2024-03-22 10:03:19.396][WARN][io.netty.channel.DefaultChannelPipeline 1152][lettuce-kqueueEventLoop-58-7][,][IllegalStateException][Unknown-ErrCode][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.][]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: cannot be started once stopped at io.netty.util.HashedWheelTimer.start(HashedWheelTimer.java:372) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.HashedWheelTimer.newTimeout(HashedWheelTimer.java:447) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.lettuce.core.protocol.ConnectionWatchdog.scheduleReconnect(ConnectionWatchdog.java:246) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.lettuce.core.protocol.ConnectionWatchdog.channelInactive(ConnectionWatchdog.java:205) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.lettuce.core.ConnectionEventTrigger.channelInactive(ConnectionEventTrigger.java:67) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.lettuce.core.protocol.CommandHandler.channelInactive(CommandHandler.java:371) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.lettuce.core.protocol.RedisHandshakeHandler.channelInactive(RedisHandshakeHandler.java:94) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.lettuce.core.ChannelGroupListener.channelInactive(ChannelGroupListener.java:69) ~[lettuce-core-6.3.1.RELEASE.jar:6.3.1.RELEASE/12e6995] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:813) ~[netty-transport-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasksFrom(SingleThreadEventExecutor.java:426) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:375) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.confirmShutdown(SingleThreadEventExecutor.java:763) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.channel.kqueue.KQueueEventLoop.run(KQueueEventLoop.java:309) ~[netty-transport-classes-kqueue-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.78.Final.jar:4.1.78.Final] at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_372] ```

Input Code

Initialize Redis Client： ```java RedisStandaloneConfiguration standaloneConfiguration = getStandaloneConfiguration(...); LettuceClientConfiguration lettuceClientConfiguration = getLettuceClientConfiguration(...); return new LettuceConnectionFactory(standaloneConfiguration, lettuceClientConfiguration); ``` Shutdown Redis Client ```java LettuceConnectionFactory oldLCF = ... oldLCF.getClientResources().shutdown(3000, 16000, TimeUnit.MILLISECONDS).get(); oldLCF.getNativeClient().shutdown(3000, 16000, TimeUnit.MILLISECONDS); oldLCF.destroy(); ```

Expected behavior/code

No following warn log.

[2024-03-22 10:03:19.396][WARN][io.netty.channel.DefaultChannelPipeline 1152][lettuce-kqueueEventLoop-58-7][,][IllegalStateException][Unknown-ErrCode][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.][]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: cannot be started once stopped

Environment

Lettuce version(s): [6.1.8.RELEASE, 6.3.1.RELEASE]
Redis version: [7.0.8]

Possible Solution

Sorry, I'm not sure，I can only try to give you what I know

Additional context

weixsun commented 3 months ago

Maybe the following line of code is redundant, and when I removed it, the situation improved.

oldLCF.getClientResources().shutdown(3000, 16000, TimeUnit.MILLISECONDS).get();

yangbodong22011 commented 3 months ago

As far as I know, shutdown has some unidentified problems, and it is recommended to use shutdownAsync. https://github.com/lettuce-io/lettuce-core/issues/2278

weixsun commented 3 months ago

@yangbodong22011 Thank you for attention，#2797 May be simpler than #2278, and I suspect I have found some evidence, so I will close this issue, thank you again for your attention to this issue.

redis / lettuce