這兩天遇到一個(gè)服務(wù)假死的問題，具體現(xiàn)象就是服務(wù)不再接收任何請(qǐng)求，客戶端會(huì)拋出Broken Pipe。

檢查系統(tǒng)狀態(tài)

執(zhí)行top，發(fā)現(xiàn)CPU和內(nèi)存占用都不高，但是通過命令

netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'

發(fā)現(xiàn)有大量的CLOSE_WAIT端口占用，繼續(xù)調(diào)用該服務(wù)的api，等待超時(shí)之后發(fā)現(xiàn)CLOSE_WAIT的數(shù)量也沒有上升，也就是說服務(wù)幾乎完全僵死。

檢查JVM情況

懷疑可能是線程有死鎖，決定先dump一下線程情況，執(zhí)行

jstack <pid> > /tmp/thread.hump

發(fā)現(xiàn)tomcat線程基本也正常，都是parking狀態(tài)。

這就比較奇怪了，繼續(xù)想是不是GC導(dǎo)致了STW，使用jstat查看垃圾回收情況

app@server:/tmp$ jstat -gcutil 1 2000 10
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 27.79 65.01 15.30 94.75 92.23 1338 44.375 1881 475.064 519.439

一看嚇一跳，F(xiàn)GC的次數(shù)居然超過了YGC，時(shí)長有475s。一定是有什么原因觸發(fā)了FGC，好在我們打開了GC log。

發(fā)現(xiàn)一段時(shí)間內(nèi)頻繁發(fā)生Allocation Failure引起的Full GC。而且eden區(qū)的使用占比也很大，考慮有頻繁新建對(duì)象逃逸到老年代造成問題。詢問了一下業(yè)務(wù)的開發(fā)，確認(rèn)有一個(gè)外部對(duì)接API沒有分頁，查詢后可能會(huì)產(chǎn)生大量對(duì)象。

由于外部API暫時(shí)無法聯(lián)系對(duì)方修改，所以為了先解決問題，對(duì)原有的MaxNewSize進(jìn)擴(kuò)容，從192MB擴(kuò)容到一倍。經(jīng)過幾天的觀察，發(fā)現(xiàn)gc基本趨于正常

S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 3.37 60.55 8.60 95.08 92.98 87 2.421 0 0.000 2.421

擴(kuò)容之前對(duì)heap進(jìn)行了dump

jmap -dump:format=b,file=heapDump <PID>

通過MAT分析內(nèi)存泄露，居然疑似是jdbc中的一個(gè)類，但其實(shí)整體占用堆容量并不多。

分析了線程數(shù)量，大約是240多條，與正常時(shí)也并沒有很大的出入。而且大量的是在sleep的定時(shí)線程。

總結(jié)

本次排查其實(shí)并未找到真正的原因，間接表象是FGC頻繁導(dǎo)致服務(wù)假死。而且acturator端口是正常工作的，導(dǎo)致health check進(jìn)程誤認(rèn)為服務(wù)正常，沒有觸發(fā)告警。如果你也遇到類似的情況歡迎一起討論。

好了，以上就是這篇文章的全部內(nèi)容了，希望本文的內(nèi)容對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，謝謝大家對(duì)腳本之家的支持。

最新評(píng)論