看懂gc日志

一、什么时候触发GC

首先我们回顾一下什么时候会触发GC:

Minor GC触发条件:当Eden区满时,触发Minor GC。

Full GC触发条件:

(1)调用System.gc时,系统建议执行Full GC,但是不必然执行

(2)老年代空间不足

(3)方法区空间不足

(4)通过Minor GC后进入老年代的平均大小大于老年代的可用内存

(5)由Eden区、From Space(survivor)区向To Space(survivor)区复制时,对象大小大于To Space可用内存,则把该对象转存到老年代,且老年代的可用内存小于该对象大小

二、看懂日志

2.1 垃圾收集器配置-XX:+UseParallelGC(Parallel Scavenge + Serial Old)

打开gc日志后,日志文件里面会打印类似下面的日志:

2018-06-15T10:44:26.630-0800: [GC (System.gc()) [PSYoungGen: 2673K->496K(38400K)] 2673K->504K(125952K), 0.0010649 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2018-06-15T10:44:26.631-0800: [Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->402K(87552K)] 504K->402K(125952K), [Metaspace: 3300K->3300K(1056768K)], 0.0066154 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2018-06-15T10:44:26.632-0800:Total time for which application threads were stopped: 0.0010226 seconds, Stopping threads took: 0.0001058 seconds

Minor GC

2018-06-15T10:44:26.630-0800: [GC (System.gc()) [PSYoungGen: 2673K->496K(38400K)] 2673K->504K(125952K), 0.0010649 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

从左到右表示
[GC类型 (System.gc()][新生代:GC前该内存区域已使用容量->GC后该内存区域已使用容量(该内存区域的总容量)] GC前Java堆已使用容量->GC后Java堆已使用容量(Java堆总容量), [GC耗时: 用户态消耗的CPU时间 内核态消耗的CPU时间, 整个过程实际所经过的墙钟时间(Wall Clock Time)]

user+sys是CPU时间,每个CPU core单独计算,所以这个时间可能会是real的好几倍。CPU时间和墙钟时间的差别是,墙钟时间包括各种非运算的等待耗时,例如等待磁盘I/O、等待线程阻塞,而CPU时间不包括这些耗时。

时钟时间(墙上时钟时间wall clock time):从进程从开始运行到结束,时钟走过的时间,这其中包含了进程在阻塞和等待状态的时间。 用户CPU时间:就是用户的进程获得了CPU资源以后,在用户态执行的时间。 系统CPU时间:用户进程获得了CPU资源以后,在内核态的执行时间。

Full GC

2018-06-15T10:44:26.631-0800: [Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->402K(87552K)] 504K->402K(125952K), [Metaspace: 3300K->3300K(1056768K)], 0.0066154 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]

从左到右表示
[GC类型 (System.gc()) [Young区: GC前Young的内存占用->GC后Young的内存占用(Young区域总大小)] [old老年代: GC前Old的内存占用->GC后Old的内存占用(Old区域总大小)] GC前堆内存占用->GC后堆内存占用(JVM堆总大小), [永久代区: GC前占用大小->C后占用大小(永久代区总大小)], GC用户耗时] [Times:用户耗时 sys=系统时间, real=实际时间] 

stop-the-world(STW)时间

2018-06-15T10:44:26.632-0800:Total time for which application threads were stopped: 0.0010226 seconds, Stopping threads took: 0.0001058 seconds

application threads stopped的时间表示应用暂停时间,Stopping threads took 的时间表示等待所有的应用线程都到达安全点花费的时间。只有应用程序线程到达安全点后,JVM才会做些特殊处理,比如垃圾收集、偏向锁擦除等等。

2.2 垃圾收集器配置-XX:UseG1GC(G1)

在java9中,G1 GC成为默认的垃圾收集器,G1 垃圾收集器的关键特性之一是能够在不牺牲吞吐量的同时,限制 GC 暂停时间(即可以设置所需的最大停顿时间)。下面看下G1的gc日志格式:

# Minor GC日志格式
2020-02-27T14:49:36.648+0800: 4.417: [GC pause (G1 Evacuation Pause) (young), 0.0382006 secs]
   [Parallel Time: 8.7 ms, GC Workers: 18]
      [GC Worker Start (ms): Min: 4416.8, Avg: 4416.8, Max: 4416.9, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.1, Avg: 0.3, Max: 1.7, Diff: 1.6, Sum: 6.3]
      [Update RS (ms): Min: 0.0, Avg: 0.9, Max: 1.4, Diff: 1.4, Sum: 16.7]
         [Processed Buffers: Min: 0, Avg: 3.1, Max: 11, Diff: 11, Sum: 56]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Object Copy (ms): Min: 6.6, Avg: 7.0, Max: 7.2, Diff: 0.7, Sum: 125.2]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 2.2]
         [Termination Attempts: Min: 1, Avg: 88.1, Max: 134, Diff: 133, Sum: 1585]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.5]
      [GC Worker Total (ms): Min: 8.3, Avg: 8.4, Max: 8.5, Diff: 0.2, Sum: 151.2]
      [GC Worker End (ms): Min: 4425.2, Avg: 4425.2, Max: 4425.3, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.3 ms]
   [Other: 29.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 28.4 ms]
      [Ref Enq: 0.4 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 75.0M(75.0M)->0.0B(2048.0K) Survivors: 2048.0K->10.0M Heap: 135.3M(245.0M)->106.8M(245.0M)]
 [Times: user=0.17 sys=0.00, real=0.04 secs]
