gc

gc

你看懂 Elasticsearch Log 中的 GC 日志了吗?

Elasticsearchrockybean 发表了文章 • 0 个评论 • 443 次浏览 • 2018-09-22 23:29 • 来自相关话题

如果你关注过 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. 第二部分是日志级别,这里分别是WARNINFO
  3. 第三部分是输出日志的类,我们后面也会讲到这个类
  4. 第四部分是当前 ES 节点名称
  5. 第五部分是 gc 关键词,我们就从这个关键词聊起。

友情提示:对 GC 已经了如指掌的同学,可以直接翻到最后看答案。

1. 什么是 GC?

GC,全称是 Garbage Collection (垃圾收集)或者 Garbage Collector(垃圾收集器)。

在使用 C语言编程的时候,我们要手动的通过 mallocfree来申请和释放数据需要的内存,如果忘记释放内存,就会发生内存泄露的情况,即无用的数据占用了宝贵的内存资源。而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,它是判定的源头,感兴趣的同学可以自己去研究下,这里就不展开讲了。

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 过程一般类似下图所示:

  1. 对象一般都是先在 Eden区创建
  2. Eden区满,触发 Young GC,此时将 Eden中还存活的对象复制到 S0中,并清空 Eden区后继续为新的对象分配内存
  3. Eden区再次满后,触发又一次的 Young GC,此时会将 EdenS0中存活的对象复制到 S1中,然后清空EdenS0后继续为新的对象分配内存
  4. 每经过一次 Young GC,存活下来的对象都会将自己存活次数加1,当达到一定次数后,会随着一次 Young GC 晋升到 Old
  5. Old区也会在合适的时机进行自己的 GC

1.2.5 常见的垃圾收集器

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

从上图我们可以看到 YoungOld区有不同的垃圾收集器,实际使用时会搭配使用,也就是上图中两两连线的收集器是可以搭配使用的。这些垃圾收集器按照运行原理大概可以分为如下几类:

  • Serial GC串行,单线程的收集器,运行 GC 时需要停止所有的用户线程,且只有一个 GC 线程
  • Parallel GC并行,多线程的收集器,是 Serial 的多线程版,运行时也需要停止所有用户线程,但同时运行多个 GC 线程,所以效率高一些
  • Concurrent GC并发,多线程收集器,GC 分多阶段执行,部分阶段允许用户线程与 GC 线程同时运行,这也就是并发的意思,大家要和并行做一个区分。
  • 其他

我们下面简单看一下他们的运行机制。

1.2.5.1 Serial GC

该类 Young区的为 Serial GCOld区的为Serial Old GC。执行大致如下所示:

1.2.5.2 Parallel GC

该类Young 区的有 ParNewParallel ScavengeOld 区的有Parallel Old。其运行机制如下,相比 Serial GC ,其最大特点在于 GC 线程是并行的,效率高很多:

1.2.5.3 Concurrent Mark-Sweep GC

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

1.2.5.4 其他

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

1.2.6 Elasticsearch 的 GC 组合

