JVM性能调优系列【三】JVM优化步骤

人工智

已于 2022-06-16 00:28:53 修改

阅读量701

点赞数

文章标签： java eclipse java-ee

于 2022-06-15 00:18:17 首次发布

原文链接：https://mp.weixin.qq.com/s/MAx0FNQVGPmuajfqNFSFmg

版权

JVM 优化步骤？

1、分析和定位当前系统的瓶颈

对于JVM的核心指标，我们的关注点和常用工具如下：

（1） CPU指标

查看占用CPU最多的进程
查看占用CPU最多的线程
查看线程堆栈快照信息
分析代码执行热点
查看哪个代码占用CPU执行时间最长
查看每个方法占用CPU时间比例

常见的命令：

// 显示系统各个进程的资源使用情况
top
// 查看某个进程中的线程占用情况
top -Hp pid
// 查看当前 Java 进程的线程堆栈信息
jstack pid

常见的工具：JProfiler、JVM Profiler、Arthas等。

（2）JVM 内存指标

查看当前 JVM 堆内存参数配置是否合理
查看堆中对象的统计信息
查看堆存储快照，分析内存的占用情况
查看堆各区域的内存增长是否正常
查看是哪个区域导致的GC
查看GC后能否正常回收到内存

常见的命令：

// 查看当前的 JVM 参数配置
ps -ef | grep java
// 查看 Java 进程的配置信息，包括系统属性和JVM命令行标志
jinfo pid
// 输出 Java 进程当前的 gc 情况
jstat -gc pid
// 输出 Java 堆详细信息
jmap -heap pid
// 显示堆中对象的统计信息
jmap -histo:live pid
// 生成 Java 堆存储快照dump文件
jmap -F -dump:format=b,file=dumpFile.phrof pid

常见的工具：Eclipse MAT、JConsole等。

（3）JVM GC指标

查看每分钟GC时间是否正常
查看每分钟YGC次数是否正常
查看FGC次数是否正常
查看单次FGC时间是否正常
查看单次GC各阶段详细耗时，找到耗时严重的阶段
查看对象的动态晋升年龄是否正常

JVM 的 GC指标一般是从 GC 日志里面查看，默认的 GC 日志可能比较少，我们可以添加以下参数，来丰富我们的GC日志输出，方便我们定位问题。

GC日志常用 JVM 参数：

// 打印GC的详细信息
-XX:+PrintGCDetails
// 打印GC的时间戳
-XX:+PrintGCDateStamps
// 在GC前后打印堆信息
-XX:+PrintHeapAtGC
// 打印Survivor区中各个年龄段的对象的分布信息
-XX:+PrintTenuringDistribution
// JVM启动时输出所有参数值，方便查看参数是否被覆盖
-XX:+PrintFlagsFinal
// 打印GC时应用程序的停止时间
-XX:+PrintGCApplicationStoppedTime
// 打印在GC期间处理引用对象的时间（仅在PrintGCDetails时启用）
-XX:+PrintReferenceGC

以上就是我们定位系统瓶颈的常用手段，大部分问题通过以上方式都能定位出问题原因，然后结合代码去找到问题根源。

2、确定优化目标

定位出系统瓶颈后，在优化前先制定好优化的目标是什么，例如：

将FGC次数从每小时1次，降低到1天1次
将每分钟的GC耗时从3s降低到500ms
将每次FGC耗时从5s降低到1s以内
…

3、制定优化方案

定位出系统瓶颈后，在优化前先制定好优化的目标是什么，例如：

将FGC次数从每小时1次，降低到1天1次
将每分钟的GC耗时从3s降低到500ms
将每次FGC耗时从5s降低到1s以内
…
针对定位出的系统瓶颈制定相应的优化方案，常见的有：
代码bug：升级修复bug。典型的有：死循环、使用无界队列。
不合理的JVM参数配置：优化 JVM 参数配置。典型的有：年轻代内存配置过小、堆内存配置过小、元空间配置过小。

4、对比优化前后的指标，统计优化效果

5、持续观察和跟踪优化效果

6、如果需要，重复以上步骤

调优案例：

一、metaspace导致频繁FGC问题

以下案例来源于网络：
服务环境：ParNew + CMS + JDK8

问题现象：服务频繁出现FGC

原因分析：

1）首先查看GC日志，发现出现FGC的原因是metaspace空间不够

对应GC日志：

Full GC (Metadata GC Threshold)

2）进一步查看日志发现元空间存在内存碎片化现象