2020-02-27T14:49:36.686+0800: 4.455: Total time for which application threads were stopped: 0.0385317 seconds, Stopping threads took: 0.0000317 seconds
2020-02-27T14:49:36.691+0800: 4.460: Application time: 0.0045216 seconds

# 第一部分
2020-02-27T14:49:36.648+0800: 4.417
表示gc发生的时间,其中4.417表示java进程启动4.417秒后发生了GC。
# 第二部分
[GC pause (G1 Evacuation Pause) (young), 0.0382006 secs]
疏散停顿(Evacuation Pause)是将活着的对象从一个区域(young or young + old)拷贝到另一个区域的阶段。(young)  表示这是一个 Young GC 事件,0.0382006 secs表示GC的时间。
# 第三部分
 [Parallel Time: 8.7 ms, GC Workers: 18]
 并行收集任务在运行过程中引发的STW(Stop The World)时间为8.7ms, GC Workers: 18 表示GC的工作线程是18个。
# 第四部分
[Eden: 75.0M(75.0M)->0.0B(2048.0K) Survivors: 2048.0K->10.0M Heap: 135.3M(245.0M)->106.8M(245.0M)]
Eden:GC前使用内存(总内存)->GC后使用内存(总内存) Survivors:由于年轻代的回收处理,survivor空间从2M涨到了10M GC前堆内存(堆总内存)->GC后堆内存(堆总内存)
# 第五部分
[Times: user=0.17 sys=0.00, real=0.04 secs]
[gc时间:用户态时间  内核态时间 墙钟时间]

# Full GC日志格式
2020-02-27T14:49:33.330+0800: 1.099: [Full GC (System.gc())  63M->24M(81M), 0.1139604 secs]
   [Eden: 62.0M(100.0M)->0.0B(24.0M) Survivors: 0.0B->0.0B Heap: 63.5M(2016.0M)->24.1M(81.0M)], [Metaspace: 14509K->14509K(1062912K)]
 [Times: user=0.14 sys=0.02, real=0.12 secs]
# 第一部分
表示gc发生的时间,其中1.099表示java进程启动1.099秒后发生了Full GC。
# 第二部分
[Full GC (System.gc())  63M->24M(81M), 0.1139604 secs] [Eden: 62.0M(100.0M)->0.0B(24.0M) Survivors: 0.0B->0.0B Heap: 63.5M(2016.0M)->24.1M(81.0M)], [Metaspace: 14509K->14509K(1062912K)]
[Full GC (出发原因) GC前占用内存->GC后占用内存(总内存), gc耗时][Eden:GC前占用内存(总内存)->GC后占用内存(总内存) Survivors:GC前占用内存->GC后占用内存 堆内存:GC前占用内存(总内存)->GC后占用内存(总内存)], [Metaspace空间: GC前占用内存->GC后占用内存(总内存)]
# 第三部分
[Times: user=0.14 sys=0.02, real=0.12 secs]
[gc时间:用户态时间  内核态时间 墙钟时间]

