JVM虚拟机(十二)ParallelGC、CMS、G1垃圾收集器的 GC 日志解析

本文主要是介绍JVM虚拟机(十二)ParallelGC、CMS、G1垃圾收集器的 GC 日志解析,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!

目录

    • 一、如何开启 GC 日志?
    • 二、GC 日志分析
      • 2.1 PS+PO 日志分析
      • 2.2 ParNew+CMS 日志分析
      • 2.3 G1 日志分析
    • 三、GC 发生的原因
      • 3.1 Allocation Failure:新生代空间不足,触发 Minor GC
      • 3.2 Metadata GC Threshold:元数据(方法区)空间不足,触发 Full GC
      • 3.3 Ergonomics:系统调用,触发 Full GC
      • 3.4 System.gc():手动调用,触发 Full GC
    • 四、实战:项目启动时速度很慢

  • 在进行 JVM 性能调优的过程中,经常要借助于 GC 日志。
  • 其实不同的垃圾收集器产生的 GC 日志大致遵循了同一个规则,只是有些许不同,不过对于 G1 收集器的 GC 日志和其他垃圾收集器有较大差别。

一、如何开启 GC 日志?

发生 GC 之后,我们要分析 GC 日志,当然就首先要拿到 GC 日志,打印 GC 日志可以通过如下命令:

java -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=14 -XX:GCLogFileSize=20M -XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -Xloggc:springboot-demo-gc".log" -jar springboot-demo.jar

  • -XX:PrintGCDetails:打印更详细的 GC 日志信息,包括各个内存区域的使用情况、GC 的触发原因等。
  • -XX:+PrintGCTimesStamps:打印 GC 发生的时间戳。(以基准时间的形式)
  • -XX:+PrintGCDateStamps:打印 GC 发生的时间戳。(以标准时间的形式,如:2024-04-13T17:35:04.859+0800)。
  • -XX:+UseGCLogFileRotation:启用 GC 日志文件的自动轮转功能,维持日志目录中的日志文件在一定的数目。
  • -XX:NumberOfGCLogFiles=14:GC 日志文件的滚动数量,使 GC 日志文件数量维持在 14 个,超出 14 个后,将日志覆盖写入到最早的日志文件中。
  • -XX:GCLogFileSize=20M:GC 日志文件的大小,超出大小后触发日志的轮转,将日志覆盖写入到最早的日志文件中。
  • -XX:+PrintHeapAtGC:在进行 GC 的前后打印出堆的信息。
  • -XX:+HeapDumpOnOutOfMemoryError:内存溢出的时候生成 dump 文件。
  • -XX:HeapDumpPath=目录/xxx.hprof:指定内存溢出时,dump 文件的生成路径,默认为当前目录。
  • -Xloggc:springboot-demo-gc".log":指定 GC 日志的输出文件。

二、GC 日志分析

2.1 PS+PO 日志分析

按照上面的步骤开启 GC 日志后,如果一次 GC 都没发生的话日志文件是空的。可以等到发生 GC 之后再打开,文件内容如下所示:

在这里插入图片描述

前面3行应该都能看懂:

  1. 第一行,打印的是当前所使用的 HotSpot 虚拟机及其对应版本号;
  2. 第二行,打印的是操作系统相关的内存信息;
  3. 第三行,打印的是当前 Java 服务启动后所配置的参数信息。这里可以看到目前使用的是默认的 Parallel GC。

下面第4行开始才是我们的 GC 日志,首先我们举一个 Young GC 日志的解析:

在这里插入图片描述

