一文掌握并应用Elasticsearch中的GC实现垃圾日志处理

迷南。 2023-02-23 08:15 9阅读 0赞

如果你关注过 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 相关的日志，那么你了解每一部分的含义吗？如果不了解，你可以继续往下看了。  
我们先从最简单的看起：

1、第一部分是**日志发生的时间**  
2、第二部分是**日志级别**，这里分别是**WARN和INFO**  
3、第三部分是**输出日志**的类，我们后面也会讲到这个类  
4、第四部分是**当前 ES 节点名称**  
5、第五部分是 **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、如何找到垃圾？  
2、如何回收垃圾？  
3、何时回收垃圾？

我们一个个来看下。

1.1、如何找到垃圾

所谓垃圾，指的是不再被使用（引用）的对象。Java 的对象都是在堆(Heap)上创建的，我们这里默认也只讨论堆。那么现在问题就变为如何判定一个对象是否还有被引用，思路主要有如下两种：

**1、引用计数法**，即在对象被引用时加1，去除引用时减1，如果引用值为0，即表明该对象可回收了。

**2、可达性分析法**，即通过遍历已知的存活对象**(GC Roots)**的引用链来标记出所有存活对象

方法1：简单粗暴效率高，但准确度不行，尤其是面对互相引用的垃圾对象时无能为力。

方法2：是目前常用的方法，这里有一个关键是** GC Roots，**它是判定的源头，感兴趣的同学可以自己去研究下，这里就不展开讲了。

![image.png][]

1.2、如何回收垃圾？

垃圾找到了，该怎么回收呢？看起来似乎是个很傻的问题。直接收起来扔掉不就好了？！对应到程序的操作，就是直接将这些对象占用的空间标记为**空闲**不就好了吗？那我们就来看一下这个基础的回收算法：标记-清除(Mark-Sweep)算法。

1.2.1 标记-清除 算法(Mark Sweep)

该算法很简单，使用通过可达性分析分析方法标记出垃圾，然后直接回收掉垃圾区域。它的一个显著问题是一段时间后，内存会出现大量碎片，导致虽然碎片总和很大，但无法满足一个大对象的内存申请，从而导致 OOM，而过多的内存碎片（需要类似链表的数据结构维护），也会导致标记和清除的操作成本高，效率低下，如下图所示：

![image.png][image.png 1]

1.2.2 复制算法(Copying)

为了解决上面算法的效率问题，有人提出了复制算法。它将可用**内存一分为二**，每次只用一块，当这一块内存不够用时，便触发 GC，将当前存活对象复制(Copy)到另一块上，以此往复。这种算法高效的原因在于分配内存时只需要将指针后移，不需要维护链表等。但它**最大的问题是对内存的浪费**，使用率只有 50%。

但这种算法在一种情况下会很高效：Java 对象的存活时间极短。据 IBM 研究，Java 对象高达 98% 是**朝生夕死**的，这也意味着每次 GC 可以回收大部分的内存，需要复制的数据量也很小，这样它的执行效率就会很高。

![image.png][image.png 2]

1.2.3 标记-整理算法(Mark Compact)

该算法解决了第1中算法的内存碎片问题，它会在回收阶段将所有内存做整理，如下图所示：

![image.png][image.png 3]

但它的问题也在于增加了整理阶段，也就增加了 GC 的时间。

1.2.4 分代收集算法(Generation Collection)

既然大部分 Java 对象是**朝生夕死**的，那么我们将内存按照 Java 生存时间分为** 新生代(Young) **和 **老年代(Old)，**前者存放短命僧，后者存放长寿佛，当然长寿佛也是由短命僧升级上来的。然后针对两者可以采用不同的回收算法，比如对于**新生代**采用复制算法会比较高效，而对**老年代**可以采用标记-清除或者标记-整理算法。这种算法也是最常用的。JVM Heap 分代后的划分一般如下所示，新生代一般会分为 Eden、Survivor0、Survivor1区，便于使用复制算法。

![image.png][image.png 4]

将内存分代后的 GC 过程一般类似下图所示：

![image.png][image.png 5]

1、对象一般都是先在 **Eden** 区创建

2、当 **Eden** 区满，触发 Young GC，此时将 Eden中还存活的对象复制到 S0中，并清空 Eden区后继续为新的对象分配内存

3、当 **Eden** 区再次满后，触发又一次的 Young GC，此时会将 Eden和S0中存活的对象复制到 S1中，然后清空Eden和S0后继续为新的对象分配内存

4、每经过一次 Young GC，存活下来的对象都会将自己存活次数加1，当达到一定次数后，会随着一次 Young GC 晋升到 Old区

5、Old区也会在合适的时机进行自己的 GC

1.2.5 常见的垃圾收集器

前面我们讲了众多的垃圾收集算法，那么其具体的实现就是垃圾收集器，也是我们实际使用中会具体用到的。现代的垃圾收集机制基本都是分代收集算法，而 Young与 Old区分别有不同的垃圾收集器，简单总结如下图：

![image.png][image.png 6]

从上图我们可以看到 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。执行大致如下所示：

![image.png][image.png 7]

1.2.5.2 Parallel GC