Elasticsearch 默认的 GC 配置是CMS GC ,其 Young 区ParNewOld 区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][这是第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. 参考资料

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

6. 相关推荐

如果你想深入的了解 JAVA GC 的知识,可以关注 ElasticTalk 公众号,回复 GC关键词后即可获取作者推荐的电子书等资料。

elasticTalk,qrcode

ES有时候old GC的时间会非常长,请问可能是因为什么原因?

Elasticsearchzqc0512 回复了问题 • 3 人关注 • 3 个回复 • 274 次浏览 • 2018-09-03 09:41 • 来自相关话题

bulk无法导入数据

Elasticsearchxinfanwang 回复了问题 • 5 人关注 • 5 个回复 • 637 次浏览 • 2018-05-14 09:59 • 来自相关话题

elasticsearch 6.0+ 版本jdk选择

Elasticsearchlaoyang360 回复了问题 • 3 人关注 • 1 个回复 • 523 次浏览 • 2018-04-18 23:41 • 来自相关话题

gc warn

Elasticsearchlaoyang360 回复了问题 • 3 人关注 • 2 个回复 • 483 次浏览 • 2018-04-16 19:28 • 来自相关话题

gc时查询耗时变高

Elasticsearchkennywu76 回复了问题 • 2 人关注 • 1 个回复 • 900 次浏览 • 2018-04-16 16:28 • 来自相关话题

es gc 导致集群挂了

Elasticsearchmedcl 回复了问题 • 2 人关注 • 1 个回复 • 538 次浏览 • 2018-01-15 11:57 • 来自相关话题

es 由于gc 引起的节点脱落

Elasticsearchklause 发表了文章 • 9 个评论 • 683 次浏览 • 2017-09-01 09:44 • 来自相关话题

最近发现es节点在gc时,引起节点脱落,将配置改成如下后,过了一阵又发生节点脱落的情况。discovery.zen.fd.ping_timeout: 60s discovery.zen.fd.ping_interval: 10s discovery.zen.fd.ping_retries: 10   这个配置值如何设置?另是否还有其他的解决方案  
最近发现es节点在gc时,引起节点脱落,将配置改成如下后,过了一阵又发生节点脱落的情况。discovery.zen.fd.ping_timeout: 60s discovery.zen.fd.ping_interval: 10s discovery.zen.fd.ping_retries: 10   这个配置值如何设置?另是否还有其他的解决方案  

es yong gc将近1s,该如果平滑调优

Elasticsearch冯坤 回复了问题 • 6 人关注 • 4 个回复 • 934 次浏览 • 2017-08-29 17:16 • 来自相关话题

求助。ES集群运行一段时间就会不断的full gc。。。请看日志

Elasticsearchybtsdst 回复了问题 • 3 人关注 • 3 个回复 • 2014 次浏览 • 2017-05-15 11:02 • 来自相关话题

条新动态, 点击查看
kennywu76

kennywu76 回答了问题 • 2017-08-28 18:35 • 4 个回复 不感兴趣

es yong gc将近1s,该如果平滑调优

赞同来自:

首先分配给ES JVM的内存应该略小于32GB,比较保险的设置是30GB。 

其次,ES一端出现1s左右的Young GC时,通常需要调优的是索引的mapping,数据写入的方式,以及查询和聚合语句本身。 高并发下,如果查询本身写得不够好,执行比较慢,或者需... 显示全部 »
首先分配给ES JVM的内存应该略小于32GB,比较保险的设置是30GB。 

其次,ES一端出现1s左右的Young GC时,通常需要调优的是索引的mapping,数据写入的方式,以及查询和聚合语句本身。 高并发下,如果查询本身写得不够好,执行比较慢,或者需要读取大量的数据,产生垃圾的速度快,数据对象被持有的时间长,GC压力加大,时间变长是不可避免的。 你无法通过调优JVM参数去满足各式各样的查询、各式各样的业务访问模式对响应时间的要求。

我见过几个查询写的有问题,造成CPU很高,GC耗时增加的场景。 研发人员在不理解ES的情况下,通常怀疑ES的JVM需要调优,而后证实是查询的高消耗带来的长时间GC。 这时候长时间GC是果,不是因。 

另外“偶尔”要看是多频繁,并且是相对并发量和业务搜索的吞吐量来看。 采集业务搜索的响应时间进行分析比较靠谱,比如响应时间的99%线是多少? 要求100%响应时间小于多少不太现实,特别是高并发场景下的数据型应用,在自己力所能及的基础上,还是需要适当和业务研发做一些battle

ES有时候old GC的时间会非常长,请问可能是因为什么原因?

回复

Elasticsearchzqc0512 回复了问题 • 3 人关注 • 3 个回复 • 274 次浏览 • 2018-09-03 09:41 • 来自相关话题

bulk无法导入数据

回复

Elasticsearchxinfanwang 回复了问题 • 5 人关注 • 5 个回复 • 637 次浏览 • 2018-05-14 09:59 • 来自相关话题

elasticsearch 6.0+ 版本jdk选择

回复

Elasticsearchlaoyang360 回复了问题 • 3 人关注 • 1 个回复 • 523 次浏览 • 2018-04-18 23:41 • 来自相关话题

gc warn

回复

Elasticsearchlaoyang360 回复了问题 • 3 人关注 • 2 个回复 • 483 次浏览 • 2018-04-16 19:28 • 来自相关话题

gc时查询耗时变高

回复

Elasticsearchkennywu76 回复了问题 • 2 人关注 • 1 个回复 • 900 次浏览 • 2018-04-16 16:28 • 来自相关话题

es gc 导致集群挂了

回复

Elasticsearchmedcl 回复了问题 • 2 人关注 • 1 个回复 • 538 次浏览 • 2018-01-15 11:57 • 来自相关话题

es yong gc将近1s,该如果平滑调优

回复

Elasticsearch冯坤 回复了问题 • 6 人关注 • 4 个回复 • 934 次浏览 • 2017-08-29 17:16 • 来自相关话题

求助。ES集群运行一段时间就会不断的full gc。。。请看日志

回复

Elasticsearchybtsdst 回复了问题 • 3 人关注 • 3 个回复 • 2014 次浏览 • 2017-05-15 11:02 • 来自相关话题

你看懂 Elasticsearch Log 中的 GC 日志了吗?

Elasticsearchrockybean 发表了文章 • 0 个评论 • 443 次浏览 • 2018-09-22 23:29 • 来自相关话题

如果你关注过 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. 第二部分是日志级别,这里分别是WARNINFO
  3. 第三部分是输出日志的类,我们后面也会讲到这个类
  4. 第四部分是当前 ES 节点名称
  5. 第五部分是 gc 关键词,我们就从这个关键词聊起。

友情提示:对 GC 已经了如指掌的同学,可以直接翻到最后看答案。

1. 什么是 GC?

GC,全称是 Garbage Collection (垃圾收集)或者 Garbage Collector(垃圾收集器)。

在使用 C语言编程的时候,我们要手动的通过 mallocfree来申请和释放数据需要的内存,如果忘记释放内存,就会发生内存泄露的情况,即无用的数据占用了宝贵的内存资源。而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,它是判定的源头,感兴趣的同学可以自己去研究下,这里就不展开讲了。

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 过程一般类似下图所示:

  1. 对象一般都是先在 Eden区创建
  2. Eden区满,触发 Young GC,此时将 Eden中还存活的对象复制到 S0中,并清空 Eden区后继续为新的对象分配内存
  3. Eden区再次满后,触发又一次的 Young GC,此时会将 EdenS0中存活的对象复制到 S1中,然后清空EdenS0后继续为新的对象分配内存
  4. 每经过一次 Young GC,存活下来的对象都会将自己存活次数加1,当达到一定次数后,会随着一次 Young GC 晋升到 Old
  5. Old区也会在合适的时机进行自己的 GC

1.2.5 常见的垃圾收集器

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

从上图我们可以看到 YoungOld区有不同的垃圾收集器,实际使用时会搭配使用,也就是上图中两两连线的收集器是可以搭配使用的。这些垃圾收集器按照运行原理大概可以分为如下几类:

  • Serial GC串行,单线程的收集器,运行 GC 时需要停止所有的用户线程,且只有一个 GC 线程
  • Parallel GC并行,多线程的收集器,是 Serial 的多线程版,运行时也需要停止所有用户线程,但同时运行多个 GC 线程,所以效率高一些
  • Concurrent GC并发,多线程收集器,GC 分多阶段执行,部分阶段允许用户线程与 GC 线程同时运行,这也就是并发的意思,大家要和并行做一个区分。
  • 其他

我们下面简单看一下他们的运行机制。

1.2.5.1 Serial GC

该类 Young区的为 Serial GCOld区的为Serial Old GC。执行大致如下所示:

1.2.5.2 Parallel GC

该类Young 区的有 ParNewParallel ScavengeOld 区的有Parallel Old。其运行机制如下,相比 Serial GC ,其最大特点在于 GC 线程是并行的,效率高很多:

1.2.5.3 Concurrent Mark-Sweep GC

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

1.2.5.4 其他

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

1.2.6 Elasticsearch 的 GC 组合

Elasticsearch 默认的 GC 配置是CMS GC ,其 Young 区ParNewOld 区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][这是第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. 参考资料

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

6. 相关推荐

如果你想深入的了解 JAVA GC 的知识,可以关注 ElasticTalk 公众号,回复 GC关键词后即可获取作者推荐的电子书等资料。

elasticTalk,qrcode

es 由于gc 引起的节点脱落

Elasticsearchklause 发表了文章 • 9 个评论 • 683 次浏览 • 2017-09-01 09:44 • 来自相关话题

最近发现es节点在gc时,引起节点脱落,将配置改成如下后,过了一阵又发生节点脱落的情况。discovery.zen.fd.ping_timeout: 60s discovery.zen.fd.ping_interval: 10s discovery.zen.fd.ping_retries: 10   这个配置值如何设置?另是否还有其他的解决方案  
最近发现es节点在gc时,引起节点脱落,将配置改成如下后,过了一阵又发生节点脱落的情况。discovery.zen.fd.ping_timeout: 60s discovery.zen.fd.ping_interval: 10s discovery.zen.fd.ping_retries: 10   这个配置值如何设置?另是否还有其他的解决方案