Elasticsearch Log GC 日誌分析詳解

阿新 • • 發佈：2018-11-12

如果你關注過 elasticsearch 的日誌，可能會看到如下類似的內容：

[2018-06-30T17:57:23,848][WARN ][o.e.m.j.JvmGcMonitorService] [qoo--eS] [gc][228384] overhead, spent [2.2s] collecting in the last [2.3s]

[2018-06-30T17:57:29,020][INFO ][o.e.m.j.JvmGcMonitorService] [qoo--eS] [gc][old][228385][160772] duration [5s], collections [1]/[5.1s], total [5s]/[4.4d], memory [945.4mb]->[958.5mb]/[1007.3mb], all_pools {[young] [87.8mb]->[100.9mb]/[133.1mb]}{[survivor] [0b]->[0b]/[16.6mb]}{[old] [857.6mb]->[857.6mb]/[857.6mb]}

看到其中的[gc]關鍵詞你也猜到了這是與 GC 相關的日誌，那麼你瞭解每一部分的含義嗎？如果不瞭解，你可以繼續往下看了。

我們先從最簡單的看起：

第一部分是日誌發生的時間
第二部分是日誌級別，這裡分別是WARN和INFO
第三部分是輸出日誌的類，我們後面也會講到這個類
第四部分是當前 ES 節點名稱
第五部分是 gc 關鍵詞，我們就從這個關鍵詞聊起。

友情提示：對 GC 已經瞭如指掌的同學，可以直接翻到最後看答案。

1. 什麼是 GC？

GC，全稱是 Garbage Collection （垃圾收集）或者 Garbage Collector

(垃圾收集器)。

在使用 C語言程式設計的時候，我們要手動的通過 malloc 和 free來申請和釋放資料需要的記憶體，如果忘記釋放記憶體，就會發生記憶體洩露的情況，即無用的資料佔用了寶貴的記憶體資源。而Java 語言程式設計不需要顯示的申請和釋放記憶體，因為 JVM 可以自動管理記憶體，這其中最重要的一部分就是 GC，即 JVM 可以自主地去釋放無用資料（垃圾）佔用的記憶體。

我們研究 GC 的主要原因是 GC 的過程會有 Stop The World(STW)的情況發生，即此時使用者執行緒會停止工作，如果 STW 的時間過長，則應用的可用性、實時性等就下降的很厲害。

GC主要解決如下3個問題：

如何找到垃圾？
如何回收垃圾？
何時回收垃圾？

我們一個個來看下。

1.1 如何找到垃圾？

所謂垃圾，指的是不再被使用（引用）的物件。Java 的物件都是在堆(Heap)上建立的，我們這裡預設也只討論堆。那麼現在問題就變為如何判定一個物件是否還有被引用，思路主要有如下兩種：

引用計數法，即在物件被引用時加1，去除引用時減1，如果引用值為0，即表明該物件可回收了。
可達性分析法，即通過遍歷已知的存活物件(GC Roots)的引用鏈來標記出所有存活物件

方法1簡單粗暴效率高，但準確度不行，尤其是面對互相引用的垃圾物件時無能為力。

方法2是目前常用的方法，這裡有一個關鍵是 GC Roots，它是判定的源頭，感興趣的同學可以自己去研究下，這裡就不展開講了。

1.2 如何回收垃圾？

垃圾找到了，該怎麼回收呢？看起來似乎是個很傻的問題。直接收起來扔掉不就好了？！對應到程式的操作，就是直接將這些物件佔用的空間標記為空閒不就好了嗎？那我們就來看一下這個基礎的回收演算法：標記-清除(Mark-Sweep)演算法。

1.2.1 標記-清除演算法(Mark Sweep)

該演算法很簡單，使用通過可達性分析分析方法標記出垃圾，然後直接回收掉垃圾區域。它的一個顯著問題是一段時間後，記憶體會出現大量碎片，導致雖然碎片總和很大，但無法滿足一個大物件的記憶體申請，從而導致 OOM，而過多的記憶體碎片（需要類似連結串列的資料結構維護），也會導致標記和清除的操作成本高，效率低下，如下圖所示：

1.2.2 複製演算法(Copying)

為了解決上面演算法的效率問題，有人提出了複製演算法。它將可用記憶體一分為二，每次只用一塊，當這一塊記憶體不夠用時，便觸發 GC，將當前存活物件複製(Copy)到另一塊上，以此往復。這種演算法高效的原因在於分配記憶體時只需要將指標後移，不需要維護連結串列等。但它最大的問題是對記憶體的浪費，使用率只有 50%。