2020-08-23T15:35:30.747+0800: 5.486: [GC (Allocation Failure) [PSYoungGen: 32768K->3799K(37888K)] 32768K->3807K(123904K), 0.1129986 secs] [Times: user=0.02 sys=0.00, real=0.11 secs] 
  • 2020-08-23T15:35:30.747+0800:代表的是垃圾回收发生的时间。

  • 5.486:表示的是从 Java 虚拟机启动以来经过的秒数。

  • GC (Allocation Failure):表示发生 GC 的原因,这里是由于分配空间失败而发生了 GC。

  • [PSYoungGen: 32768K->3799K(37888K)]

    • PSYoungGen: PS 表示的是 Parallel Scavenge 收集器,YoungGen 表示当前发生的是年轻代的垃圾回收。这里不同的垃圾收集器会有不同的名字,如:ParNew 收集器就会显示为 ParNew。
    • 32768K->3799K(37888K): 表示 GC 发生之前使用的内存空间大小为32768K,GC 发生之后使用的内存空间大小为3799K,年轻代的总容量为37888K。
  • 32768K->3807K(123904K):表示 GC 发生之前 Java堆已使用容量为32768K,GC 发生之后 Java堆已使用容量为3807K,Java堆的总容量为123904K。

    注意: YoungGen 和 Java堆中这两组 GC 前后的数字相减得到的值一般是不相等的,这是因为总空间下面还包括了老年代发生回收后释放的空间大小。可能有人会觉得奇怪,这里明明只有新生代发生了 GC,为什么老年代会有空间释放?这是因为 S 区如果空间不够的话会利用 担保机制 向老年代借用空间,所以借来的空间是可能被释放的。

  • 0.1129986 secs:表示的是 GC 所花费的时间,secs 表示单位是秒。

  • [Times: user=0.02 sys=0.00, real=0.11 secs]:这一部分并不是所有的垃圾收集器都会打印。

    • user=0.02: 表示用户态消耗的 CPU 时间。
    • sys=0.00: 表示内耗态消耗的 CPU 时间和操作从开始到结束所经过的墙钟时间,即:sys=CPU时间+墙钟时间。

补充: 墙钟时间(Wall Clock Time) 包括各种非运算的等待耗时,例如:等待磁盘I/O、等待线程阻塞,而 CPU 时间不包括这些不需要消耗 CPU 的时间。

下面我们再看一下 Full GC 的日志解析:

在这里插入图片描述

2020-08-23T15:35:34.635+0800: 9.374: [Full GC (Metadata GC Threshold) [PSYoungGen: 5092K->0K(136192K)] [ParOldGen: 12221K->12686K(63488K)] 17314K->12686K(199680K), [Metaspace: 20660K->20660K(1067008K)], 0.0890985 secs] [Times: user=0.25 sys=0.00, real=0.09 secs] 
  • 基本信息同新生代一样,就不再赘述了。
  • Full GC:表示发生了 Full GC,Full GC=Minor GC+Major GC+Metaspace GC。所以后面可以看到 3 个区域的回收信息:PSYoungGen、ParOldGen、Metaspace。而且这 3 个区域对比非常明显,新生代全部回收掉了,老年代回收了一小部分,而方法区一点都没有回收掉,这也体现了 3 个区域中存储内容的区别。
  • ParOldGen:表示 Parallel Old 收集器在回收老年代。
  • Metaspace:表示的是方法区/元空间(JDK7是永久代)。

2.2 ParNew+CMS 日志分析

我们将垃圾收集器切换为 CMS,命令如下:

-XX:+UseConcMarkSweepGC

注意:CMS 是一款老年代收集器,使用这个参数后新生代默认会使用 ParNew 收集器。

将 CMS 垃圾收集器配置好之后重启服务,等待垃圾回收之后,打开 GC 日志如下:

在这里插入图片描述

前面3行应该都能看懂:

  1. 第一行,打印的是当前所使用的 HotSpot 虚拟机及其对应版本号;
  2. 第二行,打印的是操作系统相关的内存信息;
  3. 第三行,打印的是当前 Java 服务启动后所配置的参数信息。可以看到垃圾收集器已经成功切到 ParNew 和 CMS。

首先我们来看一下 ParNew 的 Young GC 日志:

