springboot+atomikos+druid 資料庫連線失效分析

kbkb發表於2022-02-07
Spring BootUI資料庫

一、起因

　　最近檢視系統的後臺日誌，經常發現這樣的報錯資訊：The last package successfully received from the server was 40802382 milliseconds ago，截圖如下所示。

　　由於我們的系統都是在白天使用，夜裡基本上沒有使用者使用，再加上以上的報錯資訊都是出現在早晨，結合錯誤日誌初步分析，應該是資料庫連線超時自動斷開了。百度一番後，得知Mysql的預設連線時間是8小時，超過8小時沒有操作後就會自動斷開連線，但是已經使用了druid資料庫連線池，按理說已經對資料庫連線做了保護和檢查，不應該出現這樣的問題。要想徹底弄明白這個問題，就只能去研究druid資料庫連線池框架了。

二、Druid資料庫連線池

　　專案的資料庫連線池基本配置資訊如下所示

 　　通過以上的配置分析得知，一個資料庫連線從連線池中借出後經過21600s即6小時後會被強制回收，不會超過Mysql的預設8小時，而且也不存在這麼長時間的事務，所以不太可能是因為資料庫連線借出超時導致上面的錯誤，那麼就是從資料庫連線池中申請的連線已經超時了？似乎也不太可能，因為有檢查機制，即每隔30s就會檢查一次連線池中的連線是否超時，並且連線池中允許存在的空閒連線最大時間為540s。這就奇怪了，到底是什麼原因導致上面的錯誤呢？這時注意到上述錯誤堆疊中的com.atomikos.datasource.pool.ConnectionPool.findOrWaitForAnAvailableConnection。是否問題的原因在於使用了Atomikos呢，帶著這樣的疑惑去閱讀了Druid和Atomikos相關的原始碼。

　　由於Atomikos連線池是基於Druid連線池之上的，所以Atomikos新建和銷燬資料庫連線都是從Druid連線池中借出和歸還資料庫連線，而不是直接與資料庫互動，那麼我們就來看看Druid是如何維持資料庫連線的。

public DruidPooledConnection getConnection(long maxWaitMillis) throws SQLException {
　　　　 //初始化檢查配置和後臺執行緒
        init();

        if (filters.size() > 0) {
            FilterChainImpl filterChain = new FilterChainImpl(this);
            return filterChain.dataSource_connect(this, maxWaitMillis);
        } else {
            return getConnectionDirect(maxWaitMillis);
        }
    }

從Druid連線池中獲取資料庫連線，先呼叫init()方法進行初始化工作，然後呼叫getConnectionDirect()獲取連線。

decrementPoolingCount();
DruidConnectionHolder last = connections[poolingCount];
connections[poolingCount] = null;
DruidPooledConnection poolalbeConnection = new DruidPooledConnection(holder);

public DruidPooledConnection(DruidConnectionHolder holder){
        super(holder.getConnection());

        this.conn = holder.getConnection();
        this.holder = holder;
        this.lock = holder.lock;
        dupCloseLogEnable = holder.getDataSource().isDupCloseLogEnable();
        ownerThread = Thread.currentThread();
        connectedTimeMillis = System.currentTimeMillis();
}

上述是獲取連線池中連線的關鍵程式碼，即獲取connections陣列中的最後一個元素，獲取到Holder後還需要將其封裝為DruidPooledConnection，這時該連線的connectedTimeMillis會被賦值為當前時間，這個時間在後續的分析中會非常重要。

　　因為配置了testWhileIdle為true，所以需要進行下面的有效性檢查，獲取該連線的上次活躍時間，得到空閒時間，如果超過30s則做有效性檢查。

long idleMillis  = currentTimeMillis - lastActiveTimeMillis;

long timeBetweenEvictionRunsMillis = this.timeBetweenEvictionRunsMillis;

if (timeBetweenEvictionRunsMillis <= 0) {
      timeBetweenEvictionRunsMillis = DEFAULT_TIME_BETWEEN_EVICTION_RUNS_MILLIS;
}

if (idleMillis >= timeBetweenEvictionRunsMillis
        || idleMillis < 0 // unexcepted branch
         ) {
     boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
     if (!validate) {
        if (LOG.isDebugEnabled()) {
             LOG.debug("skip not validate connection.");
        }

        discardConnection(poolableConnection.holder);
        continue;
        }
}
long timeMillis = (currrentNanos - pooledConnection.getConnectedTimeNano()) / (1000 * 1000);

if (timeMillis >= removeAbandonedTimeoutMillis) {
    iter.remove();
    pooledConnection.setTraceEnable(false);
    abandonedList.add(pooledConnection);
}

同時，由於配置了removeAbandoned為true，所以需要檢查活躍連線是否超時，如果超時就斷開物理連線。下面看一下連線池的回收方法recycle的關鍵程式碼

if (phyTimeoutMillis > 0) {
    long phyConnectTimeMillis = currentTimeMillis - holder.connectTimeMillis;
    if (phyConnectTimeMillis > phyTimeoutMillis) {
          discardConnection(holder);
          return;
    }
}
lock.lock();
try {
    if (holder.active) {
        activeCount--;
        holder.active = false;
    }
    closeCount++;

    result = putLast(holder, currentTimeMillis);
    recycleCount++;
} finally {
    lock.unlock();
}

在對資料庫連線進行回收時，如果連線時間超過了資料庫的物理連線時間（預設8小時）則需要斷開物理連線，否則就呼叫putLast方法將該連線回收到連線池。

