1 問題背景

深夜，一陣急促的報(bào)警聲響起，原來是收到一連串容器內(nèi)存使用率過高的報(bào)警。查看服務(wù)器狀態(tài)，容器內(nèi)存使用率持續(xù)高達(dá)99%，記錄排查過程和分析，供大家參考。

2 問題現(xiàn)象

檢查容器狀態(tài)，觀察到以下現(xiàn)象：

• JVM堆內(nèi)存使用率正常，在50%左右波動(dòng)，在凌晨1點(diǎn)的時(shí)候年輕代使用無明顯波動(dòng)，老年代使用有直線上漲，但是執(zhí)行了一次Full GC（也可能是Major GC）后恢復(fù)了正常。

• 容器內(nèi)存使用率在凌晨1點(diǎn)的時(shí)候有一個(gè)直線的上漲，并且隨后一直保持在上漲后的水平。

服務(wù)使用的配置如下：

主要啟動(dòng)參數(shù)：-Xms4g -Xmx4g -Xmn2g -XX:+UseG1GC -XX:G1HeapRegionSize=8m -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=50

容器配置：4C5G

3 定位原因

雖然容器內(nèi)存已經(jīng)使用99%，但是JVM堆使用率在經(jīng)過一次Full GC后已經(jīng)降到了50%之后，所以并沒有立馬重啟服務(wù)，還是先來看看造成Full GC的原因。

鑒于堆使用率已經(jīng)恢復(fù)正常，查看當(dāng)時(shí)的內(nèi)存快照意義不大，決定先從觀察到的現(xiàn)象入手。因?yàn)榱璩?點(diǎn)的時(shí)候系統(tǒng)的流量不會(huì)很大，所以大概率是因?yàn)槎〞r(shí)任務(wù)造成了，先排查報(bào)警服務(wù)凌晨1點(diǎn)執(zhí)行的定時(shí)任務(wù)。幸運(yùn)的是調(diào)度平臺(tái)當(dāng)時(shí)只有一個(gè)定時(shí)任務(wù)在執(zhí)行，立馬查看對(duì)應(yīng)的邏輯，發(fā)現(xiàn)了以下代碼片段中潛在的問題（簡化之后）：

public?void?job()?{
????//?...?do?business
????int?pageSize?=?500;
????while?(?xxx?)?{
????????//?每次查詢500個(gè)訂單?
????????List<String>?orderNoList?=?orderService.getOrderPage(pageSize);
????????//?查詢500個(gè)訂單對(duì)應(yīng)的賬單
????????List<OrderBill>?orderBills?=?billService.findByOrderNos(orderNoList);
????????//?...?do?business
????}
????//?...?do?business
}

由于大部分訂單包含12至24期賬單，導(dǎo)致此處的orderBills在平均情況下含有數(shù)千至數(shù)萬條數(shù)據(jù)。經(jīng)過粗略估算，這些對(duì)象的總大小大約為5MB左右。

看啟動(dòng)參數(shù)中G1HeapRegionSize=8m，代表每個(gè)Region的大小為8M，G1 GC會(huì)將大于Region一半大小的對(duì)象直接分配到老年代。所以orderBills對(duì)象會(huì)被直接分配到老年代，這也和在凌晨1點(diǎn)的時(shí)候年輕代使用無明顯波動(dòng)，老年代使用有直線上漲的現(xiàn)象相符合。在后續(xù)的循環(huán)中，由于垃圾收集器清理的速度趕不上內(nèi)存分配的速度，導(dǎo)致垃圾逐漸積累并最終填滿整個(gè)堆空間，觸發(fā)了Full GC。

為什么GC之后容器的內(nèi)存還是一直居高不下呢？

經(jīng)過一番查閱資料，原來JVM啟動(dòng)時(shí)并不會(huì)立即實(shí)際占用全部Xms指定的內(nèi)存。Xms參數(shù)指定的是堆的初始大小，JVM會(huì)按照這個(gè)值預(yù)留內(nèi)存空間，但實(shí)際上只有在需要時(shí)才會(huì)逐漸使用這些預(yù)留的內(nèi)存。