2.3 垃圾收集器配置-XX:+UseConcMarkSweepGC(ParNew + CMS + SerialOld)

Minor GC

2022-12-28T22:36:49.648+0800: 606804.815: [GC (Allocation Failure) 606804.816: [ParNew: 2599119K->100812K(2831168K), 0.0247097 secs] 2996423K->498278K(5976896K), 0.0252095 secs] [Times: user=0.23 sys=0.04, real=0.03 secs] 

UseConcMarkSweepGC配置下使用的年轻代垃圾收集器为ParNew,日志的意思分别为:

【2022-12-28T22:36:49.648+0800】表示GC发生的时间。 【606804.815】表示本次gc与JVM启动时的相对时间,单位为秒。 【GC (Allocation Failure)】 GC表示这是一次GC,(Allocation Failure)表示GC的原因,新生代内存不足而导致新对象内存分配失败。 【ParNew】表示本次GC使用的垃圾收集器为ParNew 【2599119K->100812K(2831168K)】含义是GC前该内存区域已使用容量 -> GC后该内存区域已使用容量(该内存区域总容量) 【0.0247097 secs】表示该内存区域GC所占用的时间,单位为秒。 【2996423K->498278K(5976896K)】表示收集前后整个堆的使用情况,0.0252095 secs表示本次GC的总耗时,包括把年轻代的对象转移到老年代的时间。 【times: user=0.23 sys=0.04, real=0.03 secs】表示GC事件在不同维度的耗时,单位为秒。分别表示用户态消耗的CPU时间、内核态消耗的CPU时间和操作从开始到结束所经过的等待耗时。

Full GC

2022-12-28T22:36:44.691+0800: 606799.858: [GC (CMS Initial Mark) [1 CMS-initial-mark: 399170K(3145728K)] 535076K(5976896K), 0.0106346 secs] [Times: user=0.09 sys=0.01, real=0.02 secs] 
2022-12-28T22:36:44.702+0800: 606799.870: [CMS-concurrent-mark-start]
2022-12-28T22:36:44.851+0800: 606800.019: [CMS-concurrent-mark: 0.149/0.149 secs] [Times: user=1.22 sys=0.00, real=0.15 secs] 
2022-12-28T22:36:44.851+0800: 606800.019: [CMS-concurrent-preclean-start]
2022-12-28T22:36:44.865+0800: 606800.032: [CMS-concurrent-preclean: 0.013/0.013 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 
2022-12-28T22:36:44.865+0800: 606800.033: [CMS-concurrent-abortable-preclean-start]
2022-12-28T22:36:46.450+0800: 606801.617: [CMS-concurrent-abortable-preclean: 1.579/1.585 secs] [Times: user=3.76 sys=0.40, real=1.58 secs] 
2022-12-28T22:36:46.453+0800: 606801.621: [GC (CMS Final Remark) [YG occupancy: 1361947 K (2831168 K)]2022-12-28T22:36:46.453+0800: 606801.621: [GC (CMS Final Remark) 606801.621: [ParNew: 1361947K->82511K(2831168K), 0.0213065 secs] 1761117K->481727K(5976896K), 0.0217782 secs] [Times: user=0.22 sys=0.00, real=0.02 secs] 
606801.643: [Rescan (parallel) , 0.0099225 secs]606801.653: [weak refs processing, 0.0026229 secs]606801.655: [class unloading, 0.1842529 secs]606801.840: [scrub symbol table, 0.0395162
 secs]606801.879: [scrub string table, 0.0053289 secs][1 CMS-remark: 399215K(3145728K)] 481727K(5976896K), 0.2686861 secs] [Times: user=0.56 sys=0.01, real=0.27 secs] 
2022-12-28T22:36:46.722+0800: 606801.890: [CMS-concurrent-sweep-start]
2022-12-28T22:36:47.625+0800: 606802.793: [CMS-concurrent-sweep: 0.894/0.903 secs] [Times: user=2.66 sys=0.22, real=0.90 secs] 
2022-12-28T22:36:47.625+0800: 606802.793: [CMS-concurrent-reset-start]
2022-12-28T22:36:47.633+0800: 606802.800: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

UseConcMarkSweepGC配置下使用的年轻代垃圾收集器为CMS,CMS垃圾回收共有4个阶段,初始标记、并发标记、重新标记、并发清除4个阶段,其中只有初始标记和重新标记两个阶段会STW。

1)初始标记阶段(CMS Initial Mark)

