问题描述:
生产环境代码日志里报出来redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream这个异常问题,平均每分钟都在刷同样的异常信息.对这个异常的理解大致可以定位为连接被掐断
org.springframework.data.redis.RedisConnectionFailureException: Unexpected end of stream.; nested exception is redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream.
at org.springframework.data.redis.connection.jedis.JedisExceptionConverter.convert(JedisExceptionConverter.java:67) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.jedis.JedisExceptionConverter.convert(JedisExceptionConverter.java:41) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.jedis.JedisConnection.convertJedisAccessException(JedisConnection.java:142) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.jedis.JedisHashCommands.convertJedisAccessException(JedisHashCommands.java:448) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.jedis.JedisHashCommands.hIncrBy(JedisHashCommands.java:222) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.DefaultedRedisConnection.hIncrBy(DefaultedRedisConnection.java:947) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.connection.DefaultStringRedisConnection.hIncrBy(DefaultStringRedisConnection.java:476) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.core.DefaultHashOperations.lambda$increment$2(DefaultHashOperations.java:79) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:225) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:185) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:96) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at org.springframework.data.redis.core.DefaultHashOperations.increment(DefaultHashOperations.java:79) ~[spring-data-redis-2.1.14.RELEASE.jar!/:2.1.14.RELEASE]
at com.yundasys.gatewayadmin.service.impl.PushLogStaticServiceImpl.recordMinuteLog(PushLogStaticServiceImpl.java:114) ~[classes!/:1.0.0]
at com.yundasys.gatewayadmin.service.impl.PushLogStaticServiceImpl.cacheStatsData(PushLogStaticServiceImpl.java:61) ~[classes!/:1.0.0]
at com.yundasys.gatewayadmin.service.KafkaMqService.lambda$consumerPushLog$0(KafkaMqService.java:96) ~[classes!/:1.0.0]
查看源码找到异常报出位置
private void ensureFill() throws JedisConnectionException {
if (count >= limit) {
try {
limit = in.read(buf);
count = 0;
if (limit == -1) {
throw new JedisConnectionException("Unexpected end of stream.");
}
} catch (IOException e) {
throw new JedisConnectionException(e);
}
}
}
问题分析:
查看监控并检查配置,未发现异常问题
百度到一个相同问题的博客 『https://www.cnblogs.com/benthal/p/10761868.html 』大致是分析了一下 testOnBorrow 和 testWhileIdle
起因是更改redis客户端的参数 testOnBorrow=true => testOnBorrow=false及连接池的大小相关参数(具体看上方的连接)后产生了上述异常
原本是怀疑 testOnBorrow=false 导致获取到了无效连接,或者是因为testWhileIdle=true 导致连接被回收进而导致异常,分析之后发现pool里的连接都是有效连接,所以连接的掐断并不是发生在客户端的配置上
博主的异常最终原因是创建了过多连接,并超过redis设置的最大连接数(maxclients=10000)导致的,
并且服务端还设置了timeout=5 即5s内空闲的连接会断开,最终解决方案需要调整连接数和服务端的超时时间
参数 | 默认值 | 解释 | 效果 |
testOnBorrow | false | 从pool里边获取连接之前会对连接进行校验,校验此连接是否可用 | 如果值为false意味着从pool中拿到的连接可能为无效连接 |
testWhileIdle | true | 空闲资源回收,当连接空闲超过半个小时时,会进行资源回收将旧连接销毁后创建新的连接 | testWhileIdle空闲检查时,pool里所有的连接都是有效 |
问题解决:
看完以上博客的分析就不再纠结客户端的配置问题,以下是我的排查思路分成3种,第一种就已经解决了我的问题
1.检查redis.conf中的timeout的值
最开始就没觉得这里会出问题,因为我们线上的redis中间件都是统一配置的timeout为0,后来手欠查了一下,还真有问题
当此时间设置过短时,同一个 jedis 链接,两次访问 redis 服务的时间间隔 > ${timeout} , 服务端会单方关闭这个jedis链接,
第二次使用这个jedis对象 操作 redis 时,会发生 Unexpected end of stream
, 可以将其设置成“0(无过期)”来验证此种场景,
2.检查 redis config 中的 client-output-buffer-limit
配置
client-output-buffer-limit normal 0 0 0 slave 0 0 0 pubsub 0 0 0
请根据实际情况合理设置Redis输出缓冲区限制,确定不是因为缓冲区太小,导致链接关闭,进而引起 Unexpected end of stream
,可以临时都设置成 “0(关闭缓冲区限制)” 来验证此种场景
3.优化客户端代码,增加重试机制
经过前两步的调试,根据业务实际情况,调整配置,但这样并不能完全杜绝 Unexpected end of stream
的发生,比如 “网络抖动”之类的场景下,依然会发生此问题(实际生产环境中,此种情况发生概率极低),
但是为了防止此异常引起 jvm宕机,建议在代码层面上增加加重试机制。