1. 程式人生 > >一次jvm調優過程

一次jvm調優過程

jvm調優實戰

前端時間把公司的一個分散式定時排程的系統弄上了容器雲,部署在kubernetes,在容器執行的動不動就出現問題,特別容易jvm溢位,導致程式不可用,終端無法進入,日誌一直在刷錯誤,kubernetes也沒有將該容器自動重啟。業務方基本每天都在反饋task不穩定,後續就協助接手看了下,先主要講下該程式的架構吧。
該程式task主要分為三個模組:
console進行一些cron的配置(表示式、任務名稱、任務組等);
schedule主要從資料庫中讀取配置然後裝載到quartz再然後進行命令下發;
client接收任務執行,然後向schedule返回執行的資訊(成功、失敗原因等)。
整體架構跟github上開源的xxl-job類似,也可以參考一下。

1. 啟用jmx和遠端debug模式

容器的網路使用了BGP,打通了公司的內網,所以可以直接通過ip來進行程式的除錯,主要是在啟動的jvm引數中新增:

JAVA_DEBUG_OPTS=" -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,address=0.0.0.0:8000,server=y,suspend=n "
JAVA_JMX_OPTS=" -Dcom.sun.management.jmxremote.port=1099 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false "

其中,除錯模式的address最好加上0.0.0.0,有時候通過netstat檢視埠的時候,該位置顯示為127.0.0.1,導致無法正常debug,開啟了jmx之後,可以初步觀察堆記憶體的情況。

堆記憶體(特別是cms的old gen),初步看程式碼覺得是由於用了大量的map,本地快取了大量資料,懷疑是每次定時排程的資訊都進行了儲存。

2. memory analyzer、jprofiler進行堆記憶體分析

先從容器中dump出堆記憶體

jmap -dump:live,format=b,file=heap.hprof 58

由圖片可以看出,這些大物件不過也就10M,並沒有想象中的那麼大,所以並不是大物件的問題,後續繼續看了下程式碼,雖然每次請求都會把資訊放進map裡,如果能正常調通的話,就會移除map中儲存的記錄,由於是測試環境,執行端很多時候都沒有正常執行,甚至說業務方關閉了程式,導致排程一直出現問題,所以map的只會保留大量的錯誤請求。不過相對於該程式的堆記憶體來說,不是主要問題。

3. netty的方面的考慮

另一個小夥伴一直懷疑的是netty這一塊有錯誤,著重看了下。該程式用netty自己實現了一套rpc,排程端每次進行命令下發的時候都會通過netty的rpc來進行通訊,整個過程邏輯寫的很混亂,下面開始排查。
首先是檢視堆記憶體的中佔比:

可以看出,io.netty.channel.nio.NioEventLoop的佔比達到了40%左右,再然後是io.netty.buffer.PoolThreadCache,佔比大概達到33%左右。猜想可能是傳輸的channel沒有關閉,還是NioEventLoop沒有關閉。再跑去看一下jmx的執行緒數:

達到了驚人的1000個左右,而且一直在增長,沒有過下降的趨勢,再次猜想到可能是NioEventLoop沒有關閉,在程式碼中全域性搜尋NioEventLoop,找到一處比較可疑的地方。

聲明瞭一個NioEventLoopGroup的成員變數,通過構造方法進行了初始化,但是在執行syncRequest完之後並沒有進行對group進行shutdownGracefully操作,外面對其的操作並沒有對該類的group物件進行關閉,導致執行緒數一直在增長。

最終解決辦法:
在呼叫完syncRequest方法時,對ChannelBootStrap的group物件進行行shutdownGracefully

提交程式碼,容器中繼續測試,可以基本看出,執行緒基本處於穩定狀態,並不會出現一直增長的情況了

還原本以為基本解決了,到最後還是發現,堆記憶體還算穩定,但是,直接記憶體依舊打到了100%,雖然程式沒有掛掉,所以,上面做的,可能僅僅是為這個程式續命了而已,感覺並沒有徹底解決掉問題。

4. 直接記憶體排查

第一個想到的就是netty的直接記憶體,關掉,命令如下:

-Dio.netty.noPreferDirect=true -Dio.netty.leakDetectionLevel=advanced

查看了一下java的nio直接記憶體,發現也就幾十kb,然而直接記憶體還是慢慢往上漲。毫無頭緒,然後開始了自己的從linux層面開始排查問題

5. 推薦的直接記憶體排查方法

5.1 pmap

一般配合pmap使用,從核心中讀取記憶體塊,然後使用views 記憶體塊來判斷錯誤,我簡單試了下,亂碼,都是二進位制的東西,看不出所以然來。

pmap -d 58  | sort -n -k2
pmap -x 58  | sort -n -k3
grep rw-p /proc/$1/maps | sed -n 's/^\([0-9a-f]*\)-\([0-9a-f]*\) .*$/\1 \2/p' | while read start stop; do gdb --batch --pid $1 -ex "dump memory $1-$start-$stop.dump 0x$start 0x$stop"; done

這個時候真的懵了,不知道從何入手了,難道是linux作業系統方面的問題?

5.2 [gperftools](https://github.com/gperftools/gperftools)

起初,在網上看到有人說是因為linux自帶的glibc版本太低了,導致的記憶體溢位,考慮一下。初步覺得也可能是因為這個問題,所以開始慢慢排查。oracle官方有一個jemalloc用來替換linux自帶的,谷歌那邊也有一個tcmalloc,據說效能比glibc、jemalloc都強,開始換一下。
根據網上說的,在容器裡裝libunwind,然後再裝perf-tools,然後各種搗鼓,到最後發現,執行不了,

pprof --text /usr/bin/java java_58.0001.heap

看著工具高大上的,似乎能找出linux的呼叫棧,

6. 意外的結果

毫無頭緒的時候,回想到了linux的top命令以及日誌情況,測試環境是由於太多執行端業務方都沒有維護,導致排程系統一直會出錯,一出錯就會導致大量刷錯誤日誌,平均一天一個容器大概就有3G的日誌,cron一旦到準點,就會有大量的任務要同時執行,而且容器中是做了對io的限制,磁碟也限制為10G,導致大量的日誌都堆積在buff/cache裡面,最終直接記憶體一直在漲,這個時候,系統不會掛,但是先會一直顯示記憶體使用率達到100%。
修復後的結果如下圖所示:

總結

定時排程這個系統當時並沒有考慮到公司的系統會用的這麼多,設計的時候也僅僅是為了實現上千的量,沒想到到最後變成了一天的排程都有幾百萬次。最初那批開發也就使用了大量的本地快取map來臨時儲存資料,然後面向簡歷程式設計各種用netty自己實現了通訊的方式,一堆坑都留給了後人。目前也算是解決掉了一個由於執行緒過多導致系統不可用的情況而已,但是由於存在大量的map,系統還是得偶爾重啟一下比較好。

參考:
1.記一次線上記憶體洩漏問題的排查過程
2.Java堆外記憶體增長問題排查Case
3.Troubleshooting Native Memory Leaks in Java Applicati