JVM在完成內(nèi)存釋放后，是否將釋放的內(nèi)存返回給操作系統(tǒng)，這一行為取決于具體的JVM實(shí)現(xiàn)及其采用的垃圾回收策略。在很多情況下，JVM在進(jìn)行垃圾收集并釋放了堆內(nèi)存之后，并不會(huì)立即將這部分內(nèi)存歸還給操作系統(tǒng)。

相反，它會(huì)保留這部分內(nèi)存以備將來Java應(yīng)用程序的使用，因?yàn)閺牟僮飨到y(tǒng)重新申請(qǐng)內(nèi)存通常會(huì)比從JVM內(nèi)部管理的內(nèi)存分配更為昂貴（時(shí)間成本上）。所以一般程序還會(huì)將Xms和Xmx配置為相等的大小，避免頻繁申請(qǐng)和釋放內(nèi)存造成的性能開銷。

上面兩個(gè)問題找到原因了，小菜同學(xué)決定在本地復(fù)現(xiàn)一下進(jìn)行驗(yàn)證。

新建一個(gè)memorytest項(xiàng)目，寫一個(gè)方法模擬內(nèi)存分配：

/**
?*?模擬內(nèi)存分配
?*?@param?num?循環(huán)次數(shù)
?*?@param?size?每次分配幾MB的數(shù)據(jù)
?*/
@RequestMapping("/memory/add/{num}/{size}")
public?String?add(@PathVariable("num")?Integer?num,?@PathVariable("size")?Integer?size)?{
????for?(int?i?=?0;?i?<?num;?i++)?{
????????//?模擬查詢出來的大對(duì)象
????????byte[]?allocation?=?new?byte[size?*?1024?*?1024];
????}
????return?"";
}

用以下命令啟動(dòng)：

java?-Xms2g?-Xmx2g?-Xmn1g?-XX:+UseG1GC?-XX:G1HeapRegionSize=8m?-XX:G1ReservePercent=15?-XX:InitiatingHeapOccupancyPercent=50?-jar?memorytest-0.0.1-SNAPSHOT.jar

使用Jdk自帶的命令查詢JVM內(nèi)存分配情況，先使用jps -l查詢進(jìn)程ID:

jps?-l
16988?sun.tools.jps.Jps
9068?memorytest-0.0.1-SNAPSHOT.jar

使用jmap -heap <pid>查詢堆內(nèi)存分配：

jmap?-heap?9068
Heap?Usage:
G1?Heap:
???regions??=?256
???capacity?=?2147483648?(2048.0MB)
???used?????=?230686720?(220.0MB)
???free?????=?1916796928?(1828.0MB)
???10.7421875%?used
G1?Young?Generation:
Eden?Space:
???regions??=?26
???capacity?=?1115684864?(1064.0MB)
???used?????=?218103808?(208.0MB)
???free?????=?897581056?(856.0MB)
???19.548872180451127%?used
Survivor?Space:
???regions??=?2
???capacity?=?16777216?(16.0MB)
???used?????=?16777216?(16.0MB)
???free?????=?0?(0.0MB)
???100.0%?used
G1?Old?Generation:
???regions??=?0
???capacity?=?1015021568?(968.0MB)
???used?????=?0?(0.0MB)
???free?????=?1015021568?(968.0MB)
???0.0%?used

使用jstat -gcutil <pid> <interval[s|ms]>?1秒1次監(jiān)控堆內(nèi)存使用和GC情況（也可以使用jconsole可視化處理工具來查看內(nèi)存的使用情況）：

jstat?-gcutil?9068?1000
??S0?????S1?????E??????O??????M?????CCS????YGC?????YGCT????FGC????FGCT?????GCT???
??0.00?100.00??21.80???0.00??94.17??88.38??????1????0.023?????0????0.000????0.023

該命令返回的主要的參數(shù)的意義：
S0：Survivor space 0區(qū)的使用率。
S1：Survivor space 1區(qū)的使用率。
E：Eden區(qū)的使用率。
O：Old區(qū)（老年代）的使用率。
YGC：年輕代垃圾收集事件的次數(shù)。
YGCT：年輕代垃圾收集所耗費(fèi)的時(shí)間（秒）。
FGC：Full GC（全堆垃圾收集）事件的次數(shù)。
FGCT：Full GC所耗費(fèi)的時(shí)間（秒）。
GCT：垃圾收集所耗費(fèi)的總時(shí)間（秒）。

