「JVM 性能调优」应用程序启动耗时与延时优化

三余知行

已于 2023-03-11 09:55:45 修改

阅读量1.4k

点赞数 3

分类专栏：「JVM 体系梳理」文章标签： jvm java 开发语言

于 2023-02-04 23:58:09 首次发布

本文链接：https://blog.csdn.net/ChaoMing_H/article/details/128887253

版权

「JVM 体系梳理」专栏收录该内容

42 篇文章 14 订阅

订阅专栏

作为普通的 Java 开发者，即使不会参与太多的服务端运维、调优（需要兼顾数据库、资源池、磁盘 I/O 等方面），身边也存在很多可以应用到 JVM 知识的有趣场景；

本文的示例应用虽是 Eclipse 这一比较久远的 IDE 程序，但其中使用的优化思路和方式都值得借鉴，具备较高的实践参考价值；

文章目录

1. 程序运行状态（调优前）

配置

OS: 32 位 Windows 7
JDK: JDK 1.5 b64
Memory: 4 GB
-Xmx512m
-Dcom.sun.management.jmxremote # 启用 JMX 管理（VisualVM 中可以手机原始数据）

运行状态

整体启动过程平均耗时 15 s；
GC 总耗时 4.149 s；
- Full GC 共 19 次，耗时 3.166 s；
- Minor GC 共 378 次，耗时 0.983 s；
类加载 9115 个，耗时 4.114 s；
即时编译耗时 1.999 s；
JVM 的 Heap 总大小 512 MB，新生代 40 MB（Eden: 31.5 MB，Survivor: 4 MB x 2）、老年代 472 MB；

优化分析

非用户线程时间（Compile Time、Class Load Time、GC Time）占比几乎占了所有启动时间的一般以上（即时编译与用户线程并发执行，可能只会让用户线程变慢），JVM 本身占用了太多时间，导致使用过程中也存在明显卡顿；

2. 尝试升级 JDK 版本

每次 JDK 大版本的发布，发行商都会宣称其运行速度较上个版本有多少提升，即时这是广告性质的，但技术进步带来的性能改进是值得肯定的；因此条件允许情况下，升级 JDK 版本是一个可以考虑的方向；

调优尝试

本例将 JDK 1.5 b64 升级为 JDK 6 Update 21；但直接引入了一个 OOM 的兼容问题；

通过 VisualVM 监视进程的内存与 GC；

堆容量和堆使用量之间一直有较大的空闲空间；但每当使用量靠近容量，会触发堆容量的快速上升，堆使用量会被正常回收；可见堆区运行正常；
PermGen 区的容量和使用量几乎接近，也无回收发生；说明永久代可能存在内存溢出；

JDK 在未使用 -XX:MaxPermSize 制定永久代容量时，默认值为 64 MB，而这对本例的应用程序是不够的；但为何只在更新 JDK 5 至 JDK 6 后才会发生 OOM 呢？

通过 VisualVM -> Overview -> JVM arguments 页签发现，JDK 5 比 JDK 6 多了一个 JDK arguments 配置: -XX:MaxPermSize=256M；
通过 Eclipse 的 BugList 网站发现，在 eclipse.ini 中配置有 --launcher.XXMaxPermSize 256M，当 launcher 检测到 Eclipse 运行在 Sun 公司的 JVM 上时（因为其他商用版本的 JVM 不存在永久代，因此当时只针对 Sun JVM 做了配置），该参数会转化为 -XX:MaxPermSize=256M 传递给 JVM，但 2010 年 4 月 10 日 Oracle 完成 Sun 公司的收购后，Sun JVM 变为了 Oracle JVM，即时 JDK 1.6 Update 21 中也存在永久代，但根据条件也不会传递 -XX:MaxPermSize=256M 的参数了；

手动在 eclipse.ini 中指定 -XX:MaxPermSize=256M 即可；

3. 尝试优化编译与类加载时间

解决了 OOM 问题，发现 JDK 6 在整体应用启动时间上并没有得到优化；接下来分别从类加载和即时编译方面验证优化可行性；

类加载优化

# 使用JDK 6的类加载时间:
jps
3552
6372 org.eclipse.equinox.launcher_1.0.201.R35x_v20090715.jar
6900 Jps

jstat -class 6372
Loaded Bytes Unloaded Bytes Time
7917 10190.3 0 0.0 8.18