2024-04-20T23:25:16.823+0800: 2.236: [GC (Allocation Failure) 2024-04-20T23:25:16.825+0800: 2.237: [ParNew: 67200K->7459K(75584K), 0.0085634 secs] 67200K->7459K(243520K), 0.0108369 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
  • 这里的回收信息和上面 PS 的 GC 日志基本一样,只是新生代名称不一样,这里叫 ParNew。

下面我们看一下老年代垃圾收集器 CMS:

CMS 的相关知识

CMS 全程 Concurrent Mark Sweep,是一款并发的、使用标记-清除算法的垃圾回收器。该回收器是针对老年代垃圾回收的,是一款以获取最短回收停顿时间为目标的收集器,停顿时间短,用户体验就好。其最大特点是在进行垃圾回收时,应用仍然能正常运行。

在这里插入图片描述

CMS 整个过程分为 4 步:

  1. 初始标记(initial mark)

    需要 Stop The World。标记 GC Root 对象,因为 GC Root 对象并不会很多,所以这个过程非常快。

  2. 并发标记(concurrent mark)

    这个阶段可以和用户线程同时进行,也可以分为3步:

    (1)并发标记(CMS-concurrent-mask)

    主要是进行 GC Roots Tracing。就是说根据第1步中找到的 GC Root 对象,开始搜索,这个过程相比阶段1是比较慢的。

    (2)预清理(CMS-concurrent-preclean)

    这个阶段是为了并发标记之后发生了变化的对象。

    (3)可被终止的预清理(CMS-concurrent-abortable-preclean)

    跟预清理差不多,但是是可以被种植的,主要是为了尽可能分担下面第3步重新标记的工作,这个阶段会有一个 abort 触发条件。该阶段存在的目的是希望能发生一次 Young GC,这样就可以减少 Young 区对象的数量,降低重新标记的工作量,因为重新标记会扫描整个堆内空间。可以通过参数 -XX:CMSScavengeBeforeRemark 参数控制在重新标记前发生一次 Young GC,默认为 false。这个阶段发生的最大时间由 -XX:CMSMaxAbortablePrecleanTime 控制,默认 5s。

  3. 重新标记(remark)

    需要 Stop The World,这个阶段是为了修正在阶段2并发标记之后产生了变化的对象。

  4. 并发清除(concurrent sweep)

    和用户线程同时进行,开始正式清除垃圾,在此阶段也会产生垃圾,产生垃圾后无法清除,只能等待下一次 GC。

我们主要看看老年代垃圾收集器 CMS 的 GC 日志,我们把一个完整的老年代回收日志复制出来:

// CMS Initial Mark:对应的是 CMS 工作机制的第1步——初始标记,主要是寻找 GC Root 对象。
// 30298K(86016K):表示当前 CMS 区域已使用空间30298K,总容量86016K。
// 34587K(124736K):表示当前 Java堆已使用空间34587K,总容量124736K。
// 0.0014342 secs:表示 CMS 初始标记阶段耗时约为0.0014342秒。
// [Times: user=0.00 sys=0.00, real=0.00 secs]:表示操作系统统计这段时间内,用户态CPU耗时、内核态CPU耗时、实际耗时均为0。
2020-08-23T17:00:47.650+0800: 18.182: [GC (CMS Initial Mark) [1 CMS-initial-mark: 30298K(86016K)] 34587K(124736K), 0.0014342 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
// CMS-concurrent-mark-start:对应的是 CMS 工作机制中的第2步的第1小步——并发标记。这个阶段主要是根据 GC Root 对象表里整个引用链。
2020-08-23T17:00:47.651+0800: 18.183: [CMS-concurrent-mark-start]
// 0.061/0.061 secs:表示该阶段持续的 CPU 时间和墙钟时间。
2020-08-23T17:00:47.712+0800: 18.244: [CMS-concurrent-mark: 0.061/0.061 secs] [Times: user=0.13 sys=0.00, real=0.06 secs] 
// CMS-concurrent-preclean-start:对应的是 CMS 工作机制中的第2步的第2小步——预清理。
2020-08-23T17:00:47.712+0800: 18.244: [CMS-concurrent-preclean-start]
2020-08-23T17:00:47.714+0800: 18.245: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
// CMS-concurrent-abortable-preclean-start:对应的是 CMS 工作机制中的第2步的第3小步——可被终止的预清理。
2020-08-23T17:00:47.714+0800: 18.246: [CMS-concurrent-abortable-preclean-start]
// Young GC:在重新标记之前进行一次年轻代的垃圾回收,减少重新标记时的STW时间。
2020-08-23T17:00:48.143+0800: 18.674: [GC (Allocation Failure) 2020-08-23T17:00:48.143+0800: 18.674: [ParNew: 38720K->4111K(38720K), 0.0101415 secs] 69018K->38573K(124736K), 0.0102502 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-23T17:00:48.451+0800: 18.983: [CMS-concurrent-abortable-preclean: 0.274/0.737 secs] [Times: user=0.94 sys=0.13, real=0.74 secs] 
// CMS Final Remark:对应的是 CMS 工作机制中的第3步——重新标记,此阶段需要STW。可以看到,在此阶段前发生了一次 Young GC,这是为了减少STW时间。
2020-08-23T17:00:48.451+0800: 18.983: [GC (CMS Final Remark) [YG occupancy: 23345 K (38720 K)]2020-08-23T17:00:48.451+0800: 18.983: [Rescan (parallel) , 0.0046112 secs]2020-08-23T17:00:48.456+0800: 18.987: [weak refs processing, 0.0006259 secs]2020-08-23T17:00:48.457+0800: 18.988: [class unloading, 0.0062187 secs]2020-08-23T17:00:48.463+0800: 18.994: [scrub symbol table, 0.0092387 secs]2020-08-23T17:00:48.472+0800: 19.004: [scrub string table, 0.0006408 secs][1 CMS-remark: 34461K(86016K)] 57806K(124736K), 0.0219024 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 
// CMS-concurrent-sweep:对应的是 CMS 工作集中的第4步——并发清除,并发清除垃圾。
2020-08-23T17:00:48.473+0800: 19.005: [CMS-concurrent-sweep-start]
2020-08-23T17:00:48.489+0800: 19.020: [CMS-concurrent-sweep: 0.015/0.015 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 
// CMS-concurrent-reset-start:重置线程。
2020-08-23T17:00:48.489+0800: 19.020: [CMS-concurrent-reset-start]
2020-08-23T17:00:48.492+0800: 19.023: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

2.3 G1 日志分析

首先,通过配置切换到 G1 垃圾收集器:

-XX:+UseG1GC

修改配置后需要重新启动服务,等待一次 GC 之后,打开 GC 日志文件内容如下:

在这里插入图片描述

通过前 3 行日志可以看到,目前程序已经成功切换到 G1 垃圾收集器了。我们找一次完成的 G1 日志进行分析:

// (young), 0.0029103 secs:表示发生 GC 的区域是 Young 区,总耗时时间为 0.0029103秒。
2020-08-23T18:44:39.787+0800: 2.808: [GC pause (G1 Evacuation Pause) (young), 0.0029103 secs]// [Parallel Time: 1.9 ms, GC Workers: 4]:表示线程的并行时间是 1.9毫秒,垃圾回收并行的线程数是4。[Parallel Time: 1.9 ms, GC Workers: 4]/** 接下来的几行描述了每个 GC 工作线程在各个阶段的工作情况。 */// GC Worker Start (ms):表示各工作线程开始工作的时刻,最小值、平均值、最大值、差异(Max-Min)。[GC Worker Start (ms): Min: 2807.7, Avg: 2807.8, Max: 2807.8, Diff: 0.1]// Ext Root Scanning (ms):表示扫描外部根(如全局变量、JNI引用等)的时间。[Ext Root Scanning (ms): Min: 0.3, Avg: 0.6, Max: 0.8, Diff: 0.5, Sum: 2.2]// Update RS (ms):更新 Remembered Set(RS,记录对象引用关系的数据结构)的时间。[Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]// Scan RS (ms): 扫描 Remembered Set 的时间。[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]// Code Root Scanning (ms):扫描代码根(如类元数据、方法表等)的时间。[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]// Object Copy (ms):复制存活对象到新的内存区域的时间。[Object Copy (ms): Min: 0.9, Avg: 1.2, Max: 1.4, Diff: 0.5, Sum: 4.6]// Termination (ms):各工作线程完成任务后的终止协调时间。[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination Attempts: Min: 1, Avg: 2.5, Max: 4, Diff: 3, Sum: 10]// GC Worker Other (ms):除上述阶段外的其他工作时间。[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]// GC Worker Total (ms): 每个工作线程的总工作时间。[GC Worker Total (ms): Min: 1.7, Avg: 1.8, Max: 1.8, Diff: 0.1, Sum: 7.1]// GC Worker End (ms):各工作线程结束工作的时刻。[GC Worker End (ms): Min: 2809.5, Avg: 2809.5, Max: 2809.5, Diff: 0.0]// Code Root Fixup:修复代码根引起耗时。[Code Root Fixup: 0.0 ms]// Code Root Purge:清理代码根耗时。[Code Root Purge: 0.0 ms]// Clear CT:清除 Card Table(记录堆中哪些区域可能含有跨代引用)耗时。[Clear CT: 0.1 ms]// Other:其他操作(如CSet选择、引用处理等)的总耗时,详细列出各项操作的具体耗时。[Other: 1.0 ms][Choose CSet: 0.0 ms][Ref Proc: 0.8 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.1 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms]/** 堆内存变化 */// Eden区:GC前已使用空间6144.0KB,总容量也为6144.0KB;GC后已使用空间清零,总容量变为12.0MB。// Survivors区:GC前已使用空间为0B,GC后已使用空间变为1024.0KB。// 整个堆:GC前已使用空间6144.0KB,总容量126.0MB;GC后已使用空间1520.0KB,总容量不变。[Eden: 6144.0K(6144.0K)->0.0B(12.0M) Survivors: 0.0B->1024.0K Heap: 6144.0K(126.0M)->1520.0K(126.0M)]/** 操作系统统计 */// user:用户态CPU时间,即垃圾收集过程中花费在用户态代码上的时间。// sys:内核态CPU时间,即垃圾收集过程中花费在内核态代码上的时间。// real:实际流逝时间(wall clock time),即从垃圾收集开始到结束的真实时间。[Times: user=0.00 sys=0.00, real=0.00 secs] 

注意: G1虽然在物理上取消了新生代和老年代的区域划分,但是逻辑上依然保留了,所以日志中还会显示 young,Full GC 会用 mixed 来表示。


三、GC 发生的原因

在 Java 中,GC 是由 JVM 自动完成的,根据 JVM 系统环境而定,所以时机是不确定的。当然,我们可以手动进行垃圾回收,比如调用 System.gc() 方法通知 JVM 进行一次垃圾回收,但是具体什么时刻运行也无法控制。也就是说 System.gc() 只是通知要回收,什么时候回收由 JVM 决定。

注意: 可能有些人会以为方法区是不会发生垃圾回收的,其实方法区也是会发生垃圾回收的,只不过大部分情况下,方法区发生垃圾回收之后效率不是很高,大部分内存都回收不掉,所以我们一般讨论垃圾回收的时候也只讨论堆内的回收。

一般有以下 5 种导致 GC 发生的原因:

3.1 Allocation Failure:新生代空间不足,触发 Minor GC

GC 日志如下:

2022-01-11T17:51:35.992-0800: 47.713: [GC (Allocation Failure) [PSYoungGen: 1280509K->89599K(1308160K)] 1396384K->217194K(1509376K), 0.0251936 secs] [Times: user=0.08 sys=0.01, real=0.02 secs]

Minor GC 触发的原因:新生代空间不足。

3.2 Metadata GC Threshold:元数据(方法区)空间不足,触发 Full GC

GC 日志如下:

2022-01-11T17:54:45.790-0800: 4.307: [Full GC (Metadata GC Threshold) [PSYoungGen: 12761K->0K(497664K)] [ParOldGen: 15911K->18963K(108032K)] 28672K->18963K(605696K), [Metaspace: 34603K->34603K(1081344K)], 0.0401502 secs] [Times: user=0.16 sys=0.00, real=0.04 secs]

Full GC 触发的原因:元空间(方法区)空间不足。

3.3 Ergonomics:系统调用,触发 Full GC

GC 日志如下:

2022-01-11T17:54:53.979-0800: 12.496: [Full GC (Ergonomics) [PSYoungGen: 49151K->0K(1077760K)] [ParOldGen: 91750K->95410K(221184K)] 140902K->95410K(1298944K), [Metaspace: 53259K->53259K(1097728K)], 0.1806514 secs] [Times: user=0.96 sys=0.01, real=0.19 secs]

Full GC 触发的原因:JVM为了优化系统性能和资源使用而自动发起的,JVM需要自动调节 GC 暂停时间和吞吐量之间的平衡。

3.4 System.gc():手动调用,触发 Full GC

GC 日志如下:

2023-0½-31T12:34:56.789+0000: 123.456: [GC (System.gc()) [PSYoungGen: 4096K->1024K(10240K)] .jpg0K->5120K(20480K), 0.0013400 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

Full GC 触发的原因:程序调用了 System.gc() 函数。

注意: 当使用 System.gc() 时,它会建议(而不是强制)Java 虚拟机(JVM)执行一次垃圾回收。具体的垃圾收集类型取决于 JVM 的配置和当前的内存状态,不一定都是 Full GC。


四、实战:项目启动时速度很慢

当项目启动的时候,启动耗时特别长,这时打印 GC 日志如下:

在这里插入图片描述

其中,第一次 Full GC 及之前的 Young GC 日志如下:

2022-01-12T11:05:59.658-0800: 1.334: [GC (Allocation Failure) [PSYoungGen: 65536K->4358K(76288K)] 65536K->4374K(251392K), 0.0196609 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 2022-01-12T11:06:00.062-0800: 1.738: [GC (Allocation Failure) [PSYoungGen: 69894K->5059K(141824K)] 69910K->5147K(316928K), 0.0060396 secs] [Times: user=0.02 sys=0.01, real=0.00 secs] 2022-01-12 11:06:00,193 main ERROR Console contains an invalid element or attribute "append"2022-01-12T11:06:00.886-0800: 2.561: [GC (Allocation Failure) [PSYoungGen: 136131K->10741K(141824K)] 136219K->11359K(316928K), 0.0159439 secs] [Times: user=0.03 sys=0.01, real=0.02 secs] 2022-01-12T11:06:00.958-0800: 2.634: [GC (Metadata GC Threshold) [PSYoungGen: 23884K->7144K(272896K)] 24502K->7771K(448000K), 0.0063136 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2022-01-12T11:06:00.965-0800: 2.640: [Full GC (Metadata GC Threshold) [PSYoungGen: 7144K->0K(272896K)] [ParOldGen: 626K->7038K(88576K)] 7771K->7038K(361472K), [Metaspace: 20521K->20520K(1067008K)], 0.0280148 secs] [Times: user=0.10 sys=0.01, real=0.03 secs]

可以看到,当项目启动 1.3s 的时候,便开始触发 Minor GC 了。因为项目刚刚启动的时候,要加载很多类,随后 2.640 的时候便触发了一次 Full GC,触发的原因是元数据空间不足。元数据空间(20521K->20520K(1067008K))消耗了 20M 了,垃圾回收之后,元数据空间基本上没有被回收,因为元数据保存的是类信息。我们知道 元数据默认空间大小是21M,如果空间不足会触发 Full GC,然后扩容

第二次 Full GC 日志如下:

2022-01-12T11:06:04.538-0800: 6.214: [Full GC (Metadata GC Threshold) [PSYoungGen: 11694K->0K(466944K)] [ParOldGen: 13317K->17995K(115200K)] 25011K->17995K(582144K), [Metaspace: 34079K->34079K(1079296K)], 0.0563024 secs] [Times: user=0.15 sys=0.00, real=0.06 secs]

在项目启动的第 6s,再次触发了 Full GC,原因也是元数据空间不足。这次元数据空间(34079K->34079K(1079296K))消耗了 34M,垃圾回收完毕以后,也是基本没被回收。但是我们可以看出,元数据空间扩容了,从 21M 扩容到了 34M。

结合上面两次 Full GC 的情况来看,为了避免元数据空间扩容导致频繁 Full GC,我们可以在项目启动的时候提前设置好元数据空间的大小:

-XX:+MetaspaceSize=256M -XX:MaxMetaspaceSize=256M

我们重新配置参数,启动项目,可以看到 Full GC 的次数变少了,完整 JVM 配置参数如下所示:

‐Xloggc:./gc‐adjust‐%t.log -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M ‐XX:+PrintGCDetails -XX:+Print GCDateStamps -XX:+PrintGCTimeStamps ‐XX:+PrintGCCause ‐XX:+UseGCLogFileRotation ‐XX:NumberOfGCLogFiles=10 ‐XX:GCLogFileSize=100M 

整理完毕,完结撒花~🌻





参考地址:

1.教你如何通过分析GC日志来进行JVM调优,https://cloud.tencent.com/developer/article/1745971
2.20.GC日志详解及日志分析工具,https://www.cnblogs.com/ITPower/p/15793047.html
3.GC日志解读,这次别再说看不懂GC日志了,https://juejin.cn/post/7029130033268555807
4.GC 日志分析,https://blog.csdn.net/chengqiuming/article/details/119292491
5.【JVM系列5】深入分析Java垃圾收集算法和常用垃圾收集器,https://blog.csdn.net/zwx900102/article/details/108180739

这篇关于JVM虚拟机(十二)ParallelGC、CMS、G1垃圾收集器的 GC 日志解析的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/926460

相关文章

网页解析 lxml 库--实战

lxml库使用流程 lxml 是 Python 的第三方解析库,完全使用 Python 语言编写,它对 XPath表达式提供了良好的支 持,因此能够了高效地解析 HTML/XML 文档。本节讲解如何通过 lxml 库解析 HTML 文档。 pip install lxml lxm| 库提供了一个 etree 模块,该模块专门用来解析 HTML/XML 文档,下面来介绍一下 lxml 库

JVM 的类初始化机制

前言 当你在 Java 程序中new对象时,有没有考虑过 JVM 是如何把静态的字节码(byte code)转化为运行时对象的呢,这个问题看似简单,但清楚的同学相信也不会太多,这篇文章首先介绍 JVM 类初始化的机制,然后给出几个易出错的实例来分析,帮助大家更好理解这个知识点。 JVM 将字节码转化为运行时对象分为三个阶段,分别是:loading 、Linking、initialization

Spring Security 基于表达式的权限控制

前言 spring security 3.0已经可以使用spring el表达式来控制授权,允许在表达式中使用复杂的布尔逻辑来控制访问的权限。 常见的表达式 Spring Security可用表达式对象的基类是SecurityExpressionRoot。 表达式描述hasRole([role])用户拥有制定的角色时返回true (Spring security默认会带有ROLE_前缀),去

浅析Spring Security认证过程

类图 为了方便理解Spring Security认证流程,特意画了如下的类图,包含相关的核心认证类 概述 核心验证器 AuthenticationManager 该对象提供了认证方法的入口,接收一个Authentiaton对象作为参数; public interface AuthenticationManager {Authentication authenticate(Authenti

Spring Security--Architecture Overview

1 核心组件 这一节主要介绍一些在Spring Security中常见且核心的Java类,它们之间的依赖,构建起了整个框架。想要理解整个架构,最起码得对这些类眼熟。 1.1 SecurityContextHolder SecurityContextHolder用于存储安全上下文(security context)的信息。当前操作的用户是谁,该用户是否已经被认证,他拥有哪些角色权限…这些都被保

Spring Security基于数据库验证流程详解

Spring Security 校验流程图 相关解释说明(认真看哦) AbstractAuthenticationProcessingFilter 抽象类 /*** 调用 #requiresAuthentication(HttpServletRequest, HttpServletResponse) 决定是否需要进行验证操作。* 如果需要验证,则会调用 #attemptAuthentica

Spring Security 从入门到进阶系列教程

Spring Security 入门系列 《保护 Web 应用的安全》 《Spring-Security-入门(一):登录与退出》 《Spring-Security-入门(二):基于数据库验证》 《Spring-Security-入门(三):密码加密》 《Spring-Security-入门(四):自定义-Filter》 《Spring-Security-入门(五):在 Sprin

Java架构师知识体认识

源码分析 常用设计模式 Proxy代理模式Factory工厂模式Singleton单例模式Delegate委派模式Strategy策略模式Prototype原型模式Template模板模式 Spring5 beans 接口实例化代理Bean操作 Context Ioc容器设计原理及高级特性Aop设计原理Factorybean与Beanfactory Transaction 声明式事物

Java进阶13讲__第12讲_1/2

多线程、线程池 1.  线程概念 1.1  什么是线程 1.2  线程的好处 2.   创建线程的三种方式 注意事项 2.1  继承Thread类 2.1.1 认识  2.1.2  编码实现  package cn.hdc.oop10.Thread;import org.slf4j.Logger;import org.slf4j.LoggerFactory

JAVA智听未来一站式有声阅读平台听书系统小程序源码

智听未来,一站式有声阅读平台听书系统 🌟 开篇:遇见未来,从“智听”开始 在这个快节奏的时代,你是否渴望在忙碌的间隙,找到一片属于自己的宁静角落?是否梦想着能随时随地,沉浸在知识的海洋,或是故事的奇幻世界里?今天,就让我带你一起探索“智听未来”——这一站式有声阅读平台听书系统,它正悄悄改变着我们的阅读方式,让未来触手可及! 📚 第一站:海量资源,应有尽有 走进“智听