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

Java2B發表於2020-01-09
JVMGC

開頭：

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

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

圖片

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

圖片

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

圖片

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

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對比，圖形化對比看的更直觀。

圖片

          加關注，不迷路。
複製程式碼

相關文章