但這種演算法在一種情況下會很高效：Java 物件的存活時間極短。據 IBM 研究，Java 物件高達 98% 是朝生夕死的，這也意味著每次 GC 可以回收大部分的記憶體，需要複製的資料量也很小，這樣它的執行效率就會很高。

1.2.3 標記-整理演算法(Mark Compact)

該演算法解決了第1中演算法的記憶體碎片問題，它會在回收階段將所有記憶體做整理，如下圖所示：

但它的問題也在於增加了整理階段，也就增加了 GC 的時間。

1.2.4 分代收集演算法(Generation Collection)

既然大部分 Java 物件是朝生夕死的，那麼我們將記憶體按照 Java 生存時間分為 新生代(Young) 和 老年代(Old)，前者存放短命僧，後者存放長壽佛，當然長壽佛也是由短命僧升級上來的。然後針對兩者可以採用不同的回收演算法，比如對於新生代採用複製演算法會比較高效，而對老年代可以採用標記-清除或者標記-整理演算法。這種演算法也是最常用的。JVM Heap 分代後的劃分一般如下所示，新生代一般會分為 Eden、Survivor0、Survivor1區，便於使用複製演算法。

將記憶體分代後的 GC 過程一般類似下圖所示：

物件一般都是先在 Eden區建立
當Eden區滿，觸發 Young GC，此時將 Eden中還存活的物件複製到 S0中，並清空 Eden區後繼續為新的物件分配記憶體
當Eden區再次滿後，觸發又一次的 Young GC，此時會將 Eden和S0中存活的物件複製到 S1中，然後清空Eden和S0後繼續為新的物件分配記憶體
每經過一次 Young GC，存活下來的物件都會將自己存活次數加1，當達到一定次數後，會隨著一次 Young GC 晉升到 Old區
Old區也會在合適的時機進行自己的 GC

1.2.5 常見的垃圾收集器

前面我們講了眾多的垃圾收集演算法，那麼其具體的實現就是垃圾收集器，也是我們實際使用中會具體用到的。現代的垃圾收集機制基本都是分代收集演算法，而 Young與 Old區分別有不同的垃圾收集器，簡單總結如下圖：

從上圖我們可以看到 Young與 Old區有不同的垃圾收集器，實際使用時會搭配使用，也就是上圖中兩兩連線的收集器是可以搭配使用的。這些垃圾收集器按照執行原理大概可以分為如下幾類：

Serial GC，序列，單執行緒的收集器，執行 GC 時需要停止所有的使用者執行緒，且只有一個 GC 執行緒
Parallel GC，並行，多執行緒的收集器，是 Serial 的多執行緒版，執行時也需要停止所有使用者執行緒，但同時執行多個 GC 執行緒，所以效率高一些
Concurrent GC，併發，多執行緒收集器，GC 分多階段執行，部分階段允許使用者執行緒與 GC 執行緒同時執行，這也就是併發的意思，大家要和並行做一個區分。
其他

我們下面簡單看一下他們的執行機制。

1.2.5.1 Serial GC

該類 Young區的為 Serial GC，Old區的為Serial Old GC。執行大致如下所示：

1.2.5.2 Parallel GC

該類Young 區的有 ParNew和 Parallel Scavenge，Old 區的有Parallel Old。其執行機制如下，相比 Serial GC ，其最大特點在於 GC 執行緒是並行的，效率高很多：

1.2.5.3 Concurrent Mark-Sweep GC

該類目前只是針對 Old 區，最常見就是CMS GC，它的執行分為多個階段，只有部分階段需要停止使用者程序，這裡不詳細介紹了，感興趣可以去找相關文章來看，大體執行如下：

1.2.5.4 其他

目前最新的 GC 有G1GC和ZGC，其執行機制與上述均不相同，雖然他們也是分代收集演算法，但會把 Heap 分成多個 region 來做處理，這裡不展開講，感興趣的可以參看最後參考資料的內容。

1.2.6 Elasticsearch 的 GC 組合

Elasticsearch 預設的 GC 配置是CMS GC ，其 Young 區用 ParNew，Old 區用CMS，大家可以在 config/jvm.options中看到如下的配置：

## GC configuration
-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=75
-XX:+UseCMSInitiatingOccupancyOnly

