JVM優(yōu)化過(guò)程全記錄

HelKyle 發(fā)布于2019-08-15 11:07 / 498人閱讀

摘要：修改完這個(gè)，重新上線后，跑了一段時(shí)間查看情況可以看到比之前好一些了但是的次數(shù)還是比較多，照這情況下去一天的估計(jì)會(huì)有這當(dāng)然是不可接受的前面說(shuō)的另一個(gè)人次，飛神說(shuō)如果是跑了半年的話還可以接受。

今天看JVM群里有人發(fā)了一個(gè)GC情況，讓人幫忙看優(yōu)化的，于是我也湊熱鬧發(fā)了出來(lái)想讓群里的大神們指導(dǎo)優(yōu)化一下，以下是優(yōu)化過(guò)程記錄.

一開始我貼了下面的兩張圖

jstat看GC記錄
jstat -gcutil pid 1000 20

jcmd看VM參數(shù)(第一次使用這個(gè)命令)
jcmd pid VM.flags

可以看到Y(jié)GC了8W多次，F(xiàn)GC有1100+，相比較另一個(gè)發(fā)出來(lái)求教的，我這個(gè)更糟糕，他的是運(yùn)行了3天左右 FGC370次

然后飛神讓我看下運(yùn)行時(shí)間
ps -p pid -o etime

我的也是跑了3天左右，感覺優(yōu)化空間非常的大

又讓我拉了JVM配置
jinfo -flags pid(沒權(quán)限，沒執(zhí)行成功)
ps aux | grep pid

發(fā)現(xiàn)我的JVM完全沒做過(guò)優(yōu)化，據(jù)我自己的印象，就改過(guò)PermSize,因?yàn)檫@個(gè)OOM過(guò)，所以調(diào)大了一點(diǎn)。

然后飛神給了我一份他之前用過(guò)的配置
JAVA_OPTS="-Xms2g?-Xmx2g?-Xmn512m?-XX:MaxPermSize=256m??-server?-Xss256k?-XX:PermSize=128M?-XX:+PrintGCDetails?-XX:+PrintGCDateStamps?-Xloggc:/data/log/gclog/gc.log?-XX:+HeapDumpOnOutOfMemoryError?-XX:HeapDumpPath=/data/log/jvmdump/jvm.bin?-XX:+UseConcMarkSweepGC?-XX:+UseParNewGC??-XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly?-XX:+UseCMSCompactAtFullCollection?-XX:CMSFullGCsBeforeCompaction=0?-XX:+CMSClassUnloadingEnabled?-XX:+TieredCompilation??-XX:+PrintTenuringDistribution?-XX:+PrintGCApplicationStoppedTime?-XX:+PrintHeapAtGC

并囑咐了一句loggc和dumpPath提前mkdir

因?yàn)橐呀?jīng)是周五晚上了，我沒有權(quán)限直接修改這個(gè)配置，所以準(zhǔn)備下周一再配上去看效果。

萬(wàn)萬(wàn)沒想到，回家路上，笨神出來(lái)說(shuō)話了，要我看下存活實(shí)例

jmap -histo:live pid

由于沒有開啟GC日志，于是笨神讓我開著jstat（飛神提到jstat -gccause pid可以跟蹤gc情況），然后在另一個(gè)窗口執(zhí)行jmap -histo:live

剛開始沒明白，后來(lái)才知道原來(lái)這個(gè)命令可以觸發(fā)Full GC

可以看到執(zhí)行了Full GC以后Old區(qū)從90%降到了79%，F(xiàn)GC效果很差，說(shuō)明活對(duì)象太多了。

回過(guò)頭去看jmap實(shí)例，發(fā)現(xiàn)AtomicInteger這個(gè)類對(duì)象特別的多，竟然有300多萬(wàn)個(gè)實(shí)例,已經(jīng)是top2了。

翻看代碼沒有發(fā)現(xiàn)有使用這個(gè)類的地方，初步懷疑是依賴的jar包使用的，笨神建議dump用MAT分析一下。

dump命令導(dǎo)出文件
jmap -dump:format=b,file=pid.dump pid

檢查了一下項(xiàng)目代碼后，發(fā)現(xiàn)了問(wèn)題，項(xiàng)目代碼就不貼了

項(xiàng)目中有一個(gè)統(tǒng)計(jì)API調(diào)用次數(shù)的類使用了AtomicInteger，在這個(gè)類里針對(duì)每個(gè)用戶都會(huì)生成大概六七十個(gè)AtomicInteger實(shí)例,每次上報(bào)過(guò)數(shù)據(jù)之后只是簡(jiǎn)單的把值設(shè)置為0，導(dǎo)致負(fù)責(zé)統(tǒng)計(jì)的實(shí)例一直持有這些AtomicInteger，而且隨著新用戶的不斷增加，這些實(shí)例數(shù)量還會(huì)持續(xù)增長(zhǎng)，最終會(huì)導(dǎo)致內(nèi)存溢出。

修改完這個(gè)BUG，重新上線后，跑了一段時(shí)間查看gc情況

可以看到比之前好一些了但是FGC的次數(shù)還是比較多，照這情況下去一天的FGC估計(jì)會(huì)有200+,這當(dāng)然是不可接受的（前面說(shuō)的另一個(gè)人370次FGC，飛神說(shuō)如果是跑了半年的話還可以接受）。

看了飛神推薦的阿里畢玄大師的文章為什么不建議

于是準(zhǔn)備先不上CMS GC,就簡(jiǎn)單的把Xms,Xmn和GC日志配置了一下

-Xms2048m -Xmx2048m -XX:PermSize=128m -XX:MaxPermSize=128m -Xss256k -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/data/project/delivery_v9/code/logs/gc.log -XX:GCLogFileSize=50m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/project/delivery_v9/tomcat/jvmdump/jvm.dump

運(yùn)行了一天左右看下對(duì)比結(jié)果

未配置

已配置

可以看到配置完以后對(duì)GC影響還是挺大的(不管是YGC還是FGC)，當(dāng)然這也是必然的，畢竟沒有配置的機(jī)器初始內(nèi)存比較小，在不斷擴(kuò)容的過(guò)程中會(huì)頻繁的GC，而且這個(gè)時(shí)候其實(shí)沒配置的那臺(tái)機(jī)器內(nèi)存還沒有擴(kuò)充到上限，在資源充足的情況下，這種動(dòng)態(tài)擴(kuò)容顯然是完全沒有必要的。

配置完的機(jī)器雖然GC時(shí)間和次數(shù)已經(jīng)降了很多了，但是還是沒達(dá)到期望的結(jié)果，考慮到這個(gè)程序短時(shí)間的活對(duì)象是比較多的，可以通過(guò)調(diào)整年輕代和老年代的內(nèi)存占比來(lái)減少因?yàn)槟贻p代內(nèi)存不足導(dǎo)致晉升到老年代的對(duì)象。

現(xiàn)在已經(jīng)離開這個(gè)項(xiàng)目了，所以后面就沒有再繼續(xù)優(yōu)化了，以后再有這方面的實(shí)踐重新寫文章記錄。