2022-12-28T22:36:44.691+0800: 606799.858: [GC (CMS Initial Mark) [1 CMS-initial-mark: 399170K(3145728K)] 535076K(5976896K), 0.0106346 secs] [Times: user=0.09 sys=0.01, real=0.02 secs]

[GC (CMS Initial Mark)表示这是CMS开始对老年代进行垃圾圾收集的初始标记阶段,该阶段从垃圾回收的“根对象”开始,且只扫描直接与“根对象”直接关联的对象,并做标记,需要暂停用户线程(Stop The Word,下面统称为STW),速度很快。399170K(3145728K)表示当前老年代的容量为3145728K,在使用了399170K时开始进行CMS垃圾回收。 后面的535076K(5976896K), 0.0106346 secs表示当前整个堆的内存使用情况和本次初始标记耗费的时间,最后的[Times: user=0.09 sys=0.01, real=0.02 secs]上文已经讲过,下文将不再重复。

2)并发标记阶段(CMS concurrent mark)

2022-12-28T22:36:44.702+0800: 606799.870: [CMS-concurrent-mark-start]
2022-12-28T22:36:44.851+0800: 606800.019: [CMS-concurrent-mark: 0.149/0.149 secs] [Times: user=1.22 sys=0.00, real=0.15 secs] 
2022-12-28T22:36:44.851+0800: 606800.019: [CMS-concurrent-preclean-start]
2022-12-28T22:36:44.865+0800: 606800.032: [CMS-concurrent-preclean: 0.013/0.013 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 
2022-12-28T22:36:44.865+0800: 606800.033: [CMS-concurrent-abortable-preclean-start]
2022-12-28T22:36:46.450+0800: 606801.617: [CMS-concurrent-abortable-preclean: 1.579/1.585 secs] [Times: user=3.76 sys=0.40, real=1.58 secs] 

该阶段进行了细分,但都是和用户线程并发进行的 CMS-concurrent-mark表示并发标记阶段,会遍历整个年老代并且标记活着的对象,后面的0.149/0.149 secs表示该阶段持续的时间和时钟时间,耗时0.149秒,可见耗时是比较长的。 由于该阶运行的过程中用户线程也在运行,这就可能会发生这样的情况,已经被遍历过的对象的引用被用户线程改变,如果发生了这样的情况,JVM就会标记这个区域为Dirty Card。 CMS-concurrent-preclean阶段会把上一个阶段被标记为Dirty Card的对象以及可达的对象重新遍历标记,完成后清楚Dirty Card标记。另外,一些必要的清扫工作也会做,还会做一些final remark阶段需要的准备工作。 CMS-concurrent-abortable-preclean并发预清理,这个阶段尝试着去承担接下来STW的Final Remark阶段足够多的工作,由于这个阶段是重复的做相同的事情直到发生aboart的条件(比如:重复的次数、多少量的工作、持续的时间等等)之一才会停止。这个阶段很大程度的影响着即将来临的Final Remark的停顿。 从后面的1.579/1.585 secs显示这个阶段持续了1秒多的时间,相当的长。

3)重新标记阶段(CMS remark)

2022-12-28T22:36:46.453+0800: 606801.621: [GC (CMS Final Remark) [YG occupancy: 1361947 K (2831168 K)]
2022-12-28T22:36:46.453+0800: 606801.621: [GC (CMS Final Remark) 606801.621: [ParNew: 1361947K->82511K(2831168K), 0.0213065 secs] 1761117K->481727K(5976896K), 0.0217782 secs] [Times: user=0.22 sys=0.00, real=0.02 secs] 
606801.643: [Rescan (parallel) , 0.0099225 secs]
606801.653: [weak refs processing, 0.0026229 secs]
606801.655: [class unloading, 0.1842529 secs]
606801.840: [scrub symbol table, 0.0395162secs]606801.879: [scrub string table, 0.0053289 secs]
[1 CMS-remark: 399215K(3145728K)] 481727K(5976896K), 0.2686861 secs] [Times: user=0.56 sys=0.01, real=0.27 secs] 

该阶段同样被细分为多个子阶段