此時(shí)使用ps aux --sort -rss查看Java進(jìn)程占用的本機(jī)內(nèi)存才370MB左右，并沒有直接占用Xms設(shè)置的2g。

ps?aux?--sort?-rss
USER???????PID?%CPU?%MEM????VSZ???RSS?TTY??????STAT?START???TIME?COMMAND
root?????9068??5.4??9.9?4718036?374536?pts/1??Sl+??15:10???0:09?java?-Xms2g?-Xmx2g?-Xmn1g?-XX:+UseG1GC?-XX:G1HeapRegionSize=8m?-XX:G1ReservePercent=15?-XX:InitiatingHeapOccupancyPercent=50?-jar?memorytest-0.0.1-SNAPSHOT.jar

該命令返回的主要的參數(shù)的意義：
PID: 進(jìn)程ID。
%CPU: 進(jìn)程使用的CPU百分比。
%MEM: 進(jìn)程使用的物理內(nèi)存百分比。
RSS: 進(jìn)程當(dāng)前占用的物理內(nèi)存大小，單位通常是KB。
COMMAND: 啟動(dòng)進(jìn)程的命令行命令。

開始模擬業(yè)務(wù)分配內(nèi)存，為了方便觀察直接循環(huán)100000次，每次分配5MB空間：

http://127.0.0.1:8080/memory/add/100000/5

jstat此時(shí)監(jiān)控到內(nèi)存情況：

??S0?????S1?????E??????O??????M?????CCS????YGC?????YGCT????FGC????FGCT?????GCT???
??0.00?100.00??24.81???0.00??94.17??88.38??????1????0.023?????0????0.000????0.023
??0.00???0.00???1.48??61.36??93.38??89.74?????12????0.192?????0????0.000????0.192
??0.00?100.00???1.49??86.37??92.74??89.74?????33????0.294?????0????0.000????0.294
??0.00???0.00???2.27??99.41??92.74??89.74?????56????0.395?????0????0.000????0.395
??0.00???0.00???2.15??99.55??92.75??89.74?????84????0.522?????0????0.000????0.522
??0.00???0.00???1.94??99.77??92.20??89.00????119????0.663?????0????0.000????0.663
??0.00???0.00???4.00??99.71??92.21??89.01????169????0.834?????0????0.000????0.834
??0.00?100.00???0.75??21.43??92.22??89.01????232????0.998?????1????0.051????1.049
??0.00?100.00???0.84??99.68??92.22??89.01????252????1.025?????1????0.051????1.077
??0.00?100.00???0.88??99.87??92.25??89.01????274????1.064?????1????0.051????1.115
??0.00???0.00???1.48??70.73??92.25??89.01????299????1.110?????1????0.051????1.161
??0.00???0.00???1.48??75.90??92.25??89.01????327????1.168?????1????0.051????1.219
??0.00???0.00???1.77??99.81??92.25??89.01????361????1.239?????1????0.051????1.290
??0.00???0.00???2.41??99.92??92.27??89.01????409????1.340?????1????0.051????1.392

此時(shí)可以看到對(duì)象都直接分配到了老年代，年輕代的內(nèi)存使用沒有多大的變化，并且當(dāng)YGC（Young Generation Garbage Collection，年輕代垃圾回收）來不及回收時(shí)就會(huì)發(fā)生FGC（Full Garbage Collection，全堆垃圾回收）。

此時(shí)再使用ps aux --sort -rss查看Java進(jìn)程占用的本機(jī)內(nèi)存已經(jīng)到了2G了，并且在方法執(zhí)行完成后（也包括FGC后）也沒有釋放此內(nèi)存。

ps?aux?--sort?-rss
USER???????PID?%CPU?%MEM????VSZ???RSS?TTY??????STAT?START???TIME?COMMAND
root?????9068?77.1?60.4?4720084?2043996?pts/1?Sl+??15:10???6:03?java?-Xms2g?-Xmx2g?-Xmn1g?-XX:+UseG1GC?-XX:G1HeapRegionSize=8m?-XX:G1ReservePercent=15?-XX:InitiatingHeapOccupancyPercent=50?-jar?memorytest-0.0.1-SNAPSHOT.jar

