
問題的描述在上面,我這里簡(jiǎn)單復(fù)述一下這個(gè)問題:當(dāng)應(yīng)用被加載的時(shí)候,會(huì)有大量的請(qǐng)求被觸發(fā),這時(shí)可以看到連接數(shù)迅速增長(zhǎng)到110,活動(dòng)連接數(shù)也達(dá)到102。但后來發(fā)現(xiàn),連接數(shù)迅速下降到40,同時(shí)看到“Failed Reserve Request Count”迅速增長(zhǎng)。同時(shí)Oracle DBA也報(bào)告說很多新的連接被建立(遠(yuǎn)大于之前的110)。應(yīng)用開始拋出“XX connection pool is disabled”的錯(cuò)誤。一段時(shí)間以后,連接池自我恢復(fù)完畢,連接重新回到110,但DBA看到連接此時(shí)沒有減少,任然維持在240左右。
直覺上來看,這個(gè)問題應(yīng)該是連接池臨時(shí)disable或者flush導(dǎo)致的,而不是shrink導(dǎo)致(從后面的pool disable也能看出來,pool是被disable而不是shrink了),可以通過netstat看一下db端的連接狀態(tài),應(yīng)該很多處于close_wait狀態(tài),記連接關(guān)閉請(qǐng)求由weblogic端發(fā)起,但截至問題發(fā)生的時(shí)刻,連接本身尚未關(guān)閉。為什么會(huì)出現(xiàn)連接池臨時(shí)disable的狀況呢?問題根源在于test-connections-on-reserve的設(shè)定后,當(dāng)某個(gè)連接的idle時(shí)間超過SecondsToTrustAnIdlePoolConnection 后,這個(gè)連接在返回客戶端之前,會(huì)進(jìn)行連接測(cè)試。測(cè)試之前,WLS首先會(huì)調(diào)用checkHang()來檢查之前的連接測(cè)試是否存在掛起的現(xiàn)象,如果掛起,我們需要disable整個(gè)connection pool,同時(shí)重新初始化這個(gè)連接池。那么什么情況下,連接測(cè)試會(huì)被視為掛起呢?
當(dāng)一個(gè)連接被測(cè)試后(在測(cè)試結(jié)果返回之前),測(cè)試記錄(TestRecord)會(huì)被記錄到一個(gè)叫做currentlyRunningTests的TreeSet變量中,當(dāng)測(cè)試返回后,無論結(jié)果成功與否,這個(gè)record都會(huì)被從currentlyRunningTests中刪除。在連接被測(cè)試之前,checkHang()被調(diào)用,checkHang的邏輯如下:
1
// check and process test hang
2
private void checkHang() throws ResourceDisabledException
3

當(dāng)currentlyRunningTests中的記錄數(shù)超過五條的時(shí)候,第六條會(huì)被返回,否則不會(huì)返回測(cè)試記錄,即suspectHang將返回false。而當(dāng)記錄數(shù)超過五條的時(shí)候,我們會(huì)拿第六條記錄作為checkHang的樣本。每次連接測(cè)試成功后,wls會(huì)將這一次的測(cè)試時(shí)間作為一個(gè)樣本時(shí)間,記錄到一個(gè)successfulTestTimes數(shù)組中,這個(gè)數(shù)組最多維護(hù)10條記錄,然后wls會(huì)這10個(gè)時(shí)間中,最長(zhǎng)的那個(gè)作為樣本測(cè)試時(shí)間。最后再用這個(gè)樣本測(cè)試時(shí)間*TYPICAL_TIME_FACTOR(hard-coded value is 1.2)作為連接返回時(shí)間,如果我們的樣本record測(cè)試時(shí)間已經(jīng)超過樣本測(cè)試時(shí)間,那么suspectHang將返回true, 否則返回false。如果suspectHang返回true,當(dāng)前線程進(jìn)入for循環(huán),sleep20次(SLEEP_COUNT)后,如果測(cè)試仍然沒有返回,且currentlyRunningTests中前五個(gè)測(cè)試記錄也沒有返回的話,那么這個(gè)測(cè)試將會(huì)被視為測(cè)試掛起,這個(gè)pool就會(huì)被disable。可能引起這問題的條件是:之前的數(shù)據(jù)庫性能很好,測(cè)試都能夠迅速返回,可能測(cè)試耗時(shí)都是毫秒級(jí)的。突然某一時(shí)刻,數(shù)據(jù)庫性能急劇下降,導(dǎo)致測(cè)試耗時(shí)很長(zhǎng)(當(dāng)然包括前面的五條測(cè)試記錄)。WLS以之前的測(cè)試時(shí)間作為樣本時(shí)間來衡量此時(shí)此刻的測(cè)試結(jié)果,在數(shù)據(jù)庫性能下降、測(cè)試響應(yīng)慢的時(shí)候,很容易被當(dāng)成測(cè)試掛起來處理(即disable整個(gè)pool)。
2

3


于是客戶端看到了pool被disable的現(xiàn)象,那么Pool什么時(shí)候會(huì)被重新初始化呢,pool中有一個(gè)Healh Maintainece Task,每隔五秒,這個(gè)task會(huì)啟動(dòng)一次,用于檢查那些被disabled的pool,如果連接測(cè)試通過,那么這個(gè)Pool會(huì)被重新enable。
這個(gè)實(shí)現(xiàn)方式不是很好,于是10.3.4中對(duì)這塊做了重新設(shè)計(jì)。我們現(xiàn)在看看10.3.4中是如何實(shí)現(xiàn)的吧!
10.3.4引入了一個(gè)可配置變量weblogic.resourcepool.max_test_wait_secs,默認(rèn)為10秒,如果通過-Dweblogic.resourcepool.max_test_wait_secs將它設(shè)為0,那么連接測(cè)試的時(shí)候,將不再做checkHang。如果這個(gè)值不是0,那么checkHang的最長(zhǎng)等待時(shí)間將是這個(gè)指定的值,而不再像10.3.0中,最長(zhǎng)等待時(shí)間為樣本時(shí)間*20。同時(shí)修改了TYPICAL_TIME_FACTOR,這個(gè)值由1.2變成了10,這個(gè)值得修改對(duì)suspectHang有一定影響,但影響不大,這個(gè)參數(shù)也是硬編碼的,客戶不能對(duì)它進(jìn)行配置。這兩個(gè)參數(shù)中,對(duì)checkHang影響比較大的還是weblogic.resourcepool.max_test_wait_secs,所以如果碰到類似問題,可以通過適當(dāng)?shù)男薷倪@個(gè)值來解決問題。