GC (CMS Final Remark)表示这是CMS的重新标记阶段,会STW,该阶段的任务是完成标记整个年老代的所有的存活对象,尽管先前的pre clean阶段尽量应对处理了并发运行时用户线程改变的对象应用的标记,但是不可能跟上对象改变的速度,只是为final remark阶段尽量减少了负担。 YG occupancy: 1361947 K (2831168 K)表示年轻代当前的内存占用情况,通常Final Remark阶段要尽量运行在年轻代是足够干净的时候,这样可以消除紧接着的连续的几个STW阶段。 Rescan (parallel) , 0.0099225 secs这是整个final remark阶段扫描对象的用时总计,该阶段会重新扫描CMS堆中剩余的对象,重新从“根对象”开始扫描,并且也会处理对象关联。本次扫描共耗时 0.0099225。 weak refs processing, 0.0026229 secs第一个子阶段,表示对弱引用的处理耗时为0.0026229s。 class unloading, 0.1842529 secs第二个子阶段,表示卸载无用的类的耗时为0.1842529s。 606801.840: [scrub symbol table, 0.0395162secs]606801.879: [scrub string table, 0.0053289 secs] 最后一个子阶段,表示清理分别包含类级元数据和内部化字符串的符号和字符串表的耗时。 1 CMS-remark: 399215K(3145728K)表示经历了上面的阶段后老年代的内存使用情况。再后面的481727K(5976896K), 0.2686861 secs表示final remark后整个堆的内存使用情况和整个final remark的耗时。

4)并发清除阶段(CMS concurrent sweep)

2022-12-28T22:36:46.722+0800: 606801.890: [CMS-concurrent-sweep-start]
2022-12-28T22:36:47.625+0800: 606802.793: [CMS-concurrent-sweep: 0.894/0.903 secs] [Times: user=2.66 sys=0.22, real=0.90 secs] 
2022-12-28T22:36:47.625+0800: 606802.793: [CMS-concurrent-reset-start]
2022-12-28T22:36:47.633+0800: 606802.800: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

该阶段和用户线程并发执行,不会STW,作用是清除之前标记阶段没有被标记的无用对象并回收内存。整个过程分为两个子阶段。 CMS-concurrent-sweep第一个子阶段,任务是清除那些没有标记的无用对象(存活对象已经被标记)并回收内存。后面的参数是耗时,不再多提。 CMS-concurrent-reset第二个子阶段,作用是重新设置CMS算法内部的数据结构,准备下一个CMS生命周期的使用。

补充说明:什么时候会用到SerialOld

CMS收集器会在老年代内存使用到一定程度时就触发垃圾回收,这是因为CMS收集器的一个缺陷导致的这种设定,也就是无法处理“浮动垃圾”,“浮动垃圾”就是指标记清除阶段用户线程运行产生的垃圾,而这部分对象由于没有做标记处理所以在本次CMS收集中是无法处理的。如果CMS是在老年代空间快用完时才启动垃圾回收,那很可能会导致在并发阶段由于用户线程持续产生垃圾而导致老年代内存不够用而导致“Concurrent Mode Failure”失败,那这时候虚拟机就会启用后备预案,临时启用Serial Old收集器来重新进行老年代的垃圾收集,Serial Old是基于“标记-整理”算法的单线程收集器,这样停顿时间就会很长。这个CMS启动的内存使用阈值可以通过参数-XX:CMSInitiatiingOccupancyFranction来设置,默认为68%(这是网上查到的数据),不过这68%应该是JDK1.8之前版本的默认参数。

三、触发垃圾收集的原因

jvm的源码中列举了发生GC的原因枚举

