search

redis / lettuce

Advanced Java Redis client for thread-safe sync, async, and reactive usage. Supports Cluster, Sentinel, Pipelining, and codecs.
https://lettuce.io
MIT License
5.39k stars 970 forks source link

RedisConnectionFailureException in Application #3029

Open captainpro-eng opened 12 hours ago

captainpro-eng commented 12 hours ago

I am experiencing a connection failure when trying to connect to the Redis server from my application. Below are the logs of the issue:


DEBUG [2024-10-25 19:30:04,019]  o.s.d.r.c.RedisConnectionUtils: Opening RedisConnection
DEBUG [2024-10-25 19:30:04,019]  i.l.c.c.RedisClusterClient: connectCluster([RedisURI [host='tp-redis-cluster-leader', port=6379]])
DEBUG [2024-10-25 19:30:04,020]  i.l.c.c.RoundRobinSocketAddressSupplier: Resolved SocketAddress 192.168.34.32:6379 using for Cluster node 7ae8e417b9826c1afc3b4de8b6a1b8590fed5447
DEBUG [2024-10-25 19:30:04,020]  i.l.core.RedisClient: Connecting to Redis at 192.168.34.32:6379
DEBUG [2024-10-25 19:30:04,023]  i.l.c.p.CommandHandler: [channel=0xd67f7149, [id: 0xbf778c0d] (inactive), chid=0xc] channelRegistered()
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] channelActive()
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] activateEndpointAndExecuteBufferedCommands 0 command(s) buffered
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] activating endpoint
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] flushCommands()
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] flushCommands() Flushing 0 commands
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.ConnectionWatchdog: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, last known addr=/192.168.34.32:6379] channelActive()
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.ConnectionWatchdog: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, last known addr=/192.168.34.32:6379] channelActive()
DEBUG [2024-10-25 19:30:04,024]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] channelActive() done
DEBUG [2024-10-25 19:30:04,025]  i.l.core.RedisClient: Connecting to Redis at 192.168.34.32:6379: Success
DEBUG [2024-10-25 19:30:04,025]  i.l.c.RedisChannelHandler: dispatching command SubscriptionCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.protocol.Command]
DEBUG [2024-10-25 19:30:04,025]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] write() writeAndFlush command ClusterCommand [command=SubscriptionCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.protocol.Command], redirections=0, maxRedirections=5]
DEBUG [2024-10-25 19:30:04,025]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] write(ctx, ClusterCommand [command=SubscriptionCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.protocol.Command], redirections=0, maxRedirections=5], promise)
DEBUG [2024-10-25 19:30:04,025]  i.l.c.p.CommandEncoder: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379] writing command ClusterCommand [command=SubscriptionCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.protocol.Command], redirections=0, maxRedirections=5]
DEBUG [2024-10-25 19:30:04,026]  i.l.c.p.DefaultEndpoint: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, epid=0xc] write() done
DEBUG [2024-10-25 19:30:04,026]  i.l.c.p.ConnectionWatchdog: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, last known addr=/192.168.34.32:6379] userEventTriggered(ctx, io.lettuce.core.ConnectionEvents$Activated@3ddc75fb)
DEBUG [2024-10-25 19:30:04,026]  i.l.c.p.ConnectionWatchdog: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, last known addr=/192.168.34.32:6379] userEventTriggered(ctx, io.lettuce.core.ConnectionEvents$Activated@3ddc75fb)
DEBUG [2024-10-25 19:30:04,028]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Received: 1024 bytes, 1 commands in the stack
DEBUG [2024-10-25 19:30:04,028]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Stack contains: 1 commands
DEBUG [2024-10-25 19:30:04,028]  i.l.c.p.RedisStateMachine: Decode LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand]
DEBUG [2024-10-25 19:30:04,028]  i.l.c.p.RedisStateMachine: Decoded LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand], empty stack: false
DEBUG [2024-10-25 19:30:04,029]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Received: 16384 bytes, 1 commands in the stack
DEBUG [2024-10-25 19:30:04,029]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Stack contains: 1 commands
DEBUG [2024-10-25 19:30:04,029]  i.l.c.p.RedisStateMachine: Decode LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand]
DEBUG [2024-10-25 19:30:04,031]  i.l.c.p.RedisStateMachine: Decoded LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand], empty stack: false
DEBUG [2024-10-25 19:30:04,031]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Received: 65536 bytes, 1 commands in the stack
DEBUG [2024-10-25 19:30:04,032]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Stack contains: 1 commands
DEBUG [2024-10-25 19:30:04,032]  i.l.c.p.RedisStateMachine: Decode LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand]
ERROR [2024-10-25 19:30:04,032]  c.g.p.p.c.RedisController: Failed to connect to Redis
org.springframework.data.redis.RedisConnectionFailureException: Unable to connect to Redis; nested exception is io.lettuce.core.RedisConnectionException: Unable to connect
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.getNativeConnection(LettuceConnectionFactory.java:1092)
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.getConnection(LettuceConnectionFactory.java:1065)
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory.getClusterConnection(LettuceConnectionFactory.java:362)
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory.getConnection(LettuceConnectionFactory.java:332)
        at org.springframework.data.redis.core.RedisConnectionUtils.doGetConnection(RedisConnectionUtils.java:132)
        at org.springframework.data.redis.core.RedisConnectionUtils.getConnection(RedisConnectionUtils.java:95)
        at org.springframework.data.redis.core.RedisConnectionUtils.getConnection(RedisConnectionUtils.java:82)
        at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:211)
        at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:184)
        at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:95)
        at org.springframework.data.redis.core.DefaultValueOperations.set(DefaultValueOperations.java:236)
        at com.generalmobi.progate.pbs.component.RedisController.testRedisConnection(RedisController.java:26)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:189)
        at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
        at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:800)
        at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1038)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1005)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:897)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:882)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:117)
        at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:106)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:834)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1417)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:750)
