行百里er
行百里er
2020-11-02
目录

【GC系列】JVM的常用GC参数及GC日志解析

作者：行百里er

博客：https://chendapeng.cn (opens new window)

提示

这里是 行百里er 的博客：行百里者半九十，凡事善始善终，吾将上下而求索！

今天继续GC系列第三篇，熬夜不易，欢迎一键三连，给个鼓励，不点赞也没关系，我还可以，谢谢捧场[捂脸]。

# 常见垃圾回收器组合设定

在oracle官网上可以看到如何开启使用指定垃圾回收的命令：

https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html (opens new window)

JVM命令-垃圾回收器组合

垃圾回收器通常是组合使用的，我根据官网总结一下常见垃圾回收器的组合。

  • -XX:+UseConcMarkSweepGC

启用CMS垃圾收集器用于老年代。

当以吞吐量为主的垃圾回收器（-XX:+UseParallelGC）无法满足应用程序的延时要求时，Oracle建议使用的垃圾回收器是CMS或者G1（-XX:+UseG1GC）

默认情况下，此选项是禁用的，HotSpot VM会根据计算机的配置和JDK版本自动选择收集器。

启用此选项后，-XX:+UseParNewGC选项将自动开启，并且不应禁用它，因为在JDK 8中不推荐使用以下选项组合：-XX:+UseConcMarkSweepGC -XX:-UseParNewGC。

而CMS一旦老年代产生了很多内存碎片，它还会使用Serial Old进行清除。

所以，-XX:+UseConcMarkSweepGC=ParNew+CMS+Serial Old

  • -XX:+UseG1GC

启用G1垃圾回收器。

它适用于具有大量RAM的多处理器计算机。它能满足GC暂停时间目标，同时保持良好的吞吐量。

建议将G1收集器用于需要大堆（大小约为6 GB或更大）且GC延迟要求有限（稳定且可预测的暂停时间低于0.5秒）的应用程序。

  • -XX:+UseParallelGC

使用并行清除垃圾收集器（也称为吞吐量收集器）来利用多个处理器来提高应用程序的性能。

默认情况下，此选项是禁用的，HotSpot根据计算机的配置和JDK版本自动选择收集器。

如果启用，则 -XX:+UseParallelOldGC选项也将自动启用，除非明确禁用它。

所以，-XX:+UseParallelGC=Parallel Scavenge+Parallel Old

  • -XX:+UseParallelOldGC

FullGC时使用ParallelOld。默认情况下，此选项是禁用的。

-XX:+UseParallelGC时，会自动-XX:+UseParallelOldGC。

  • -XX:+UseParNewGC

支持在年轻代中使用并行线程进行收集。

默认情况下，此选项是禁用的。

当设置-XX:+UseConcMarkSweepGC选项时，它将自动启用。

在JDK 8中，不建议使用-XX:+UseParNewGC选项而不使用-XX:+UseConcMarkSweepGC选项，也就是说ParNew和CMS最好同时启用，不要强行开一个禁一个。

  • -XX:+UseSerialGC

启用Serial GC。

对于不需要垃圾回收具有任何特殊功能的小型和简单的应用程序，这通常是最佳选择。

默认情况下，此选项是禁用的，并且将根据计算机的配置和JVM的类型自动选择收集器。

-XX:+UseSerialGC=Serial New+Serial Old。

# 查看JDK默认的垃圾回收器

使用如下命令

java -XX:+PrintCommandLineFlags -version
1

可以查看当前使用的JDK版本、虚拟机名称及使用的垃圾回收器。

JDK 1.8 HotSpot VM默认GC是ParallelGC

jdk1.8默认GC

JDK 11 HotSpot VM默认GC是G1

jdk11默认的GC是G1

# JVM常用命令参数

JVM命令可从如下网站查阅：

https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html (opens new window)

HotSpot参数分类

  • 标准 -开头，所有的HotSpot都支持，比如java -version

保证Java虚拟机（JVM）的所有实现都支持标准选项。它们用于常见操作，例如检查JRE版本，设置类路径，启用详细输出等。

  • 非标准 -X开头，特定版本HotSpot支持特定命令

非标准选项是特定于Java HotSpot虚拟机的通用选项，因此不能保证所有JVM实现都支持它们，并且它们可能会发生变化。这些选项以-X开头。

  • 不稳定 -XX开头，下个版本可能取消

