性能问答>commoms-pool1.6 获取client超时>
6回复
2年前

commoms-pool1.6 获取client超时



项目中使用apache commoms-pool1.6 的GenericKeyedObjectPool来管理thrift客户端。参数设置为

this.pool.setMaxActive(100);
this.pool.setMaxIdle(20);
this.pool.setTestOnBorrow(true);
this.pool.setMaxWait(10000);
this.pool.setTestWhileIdle(true);
this.pool.setMinEvictableIdleTimeMillis(8分钟);
this.pool.setTimeBetweenEvictionRunsMillis(3分钟);

发现每天早上7-8 下午1点 4点左右会出现从pool中获取client慢的现象。
日志如下
20191119 171740 的屏幕截图.png

其中numberActive是通过pool.getNumActive(endpointKey)来获取的。可以看出每个endpoint的active数量不高。

查看过GenericKeyedObjectPool的源码,发现内部使用的锁是对象本身,而且只会在更新内部状态变量时持有,创建client时不持有。而导致线程阻塞的情况是对应key的client到达MaxActive时,调用borrowObject的线程会阻塞等待有可用client.对比日志中active的数量基本是1个两个,所以应该不是这种情况引起的获取超时。猜测是对多线程对GenericKeyedObjectPool对象锁的竞争引起。

出问题的时间点,进行了 jstack dump
截图如下:

20191119 165253 的屏幕截图.png
发现日志中很多线程阻塞在GenericKeyedObjectPool对象上
而持有这个锁的线程
20191119 165547 的屏幕截图.png
似乎也在阻塞?
有时是阻塞在
20191119 165503 的屏幕截图.png
另外查看了问题时间点的qps thread数量 cpu利用率 内存等都没有完全的相关性。

还查看过问题的点的gc情况,full gc也没有发生,应该不是full gc引起的停顿
发生前gc:
20191119 165951 的屏幕截图.png
发生后gc:
20191119 170022 的屏幕截图.png

jvm配置
20191119 172524 的屏幕截图.png

此问题困扰鄙人多日,一直没找到原因,在此请求perfma社区各位大佬帮忙看下,不胜感激!

3667 阅读
请先登录,查看4条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步