Caused by: io.lettuce.core.RedisConnectionException: Unable to connect
        at io.lettuce.core.RedisConnectionException.create(RedisConnectionException.java:94)
        at io.lettuce.core.AbstractRedisClient.getConnection(AbstractRedisClient.java:261)
        at io.lettuce.core.cluster.RedisClusterClient.connect(RedisClusterClient.java:348)
        at org.springframework.data.redis.connection.lettuce.ClusterConnectionProvider.getConnection(ClusterConnectionProvider.java:85)
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.getNativeConnection(LettuceConnectionFactory.java:1085)
        ... 74 common frames omitted
Caused by: java.lang.UnsupportedOperationException: null
        at java.util.AbstractList.add(AbstractList.java:148)
        at java.util.AbstractList.add(AbstractList.java:108)
        at io.lettuce.core.output.ArrayOutput.set(ArrayOutput.java:54)
        at io.lettuce.core.protocol.RedisStateMachine.safeSet(RedisStateMachine.java:357)
        at io.lettuce.core.protocol.RedisStateMachine.decode(RedisStateMachine.java:138)
        at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:708)
        at io.lettuce.core.protocol.CommandHandler.decode0(CommandHandler.java:672)
        at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:658)
        at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:587)
        at io.lettuce.core.protocol.CommandHandler.channelRead(CommandHandler.java:556)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
        at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
        at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:648)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:583)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:500)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        ... 1 common frames omitted
DEBUG [2024-10-25 19:30:04,036]  i.l.c.p.RedisStateMachine: Decoded LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand], empty stack: false
DEBUG [2024-10-25 19:30:04,036]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Received: 7237 bytes, 1 commands in the stack
DEBUG [2024-10-25 19:30:04,036]  i.l.c.p.CommandHandler: [channel=0xd67f7149, /192.168.196.31:48170 -> /192.168.34.32:6379, chid=0xc] Stack contains: 1 commands
DEBUG [2024-10-25 19:30:04,036]  i.l.c.p.RedisStateMachine: Decode LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand]
DEBUG [2024-10-25 19:30:04,037]  i.l.c.p.RedisStateMachine: Decoded LatencyMeteredCommand [type=COMMAND, output=ArrayOutput [output=[], error='null'], commandType=io.lettuce.core.cluster.ClusterCommand], empty stack: true
tishun commented 12 hours ago

Greetings @captainpro-eng,

Seems like the Lettuce driver is having trouble decoding the result coming from the server (which seems to be null). This seems to happen during the time the driver is attempting to connect to one of the nodes of your cluster.

However there is quite little information for me to continue researching this problem.

What is the server, how is it configured? Are you able to connect to it with another client (e.g. redis-cli) successfully? What version of the driver are you using?

captainpro-eng commented 11 hours ago

Hi @tishun ,

Thanks for your reply.

I'm using a Redis cluster in Kubernetes, and I am able to connect through redis-cli and Jedis as well. However, due to the lack of features (such as topology refresh) that are necessary in a Kubernetes environment with Jedis, we decided to switch to Lettuce. I'm using it through Spring Data Redis. Below are the versions:

Lettuce: 5.1.3.RELEASE Spring Data Redis: 2.1.4.RELEASE Let me know if you need any more help!