# 使用JDK 5类加载时间:
jps
3552
7272 Jps
7216 org.eclipse.equinox.launcher_1.0.201.R35x_v20090715.jar

jstat -class 7216
Loaded Bytes Unloaded Bytes Time
7902 9691.2 3 2.6 4.34

JDK 6 的类加载时长（8.18 s）是 JDK 5（4.34 s）的几乎 2 倍（可能与使用的机器有关，JDK 6 新加入了类型检查验证器）；

使用 -Xverify:none 禁用字节码验证过程，类加载时间明显得到优化；整体应用启动时间上也使得 JDK 6（13 s）由于 JDK 5（12 s）；

# 使用JDK 6的类加载时间:
jps
5512 org.eclipse.equinox.launcher_1.0.201.R35x_v20090715.jar
5596 Jps

jstat -class 5512
Loaded Bytes Unloaded Bytes Time
6749 8837.0 0 0.0 3.94

# 使用JDK 1.5的类加载时间:
jps
4724 org.eclipse.equinox.launcher_1.0.201.R35x_v20090715.jar
5412 Jps

jstat -class 4724
Loaded Bytes Unloaded Bytes Time
6885 9109.7 3 2.6 3.10

即时编译优化

即时编译，Just In Time Compiler，Java 语言为实现跨平台特性，将 Java 代码编译成 Class 格式的 JVM 字节码（Byte Code），然后 JVM 通过解释的方式执行这些字节码，但是这比起 C/C++ 编译成本地二进制代码执行的速度要慢很多；因此如果一段代码会被调用较多次数，JVM 会将之判定为热点代码，并将之交由即时编译器编译成本地代码，提高执行速度（由于完全在运行期动态编译，这比 C/C++ 的编译器静态编译的代码更优秀，根据收集运行期统计信息可以进行一些激进的优化手段，优化范围覆盖更多极端情况，如将不成立的优化退回解释状态或重新编译执行）；

通过 -Xint 禁用即时编译，强制 JVM 对字节码以纯解释方式执行；发现程序启动耗时剧增；没有即时编译支持的代码执行速度是大幅下降的；

HotSpot 的两个 JIT Compiler

C1，轻量级编译器，面向 Client 模式的 HotSpot；
C2，重量级编译器，面向 Server 模式的 HotSpot，拥有更多的优化措施；

4. 尝试优化 GC 频率

应用启动的短短 15 s 中，共发生了 19 次 Full GC 和 378 次 Minor GC，一共 397 次 GC 共造成了超过 4 s 的停顿；而且在引用启动完成后，在应用运行过程中 GC 还将可能保持这个频率，这是很糟糕的；

Minor GC

Eden 区与 Survivor 区之和过小，导致 Minor GC 频繁触发；

Full GC

通过 -XX:+PrintGCTimeStamps（打印 GC 停顿时间）、-XX:+PrintGCDetails（打印 GC 详细信息）、-verbose:gc（打印 GC 信息，输出内容已被前一个参数包括，可以不写）、-Xloggc:gc.log 等 GC 日志分析 Full GC 产生的原因，发现都是老年代空间耗尽；

1.575: [Full GC 1.575: [Tenured: 4800K->5046K(5784K), 0.0543136 secs] 5189K->5046K(6360K), [Perm : 12287K->1228 ...

且老年代回收状态很不理想（每次 Full GC 回收的老年代空间很小），老年代多次触发扩容：1536KB -> 1664KB -> 2684KB -> … -> 42056KB -> 46828KB；

优化方案

针对 Mnior GC: 设置 Xmn128MB，提升新生代大小，避免频繁 Minor GC；
针对 Full GC: 将 -Xms 和 -XX:PerSize 设置得跟 -Xmx（512 MB）和 -XX:MaxPermSize（96 MB）一样，避免运行时自动扩展；

调整内存配置后，启动过程共发生 8 次 Minor GC 和 4 次 Full GC，总耗时为 1.928 s；优化了不少，但 Full GC 依旧比较惹眼；

通过 jstat -gccause 查看最近一次 GC 原因；

jps
9772 Jps
4068 org.eclipse.equinox.launcher_1.0.201.R35x_v20090715.jar

jstat -gccause 4068
S0 S1 E O P YGC YGCT FGC FGCT GCT LGCC GCC
0.00 0.00 1.00 14.81 39.29 6 0.422 20 5.992 6.414
System.gc() No GC