【金三銀四-JVM系列】CMS收集器與GC日誌分析定位問題詳解

Java2B發表於2020-01-09

開頭:

今天2B哥要和大家分享一篇硬貨,為什麼呀?因為有兩個好事情:

一、哥升級了LV2了 哈哈心情倍爽。

圖片

二、拿到了公司給的2千股圖片

在公司呆了2年了,終於成為了東哥的好兄弟。

圖片

CMS收集器實戰:

實戰開始,準備好了沒

構建Spring Boot專案:

圖片

圖片

模擬業務場景程式碼:

@RestController
public class IndexController {
/***
 * 存big物件
 * @return
 */
@GetMapping("/put")
public String process() {
   ArrayList<User> users = queryUsers();
   for (User user:users){
      //TODO 業務操作
   }
   return "ok";
}
private ArrayList<User> queryUsers() {
   ArrayList<User> users = new ArrayList<>();
   for (int i = 0; i < 50000; i++) {
      users.add(new User(i, "java2b"));
   }
   return users;
}
}
public class User {

   private int id;
   private String name;
   private byte[] data;

   public User(int id, String name) {
      this.id = id;
      this.name = name;
      data=new byte[1 * 128 * 1024];
   }
}

輸出收集器資訊:

/***
 * 列印jvm資訊
 * @return
 */
@GetMapping("/info")
public String info() {
   List<GarbageCollectorMXBean> garbages = ManagementFactory.getGarbageCollectorMXBeans();
   StringBuilder stringBuilder = new StringBuilder();
   for (GarbageCollectorMXBean garbage : garbages) {
      stringBuilder.append("垃圾收集器:名稱=" + garbage.getName() + ",收集=" + garbage.getCollectionCount() + ",總花費時間="
              + garbage.getCollectionTime());
      // + ",記憶體區名稱=" + Arrays.deepToString(garbage.getMemoryPoolNames()));
      stringBuilder.append("\r\n");
   }
   MemoryMXBean memory = ManagementFactory.getMemoryMXBean();
   MemoryUsage headMemory = memory.getHeapMemoryUsage();
   long MB = 1024 * 1024;
   stringBuilder.append("head堆:");
   stringBuilder.append("\t初始(M):" + headMemory.getInit() / MB);
   stringBuilder.append("\t最大(上限)(M):" + headMemory.getMax() / MB);
   stringBuilder.append("\t當前(已使用)(M):" + headMemory.getUsed() / MB);
   stringBuilder.append("\t提交的記憶體(已申請)(M):" + headMemory.getCommitted() / MB);
   stringBuilder.append("\t使用率:" + headMemory.getUsed() * 100 / headMemory.getCommitted() + "%");
   return stringBuilder.toString();
}

生成jar包部署到伺服器

圖片

啟動引數:

java -Xms256m -Xmx256m -verbose:gc -Xloggc:/root/jvm/gc-cms.log -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintHeapAtGC -XX:HeapDumpPath=/root/jvm/dump.hprof -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCTimeStamps -XX:+PrintCommandLineFlags -XX:+PrintFlagsFinal -XX:+PrintGCDetails -XX:+UseCMSCompactAtFullCollection -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.port=6666 -Djava.rmi.server.hostname=192.168.0.31 -jar /root/jvm/jvm-web-0.0.1-SNAPSHOT.jar > catalina.out &

這兒要插播下JVM引數意義.

JVM引數詳解:

JVM引數 含義
-XX:-CMSPrecleaningEnabled 不進行預清理,度過我們之前的文章的都知道,CMS 在併發標記和重新標記的這段時間內,會有一個預清理的工作,而這個通過會嘗試5秒之內等待來一次 YGC。以免在後面的重新標記階段耗費大量時間來標記新生代的物件。
-XX:+UseConcMarkSweepGC 此引數將啟動 CMS 回收器。預設新生代是 ParNew,也可以設定 Serial 為新生代收集器。該引數等價於 -Xconcgc。
-XX:ParallelGCThreads 由於是並行處理器,當然也可以指定執行緒數。預設併發執行緒數是:(ParallelGCThreads + 3)/ 4)。
-XX:ConcGCThreads 或者 -XX:ParallelCMSThreads ;除了上面設定執行緒的方式,你也可以通過這個兩個引數任意一個手工設定 CMS 併發執行緒數
-XX:CMSInitiatingOccupancyFraction 由於 CMS 回收器不是獨佔式的,在垃圾回收的時候應用程式仍在工作,所以需要留出足夠的記憶體給應用程式,否則會觸發 FGC。而什麼時候執行 CMS GC 呢?通過該引數即可設定,該參數列示的是老年代的記憶體使用百分比。當達到這個閾值就會執行 CMS。預設是68。 如果老年代記憶體增長很快,建議降低閾值,避免 FGC,如果增長慢,則可以加大閾值,減少 CMS GC 次數。提高吞吐量。
-XX:+UseCMSCompactAtFullCollection 由於 CMS 使用標記清理演算法,記憶體碎片無法避免。該引數指定每次 CMS 後進行一次碎片整理。
-XX:CMSFullGCsBeforeCompaction 由於每次進行碎片整理將會影響效能,你可以使用該引數設定多少次 CMS 後才進行一次碎片整理,也就是記憶體壓縮。
-XX:+CMSClassUnloadingEnabled 允許對類後設資料進行回收。
-XX:CMSInitiatingPermOccupancyFraction 當永久區佔用率達到這一百分比時,啟動 CMS 回收(前提是 -XX:+CMSClassUnloadingEnabled 啟用了)。
-XX:UseCMSInitiatingOccupancyOnly 表示只在到達閾值的時候才進行 CMS 回收。
XX:CMSWaitDuration=2000 由於CMS GC 條件比較簡單,JVM有一個執行緒定時掃描Old區,時間間隔可以通過該引數指定(毫秒單位),預設是2s。

