项目版本
spingboot使用2.3.4.RELEASE，内置的lettuce版本为5.3.4.RELEASE
服务为容器化部署，redis裸机部署
redis是单节点（生产情况redis使用sentinel集群，未出现此类问题）
问题描述
- 项目初启动时，lettuce连接及查询正常。
- 但是隔一定的时间间隔服务无请求（大概1天？），接口再次实行会报错，日志打印
org.springframework.dao.QueryTimeoutException: Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeou
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[tomcat-embed-core-9.0.38.jar:4.0.FR]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.springframework.web.filter.ForwardedHeaderFilter.doFilterInternal(ForwardedHeaderFilter.java:149) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.9.RELEASE.jar:5.2.9.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.coyote.AbstractProtocol C o n n e c t i o n H a n d l e r . p r o c e s s ( A b s t r a c t P r o t o c o l . j a v a : 868 ) [ t o m c a t − e m b e d − c o r e − 9.0.38. j a r : 9.0.38 ] a t o r g . a p a c h e . t o m c a t . u t i l . n e t . N i o E n d p o i n t ConnectionHandler.process(AbstractProtocol.java:868) ~[tomcat-embed-core-9.0.38.jar:9.0.38] at org.apache.tomcat.util.net.NioEndpoint ConnectionHandler.process(AbstractProtocol.java:868) [tomcat−embed−core−9.0.38.jar:9.0.38]atorg.apache.tomcat.util.net.NioEndpointSocketProcessor.doRun(NioEndpoint.java:1590) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_275]
at java.util.concurrent.ThreadPoolExecutor W o r k e r . r u n ( T h r e a d P o o l E x e c u t o r . j a v a : 624 ) [ ? : 1.8. 0 2 75 ] a t o r g . a p a c h e . t o m c a t . u t i l . t h r e a d s . T a s k T h r e a d Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_275] at org.apache.tomcat.util.threads.TaskThread Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0275]atorg.apache.tomcat.util.threads.TaskThreadWrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.38.jar:9.0.38]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
Caused by: io.lettuce.core.RedisCommandTimeoutException: Command timed out after 10 second(s)
at io.lettuce.core.ExceptionFactory.createTimeoutException(ExceptionFactory.java:51) ~[lettuce-core-5.3.4.RELEASE.jar:5.3.4.RELEASE]
at io.lettuce.core.LettuceFutures.awaitOrCancel(LettuceFutures.java:119) ~[lettuce-core-5.3.4.RELEASE.jar:5.3.4.RELEASE]
at io.lettuce.core.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:75) ~[lettuce-core-5.3.4.RELEASE.jar:5.3.4.RELEASE]
at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:79) ~[lettuce-core-5.3.4.RELEASE.jar:5.3.4.RELEASE]
at com.sun.proxy.$Proxy191.get(Unknown Source) ~[?:?]
at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.get(LettuceStringCommands.java:66) ~[spring-data-redis-2.3.4.RELEASE.jar:2.3.4.RELEASE]
… 64 more
看现象盲猜：服务器对长时间不活跃的连接举行了关闭，而客户端没有探活机制，一直在持有旧连接，有请求的时候由于服务端已经关闭了连接导致客户端超时，lettuce的重试机制新建连接，最后恢复。
ps:一开始也猜测过服务器的负载过大导致redis实行超时，但是查询过服务器的负载发现并不高，同时本地redis客户端连接查询速度都非常快，因此排除负载问题。
解决步骤
第一步
我的项目中lettuce配置为：
- spring.redis.database=0
- spring.redis.lettuce.pool.max-active=16
- spring.redis.lettuce.pool.min-idle=0
- spring.redis.lettuce.pool.max-wait=5000
- spring.redis.lettuce.pool.max-idle=20
- spring.redis.timeout=1200
- spring.redis.lettuce.pool.time-between-eviction-runs=1000
- 修改为
- spring.redis.lettuce.pool.min-idle=1
- 增加,以下两个配置理论上只对cluster集群的redis生效，我测试为单节点，所以可能没有用，考虑到有同学是这个场景，可以尝试
- spring.redis.lettuce.cluster.refresh.adaptive=true
- spring.redis.lettuce.cluster.refresh.period=10s
观察结果：redis连接超时非常仍旧会有，但是接口恢复速度明显提升。以前三五分钟才会恢复，调整后第一次非常，秒级的第二三次查询会恢复 。
第二步（此操纵有效！！！）
若第一步无效，则在redisTemplate的bean中对lettuceConnectionFactory增加validateConnection属性设置。
源码中是在获取连接时如果连接中断则更新连接，不确定在连接保持的时候是否能够 持续 查验并更新连接，而非在获取连接时的 一次性 校验。如果不行，大概须要手动写定时任务做连接校验，但是这种实现太丑了。
当然，如果就算是在获取连接时的一次性校验，只要校验效率足够高，能够毫秒级的完成校验及连接更新，在用户感知上趋近于无，且不触发上述非常，则最好。
- @Bean
- public RedisTemplate<String, Object> redisTemplate(LettuceConnectionFactory lettuceConnectionFactory) {
- // 重点
- lettuceConnectionFactory.setValidateConnection(true);
-
- RedisTemplate<String, Object> redisTemplate = new RedisTemplate<>();
- redisTemplate.setConnectionFactory(lettuceConnectionFactory);
- redisTemplate.setKeySerializer(new StringRedisSerializer());
- redisTemplate.setHashKeySerializer(new StringRedisSerializer());
- redisTemplate.setValueSerializer(new JdkSerializationRedisSerializer());
- redisTemplate.setHashValueSerializer(new JdkSerializationRedisSerializer());
- redisTemplate.afterPropertiesSet();
- return redisTemplate;
- }
服务前期已接入pinpoint，通过pinpoint请求调用分析，可以明显看到，连接确实是已经断开，但是因为我们有ValidateConnection的连接校验逻辑，ping的时候没有相应，因此更新了连接，后续的服务逻辑实行没有碰到非常了。
后续的接口正常实行是毫秒级的耗时：
缘故原由分析：
lettuce中的连接因为长时间空闲，因此被断开，这个断开的操纵不确定是服务端还是客户端发起的，后续有时间再深入研究吧。
这个也解释了为什么生产情况没有碰到这个问题，因为生产情况有大量且持续的请求，redis连接是活跃的，因此不存在连接因空闲被中断的问题。
测试情况访问量小且不连续（空闲时间多），导致连接被中断，造成了假死现象。目前使用不报错，只管长时间空闲后的第一次访问会因为连接查验+重置的操纵导致耗时增加，但是接口不会报错，后续逻辑均正常实行，在可接受范围内。
若小伙伴们仍以为初次连接的高耗时不可接受，那就写个定时任务，定时实行validateConnection()方法吧，保持lettuce连接池中的连接均活跃，我是不太喜好这么整。
极度方案
不嫌麻烦的话，可以把客户端换回jedis，jedis中带有探活逻辑。
20241114更新
别的一个服务同样碰到此问题，但加完lettuceConnectionFactory.setValidateConnection(true);之后，每次连接校验的时候都会报
- 2024-11-14 11:26:30.009|INFO |9076|scheduling-1|org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.validateConnection(LettuceConnectionFactory.java:1413)|Validation of shared connection failed. Creating a new connection.
- @Resource
- private LettuceConnectionFactory connectionFactory;
-
- /**
- * 每隔30s进行一次连接校验避免连接失效
- */
- @Scheduled(cron="0/30 * * * * ?")
- public void task() {
- log.info("=============连接校验开始=======");
- connectionFactory.validateConnection();
- log.info("=============连接校验结束=======");
- }
先去github搜issue：
https://github.com/redis/lettuce/issues/2177
发现此issue跟我的现象一模一样，但是很遗憾没有解决方案。
https://github.com/redis/lettuce/issues/1428
讨论很多，比较深入
https://bbs.csdn.net/topics/392566194
有解决方案
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！更多信息从访问主页：qidao123.com:ToB企服之家，中国第一个企服评测及商务社交产业平台。 |