1.3 何時進行回收？

現在我們已經知道如何找到和回收垃圾了，那麼什麼時候回收呢？簡單總結如下：

Young 區的GC 都是在 Eden 區滿時觸發
Serial Old 和 Parallel Old 在 Old 區是在 Young GC 時預測Old 區是否可以為 young 區 promote 到 old 區的 object 分配空間，如果不可用則觸發 Old GC。這個也可以理解為是 Old區滿時。
CMS GC 是在 Old 區大小超過一定比例後觸發，而不是 Old 區滿。這個原因在於 CMS GC 是併發的演算法，也就是說在 GC 執行緒收集垃圾的時候，使用者執行緒也在執行，因此需要預留一些 Heap 空間給使用者執行緒使用，防止由於無法分配空間而導致 Full GC 發生。

2. GC Log 如何閱讀？

前面講了這麼多，終於可以回到開篇的問題了，我們直接來看答案

[2018-06-30T17:57:23,848][WARN ][o.e.m.j.JvmGcMonitorService] [qoo--eS] [gc][228384] overhead, spent [2.2s] collecting in the last [2.3s]

[gc][這是第228384次GC 檢查] 在最近 2.3 s 內花了 2.2s 用來做垃圾收集，這佔比似乎有些過了，請抓緊來關注下。

[2018-06-30T17:57:29,020][INFO ][o.e.m.j.JvmGcMonitorService] [qoo--eS] [gc][old][228385][160772] duration [5s], collections [1]/[5.1s], total [5s]/[4.4d], memory [945.4mb]->[958.5mb]/[1007.3mb], all_pools {[young] [87.8mb]->[100.9mb]/[133.1mb]}{[survivor] [0b]->[0b]/[16.6mb]}{[old] [857.6mb]->[857.6mb]/[857.6mb]}

我們直接來看具體的含義好了，相信有了前面的 GC 基礎知識，大家在看這裡解釋的時候就非常清楚了。

[gc][本次是 old GC][這是第228385次 GC 檢查][從 JVM 啟動至今發生的第 160772次 GC]
duration [本次檢查到的 GC 總耗時 5 秒，可能是多次的加和],
collections [從上次檢查至今總共發生1次 GC]/[從上次檢查至今已過去 5.1 秒],
total [本次檢查到的 GC 總耗時為 5 秒]/[從 JVM 啟動至今發生的 GC 總耗時為 4.4 天]，
memory [ GC 前 Heap memory 空間]->[GC 後 Heap memory 空間]/[Heap memory 總空間],
all_pools(分代部分的詳情) {[young 區][GC 前 Memory ]->[GC後 Memory]/[young區 Memory 總大小] } {[survivor 區][GC 前 Memory ]->[GC後 Memory]/[survivor區 Memory 總大小] }{[old 區][GC 前 Memory ]->[GC後 Memory]/[old區 Memory 總大小] }

3. 看看原始碼

從日誌中我們可以看到輸出這些日誌的類名叫做JvmGcMonitorService，我們去原始碼中搜索很快會找到它/Users/rockybean/code/elasticsearch/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java，這裡就不詳細展開講解原始碼了，它執行的內容大概如下圖所示:

關於列印日誌的格式在原始碼也有，如下所示：

private static final String SLOW_GC_LOG_MESSAGE =
"[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}";
private static final String OVERHEAD_LOG_MESSAGE = "[gc][{}] overhead, spent [{}] collecting in the last [{}]";

另外細心的同學會發現輸出的日誌中 gc 只分了 young 和 old ，原因在於 ES 對 GC Name 做了封裝，封裝的類為：org.elasticsearch.monitor.jvm.GCNames，相關程式碼如下：

    public static String getByMemoryPoolName(String poolName, String defaultName) {
        if ("Eden Space".equals(poolName) || "PS Eden Space".equals(poolName) || "Par Eden Space".equals(poolName) || "G1 Eden Space".equals(poolName)) {
            return YOUNG;
        }
        if ("Survivor Space".equals(poolName) || "PS Survivor Space".equals(poolName) || "Par Survivor Space".equals(poolName) || "G1 Survivor Space".equals(poolName)) {
            return SURVIVOR;
        }
        if ("Tenured Gen".equals(poolName) || "PS Old Gen".equals(poolName) || "CMS Old Gen".equals(poolName) || "G1 Old Gen".equals(poolName)) {
            return OLD;
        }
        return defaultName;
    }

    public static String getByGcName(String gcName, String defaultName) {
        if ("Copy".equals(gcName) || "PS Scavenge".equals(gcName) || "ParNew".equals(gcName) || "G1 Young Generation".equals(gcName)) {
            return YOUNG;
        }
        if ("MarkSweepCompact".equals(gcName) || "PS MarkSweep".equals(gcName) || "ConcurrentMarkSweep".equals(gcName) || "G1 Old Generation".equals(gcName)) {
            return OLD;
        }
        return defaultName;
    }