再模擬一次業(yè)務(wù)分配內(nèi)存，為了方便觀察直接循環(huán)100000次，這次每次分配2MB空間：

http://127.0.0.1:8080/memory/add/100000/2

jstat此時(shí)監(jiān)控到內(nèi)存情況：

??S0?????S1?????E??????O??????M?????CCS????YGC?????YGCT????FGC????FGCT?????GCT???
??0.00?100.00??15.04???0.00??94.14??88.45??????1????0.027?????0????0.000????0.027
??0.00?100.00??15.04???0.00??94.14??88.45??????1????0.027?????0????0.000????0.027
??0.00?100.00??93.18???0.00??93.15??89.36??????2????0.043?????0????0.000????0.043
??0.00?100.00??51.49???0.66??93.15??89.36?????22????0.146?????0????0.000????0.146
??0.00???0.00??68.15???1.48??93.15??89.36?????44????0.167?????0????0.000????0.167
??0.00???0.00??81.48???1.48??93.15??89.36?????66????0.186?????0????0.000????0.186
??0.00???0.00??16.30???1.48??93.15??89.36?????89????0.207?????0????0.000????0.207
??0.00???0.00??58.52???1.48??93.15??89.36????111????0.226?????0????0.000????0.226
??0.00???0.00???4.44???1.48??93.16??89.36????134????0.246?????0????0.000????0.246
??0.00?100.00??50.00???0.66??93.16??89.36????156????0.265?????0????0.000????0.265
??0.00???0.00??88.15???1.49??93.16??89.36????178????0.284?????0????0.000????0.284
??0.00???0.00??41.48???1.49??93.16??89.36????201????0.305?????0????0.000????0.305
??0.00???0.00??87.41???1.49??93.16??89.36????223????0.324?????0????0.000????0.324
??0.00???0.00??27.41???1.49??93.17??89.36????246????0.344?????0????0.000????0.344
??0.00???0.00??89.63???1.49??93.17??89.36????263????0.358?????0????0.000????0.358
??0.00???0.00??89.63???1.49??93.17??89.36????263????0.358?????0????0.000????0.358

此時(shí)很明顯可以看到對(duì)象都直接分配到了年輕代，年輕代的回收效率也比老年代高，并且沒有產(chǎn)生FGC。

再結(jié)合本次報(bào)警的現(xiàn)象，解決辦法也呼之欲出：

• 通過減少查詢返回的數(shù)據(jù)量，避免大對(duì)象直接分配至老年代。

• 調(diào)整Region大小，較大的Region可以提高大對(duì)象分配的效率，同時(shí)可能會(huì)導(dǎo)致GC停頓時(shí)間變長，較小的Region可能意味著更短的停頓時(shí)間，但是會(huì)增加維護(hù)開銷，可能導(dǎo)致更高的CPU使用率。所以需要通過監(jiān)控工具（如JConsole、VisualVM等）觀察不同Region大小設(shè)置下的GC表現(xiàn)和應(yīng)用吞吐量，以找到最佳平衡點(diǎn)。

4 問題小結(jié)

JVM內(nèi)存問題可能不常有，但是一旦發(fā)生可能對(duì)我們系統(tǒng)造成極大的影響，此次內(nèi)存飆升也給我們敲響了警鐘，發(fā)現(xiàn)了我們?cè)谶@邊注重的不夠，很多監(jiān)控和日志并不完整，如啟動(dòng)參數(shù)中沒有加上發(fā)生OOM時(shí)自動(dòng)dump文件的參數(shù)等。好在此次服務(wù)未受到影響，所有有足夠的時(shí)候給我們?nèi)ヅ挪楹万?yàn)證。特此結(jié)合此次排查的過程的一些收獲記錄一下，假設(shè)下次還有發(fā)生可以有所參考：

• 如果對(duì)業(yè)務(wù)產(chǎn)生了影響，服務(wù)不可用或者進(jìn)程直接沒有了，首先需要快速止損，包括熔斷、重啟、手動(dòng)GC等方式。但是操作前需要先dump出內(nèi)存快照方便問題排查，命令如下：