boolean putLast(DruidConnectionHolder e, long lastActiveTimeMillis) {
        if (poolingCount >= maxActive || e.discard) {
            return false;
        }

        e.lastActiveTimeMillis = lastActiveTimeMillis;
        connections[poolingCount] = e;
        incrementPoolingCount();

        if (poolingCount > poolingPeak) {
            poolingPeak = poolingCount;
            poolingPeakTime = lastActiveTimeMillis;
        }

        notEmpty.signal();
        notEmptySignalCount++;

        return true;
}

注意上述標紅的地方，回收的這個連線的lastActiveTimeMillis被重新整理為當前時間，這個時間也是非常重要的，在後續分析中會用到。

三、Atomikos框架

　　專案關於Atomikos的配置資訊，如下所示

從上面的配置可以看出，atomikos連線池的最大連線數是25個，最小連線數是10個，連線最大的存活時間是500s，下面來看一下atomikos的原始碼。

private void init() throws ConnectionPoolException
{
　　　　
     if ( LOGGER.isTraceEnabled() ) LOGGER.logTrace ( this + ": initializing..." );
　　　//如果連線池最小連線數沒有達到就新增資料庫連線
     addConnectionsIfMinPoolSizeNotReached();
　　  //開啟維持連線池平衡的執行緒
     launchMaintenanceTimer();
}

 以上是Atomikos初始化的部分，先補充資料庫連線池達到最小連線數，然後開啟後臺執行緒維持連線池的平衡。

private void launchMaintenanceTimer() {
        int maintenanceInterval = properties.getMaintenanceInterval();
        if ( maintenanceInterval <= 0 ) {
            if ( LOGGER.isTraceEnabled() ) LOGGER.logTrace ( this + ": using default maintenance interval..." );
            maintenanceInterval = DEFAULT_MAINTENANCE_INTERVAL;
        }
        maintenanceTimer = new PooledAlarmTimer ( maintenanceInterval * 1000 );
        maintenanceTimer.addAlarmTimerListener(new AlarmTimerListener() {
            public void alarm(AlarmTimer timer) {
                reapPool();
　　　　　　　　　 //如果達到了最大的存活時間就移除該連線
                removeConnectionsThatExceededMaxLifetime();
　　　　　　　　　 //如果沒有滿足最小連線數就新增連線
                addConnectionsIfMinPoolSizeNotReached();
　　　　　　　　   //移除超過最小連線數以外的連線
                removeIdleConnectionsIfMinPoolSizeExceeded();
            }
        });
        TaskManager.SINGLETON.executeTask ( maintenanceTimer );
    }

 在配置中，maintenanceInterval的值為30，即每個30秒執行一次上述的四個方法，主要看一下removeConnectionsThatExceededMaxLifetime()這個方法。

private synchronized void removeConnectionsThatExceededMaxLifetime()
    {
        long maxLifetime = properties.getMaxLifetime();
        if ( connections == null || maxLifetime <= 0 ) return;

        if ( LOGGER.isTraceEnabled() ) LOGGER.logTrace ( this + ": closing connections that exceeded maxLifetime" );

        Iterator<XPooledConnection> it = connections.iterator();
        while ( it.hasNext() ) {
            XPooledConnection xpc = it.next();
            long creationTime = xpc.getCreationTime();
            long now = System.currentTimeMillis();
            if ( xpc.isAvailable() &&  ( (now - creationTime) >= (maxLifetime * 1000L) ) ) {
                if ( LOGGER.isTraceEnabled() ) LOGGER.logTrace ( this + ": connection in use for more than " + maxLifetime + "s, destroying it: " + xpc );
　　　　　　　　　 //如果超過最大的存活時間就銷燬該連線
                destroyPooledConnection(xpc);
                it.remove();
            }
        }
        logCurrentPoolSize();
    }

上述方法遍歷資料庫連線池中的所有連線，如果存活時間超過maxLifetime即500s就銷燬該連線，這時由於連線池中的連線數就小於minPoolSize，所以會立即補充新的連線到連線池中。那麼，系統在夜間沒有使用者使用時，Atomikos連線池的執行狀態為：維持最小的連線數10個資料庫連線，當這10個連線超過500s時就會銷燬，再重新建立10個新的資料庫連線，不斷重複這樣的操作。

四、分析與總結

　　下面我們開始分析產生錯誤日誌的原因，當沒有使用者使用系統時，Druid連線池應該有10個空閒的連線，Atomikos連線池也有10個空閒的連線，這時Atomikos的10個連線達到了最大的生存時間500s，就需要銷燬這些連線，對於Druid來說就是回收連線，呼叫recycle方法。由於這10個連線應該是500s之前從Druid連線池借出的，所以它們的connectTimeMillis也是500s之前的時間，即物理連線時間肯定小於8小時，可以成功回收到Druid連線池中，同時lastActiveTimeMillis也更新為當前時間，放在connections陣列的末尾。

　　與此同時，Atomikos還需要重新生成10個新的連線，即從Druid連線池獲取10個連線，呼叫getConnection方法，這時會進行有效性的檢查，又因為lastActiveTimeMillis基本上為當前時間，所以idleMillis肯定比30s小，不需要進行select 1的連線資料庫操作，這樣即使該連線已經失效了還是會借出給Atomikos。每隔500s不斷迴圈上述操作，並且期間沒有使用者的操作，一旦超過8個小時的Mysql連線時間，Atomikos在使用資料庫連線時就會產生上述日誌中的錯誤了。

　　綜上所述，導致報錯的原因其實是使用了兩層資料庫連線池，這樣Druid連線池借出的資料庫連線並沒有被實際使用，這才導致這些資料庫連線成功躲避了Druid本身的檢查機制。

相關文章