記一次獲取連接超時的排查過程Connection is not available, request timed out after 30002ms

背景

之前在壓測一個用java寫的應(yīng)用時,偶爾會報如下的錯誤:

org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30002ms.
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:305)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:474)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
    at com.quantil.cm.api.service.PurgeTaskService$$EnhancerBySpringCGLIB$$b4db5835.create(<generated>)

排查過程

1. MySQL最大連接數(shù)排查

show variables like '%conn%'

image.png

MySQL設(shè)置的最大連接數(shù)為32768聂使,API開啟的連接池也只有100個,因此排除這個原因

2. MySQL連接池泄露

百度找了一下相關(guān)資料贱呐,發(fā)現(xiàn)有可能是因為MyBatis自定義攔截器沒有釋放連接的原因供屉。

因為這個java應(yīng)用也自定義了一個攔截器用來分頁瘟栖,但是連接本地數(shù)據(jù)庫進行壓測的時候并沒有出現(xiàn)這個錯誤横蜒,因此也排除了連接池泄露的原因

3. 源碼研究

直接在IDEA查找關(guān)鍵字Connection is not available,發(fā)現(xiàn)只有在HikariPool.java的方法getConnection里面會拋錯throw createTimeoutException(startTime)
方法代碼如下:

public Connection getConnection(final long hardTimeout) throws SQLException
   {
      suspendResumeLock.acquire();
      final long startTime = currentTime();

      try {
         long timeout = hardTimeout;
         do {
            PoolEntry poolEntry = connectionBag.borrow(timeout, MILLISECONDS);
            if (poolEntry == null) {
               break; // We timed out... break and throw exception
            }

            final long now = currentTime();
            if (poolEntry.isMarkedEvicted() || (elapsedMillis(poolEntry.lastAccessed, now) > ALIVE_BYPASS_WINDOW_MS && !isConnectionAlive(poolEntry.connection))) {
               closeConnection(poolEntry, poolEntry.isMarkedEvicted() ? EVICTED_CONNECTION_MESSAGE : DEAD_CONNECTION_MESSAGE);
               timeout = hardTimeout - elapsedMillis(startTime);
            }
            else {
               metricsTracker.recordBorrowStats(poolEntry, startTime);
               return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry), now);
            }
         } while (timeout > 0L);

         metricsTracker.recordBorrowTimeoutStats(startTime);
         throw createTimeoutException(startTime);
      }
      catch (InterruptedException e) {
         Thread.currentThread().interrupt();
         throw new SQLException(poolName + " - Interrupted during connection acquisition", e);
      }
      finally {
         suspendResumeLock.release();
      }
   }

大概看了一下這個方法做的事情右核,其實就是從連接池里面去borrow一個連接慧脱,然后返回。如果borrow了30s還沒borrow到贺喝,那么就會拋錯了菱鸥。

這個時候真相呼之欲出了宗兼,什么情況會造成獲取連接池連接超時?

  • 連接泄露
    某些線程拿到了連接后沒有歸還氮采,持續(xù)久了就出問題
  • 連接歸還連接池太慢
    極端點殷绍,數(shù)據(jù)庫響應(yīng)時間要花1s,10個連接池1秒也只能處理10個請求鹊漠。這個時候如果有500個并發(fā)那得50s才能處理完主到,這不就超時了
  • 連接歸還連接池很快,但是借的線程太多
    數(shù)據(jù)庫響應(yīng)很快躯概,無奈并發(fā)太高登钥,遠超連接池大小。假設(shè)連接池只有10個連接娶靡,但是有100個線程在borrow連接的話牧牢,是不是有可能會出現(xiàn)某些倒霉的線程30s一直borrow不到連接的情況?

本例排除了前兩種可能姿锭,因此猜測是第三種原因塔鳍。 并發(fā)數(shù)遠大于連接池大小,導(dǎo)致有可能出現(xiàn)某些線程30s內(nèi)一直獲取不到連接呻此,從而拋錯

bug本地復(fù)現(xiàn)

既然是懷疑并發(fā)數(shù)大于連接池大小大致的轮纫,那我們將hikari的線程數(shù)設(shè)置成10(設(shè)置小點避免引入數(shù)據(jù)庫的干擾),然后開500并發(fā)來測試本地java應(yīng)用
spring.datasource.hikari.maximum-pool-size=10
ab壓測命令
ab -c 500 -n 50000 -p body.json http://127.0.0.1:8080/api/test

  1. 本地數(shù)據(jù)庫復(fù)現(xiàn)
    無法復(fù)現(xiàn)焚鲜?蜡感??恃泪?VP恕!1春酢情连!
    10個連接,500個并發(fā)都能完美處理過來@佬АH匆ā!
    懷疑是因為本地通信太快了锤灿,500個并發(fā)可能還不足以看出來挽拔。(這里沒有再往上調(diào)并發(fā)數(shù),理論上應(yīng)該調(diào)大也能復(fù)現(xiàn)但校,就是不知道得多大螃诅。。。)

  2. 遠程數(shù)據(jù)庫復(fù)現(xiàn)
    換成和java應(yīng)用不在同一個內(nèi)網(wǎng)的外網(wǎng)數(shù)據(jù)庫
    ab剛啟動沒一會术裸,java應(yīng)用就拋出了這個可愛的錯誤倘是!
    nice!

如何解決

既然問題是因為并發(fā)數(shù)遠大于連接池大小導(dǎo)致的袭艺,那么有以下幾個解決方案:

  • 增加連接池大小
    簡單暴力搀崭,如果你可以預(yù)見并發(fā)數(shù)的上限的話
  • 數(shù)據(jù)庫和api部署在同一個內(nèi)網(wǎng)
    加快單個請求的響應(yīng)速度,較少線程等待時間