JVM工具引數:

JVM引數 含義
-XX:+PrintGCDateStamps 列印 GC 日誌時間戳
-XX:+PrintGCDetails 列印 GC 詳情
-XX:+PrintGCTimeStamps 印此次垃圾回收距離jvm開始執行的所耗時間
-Xloggc: 將垃圾回收資訊輸出到指定檔案
-verbose:gc 列印 GC 日誌
-XX:+PrintGCApplicationStopedTime 檢視 gc 造成的應用暫停時間
XX:+PrintTenuringDistribution 物件晉升的日誌
-XX:+HeapDumpOnOutOfMemoryError 記憶體溢位時輸出 dump 檔案

圖片

啟動效果:

圖片

訪問:

我們不難發現新生代用的是parNew 老年代用的cms

圖片

請求put:

我們通過http訪問put方法之後看看效果:

效果如下:

圖片

圖片

圖片

圖片

在執行的過程中我們發現有大量的物件進入老年代,觸發了full gc,cms一直在收集。

使用率達到99%,cms也一刻沒停下:

圖片

日誌分析:

圖片

日誌分析1.0版本:

我們抽取一條日誌來分析下

[GC (Allocation Failure) 0K->63K(64K), 0.0047147 secs] 10258K->6780K(46144K), [Metaspace: 3434K->3434K(1056768K)], 0.0047613 secs][Times: user=0.02 sys=0.00, real=0.00 secs]

該日誌為四個部分:

Full GC:

表明進行了一次垃圾回收,前面沒有Full修飾,表明這是一次Minor GC ,注意它不表示只GC新生代,並且現有的不管是新生代還是老年代都會STW。

Allocation Failure:

表明本次引起GC的原因是因為在年輕代中沒有足夠的空間能夠儲存新的資料了。

10258K->6780K(46144K),:單位是KB

三個引數分別為:GC前該記憶體區域(這裡是年輕代)使用容量,GC後該記憶體區域使用容量,該記憶體區域總容量。

0.0047613 secs:

該記憶體區域GC耗時,單位是秒

[Times: user=0.04 sys=0.00, real=0.01 secs]:

分別表示使用者態耗時,核心態耗時和總耗時

圖片

日誌分析2.0版本:

採用線上gceasy來進行分析,我們開啟網址,然後上傳我們生產的gc日誌,如圖所示:

圖片

優化問題:

列出了可以優化的4個問題新生代和老年代元空間記憶體佔用情況

圖片

吞吐量統計:97.39%

圖片

各各分代的記憶體變化:

圖片

CMS垃圾收集器不同時期發生的耗時

圖片

圖片

GC發生次數的分類和耗時情況

圖片

定位問題:

我們通過生產的快照檔案來定位問題:

圖片

圖片

JProfiler:

下載到本地通過JProfiler開啟檢視

圖片

檢視大物件:

圖片

我們不難發現是ArrayList集合佔用了96%的記憶體,那我們來看看哪塊程式碼大量用到了我們ArrayList集合了?

圖片

找到對應程式碼

圖片

通過此程式碼我們就發現put方法大量用到了ArrayList集合造成的記憶體溢位OOM

總結:

上述實戰相信大家都明白了,大致流程就是:

1、夠將SpringBoot專案 模擬真實大批量使用者場景

2、配置JVM引數然後部署執行監控資料生成日誌檔案

3、通過分析日誌檔案確認問題。

需要上文程式碼和軟體的朋友,可以關注我的微信:Java2B,大家可以自己實操下加深印象。

今天就寫到這了。覺得不錯歡迎關注點贊,你們的點贊關注是我出好文最大的動力。

能看到這的都是牛人,麻煩幫忙點個贊關注下,下篇我繼續帶來CMS和G1實戰PK對比,圖形化對比看的更直觀。

相關文章