const char* GCCause::to_string(GCCause::Cause cause) {
  switch (cause) {
    case _java_lang_system_gc://Java程序中手动调用System.gc()方法触发的GC。
      return "System.gc()";

    case _full_gc_alot://定期触发的GC(JDK内测专属,JVM开发时使用)。
      return "FullGCAlot";

    case _scavenge_alot://定期触发的GC(JDK内测专属,JVM开发时使用)。
      return "ScavengeAlot";

    case _allocation_profiler://使用-Xaprof参数运行程序,在JVM结束时会触发的GC(JFK1.8被弃用了)。
      return "Allocation Profiler";

    case _jvmti_force_gc://强制调用本地方法库中的native方法:ForceGarbageCollection(jvmtiEnv* env)触发的GC。
      return "JvmtiEnv ForceGarbageCollection";

    case _gc_locker://如果线程执行在 JNI 临界区时,刚好需要进行 GC,此时GCLocker将会阻止GC的发生,同时阻止其他线程进入JNI临界区,直到最后一个线程退出临界区时触发一次GC。
      return "GCLocker Initiated GC";

    case _heap_inspection://通过jmap命令进行堆检测时触发的GC。堆检测命令:jmap -histo:live <pid>
      return "Heap Inspection Initiated GC";

    case _heap_dump://通过jmap命令进行堆转储时触发的GC。堆转储命令:jmap -dump:live,format=b,file=heap.out <pid>
      return "Heap Dump Initiated GC";

    case _wb_young_gc://测试时主动触发的Young GC(需要增加WhiteBox的Agent才能使用)。
      return "WhiteBox Initiated Young GC";

    case _wb_conc_mark:
      return "WhiteBox Initiated Concurrent Mark";

    case _wb_full_gc:
      return "WhiteBox Initiated Full GC";

    case _no_gc://用于表示CMS的并发标记阶段。
      return "No GC";

    case _allocation_failure://对象分配时内存不足导致分配失败触发的GC。
      return "Allocation Failure";

    case _tenured_generation_full://年老代空间内存不足触发的GC。
      return "Tenured Generation Full";

    case _metadata_GC_threshold://元数据空间内存不足触发的GC。
      return "Metadata GC Threshold";

    case _metadata_GC_clear_soft_refs:
      return "Metadata GC Clear Soft References";

    case _cms_generation_full://CMS发生FullGC.
      return "CMS Generation Full";

    case _cms_initial_mark://CMS初始标记阶段的日志信息。
      return "CMS Initial Mark";

    case _cms_final_remark://CMS重新标记阶段的日志信息。
      return "CMS Final Remark";

    case _cms_concurrent_mark://CMS并发标记阶段的日志信息。
      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://一般出现在PS+PO组合中,空间分配担保时触发的GC。
      return "Ergonomics";

    case _g1_inc_collection_pause://G1中没有空闲的region区导致分配失败时触发的GC。
      return "G1 Evacuation Pause";

    case _g1_humongous_allocation://没有Humongous区分配大对象时触发的GC。
      return "G1 Humongous Allocation";

    case _dcmd_gc_run:
      return "Diagnostic Command";

    case _last_gc_cause://正常情况下该信息是看不到的。
      return "ILLEGAL VALUE - last gc cause - ILLEGAL VALUE";

    default://未知(未定义)的原因触发的GC。
      return "unknown GCCause";
  }
  ShouldNotReachHere();
}

常见的有以下几种:

  • System.gc(): 手动触发GC操作。

  • CMS: CMS GC 在执行过程中的一些动作,重点关注 CMS Initial Mark 和 CMS Final Remark 两个 STW 阶段。

  • Concurrent Mode Failure: CMS GC 运行期间,Old 区预留的空间不足以分配给新的对象,此时收集器会发生退化,严重影响 GC 性能,下面的一个案例即为这种场景。

  • Heap Inspection Initiated GC:使用jmap -histo:live触发的GC。

  • Allocation Failure:分配失败,JVM的Eden区中没有更多的空间来分配对象了。

  • GCLocker Initiated GC: 如果线程执行在 JNI 临界区时,刚好需要进行 GC,此时 GC Locker 将会阻止 GC 的发生,同时阻止其他线程进入 JNI 临界区,直到最后一个线程退出临界区时触发一次 GC。

  • Promotion Failure: Old 区没有足够的空间分配给 Young 区晋升的对象(即使总可用内存足够大)。

参考:

java之GC日志该怎么看 https://blog.csdn.net/qq_21383435/article/details/80702205

深入理解G1的GC日志 https://juejin.im/post/5d33be9d5188253a2e1b8fa6

理解CMS GC日志 https://www.jianshu.com/p/ba768d8e9fec

Java 垃圾回收器之CMS GC问题分析与解决 https://bbs.huaweicloud.com/blogs/387344

深入理解Major GC, Full GC, CMS https://developer.aliyun.com/article/140544

Last updated