問題出現:
運維小夥伴回報系統某應用出現cpu爆了,同時報Mysql、Redis異常,如下圖所示:

問題排查:
遇到問題,馬上去看日志,報錯如下:
DUBBO Thread pool is EXHAUSTED
Could not get JDBC Connection
意思是dubbo線程滿了。但是啥原因造成線程滿的呢?繼續排查,因為我們不知道是在哪裡報的錯。這時候我們需要通過JVM去排查問題了。
step 1:
top 指令觀察 JAVA程序cpu。由于沒有及時截圖,是以,沒有截圖了,隻能字面描述下。當時這個應用的cpu約為120%左右。接下來 top -H -p (應用線程ID),發現裡面的程序都是呈現穩定的部分是 2.0% ,1.7% ,0.7% 等,并沒有說哪個程序特别高。
step 2:
jstack -l (應用線程ID) > (應用線程ID).txt
打開日志一看。沒有發現死鎖的異常報錯,但是發現大量的 BLOCKED ,如圖:
同時看到是Redis的報錯,然後可以初步鎖定問題點集中在Redis,先從它入手。接下來再調用dubbo-jstack日志,如圖所示:
大家可以看到,目前 12 、13的程序都在等待 304 這個程序。那麼304這個程序做了什麼?這是又去看下代碼。
大家可以看到這裡用到Redis緩存,那麼究竟發生什麼事導緻它影響了别的程序在等待呢?是什麼報錯,都是在等待它呢?我繼續往前看dubbo-jstack日志,發現除了304,還有别的在等待,如下圖的 18、19 在等待 257。
那麼 257 、304發生了什麼?這是我想起了最初的報錯。
redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
這時候,我煥然大悟,我接着去看配置,如圖:
Redis連結逾時時間為3秒。豁然開朗。
總結問題原因:
綜上所示,首先是系統發生了并發的請求,讀取Redis 最大連接配接數是500。這時連接配接請求數大于500,是以出現了有個程序如257拿不到Redis資源,他會等待三秒,由于Redis是單線程原理,那麼别的程序執行到這一步,就會被鎖住,等待257執行,這時候 257 三秒逾時了。報錯: redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool 。三秒内,就會有很多程序在等待了。Redis一有資源就會被其他程序去擷取,剛好到304,Redis pool 又滿了,是以又出現上述的情況。在等待的程序是Dubbo 程序,由于它們在等待,是以得不到資源釋放,是以出現了 DUBBO Thread pool is EXHAUSTED。 由于Redis拿不到資源,那麼程式就會去讀資料庫,又不釋放資料庫資源,導緻Could not get JDBC Connection。是以,這一系列連鎖反應的Dubbo pool ,JDBC的問題,都是源于并發下,Redis 連接配接池的資源不夠。
解決辦法:
1、調大Redis 連接配接池的大小。(但是不建議這麼做,一般Redis連接配接池都是夠用)
2、調整業務邏輯。(排查到這裡,已經給到相應的負責人去定位了。譬如:封裝200條資料作為一次請求Dubbo,從請求Dubbo200次降到一次去實作)