线上碰到一个问题:
redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
at redis.clients.util.Pool.getResource(Pool.java:22)
线上会相隔不定时的天数后出现一次JedisPool种getresouce拿不到resource的情况。中间陆陆续续上过很多次线,然后废了很大劲努力排除掉了业务可能和多次上线的代码问题。业务数据量即便是在测试环境种建造了更多,也不会导致那种情况的出现。而业务代码测试环境和线上相同,后来在测试环境压测的压力和线上差不多的情况下,也不会重现这个问题。
后来就有一种束手无策的感觉了,最后只能推论是当时应用集群到Redis集群的网络出了问题了,但是由于种种原因一直没有在集群间添加网络状态的监控,也就只能是猜测了,但是又没办法重现。后来偷偷在线上的一台服务器上面添加了ping的监控,很简单:ping -i 1 192.168.134.155 > pinglog_{`date +%Y-%m-%d`}.log &,该命令的效果比较简单,就是每隔1sping一次目标服务器,然后打印到按天分开的日志里面。然而这种事情不再出现我们酒没办法验证推论,领导又催的非常紧,没办法还是需要验证出来啊。
开始的时候,根据代码来找原因,代码里面从jedispool种获得jedis资源实例的代码是使用了java7里面的try-with-resouce的写法,也就是用完之后,于是就怀疑是不是这种写法,在try块里面有了其他异常会导致resouce无法正常关闭,导致某个Jedis实例用完后没有还给JedisPool,导致资源不足?
public class JedisTest { private static final JedisPool jedisPool; static { JedisPoolConfig config = new JedisPoolConfig(); config.setMaxIdle(20); config.setMaxTotal(40); config.setMinIdle(10); jedisPool = new JedisPool(config, "127.0.0.1", 8279, 1000); } public static void main(String[] args) { try(Jedis jedis = jedisPool.getResource()){ throw new Exception("~"); }catch (Exception e){ //do nothing } } }
后来其实在JedisPool里面的断点很容易就可以看到java7 并没有错误,多心了。
于是,那还是回归主题,其实只要认真分析,不会又那么困难的问题出现:
其实getresouce报错有两种可能:
1、本身有错误---排除,首先如果这个方法有错误,那么之前应该会一直出现,或者其他人也早该把开源包的错误爆出,排除这种可能;
2、就是在规定时间内没取到资源。
刚才我们看maxtotal里面定义了池子最大就40个,如果真的40个都在用,并且在超时的100ms内没人return resouce,那报错也正常。
也就是说,我们出现了40个全部被用到,并且在超时的100ms内没有任何资源还给JedisPool。
后来恰好,在打印的jstack的信息种发现了大量的time_waiting状态的线程在等待从Jedispool.getResouce().
那么什么情况下会导致这个情况出现?
假设现在并发来了41个请求,然后其中40个正常的进行,但是第41没拿到资源,于是等待规定的超时时间,但是这会从应用到Redis集群间网络出现抖动,暂时不通,会导致40个请求种的里面的jedis的get或者set操作变慢甚至超时。
我们设想一种情况:从jedisPool里面拿资源的超时时间是100ms,程序里面进行get或者set资源的是200ms超时,那么就有可能出现这种情况。
事实证明我们的配置确实是jedis里面去get或者set一个key的时候,超时时间是200ms,那也就是说,如果网络发生了抖动,那就会在并发的情况下迅速耗光资源池,然后超时后报错才还回去,但是那个时间早就发生了getResouce的错误。
Bingo,其实很简单的原因,那就是没有正确的理解两个超时时间之间的关系。
我们可以简单测试一下:
public static void main(String[] args) { ExecutorService service = Executors.newFixedThreadPool(20); for(int i = 0;i < 20 ;i ++){ service.execute(new Runnable() { @Override public void run() { try(Jedis jedis = jedisPool.getResource()) { Thread.sleep(200L); } catch (InterruptedException e) { System.out.println(e); } } }); } }
由于本地环境问题,只是示例代码,就不执行了。其实很容易就还原了问题出来。
后面只要调小jedis的get和set方法的超时时间,同时也尽量小的使用getresource的超时时间(这里为什么不加大,因为在高并发的情况下会迅速耗光线程数量,jstack里面甚至出现了500个线程有450个是time_waiting的状态,这可不是我们想要的结果)。
然后在服务器之间添加监控和警报,及时报警进行网络的修复。