在上面的程式碼中，你會看到很多我們在上一節中提到的 GC 演算法的名稱。

至此，原始碼相關部分也講解完畢，感興趣的大家可以自行去查閱。

4. 總結

講解 GC 的文章已經很多，本文又嘮嘮叨叨地講一遍基礎知識，是希望對於第一次瞭解 GC 的同學有所幫助。因為只有瞭解了這些基礎知識，你才不至於被這些 GC 的輸出嚇懵。希望本文對你理解 ES 的 GC 日誌有所幫助。

5. 參考資料

Java Hotspot G1 GC的一些關鍵技術（https://mp.weixin.qq.com/s/4ufdCXCwO56WAJnzng_-ow）
Understanding Java Garbage Collection（https://www.cubrid.org/blog/understanding-java-garbage-collection）
《深入理解Java虛擬機器：JVM高階特性與最佳實踐》

6. 相關推薦

如果你想深入的瞭解 JAVA GC 的知識，可以關注 ElasticTalk 公眾號，回覆 GC關鍵詞後即可獲取作者推薦的電子書等資料。

本文轉自地址：http://elasticsearch.cn/article/812

Elasticsearch Log GC 日誌分析詳解

1. 什麼是 GC？

1.1 如何找到垃圾？

1.2 如何回收垃圾？

1.2.1 標記-清除演算法(Mark Sweep)

1.2.2 複製演算法(Copying)

1.2.3 標記-整理演算法(Mark Compact)

1.2.4 分代收集演算法(Generation Collection)

1.2.5 常見的垃圾收集器

1.2.5.1 Serial GC

1.2.5.2 Parallel GC

1.2.5.3 Concurrent Mark-Sweep GC

1.2.5.4 其他

1.2.6 Elasticsearch 的 GC 組合

1.3 何時進行回收？

2. GC Log 如何閱讀？

3. 看看原始碼

4. 總結

5. 參考資料

6. 相關推薦

Elasticsearch Log GC 日誌分析詳解

Linux日誌分析詳解

Yolo3的日誌分析詳解2-主要分析總的損失值、平均損失值等

關於syslog日誌功能詳解事件日誌分析、EventLog Analyzer

elasticSearch+spring 整合 maven依賴詳解

日誌配置詳解

MongoDB執行計劃分析詳解（1）

Tomcat日誌系統詳解

Java垃圾回收（GC）機制詳解

Elasticsearch慢查詢日誌分析

elasticsearch-.yml（中文配置詳解）

JVM結構、GC工作機制詳解

Log4J日誌配置詳解

22.Linux-塊設備驅動之框架詳細分析(詳解)

JVM、Gc工作機制詳解

JVM-GC日誌分析

elasticsearch系列三：索引詳解（分詞器、文檔管理、路由詳解）

業余草分享面試題，JVM結構、GC工作機制詳解

iOS培訓就業前景分析詳解

轉 Elasticsearch的使用場景深入詳解(Elasticsearch實戰篇)

Elasticsearch Log GC 日誌分析詳解

1. 什麼是 GC？

1.1 如何找到垃圾？

1.2 如何回收垃圾？

1.2.1 標記-清除 演算法(Mark Sweep)

1.2.2 複製演算法(Copying)

1.2.3 標記-整理演算法(Mark Compact)

1.2.4 分代收集演算法(Generation Collection)

1.2.5 常見的垃圾收集器

1.2.5.1 Serial GC

1.2.5.2 Parallel GC

1.2.5.3 Concurrent Mark-Sweep GC

1.2.5.4 其他

1.2.6 Elasticsearch 的 GC 組合

1.3 何時進行回收？

2. GC Log 如何閱讀？

3. 看看原始碼

4. 總結

5. 參考資料

6. 相關推薦

相關推薦

1.2.1 標記-清除演算法(Mark Sweep)