#jmap命令保存整個(gè)Java堆（在你dump的時(shí)間不是事故發(fā)生點(diǎn)的時(shí)候尤其推薦）
jmap?-dump:format=b，file=heap.bin?<pid>?

#jmap命令只保存Java堆中的存活對(duì)象，?包含live選項(xiàng)，會(huì)在堆轉(zhuǎn)儲(chǔ)前執(zhí)行一次Full?GC
jmap?-dump:live，format=b，file=heap.bin?<pid>

#jcmd命令保存整個(gè)Java堆，Jdk1.7后有效
jcmd?<pid>?GC.heap_dump?filename=heap.bin

還有在啟動(dòng)參數(shù)中添加發(fā)生OOM時(shí)自動(dòng)生成heapdump的參數(shù):-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heap.bin啟動(dòng)參數(shù)中添加GC日志打印相關(guān)的參數(shù)：

#?Java8及以下
-XX:+PrintGCDetails?-XX:+PrintGCDateStamps?-Xloggc:<path>

#?Java9及以上
-Xlog:gc*:<path>:time

• 如果對(duì)業(yè)務(wù)無影響，可以先觀察現(xiàn)象進(jìn)行排查。如果是近期有業(yè)務(wù)增加，則可以考慮是否需要擴(kuò)容，如果是周期性的表現(xiàn)，則可以排查定時(shí)任務(wù)。

• 對(duì)導(dǎo)出的內(nèi)存快照文件使用MAT等工具進(jìn)行分析，一般會(huì)比較直觀的看到當(dāng)前堆內(nèi)情況。

• 如果服務(wù)還可用，也可以使用命令進(jìn)行排查，Jdk本身也已經(jīng)提供非常多輕量的小工具，主要用于監(jiān)視虛擬機(jī)運(yùn)行狀態(tài)和進(jìn)行故障處理，常用的如下（還有一些第三方的工具也很好用，如arthas等）：

jstat -gcutil <pid>?：監(jiān)視Java堆狀況，主要關(guān)注已使用空間的百分比和GC情況

jmap -heap <pid>?：顯示Java堆詳細(xì)信息

jmap -histo[:live]?<pid>?：顯示堆中對(duì)象統(tǒng)計(jì)信息：快速識(shí)別哪些類的實(shí)例占用了大量的堆內(nèi)存

• 如果是棧溢出，拋出StackOverflowError異常，需要著重檢查是否有死循環(huán)或者代碼調(diào)用鏈路不合理。

• 還有可能是堆外內(nèi)存泄露（元空間、直接內(nèi)存等），此情況一般較少發(fā)生，排查起來也更加復(fù)雜，小菜同學(xué)對(duì)于這部分的實(shí)操有限，這里就不詳細(xì)分析了，還需要繼續(xù)學(xué)習(xí)。

5 總結(jié)

面對(duì)內(nèi)存使用率的異常，不僅要關(guān)注即時(shí)的解決方案，還需要考慮如何從根本上避免此類問題的再次發(fā)生。如使用優(yōu)化數(shù)據(jù)結(jié)構(gòu)、減少不必要的計(jì)算、采用懶加載等策略，以及建立細(xì)致的內(nèi)存監(jiān)控體系等。性能優(yōu)化不應(yīng)該僅僅是面對(duì)問題時(shí)的臨時(shí)行動(dòng)，而應(yīng)該成為開發(fā)文化的一部分。

希望這次的經(jīng)歷和總結(jié)能夠?yàn)槲磥砜赡苡龅降念愃茊栴}提供一點(diǎn)參考的價(jià)值，也希望屏幕前的大佬對(duì)小菜同學(xué)寫的不對(duì)或者遺漏的地方不吝指正，非常感謝！

關(guān)于作者? ? 蔡闖，金融技術(shù)部后端研發(fā)工程師文章來源地址http://www.zghlxwxcb.cn/news/detail-848105.html

到了這里，關(guān)于什么！服務(wù)器內(nèi)存又雙叒叕打滿了！的文章就介紹完了。如果您還想了解更多內(nèi)容，請(qǐng)?jiān)谟疑辖撬阉鱐OY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關(guān)文章，希望大家以后多多支持TOY模板網(wǎng)！