生产一次RedisCommandTimeoutException问题分析

1、在某个时间段,生产日志大量出现RedisCommandTimeoutException,一共98次:

grep "RedisCommandTimeoutException"  *_2021-09-10.5.log |wc -l

2、查看第一次出现的位置:

grep -C 100  "RedisCommandTimeoutException" *_2021-09-10.5.log |head -201

 

完整异常信息如下:

2021-09-10 14:50:33.423 INFO [http-nio-7001-exec-362]com.***.web.config.GlobalExceptionHandler.printLog:300 -Method[Method[invoke:-1]]错误码:global_exception_warn_web_log,错误信息:Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 2 second(s)-->Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 2 second(s)
com.cfc.common.utils.TranFailException: Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 2 second(s)-->Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 2 second(s)
	at com.cfc.common.utils.LogUtil$HanderExVo.invoke(LogUtil.java:412)
	at com.cfc.common.utils.LogUtil.handerEx(LogUtil.java:319)
	at com.cfc.common.utils.LogUtil.handerEx(LogUtil.java:280)
	at com.cfc.common.utils.LogUtil.handerEx(LogUtil.java:257)
	at com.cfc.common.utils.LogUtil.handerEx(LogUtil.java:245)
	at com.***.web.config.GlobalExceptionHandler.jsonErrorHandler(GlobalExceptionHandler.java:47)
	at sun.reflect.GeneratedMethodAccessor6324.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
	at org.springframework.web.servlet.mvc.method.annotation.ExceptionHandlerExceptionResolver.doResolveHandlerMethodException(ExceptionHandlerExceptionResolver.java:408)
	at org.springframework.web.servlet.handler.AbstractHandlerMethodExceptionResolver.doResolveException(AbstractHandlerMethodExceptionResolver.java:61)
	at org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver.resolveException(AbstractHandlerExceptionResolver.java:140)
	at org.springframework.web.servlet.handler.HandlerExceptionResolverComposite.resolveException(HandlerExceptionResolverComposite.java:79)
	at org.springframework.web.servlet.DispatcherServlet.processHandlerException(DispatcherServlet.java:1298)
	at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:1110)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1056)
	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.doPost(FrameworkServlet.java:908)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
	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.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
	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:118)
	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:118)
	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:118)
	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:202)
	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:853)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.dao.QueryTimeoutException: Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out after 2 second(s)
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:70)
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41)
	at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44)
	at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42)
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:268)
	at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.convertLettuceAccessException(LettuceStringCommands.java:799)
	at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.get(LettuceStringCommands.java:68)
	at org.springframework.data.redis.connection.DefaultedRedisConnection.get(DefaultedRedisConnection.java:253)
	at org.springframework.data.redis.core.DefaultValueOperations$1.inRedis(DefaultValueOperations.java:57)
	at org.springframework.data.redis.core.AbstractOperations$ValueDeserializingRedisCallback.doInRedis(AbstractOperations.java:59)
	at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:224)
	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.get(DefaultValueOperations.java:53)
	at com.***.basic.redis.service.RedisService.get(RedisService.java:134)
	at com.***.basic.service.impl.AppParamServiceImpl.queryOneParamValue(AppParamServiceImpl.java:55)
	at com.***.service.service.impl.OrdersServiceImpl.taskResourceUsers(OrdersServiceImpl.java:969)
	at com.***.service.service.impl.OrdersServiceImpl.getTaskUsers(OrdersServiceImpl.java:925)
	at com.***.service.service.impl.OrdersServiceImpl.reformatOrders(OrdersServiceImpl.java:630)
	at com.***.service.service.impl.OrdersServiceImpl.getBussOrders(OrdersServiceImpl.java:913)
	at com.***.service.service.impl.OrdersServiceImpl$$FastClassBySpringCGLIB$$64bca082.invoke(<generated>)
	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
	at org.springframework.transaction.interceptor.TransactionInterceptor$$Lambda$719/1122356159.proceedWithInvocation(Unknown Source)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:295)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
	at com.***.service.service.impl.OrdersServiceImpl$$EnhancerBySpringCGLIB$$ea15cf3a.getBussOrders(<generated>)
	at com.***.web.controller.BusinessInfoController.listBussinfo(BusinessInfoController.java:207)
	at com.***.web.controller.BusinessInfoController$$FastClassBySpringCGLIB$$fa862eb4.invoke(<generated>)
	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:56)

3、首先检查redis连接问题,是否可用,通过telnet 等命令,发现redis服务端是正常的,那么redis可用性没有问题

telnet  ip  port

 4、在项目中搜索用到lettuce的地方,原来是springboot自身集成的 lettuce

5、也不像是程序客户端,连接池占满,获取不到连接的问题。所以从第一次抛出异常的日志中继续找问题:

找到 http-nio-7001-exec-362  线程,传入的参数:

入参=ROLE_PARAMS,administrator

6、异常详细信息,关联代码的地方:

7、对应代码的地方:

 

8、去看一下redis中的数据,get key,发现是存在的,所以排除了是redis没有获取到的问题;

而且不是每次get都会报错,偶然性的; 

9、但是redis获取key的时候,是失败了,而我们的redis,用的是

RedisTemplate,springboot集成的

  pom中引用的redis,注意这里,并没有添加指定的版本号,如果不指定版本号,spring-boot-starter-parent 会为我们提供常用jar包版本(如果不用指定,会有一个默认指定)

10、用jar -vtf   *.jar 命令,解压查看集成的版本:

这里用了lettuce-core-5.1.8.RELEASE.jar的版本

11、问题猜测,尝试解决:

用的springboot自带的redis,底层集成了lettuce,

以lettuce驱动连接redis的过程当中,会出现连接断开的情况,导致无法新增成功,超过一定时间还没有正常,就会出现连接超时的情况;

修改后有待验证!

解决方案,在pom.xml中更换指定的lettuce版本,或者更换成jedis客户端,这里排除掉lettuce:

 

12、参考以下大量博客,猜测得出结论,版本问题:

Redis command timed out nested exception is io.lettuce.core.RedisCommandTimeoutException_single_cong的博客-CSDN博客

SpringBoot集成Redis后,运行一段时间后发现RedisCommandTimeoutException - 灰信网(软件开发博客聚合)
Issues · lettuce-io/lettuce-core · GitHub
 

 Springboot2.x集成lettuce连接redis集群报超时异常Command timed out after 6 second(s) - 朱季谦 - 博客园Lettuce bug(RedisCommandTimeoutException) in spring-boot-autoconfigure 2.0.5 · Issue #1756 · lettuce-io/lettuce-core · GitHub


io.lettuce.core.RedisCommandTimeoutException: Command timed out · Issue #1092 · lettuce-io/lettuce-core · GitHub

 

 

  • 8
    点赞
  • 20
    收藏
    觉得还不错? 一键收藏
  • 3
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论 3
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值