前言:这是几个月前压测某项目登陆接口时遇到的性能问题,虽然你们不必定会遇到,可是分析定位问题的思路仍是能够参考一下。git
一、压测过程当中,tps忽然剧烈降低,且全部请求失败(下图绿线)github
服务端错误日志,获取不到redis链接池(Could not get a resource from the pool),另外,从下图能够看到,当前jedis版本是2.9.1web
获取不到链接,多是这四种状况:
Timeout waiting for idle object
Pool exhausted
Unable to activate object
Unable to validate objectredis
下图,表示等待空闲链接超时apache
二、jedis的链接池就是用commons-pool2来管理的,使用jvisualvm打开对应的应用进程,根据上图的提示,找到org.apache.commons.pool2多线程
能够看到相关的配置svg
活动链接1000,链接满了性能
dump堆内存进行分析(此时压测已经中止)测试
根据文章开头的日志信息,搜索org.apache.commons.pool2.impl,而后双击下面的DefaultPooledObject类线程
进入实例
实例状态是ALLOCATED
ALLOCATED表示在使用中,压测结束后,虽然链接释放了,可是资源没归还
下面能够看到,dataSource为空
若是dataSource为空,就走else,说明只关闭了链接,资源没归还到队列中,后面的线程就获取不到空闲链接
能够看到,实例有不少
为何会出现这种状况呢?
经过查看源码及官网,能够肯定,这是2.9.1的bug,改成2.9.0就没报错了。
官网:https://github.com/xetorthio/jedis/pull/1918/commits/df1bffa3c77f4ede4c912f2c3e78b5c8857725e7
Move dataSource reset before connection returned to pool.
If datasource reset after the connection returned to pool, it might reset the datasource after it was allocated to another thread
意思是:在链接返回到池以前重置移动数据源。
若是数据源在链接返回到池以后重置,那么它可能会在将数据源分配给另外一个线程以后重置该数据源
三、出现不少实例状态是ALLOCATED,dataSource为null的缘由:
在多线程时,若是dataSource在链接释放后重置(根据代码逻辑可知:链接释放前,资源已经归还,可是未重置),可能在重置前,这个dataSource已经分配给另一个线程了,此时重置,就把已经获取了这个dataSource的线程的dataSource重置了,这样就致使不少状态是ALLOCATED、dataSource值为null的实例,进而这些线程都只关闭了链接,而没有归还资源,最终致使获取不到链接,即文章开头的异常日志信息,这也印证了都是压测一段时间后才开始报错的现象。
另外,有些性能问题,仍是须要必定的代码能力,并且,测试会代码是个趋势。