这是高级选项，以-XX开头，不建议随意使用。这些是开发人员选项，用于调整Java HotSpot虚拟机操作的特定区域，这些区域通常具有特定的系统要求，并且可能需要对系统配置参数的特权访问。也不能保证所有JVM实现都支持它们，并且它们可能会发生变化。

下面我们用一段程序，通过调JVM参数，使用JVM命令用不同的GC，看一下运行情况。

开始之前，先普及一下内存泄漏和内存溢出。

内存泄漏（memory leak）：是指程序在申请内存后，无法释放已申请的内存空间，一次内存泄漏似乎不会有大的影响，但内存泄漏堆积后的后果就是内存溢出。

内存溢出（out of memory）：指程序申请内存时，没有足够的内存供申请者使用。比如程序不断地产生对象到内存不够了报错OOM就是所谓的内存溢出。

内存泄漏与内存溢出

再来看程序：

import java.util.LinkedList;
import java.util.List;

public class GCTest {
    public static void main(String[] args) {
        System.out.println("program start!");
        List list = new LinkedList();
        for (;;) {
            byte[] b = new byte[1024 * 1024];
            list.add(b);
        }
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13

很简单的一段测试代码，肯定会产生内存溢出，我们使用相关命令来观察一下。

默认情况下，运行代码：

[root@basic ~]# java GCTest
program start!
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at GCTest.main(GCTest.java:9)
1
2
3
4

报了内存溢出。

如果我们想知道他的内存分配过程，可以在运行的时候添加相应的JVM参数，下面来找几个常用的参数分别实验一下。

  • java -XX:+PrintCommandLineFlags GCTest
[root@basic ~]# java -XX:+PrintCommandLineFlags GCTest
-XX:InitialHeapSize=32449856 -XX:MaxHeapSize=519197696 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
program start!
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at GCTest.main(GCTest.java:9)
1
2
3
4
5

-XX:+PrintCommandLineFlags：打印人类可识别的JVM相关信息，例如堆空间大小和选定的垃圾收集器。

InitialHeapSize：起始堆大小，根据内存计算出来

MaxHeapSize：最大堆大小

UseCompressedClassPointers：使用压缩Class指针，比如Object.class，压缩后-XX:+UseCompressedClassPointer的情况在内存中占用4byte，不压缩-XX:-UseCompressedClassPointer的情况为8byte

UseCompressedOops：引用类型是否压缩，-XX:+UseCompressedOops表示压缩，压缩后的引用类型在内存中占4byte，不压缩的情况占用8byte。

  • java -Xmn10M -Xms40M -Xmx60M -XX:+PrintCommandLineFlags -XX:+PrintGC GCTest

-Xmn 新生代大小

-Xms 最小堆大小

-Xmx 最大堆大小，最好和Xms设置一样的值，防止堆弹来弹去，影响性能

-XX:+PrintGC 打印GC信息

执行如下：

[root@basic ~]# java -Xmn10M -Xms40M -Xmx60M -XX:+PrintCommandLineFlags -XX:+PrintGC GCTest
-XX:InitialHeapSize=41943040 -XX:MaxHeapSize=62914560 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintCommandLineFlags -XX:+PrintGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
program start!
[GC (Allocation Failure)  7839K->7592K(39936K), 0.0274278 secs]
[GC (Allocation Failure)  14920K->14704K(39936K), 0.0091149 secs]
[GC (Allocation Failure)  22024K->21872K(39936K), 0.0124746 secs]
[GC (Allocation Failure)  29195K->29008K(39936K), 0.0150616 secs]
[Full GC (Ergonomics)  29008K->28929K(55296K), 0.0209756 secs]
[GC (Allocation Failure)  36254K->36225K(55296K), 0.0102666 secs]
[GC (Allocation Failure)  43543K->43393K(55808K), 0.0087281 secs]
[Full GC (Ergonomics)  43393K->43265K(60928K), 0.0104380 secs]
[GC (Allocation Failure) -- 51630K->58798K(60928K), 0.0100362 secs]
[Full GC (Ergonomics)  58798K->51458K(60928K), 0.0055668 secs]
[Full GC (Ergonomics)  58793K->58626K(60928K), 0.0045510 secs]
[Full GC (Allocation Failure)  58626K->58614K(60928K), 0.0116986 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at GCTest.main(GCTest.java:9)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

[GC (Allocation Failure) 7839K->7592K(39936K), 0.0274278 secs]：新生代的GC，GC后堆内存占用从7839K减少到7592K，堆大小为39936K

可以看到，多次YGC后，回收不了了，就产生了FGC：

[Full GC (Ergonomics) 29008K->28929K(55296K), 0.0170423 secs]：产生了FullGC，GC后堆内存占用从29008K较少到28929K

  • java -Xmn10M -Xms40M -Xmx60M -XX:+PrintCommandLineFlags -XX:+PrintGCDetails GCTest

-XX:+PrintGCDetails可以打印更详细的GC信息：

[root@basic ~]# java -Xmn10M -Xms40M -Xmx60M -XX:+PrintCommandLineFlags -XX:+PrintGCDetails GCTest
-XX:InitialHeapSize=41943040 -XX:MaxHeapSize=62914560 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintCommandLineFlags -XX:+PrintGCDetails -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
program start!
[GC (Allocation Failure) [PSYoungGen: 7839K->352K(9216K)] 7839K->7528K(39936K), 0.0074573 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 7680K->320K(9216K)] 14856K->14664K(39936K), 0.0070717 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 
[GC (Allocation Failure) [PSYoungGen: 7640K->320K(9216K)] 21984K->21832K(39936K), 0.0064630 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 7643K->320K(9216K)] 29155K->29000K(39936K), 0.0070857 secs] [Times: user=0.01 sys=0.02, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 320K->0K(9216K)] [ParOldGen: 28680K->28929K(46080K)] 29000K->28929K(55296K), [Metaspace: 2514K->2514K(1056768K)], 0.0181374 secs] [Times: user=0.04 sys=0.01, real=0.02 secs] 
[GC (Allocation Failure) [PSYoungGen: 7325K->128K(9216K)] 36254K->36225K(55296K), 0.0090166 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 
[GC (Allocation Failure) [PSYoungGen: 7446K->128K(9728K)] 43543K->43393K(55808K), 0.0045376 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 128K->0K(9728K)] [ParOldGen: 43265K->43265K(51200K)] 43393K->43265K(60928K), [Metaspace: 2514K->2514K(1056768K)], 0.0076301 secs] [Times: user=0.01 sys=0.02, real=0.01 secs] 
[GC (Allocation Failure) --[PSYoungGen: 8365K->8365K(9728K)] 51630K->58798K(60928K), 0.0056167 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 8365K->1024K(9728K)] [ParOldGen: 50433K->50433K(51200K)] 58798K->51458K(60928K), [Metaspace: 2514K->2514K(1056768K)], 0.0113353 secs] [Times: user=0.02 sys=0.01, real=0.02 secs] 
[Full GC (Ergonomics) [PSYoungGen: 8360K->8192K(9728K)] [ParOldGen: 50433K->50433K(51200K)] 58793K->58626K(60928K), [Metaspace: 2514K->2514K(1056768K)], 0.0056429 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 
[Full GC (Allocation Failure) [PSYoungGen: 8192K->8192K(9728K)] [ParOldGen: 50433K->50422K(51200K)] 58626K->58614K(60928K), [Metaspace: 2514K->2514K(1056768K)], 0.0181221 secs] [Times: user=0.04 sys=0.00, real=0.02 secs] 
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at GCTest.main(GCTest.java:9)
Heap
 PSYoungGen      total 9728K, used 8533K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 9216K, 92% used [0x00000000ff600000,0x00000000ffe55678,0x00000000fff00000)
  from space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
  to   space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
 ParOldGen       total 51200K, used 50422K [0x00000000fc400000, 0x00000000ff600000, 0x00000000ff600000)
  object space 51200K, 98% used [0x00000000fc400000,0x00000000ff53d878,0x00000000ff600000)
 Metaspace       used 2545K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 275K, capacity 386K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26

此外，关于GC信息的参数还有：

-XX:+PrintGCTimeStamps：在每个GC上打印时间戳。

-XX:+PrintGCApplicationConcurrentTime：打印自上一次暂停（例如GC暂停）以来经过的时间。

-XX:+PrintGCDateStamps：在每个GC上打印日期戳。

-XX:+PrintGCTaskTimeStamps：为每个单独的GC工作线程任务启用时间戳打印。

  • java -XX:+UseConcMarkSweepGC -XX:+PrintCommandLineFlags -XX:+PrintGC GCTest

这个主要是看切换成CMS垃圾回收器的GC过程信息：

[root@basic ~]# java -XX:+UseConcMarkSweepGC -XX:+PrintCommandLineFlags -XX:+PrintGC GCTest
-XX:InitialHeapSize=32449856 -XX:MaxHeapSize=519197696 -XX:MaxNewSize=172666880 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintCommandLineFlags -XX:+PrintGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 
program start!
[GC (Allocation Failure)  7865K->7452K(31680K), 0.0055673 secs]
[GC (Allocation Failure)  15815K->15634K(31680K), 0.0051261 secs]
[GC (CMS Initial Mark)  22965K(31680K), 0.0014019 secs]
[GC (Allocation Failure)  23989K->23956K(33736K), 0.0060109 secs]
[GC (Allocation Failure)  32314K->32191K(41960K), 0.0238551 secs]
[GC (Allocation Failure)  40551K->40280K(50184K), 0.0254390 secs]
[GC (Allocation Failure)  48641K->48486K(58408K), 0.0273632 secs]
[GC (Allocation Failure)  56847K->56655K(65796K), 0.0104898 secs]
[GC (CMS Final Remark)  65017K(65796K), 0.0020809 secs]
[GC (Allocation Failure)  65017K->64822K(74020K), 0.0080847 secs]
[GC (Allocation Failure)  73184K->72985K(116060K), 0.0048156 secs]
[GC (Allocation Failure)  81348K->81174K(116060K), 0.0156927 secs]
[GC (Allocation Failure)  89536K->89366K(116060K), 0.0164924 secs]
[GC (CMS Initial Mark)  91585K(116060K), 0.0005150 secs]
[GC (Allocation Failure)  97729K->97558K(116060K), 0.0200535 secs]
[GC (Allocation Failure)  105921K->105749K(116060K), 0.0195895 secs]
[GC (Allocation Failure)  114111K->113943K(123256K), 0.0185969 secs]
[GC (Allocation Failure)  122306K->122133K(131480K), 0.0174622 secs]
[GC (Allocation Failure)  130496K->130328K(139704K), 0.0168396 secs]
[GC (Allocation Failure)  138690K->138518K(147928K), 0.0222069 secs]
[GC (Allocation Failure)  146881K->146712K(156152K), 0.0189141 secs]
[GC (Allocation Failure)  155075K->154903K(164376K), 0.0212268 secs]
[GC (Allocation Failure)  163265K->163097K(172600K), 0.0184528 secs]
[GC (Allocation Failure)  171460K->171289K(180824K), 0.0230886 secs]
[GC (Allocation Failure)  179652K->179482K(189048K), 0.0197197 secs]
[GC (Allocation Failure)  187844K->187672K(197272K), 0.0211699 secs]
[GC (Allocation Failure)  196035K->195864K(205496K), 0.0219487 secs]
[GC (Allocation Failure)  204227K->204056K(213720K), 0.0221430 secs]
[GC (Allocation Failure)  212419K->212251K(221944K), 0.0237262 secs]
[GC (Allocation Failure)  220613K->220443K(230168K), 0.0274986 secs]
[GC (Allocation Failure)  228806K->228635K(238392K), 0.0253731 secs]
[GC (Allocation Failure)  236998K->236826K(246616K), 0.0186347 secs]
[GC (Allocation Failure)  245188K->245018K(254840K), 0.0188651 secs]
[GC (Allocation Failure)  253381K->253212K(263064K), 0.0232380 secs]
[GC (Allocation Failure)  261575K->261403K(271288K), 0.0192675 secs]
[GC (Allocation Failure)  269765K->269597K(279512K), 0.0250426 secs]
[GC (Allocation Failure)  277960K->277787K(287736K), 0.0230294 secs]
[GC (Allocation Failure)  286151K->285982K(295960K), 0.0252418 secs]
[GC (Allocation Failure)  294345K->294174K(304184K), 0.0195708 secs]
[GC (Allocation Failure)  302537K->302366K(312408K), 0.0252629 secs]
[GC (Allocation Failure)  310729K->310559K(320632K), 0.0241283 secs]
[GC (Allocation Failure)  318921K->318749K(328856K), 0.0235919 secs]
[GC (Allocation Failure)  327112K->326943K(336052K), 0.0204393 secs]
[GC (Allocation Failure)  335306K->335133K(344276K), 0.0242358 secs]
[Full GC (Allocation Failure)  343496K->343313K(344276K), 0.0948962 secs]
[GC (Allocation Failure)  344507K->347589K(349120K), 0.0145370 secs]
[Full GC (Allocation Failure)  347589K->344337K(349120K), 0.0053974 secs]
[GC (CMS Initial Mark)  345361K(491072K), 0.0031466 secs]
[GC (CMS Final Remark)  352315K(491072K), 0.0021340 secs]
[Full GC (Allocation Failure)  489533K->488726K(491072K), 0.0355269 secs]
[GC (CMS Initial Mark)  489750K(491072K), 0.0017936 secs]
[Full GC (Allocation Failure)  490513K->489750K(491072K), 0.0029711 secs]
[Full GC (Allocation Failure)  489750K->489739K(491072K), 0.0662137 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at GCTest.main(GCTest.java:9)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58

乍一看，和默认的ParallelGC日志信息差不多，就是长了点，其实他就是多了一些CMS Initial Mark、CMS Final Remark等信息，

CMS初始标记、重新标记这些概念在上一篇已有介绍：

【GC系列】JVM堆内存分代模型及常见的垃圾回收器 (opens new window)

通过这段日志可以看到最后通过几次FullGC都没办法清除，最终导致了OOM。

# PS GC日志详解

先看这一句：

[GC (Allocation Failure) [PSYoungGen: 7839K->368K(9216K)] 7839K->7544K(39936K), 0.0072850 secs] [Times: user=0.01 sys=0.02, real=0.01 secs]

该句GC日志的含义：

GC：YGC，产生在年轻代（新生代）的GC。

Allocation Failure：产生GC的原因。

PSYoungGen：PS，新生代。

7839K->368K（9216K）：垃圾回收之前是7839K，回收之后是368K（也就是说回收了7839-368的空间大小），9216K是整个年轻代的堆大小。

7839K->7544K(39936K)：整个堆的空间大小变化。为什么总堆大小和年轻代的一样都是7839K，没有old区了吗？原因就是全被年轻代占用了。

0.0072850 secs：本次GC所耗时间

[Times: user=0.01 sys=0.02, real=0.01 secs]：user表示用户态耗时，sys表示内核态耗时，real表示实际耗时

一旦产生了内存溢出，GC日志把整个堆heap dump出来：

Heap
PSYoungGen      total 9728K, used 8533K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 9216K, 92% used [0x00000000ff600000,0x00000000ffe55678,0x00000000fff00000)
  from space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
  to   space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
ParOldGen       total 51200K, used 50422K [0x00000000fc400000, 0x00000000ff600000, 0x00000000ff600000)
  object space 51200K, 98% used [0x00000000fc400000,0x00000000ff53d878,0x00000000ff600000)
Metaspace       used 2545K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 275K, capacity 386K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9

这个信息已经很明确了，比如PSYoungGen是新生代，eden是新生代中的eden区，from、to是两个survivor区，ParOldGen是老年代，Metaspace是元空间。

主要看这几个内存地址：

[0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

[起始地址, 使用空间结束地址, 整体空间结束地址)
1
2
3

eden space 9216K, 92% used [0x00000000ff600000,0x00000000ffe55678,0x00000000fff00000)：

表示eden区的空间的内存地址从0x00000000ff600000到0x00000000fff00000，总共9216K，已使用了92%。

首发公众号 行百里er ，欢迎老铁们关注阅读指正。

#JVM
上次更新: 2022/10/04, 18:14:30
【GC系列】JVM堆内存分代模型及常见的垃圾回收器
【优雅的避坑】从验证码生成代码的优化到 JVM 栈和堆

← 【优雅的避坑】从验证码生成代码的优化到 JVM 栈和堆→

最近更新
01
重要数据不能丢！MySQL数据库定期备份保驾护航！
05-22
02
分布式事务解决方案之 Seata（二）：Seata AT 模式
09-09
03
Seata 番外篇：使用 docker-compose 部署 Seata Server（TC）及 K8S 部署 Seata 高可用
09-05
更多文章>
Theme by Vdoing | Copyright © 2020-2023 行百里er | MIT License | 豫ICP备2022020385号-1