一次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 Applications


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM