【工作笔记】GC cause

起因

在每周例行检查生产异常时，发现在生产的机器上出现了一种新的 GC 即 Ergonomics，咸鱼的我表示第一次看到这种 Full GC，于是乎就想研究下什么情况下会出现 GC。如果文章写得好全靠度娘，毕竟我还菜
额外：从 jdk8 开始，gc 日志会默认打印 gc cause，如果是 jdk8 之前的版本，可以通过 JVM 参数 -XX:+PrintGCCause 来打印 gc cause

源码

基于 OPENJDK 8

/*
 * Copyright (c) 2002, 2013, Oracle and/or its affiliates. All rights reserved.
 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
 *
 * This code is free software; you can redistribute it and/or modify it
 * under the terms of the GNU General Public License version 2 only, as
 * published by the Free Software Foundation.
 *
 * This code is distributed in the hope that it will be useful, but WITHOUT
 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
 * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
 * version 2 for more details (a copy is included in the LICENSE file that
 * accompanied this code).
 *
 * You should have received a copy of the GNU General Public License version
 * 2 along with this work; if not, write to the Free Software Foundation,
 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
 *
 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
 * or visit www.oracle.com if you need additional information or have any
 * questions.
 *
 */

#include "precompiled.hpp"
#include "gc_interface/gcCause.hpp"

const char* GCCause::to_string(GCCause::Cause cause) {
  switch (cause) {
    case _java_lang_system_gc:
      return "System.gc()";

    case _full_gc_alot:
      return "FullGCAlot";

    case _scavenge_alot:
      return "ScavengeAlot";

    case _allocation_profiler:
      return "Allocation Profiler";

    case _jvmti_force_gc:
      return "JvmtiEnv ForceGarbageCollection";

    case _gc_locker:
      return "GCLocker Initiated GC";

    case _heap_inspection:
      return "Heap Inspection Initiated GC";

    case _heap_dump:
      return "Heap Dump Initiated GC";

    case _wb_young_gc:
      return "WhiteBox Initiated Young GC";

    case _update_allocation_context_stats_inc:
    case _update_allocation_context_stats_full:
      return "Update Allocation Context Stats";

    case _no_gc:
      return "No GC";

    case _allocation_failure:
      return "Allocation Failure";

    case _tenured_generation_full:
      return "Tenured Generation Full";

    case _metadata_GC_threshold:
      return "Metadata GC Threshold";

    case _cms_generation_full:
      return "CMS Generation Full";

    case _cms_initial_mark:
      return "CMS Initial Mark";

    case _cms_final_remark:
      return "CMS Final Remark";

    case _cms_concurrent_mark:
      return "CMS Concurrent Mark";

    case _old_generation_expanded_on_last_scavenge:
      return "Old Generation Expanded On Last Scavenge";

    case _old_generation_too_full_to_scavenge:
      return "Old Generation Too Full To Scavenge";

    case _adaptive_size_policy:
      return "Ergonomics";

    case _g1_inc_collection_pause:
      return "G1 Evacuation Pause";

    case _g1_humongous_allocation:
      return "G1 Humongous Allocation";

    case _last_ditch_collection:
      return "Last ditch collection";

    case _last_gc_cause:
      return "ILLEGAL VALUE - last gc cause - ILLEGAL VALUE";

    default:
      return "unknown GCCause";
  }
  ShouldNotReachHere();
}

System.gc()

调用 System.gc() 时触发
注意，调用该方法只是额外启动一个方法然后在合适的时间去执行 GC。所以它并不能保证立刻触发 GC（和JVM执行GC有关），也不能保证一定会执行 GC（和垃圾回收器有关），也不能保证触发的 GC 时 Young GC 还是 Full GC（和垃圾回收器有关）
如果想禁用显式 GC（默认不禁用）：

-XX:+DisableExplicitGC 

FullGCAlot

JDK 的调试版本可以设置，用来定期触发 GC，我自己的项目中测试时提示如下异常：

Error: VM option 'FullGCALot' is develop and is available only in debug version of VM

ScavengeAlot

JDK 的调试版本可以设置，用来定期触发 GC，我自己的项目中测试时提示如下异常：

Error: VM option 'ScavengeALot' is develop and is available only in debug version of VM

Allocation Profiler

使用 -Xaprof 设置运行项目，它会在 jvm 退出之前触发。 -Xaprof 选项已在 java 8 中删除

JvmtiEnv ForceGarbageCollection

JVMTI 是 Java 虚拟机所提供的 native 编程接口，用来对 Java 运行态测试和分析，常见的实现就是各种各样的 Java Agent 了
这个 GC 的产生原因，其实就是你自己强制调用 GC

ForceGarbageCollection(jvmtiEnv* env)

GCLocker Initiated GC

当使用本地方法 JNI 函数访问 JVM 中的字符串或数组数据，为保证数据安全性和准确性，获取数据（GetStringCritical）和释放数据（ReleaseStringCritical）这段过程必须在 “critical region”（临界区）执行
如果在执行临界区这段时间发生了 GC，JVM 会阻断 GC 的发生，也会阻断其他线程进入临界区，同时调 ReleaseStringCritical。当最后一个临界区的线程退出后，JVM 再进行一个 GC，即 GCLocker Initiated GC，具体源码的执行过程可以参考：JVM源码分析之GC locker深度分析

Heap Inspection Initiated GC

该 GC 是当你对堆进行检查时触发，使用如下命令才能出现

jmap -histo:live <pid>

Heap Dump Initiated GC

该 GC 是当你对堆进行转储时触发，使用如下命令才能出现

jmap -dump:live,format=b,file=heap.out <pid>

WhiteBox Initiated Young GC

测试时主动触发的 Young GC，需要增加 WhiteBox 的 Agent 才能使用，后边会讲 WhiteBox

Update Allocation Context Stats

原为：GCs can be initiated solely for the purpose of getting updated allocation context statistics; these GCs should be identifiable by a unique GCCause. Add a new cause “_update_allocation_context_stats”.这个 GC 仅用于获取更新的分配上下文统计信息。具体参照：JDK-8058235 : identify GCs initiated to update allocation context stats

No GC

用来指示 CMS 并发标记的阶段

Allocation Failure

Allocation Failure 表示向 Young generation(eden) 给新对象申请空间，但是 Young generation(eden) 剩余的合适空间不够所需的大小导致的 Young GC，在 G1 垃圾回收器中非常常见这个 GC

// 三个参数分别是：最大堆，初识堆，年轻代 
-Xmx
-Xms
-Xmn
// 年轻代中eden和survivor的比例，默认8：1：1，即SurvivorRatio=8，SurvivorRatio=4时意味着比例为 4：1：1
–XX:SurvivorRatio
// 年轻代和老年代比例，默认1：2
-xx:newratio

Tenured Generation Full

是针对老年代的一个 Full GC。原因是老年代的对象长期存在并不断有新的生成从而导致 Tenured Generation 满了，最后触发 GC

Metadata GC Threshold

元空间不足造成的 GC

// 初识元空间大小，默认 21MB
-XX:MetaspaceSize=128
// 最大元空间大小
-XX:MaxMetaspaceSize=128

CMS Generation Full

CMS Initial Mark

CMS Final Remark

CMS Concurrent Mark

Old Generation Expanded On Last Scavenge

Old Generation Too Full To Scavenge

Ergonomics

这种异常会发生在 Parallel Scavenge+Serial Old 的组合下，如果老生代的剩余空间少于下一次收集所需的剩余空间，那么现在就做一个 Full GC，其实就是虚拟机估算出下次分配可能会发生无法分配的问题，于是提前发生一次 Full GC。详细参考读懂一行Full GC日志（回复JVM内存分配担保机制一文中 Mr/Mrs Xxx 在留言区提出的问题）
注意：JDK 1.8 默认使用 UseParallelGC 垃圾回收器，该垃圾回收器默认启动了 AdaptiveSizePolicy，会根据 GC 的情况自动计算计算 Eden、From 和 To 区的大小

G1 Evacuation Pause

当没有更多的空闲 region 被提升到老一代或者复制到幸存空间时，并且由于堆已经达到最大值，堆不能扩展，从而发生 Evacuation Failure

G1 Humongous Allocation

Humongous（大型对象）是大于 G1 中 region 大小 50％ 的对象。在大量分配之前，jvm 会检查它是否应该执行例行 Evacuation Pause 而不考虑实际分配大小，但如果由于此检查而触发，则将被列为大量分配。此情况也用于任何用于为分配释放足够空间的集合

Last ditch collection

对于 perm gen（java 7 或更早版本）和元空间（java 8+），如果分配失败并且无法扩展内存池时触发该 GC，表象为已经进行了一个 Metadata GC，然后又触发了 Last ditch collection
原因多为 metaspace 的内存碎片化，即引用过多且没有清除
举例：大量使用反射，在 Java 虚拟机中，每个类加载器都有一个 ClassLoaderData 的数据结构，ClassloaderData 内部有管理内存的 Metaspace，Metaspace 在 initialize 的时候会调用 get_initialization_chunk 分配第一块 Metachunk，类加载器在类的时候是以 Metablock 为单位来使用 Metachunk。当创建很多类加载器，而每个类加载器又加载了很少的类，即会出现该问题。详细参考：记一次诡异的频繁Full GC 大量类加载器创建导致诡异FullGC

# 这里偷偷记录下别的查问题的linux命令
jcmd pid GC.class_stats |awk '{print $13}'| sort | uniq -c |sort -r| head
grep Gang jstack.log | awk '{print $3,$4,$5}' |uniq -c  

ILLEGAL VALUE - last gc cause - ILLEGAL VALUE

Included for completeness，正常情况看不到此信息

unknown GCCause

Included for completeness，正常情况看不到此信息

使用 WhiteBox API

• 编译 WhiteBox API

将https://github.com/openjdk/jdk/tree/master/test/lib路径下的sun目录取出，编译成一个 jar 包，名字假设是 whitebox.jar

• 编写测试程序

将 whitebox.jar 添加到你的项目依赖，之后写代码

public static void main(String[] args) throws Exception {
        WhiteBox whiteBox = WhiteBox.getWhiteBox();
        //获取 ReservedCodeCacheSize 这个 JVM flag 的值
        Long reservedCodeCacheSize = whiteBox.getUintxVMFlag("ReservedCodeCacheSize");
        System.out.println(reservedCodeCacheSize);
        //打印堆内存各项指标
        whiteBox.printHeapSizes();
        //执行full GC
        whiteBox.fullGC();
        
        //保持进程不退出，保证日志打印完整
        Thread.currentThread().join();
}

• 启动程序查看效果

使用启动参数启动程序:

-Xbootclasspath/a:/home/project/whitebox.jar -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -Xlog:gc

其中前三个 Flag 表示启用 WhiteBox API，最后一个表示打印 GC info 级别的日志到控制台

我的输出：

[0.036s][info][gc] Using G1
[0.048s][info][gc,init] Version: 17-internal+0-adhoc.Administrator.jdk (fastdebug)
[0.048s][info][gc,init] CPUs: 16 total, 16 available
[0.048s][info][gc,init] Memory: 16304M
[0.048s][info][gc,init] Large Page Support: Disabled
[0.048s][info][gc,init] NUMA Support: Disabled
[0.048s][info][gc,init] Compressed Oops: Enabled (32-bit)
[0.048s][info][gc,init] Heap Region Size: 1M
[0.048s][info][gc,init] Heap Min Capacity: 512M
[0.048s][info][gc,init] Heap Initial Capacity: 512M
[0.048s][info][gc,init] Heap Max Capacity: 512M
[0.048s][info][gc,init] Pre-touch: Disabled
[0.048s][info][gc,init] Parallel Workers: 13
[0.048s][info][gc,init] Concurrent Workers: 3
[0.048s][info][gc,init] Concurrent Refinement Workers: 13
[0.048s][info][gc,init] Periodic GC: Disabled
[0.049s][info][gc,metaspace] CDS disabled.
[0.049s][info][gc,metaspace] Compressed class space mapped at: 0x0000000100000000-0x0000000140000000, reserved size: 1073741824
[0.049s][info][gc,metaspace] Narrow klass base: 0x0000000000000000, Narrow klass shift: 3, Narrow klass range: 0x140000000
[1.081s][info][gc,start    ] GC(0) Pause Young (Normal) (WhiteBox Initiated Young GC)
[1.082s][info][gc,task     ] GC(0) Using 12 workers of 13 for evacuation
[1.089s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.5ms
[1.089s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.1ms
[1.089s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 3.4ms
[1.089s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 1.6ms
[1.089s][info][gc,phases   ] GC(0)   Other: 1.3ms
[1.089s][info][gc,heap     ] GC(0) Eden regions: 8->0(23)
[1.089s][info][gc,heap     ] GC(0) Survivor regions: 0->2(4)
[1.089s][info][gc,heap     ] GC(0) Old regions: 0->0
[1.089s][info][gc,heap     ] GC(0) Archive regions: 0->0
[1.089s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[1.089s][info][gc,metaspace] GC(0) Metaspace: 6891K(7104K)->6891K(7104K) NonClass: 6320K(6400K)->6320K(6400K) Class: 571K(704K)->571K(704K)
[1.089s][info][gc          ] GC(0) Pause Young (Normal) (WhiteBox Initiated Young GC) 7M->1M(512M) 7.864ms
[1.089s][info][gc,cpu      ] GC(0) User=0.00s Sys=0.00s Real=0.01s
---------------------------------
[1.091s][info][gc,task     ] GC(1) Using 12 workers of 13 for full compaction
[1.108s][info][gc,start    ] GC(1) Pause Full (WhiteBox Initiated Full GC)
[1.108s][info][gc,phases,start] GC(1) Phase 1: Mark live objects
[1.117s][info][gc,phases      ] GC(1) Phase 1: Mark live objects 8.409ms
[1.117s][info][gc,phases,start] GC(1) Phase 2: Prepare for compaction
[1.120s][info][gc,phases      ] GC(1) Phase 2: Prepare for compaction 3.031ms
[1.120s][info][gc,phases,start] GC(1) Phase 3: Adjust pointers
[1.126s][info][gc,phases      ] GC(1) Phase 3: Adjust pointers 5.806ms
[1.126s][info][gc,phases,start] GC(1) Phase 4: Compact heap
[1.190s][info][gc,phases      ] GC(1) Phase 4: Compact heap 63.812ms
[1.193s][info][gc,heap        ] GC(1) Eden regions: 1->0(25)
[1.193s][info][gc,heap        ] GC(1) Survivor regions: 2->0(4)
[1.193s][info][gc,heap        ] GC(1) Old regions: 0->3
[1.193s][info][gc,heap        ] GC(1) Archive regions: 0->0
[1.193s][info][gc,heap        ] GC(1) Humongous regions: 0->0
[1.193s][info][gc,metaspace   ] GC(1) Metaspace: 6895K(7104K)->6895K(7104K) NonClass: 6323K(6400K)->6323K(6400K) Class: 571K(704K)->571K(704K)
[1.193s][info][gc             ] GC(1) Pause Full (WhiteBox Initiated Full GC) 1M->0M(512M) 84.846ms
[1.202s][info][gc,cpu         ] GC(1) User=0.19s Sys=0.63s Real=0.11s

• WhiteBox API 的使用场景

1. JDK 框架源码在测试的时候，需要用 WhiteBox API 进行测试
2. 压测 JVM 的时候，需要模拟一些场景，需要用 WhiteBox API 执行一些底层操作，例如强制 full GC。比较有名的就是 jcstress 对 JVM 进行压测就用到了 WhiteBox API
3. 一些性能极限场景，需要用到 WhiteAPI 进行模拟，压测
4. 学习 JVM 原理的时候会用到

参考

• gc causes