对应GC日志：

Metaspace       used 35337K, capacity 56242K, committed 56320K, reserved 1099776K

这边简单解释下这几个参数的意义

used ：已使用的空间大小
capacity：当前已经分配且未释放的空间容量大小
committed：当前已经分配的空间大小
reserved：预留的空间大小

结合下图来看更容易理解，元空间的分配以 chunk 为单位，当一个 ClassLoader 被垃圾回收时，所有属于它的空间（chunk）被释放，此时该 chunk 称为 Free Chunk，而 committed chunk 就是 capacity chunk 和 free chunk 之和。
在这里插入图片描述
之所以说内存存在碎片化现象就是根据 used 和 capacity 的数据得来的，上面说了元空间的分配以 chunk 为单位，即使一个 ClassLoader 只加载1个类，也会独占整个 chunk，所以当出现 used 和 capacity 两者之差较大的时候，说明此时存在内存碎片化的情况。

GC日志demo如下：

{Heap before GC invocations=0 (full 0):
 par new generation   total 314560K, used 141123K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,  50% used [0x00000000c0000000, 0x00000000c89d0d00, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
  to   space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
 concurrent mark-sweep generation total 699072K, used 0K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 35337K, capacity 56242K, committed 56320K, reserved 1099776K
  class space    used 4734K, capacity 8172K, committed 8172K, reserved 1048576K
1.448: [Full GC (Metadata GC Threshold) 1.448: [CMS: 0K->10221K(699072K), 0.0487207 secs] 141123K->10221K(1013632K), [Metaspace: 35337K->35337K(1099776K)], 0.0488547 secs] [Times: user=0.09 sys=0.00, real=0.05 secs] 
Heap after GC invocations=1 (full 1):
 par new generation   total 314560K, used 0K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
  to   space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
 concurrent mark-sweep generation total 699072K, used 10221K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 35337K, capacity 56242K, committed 56320K, reserved 1099776K
  class space    used 4734K, capacity 8172K, committed 8172K, reserved 1048576K
}
{Heap before GC invocations=1 (full 1):
 par new generation   total 314560K, used 0K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
  to   space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
 concurrent mark-sweep generation total 699072K, used 10221K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 35337K, capacity 56242K, committed 56320K, reserved 1099776K
  class space    used 4734K, capacity 8172K, committed 8172K, reserved 1048576K
1.497: [Full GC (Last ditch collection) 1.497: [CMS: 10221K->3565K(699072K), 0.0139783 secs] 10221K->3565K(1013632K), [Metaspace: 35337K->35337K(1099776K)], 0.0193983 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
Heap after GC invocations=2 (full 2):
 par new generation   total 314560K, used 0K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
  to   space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
 concurrent mark-sweep generation total 699072K, used 3565K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 17065K, capacity 22618K, committed 35840K, reserved 1079296K
  class space    used 1624K, capacity 2552K, committed 8172K, reserved 1048576K

元空间主要适用于存放类的相关信息，而存在内存碎片化说明很可能创建了较多的类加载器，同时使用率较低。

因此，当元空间出现内存碎片化时，我们会着重关注是不是创建了大量的类加载器。

3）通过 dump 堆存储文件发现存在大量 DelegatingClassLoader

通过进一步分析，发现是由于反射导致创建大量 DelegatingClassLoader。其核心原理如下：

在 JVM 上，最初是通过 JNI 调用来实现方法的反射调用，当 JVM 注意到通过反射经常访问某个方法时，它会将该方法的访问从 JNI 优化成字节码的方式来执行，我们称为膨胀（inflation）机制。如果使用字节码的方式，则会为该方法生成一个 DelegatingClassLoader，如果存在大量方法经常反射调用，则会导致创建大量 DelegatingClassLoader。

反射调用频次达到多少才会从 JNI 转字节码？

默认是15次，可通过参数 -Dsun.reflect.inflationThreshold 进行控制，在小于该次数时会使用 JNI 的方式对方法进行调用，如果调用次数超过该次数就会使用字节码的方式生成方法调用。
分析结论：反射调用导致创建大量 DelegatingClassLoader，占用了较大的元空间内存，同时存在内存碎片化现象，导致元空间利用率不高，从而较快达到阈值，触发 FGC。

优化策略：
1）适当调大 metaspace 的空间大小。
2）优化不合理的反射调用。例如最常见的属性拷贝工具类 BeanUtils.copyProperties 可以使用 mapstruct 替换。