该类Young 区的有 ParNew和 Parallel Scavenge，Old 区的有Parallel Old。其运行机制如下，相比 Serial GC ，其最大特点在于 GC 线程是并行的，效率高很多：

![image.png][image.png 8]

1.2.5.3 Concurrent Mark-Sweep GC

该类目前只是针对 Old 区，最常见就是CMS GC，它的执行分为多个阶段，只有部分阶段需要停止用户进程，这里不详细介绍了，感兴趣可以去找相关文章来看，大体执行如下：

![image.png][image.png 9]

1.2.5.4 其他

目前最新的 GC 有G1GC和ZGC，其运行机制与上述均不相同，虽然他们也是分代收集算法，但会把 Heap 分成多个 region 来做处理，这里不展开讲，感兴趣的可以参看最后参考资料的内容。

![image.png][image.png 10]

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 何时进行回收？

现在我们已经知道如何找到和回收垃圾了，那么什么时候回收呢？简单总结如下：

1、Young 区的GC 都是在 Eden 区满时触发

2、Serial Old 和 Parallel Old 在 Old 区是在 Young GC 时预测Old 区是否可以为 young 区 promote 到 old 区 的 object 分配空间，如果不可用则触发 Old GC。这个也可以理解为是 Old区满时。

3、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 在最近 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这是第228385次 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\]/\[young区 Memory 总大小\] \} \{survivor 区->\[GC后 Memory\]/\[survivor区 Memory 总大小\] \}\{old 区->\[GC后 Memory\]/\[old区 Memory 总大小\] \}

### 3. 看看源码 ###

从日志中我们可以看到输出这些日志的类名叫做JvmGcMonitorService，我们去源码中搜索很快会找到  
它/Users/rockybean/code/elasticsearch/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java，这里就不详细展开讲解源码了，它执行的内容大概如下图所示:

![image.png][image.png 11]

关于打印日志的格式在源码也有，如下所示：

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. 参考资料 ###

1.  Java Hotspot G1 GC的一些关键技术（[https://mp.weixin.qq.com/s/4ufdCXCwO56WAJnzng\_-ow][https_mp.weixin.qq.com_s_4ufdCXCwO56WAJnzng_-ow]）
2.  Understanding Java Garbage Collection（[https://www.cubrid.org/blog/understanding-java-garbage-collection][https_www.cubrid.org_blog_understanding-java-garbage-collection]）
3.  《深入理解Java虚拟机：JVM高级特性与最佳实践》

> 声明：本文由原文《你看懂 Elasticsearch Log 中的 GC 日志了吗？》作者“魏彬”授权转载，对未经许可擅自使用者，保留追究其法律责任的权利。

[image.png]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvM2ZjZDNlMTU4OGE5NGQ4NTk0YmQ3MDQ1MDQ3NjA5Y2QucG5n?x-oss-process=image/format,png
[image.png 1]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvYjc0ZmI0ZjQwZWZjNGU3NDgyY2IwMTBkYjc4ZTAxNjMucG5n?x-oss-process=image/format,png
[image.png 2]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvNWRiMzllZjIxOGUxNDU2YWI1ZDA4Yzk5YjE3OWVhYjIucG5n?x-oss-process=image/format,png
[image.png 3]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvOTVjMDg4NDdhOWUxNDJkMWE2ODk0NGU4NDI4NDI0MWIucG5n?x-oss-process=image/format,png
[image.png 4]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvOWIwNWZlNWRlNDA5NDQ0YTllNzFiYmNiODgwMDA4MzIucG5n?x-oss-process=image/format,png
[image.png 5]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvMmQ0NGUyZjg5OTA2NGIxZmIyMTNkMWQwZTc1ZTA4YzIucG5n?x-oss-process=image/format,png
[image.png 6]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvMmQ4NDg2OGExMGFiNGI0YmE0ODcxNTgxNjU3YzlkMjgucG5n?x-oss-process=image/format,png
[image.png 7]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvOGQyOWExN2Y1NDE2NDE1Nzk4MjNhYWY5MWU0ZDMxYTQucG5n?x-oss-process=image/format,png
[image.png 8]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvODhiZjRlOTRhYzAzNDUxMDljOGNhODVmNTZjN2Q3MTEucG5n?x-oss-process=image/format,png
[image.png 9]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvMmY4ZmY0NTRiNGYzNDhmM2I4YWM1Yzg3YzVlZjM3MGQucG5n?x-oss-process=image/format,png
[image.png 10]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvMzRjMzRiYWMwY2E0NDUyOGE3NmY0ZjViODhmMmNmYWQucG5n?x-oss-process=image/format,png
[image.png 11]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly91Y2MuYWxpY2RuLmNvbS9waWMvZGV2ZWxvcGVyLWVjb2xvZ3kvNDMxNzVkMTk2ZGQwNDE4OGJkNTE0NDFkYWVhMWIzYjAucG5n?x-oss-process=image/format,png
[https_mp.weixin.qq.com_s_4ufdCXCwO56WAJnzng_-ow]: https://mp.weixin.qq.com/s/4ufdCXCwO56WAJnzng_-ow
[https_www.cubrid.org_blog_understanding-java-garbage-collection]: https://www.cubrid.org/blog/understanding-java-garbage-collection