DBCP踩坑(一):产生大量TIME_WAIT

652 阅读2分钟

问题背景:压力测试时,发现存在大量TIME_WAIT连接,存在端口占满风险

问题分析:

  • 通过netstat查看TIME_WAIT连接,发现大量的TIME_WAIT连接是应用层连向某个IP的3306建立的,经过确认是该应用对应的数据库链接;
  • 根据目前的线索反推情况应该是应用和数据库不停的创建连接和断开链接导致的;
  • 但是应用层使用了DBCP1.4.0连接池,理论上不应该建立的连接数不应该超过maxActive才对;
  • 当前主要配置有:initialSize=5,maxActive=50,maxIdle=8,minIdle=5,maxWait=10000,testWhileIdle=true,validationQuery=SELECT 1,numTestsPerEvictionRun=10,minEvictableEvictionTimeMillis=180000,timeBetweenEvictionMillis=30000
  • 经过对其他测试环境的查看,发现其他环境并没有这个问题,只有压力测试环境有这个情况,所以这个问题肯定和高并发有关;
  • 应用日志并没有异常线索;
  • 基于上述分析,没有特别明确的排查方向,根据TIME_WAIT的原理,是由TCP连接中主动断开链接的一端进入该状态,维持2MSL(默认值)。
  • 从断开入手开始排查,发现Dbcp是通过_factory.destroyObject(obj)来进行链接断开的,同时因为日志中没有堆栈相关异常信息,所以应该是走正常中的断开逻辑,而不是异常后引发的断开; 排查涉及_factory.destroyObject(obj)调用的相关源码,最终找到问题:
@Override
    public void returnObject(T obj) throws Exception {
    //...省略非关键部分
    if((_maxIdle >= 0) && (_pool.size() >= _maxIdle)) {
        shouldDestroy = true;
    } else if(success) {
        // borrowObject always takes the first element from the queue,
        // so for LIFO, push on top, FIFO add to end
        if (_lifo) {
            _pool.addFirst(new ObjectTimestampPair<T>(obj));
        } else {
            _pool.addLast(new ObjectTimestampPair<T>(obj));
        }
        if (decrementNumActive) {
            _numActive--;
        }
        doAllocate = true;
    }
     //...省略非关键部分
    if(shouldDestroy) {
    try {
        _factory.destroyObject(obj);
    } catch(Exception e) {
        // ignored
    }
     //...省略非关键部分
}

这是dbcp正常归还连接池的逻辑,其中关键问题在于if((_maxIdle >= 0) && (_pool.size() >= _maxIdle))阅读代码发现,当连接池的大小大于maxIdle时就会走到下面_factory.destroyObject(obj)立即释放连接。即在归还连接时如果发现当前pool大小大于maxIdle则立即释放连接。

结合高并发的现象背景,我们在测试时的并发加到了800并发,所有请求都会进行数据库操作,在某个瞬间可能出现大量的SQL执行完毕进行连接归还,而我们配置的maxIdle=8太小,800并发下,同一时间归还连接数超过8个的概率就非常大了,于是触发_factory.destroyObject(obj)操作,断开链接,该链接对应的netstat进入TIME-WAIT。

问题定位清楚后,解决起来就简单了,将maxIdle调大,经过查看一些资料,建议将maxIdle设置的与maxActive相等。