其實個人以為這個問題基本無解猾编,要是并發(fā)數(shù)無限提高的話還是一樣會出問題瘤睹。

這個問題就和偶爾網(wǎng)絡(luò)抽風(fēng)一樣,概率挺小的答倡,感覺可以不用管~

后話

該錯誤的本質(zhì)原因其實就是線程去borrow連接超時拋出的轰传,超時的原因說白了就是超時時間內(nèi)一直拿不到可用連接,因此可以從這方面下手去排查苇羡。

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末绸吸,一起剝皮案震驚了整個濱河市鼻弧,隨后出現(xiàn)的幾起案子设江,更是在濱河造成了極大的恐慌,老刑警劉巖攘轩,帶你破解...
    沈念sama閱讀 210,914評論 6 490
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件叉存,死亡現(xiàn)場離奇詭異,居然都是意外死亡度帮,警方通過查閱死者的電腦和手機歼捏,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 89,935評論 2 383
  • 文/潘曉璐 我一進店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來笨篷,“玉大人瞳秽,你說我怎么就攤上這事÷食幔” “怎么了练俐?”我有些...
    開封第一講書人閱讀 156,531評論 0 345
  • 文/不壞的土叔 我叫張陵,是天一觀的道長冕臭。 經(jīng)常有香客問我腺晾,道長,這世上最難降的妖魔是什么辜贵? 我笑而不...
    開封第一講書人閱讀 56,309評論 1 282
  • 正文 為了忘掉前任悯蝉,我火速辦了婚禮,結(jié)果婚禮上托慨,老公的妹妹穿的比我還像新娘鼻由。我一直安慰自己,他們只是感情好,可當(dāng)我...
    茶點故事閱讀 65,381評論 5 384
  • 文/花漫 我一把揭開白布嗡靡。 她就那樣靜靜地躺著跺撼,像睡著了一般。 火紅的嫁衣襯著肌膚如雪讨彼。 梳的紋絲不亂的頭發(fā)上歉井,一...
    開封第一講書人閱讀 49,730評論 1 289
  • 那天,我揣著相機與錄音哈误,去河邊找鬼哩至。 笑死,一個胖子當(dāng)著我的面吹牛蜜自,可吹牛的內(nèi)容都是我干的菩貌。 我是一名探鬼主播,決...
    沈念sama閱讀 38,882評論 3 404
  • 文/蒼蘭香墨 我猛地睜開眼重荠,長吁一口氣:“原來是場噩夢啊……” “哼箭阶!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起戈鲁,我...
    開封第一講書人閱讀 37,643評論 0 266
  • 序言:老撾萬榮一對情侶失蹤仇参,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后婆殿,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體诈乒,經(jīng)...
    沈念sama閱讀 44,095評論 1 303
  • 正文 獨居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點故事閱讀 36,448評論 2 325
  • 正文 我和宋清朗相戀三年婆芦,在試婚紗的時候發(fā)現(xiàn)自己被綠了怕磨。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點故事閱讀 38,566評論 1 339
  • 序言:一個原本活蹦亂跳的男人離奇死亡消约,死狀恐怖肠鲫,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情或粮,我是刑警寧澤导饲,帶...
    沈念sama閱讀 34,253評論 4 328
  • 正文 年R本政府宣布,位于F島的核電站被啼,受9級特大地震影響帜消,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜浓体,卻給世界環(huán)境...
    茶點故事閱讀 39,829評論 3 312
  • 文/蒙蒙 一泡挺、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧命浴,春花似錦娄猫、人聲如沸贱除。這莊子的主人今日做“春日...
    開封第一講書人閱讀 30,715評論 0 21
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽月幌。三九已至,卻和暖如春悬蔽,著一層夾襖步出監(jiān)牢的瞬間扯躺,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 31,945評論 1 264
  • 我被黑心中介騙來泰國打工蝎困, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留录语,地道東北人。 一個月前我還...
    沈念sama閱讀 46,248評論 2 360
  • 正文 我出身青樓禾乘,卻偏偏與公主長得像澎埠,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子始藕,可洞房花燭夜當(dāng)晚...
    茶點故事閱讀 43,440評論 2 348

推薦閱讀更多精彩內(nèi)容

  • 所有知識點已整理成app app下載地址 J2EE 部分: 1.Switch能否用string做參數(shù)蒲稳? 在 Jav...
    侯蛋蛋_閱讀 2,412評論 1 4
  • Java SE 基礎(chǔ): 封裝、繼承伍派、多態(tài) 封裝: 概念:就是把對象的屬性和操作(或服務(wù))結(jié)合為一個獨立的整體江耀,并盡...
    Jayden_Cao閱讀 2,103評論 0 8
  • 最原始的數(shù)據(jù)庫連接就是我們打開一個連接,使用過后再關(guān)閉該鏈接來釋放資源拙已。頻繁的新建打開再關(guān)閉連接對jvm和數(shù)據(jù)庫都...
    野柳閱讀 6,345評論 1 11
  • 不管你是新程序員還是老手决记,你一定在面試中遇到過有關(guān)線程的問題摧冀。Java語言一個重要的特點就是內(nèi)置了對并發(fā)的支持倍踪,讓...
    堯淳閱讀 1,590評論 0 25
  • 最近總是在各種網(wǎng)站或者平臺上看到一些這樣的話~“我三十歲了,學(xué)設(shè)計晚不晚索昂;我二十多歲了建车,想學(xué)畫畫還來得及嗎”~等等...
    我家屋后有條河閱讀 191評論 0 1