问题介绍
最近查看生产日志,在日志中发现一些“Unexpect end of stream”的报错,这个异常之前也出现过,但之前出现的次数都比较少,没太引起注意,最近出现的此类错误的次数越来越多,于是引起了重视。
环境介绍
Jedis的版本是:2.7.3
redis的版本是:2.6.0
jedis的配置如下:
<bean id="jedisConfig" class="org.apache.commons.pool2.impl.GenericObjectPoolConfig">
<property name="maxToal" value="100" />
<property name="maxIdle" value="100" />
<property name="minIdle" value="10" />
<property name="testWhileIdle" value="true" />
<property name="minEvictableIdleTimeMillis" value="160000" />
</bean>
解决过程
- 首先通过异常提示,可以确定的是服务端主动关闭了连接,导致客户端拿到一个已经被服务端关闭的连接在执行命令,导致抛出异常。
- 在网上查询资料,看大家是否也遇到过此类问题,结合自己的经验来看,没能很好地解决这个问题。
- 找DBA拿了一下redis的配置,发现redis的超时配置是300s,maxclients采用的是默认值10000,client-output-buffer-limit normal 512M 256 60。
- 猜测。maxclients的设置成10000,这个参数应该不会导致redis主动关闭连接的情况,client-output-buffer-limit被设置成一个相对比较大的数值也不会导致redis主动关闭连接的情况,于是就把目标放在了timeout参数上。我们知道在配置了timeout参数的情况下,redis会每隔一段时间将连接到redis的空闲连接关闭掉,这个空闲的时间就是通过timeout设置的。
- 翻阅了JedisPool的源码,发现在配置了timeBetweenEvictionRunsMillis参数的情况下(该参数值大于0),JedisPool会启动一个Timer定时关闭空闲连接(连接是否空闲的判断依据是连接的空闲时间大于minEvictableIdleTimeMillis则连接空闲),每次关闭的空闲连接数是由参数numTestsPerEvictionRun设置的,该参数的默认值是3,结合我们对JedisPool的配置,也就是说JedisPool每160s才关闭三个空闲连接,而redis的配置的timeout参数是300s,所以就有可能导致拿到被关闭的空闲连接的情况导致该异常。
- 验证。重新设置JedisPool参数后,并做测试之后未出现此类错误。
后记
为啥Jedis在抛出该错误的时机是读取redis返回结果的时候抛出异常呢?而不是在写redis命令到redis的时候报异常呢?具体参考RedisInputStream
类。一开始我也不解,为了重现此类场景我模拟了客户端与服务端的通信,并让服务端主动关闭连接,结果与此现象一致。
原因是tcp的四次挥手机制,服务端关闭连接后,客户端会马上返回一个ack,使服务端从fin-wait-1 -> fin-wait-2状态,客户端处于close-wait状态,我们知道处于close-wait状态的一端可以继续往另一端发送数据而不能读取数据。