[Java虚拟机][优化实战][使用VisualVM监控和加速Intellij Idea启动]

[Java高级][Java虚拟机][优化实战][使用VisualVM监控和加速Intellij Idea启动]

序

JDK提供了许多JVM监视工具，用于监控和分析 JVM和Java程序的运行状况，
VisualVM是其中最强大的一个。

VisualVM实用教程

《深入理解Java虚拟机》一书中 提到以Eclipse为例 加速其启动速度

那这里 我们仿照此文内容
使用VisualVM来监控idea启动过程 并优化启动速度

Intellij idea 版本信息

IntelliJ IDEA 2018.1 
Subscription is active until October 14, 2018
JRE: 1.8.0_152-release-1136-b20 amd64
JVM: OpenJDK 64-Bit Server VM 由 JetBrains s.r.o 
Windows 10 10.0

调优前的程序状态

idea启动参数

-Xms600m
-Xmx1024m
-XX:ReservedCodeCacheSize=240m
-XX:+UseConcMarkSweepGC
-XX:SoftRefLRUPolicyMSPerMB=50
-ea
-Dsun.io.useCanonCaches=false
-Djava.net.preferIPv4Stack=true
-XX:+HeapDumpOnOutOfMemoryError
-XX:-OmitStackTraceInFastThrow
-Dfile.encoding=UTF-8

已经有一些改进
如最小堆大小改为600m 默认为128m
最大堆设置为1024m 默认为512m

此处启动的是64位 Intellij idea 所以
启动参数中没有-server
因为64位JVM默认就是server模式的
而且并没有client模式

Idea启动后默认打开的是一个SpringBoot项目
依赖大概在20个左右 并不是很多

启动 使用VisualVM 监控启动信息

可以看到 耗时共分为一下几个部分

阶段	耗时	GC次数
编译	59.375	/
类加载	21.263s	/
垃圾回收	0.853s	27
Eden区回收	0.384s	15
老年代回收	0.469s	12

耗时很长 一共1分20秒左右

其中JIT编译耗时最长 为59.3秒
加载类46111个 耗时21.2秒
垃圾收集27次 耗时 0.853s 其中

• MinorGC 被触发15次 耗时0.384s
• FullGC 被触发12次 耗时0.469s

虚拟机堆空间1024mb被划分为341.312mb的新生代
(其中为273.062mb的eden区和两个34.125mb的survivor区)
和682.688mb的老年代

其中非用户时间 如编译时间 类加载时间 垃圾回收时间等占用过长
下面进行调优

编译时间和类加载时间优化

编译时间其实并没有太大优化空间
因为64位虚拟机默认使用server模式运行
会使用强化的c2编译器 所以编译耗时较长
但是这里的损失可以在程序运行时补回来

那类加载时间是否可以优化呢
其实也没有太大的空间

idea的代码显然是广泛使用的 可以认为是可信的
那么可以通过参数 -Xverify:none 来禁止字节码验证
测试可以提升5s左右的时间

调整内存设置控制垃圾收集频率

Intellij idea启动是使用自带JDK的
而idea 2018自带的JDK是OpenJDK 8
OpenJDK默认使用的是ParNew收集器

既然在编译时间和类加载时间上不能优化
只能在内存设置上做文章了

先打印GC日志

添加参数

-XX:+PrintGCTimeStamps //打印GC时间戳
-XX:+PrintGCDetails //打印GC详细信息
-verbose:gc //打印GC信息
-Xloggc:gcinfo.log //将结果输出到gcinfo.log文件

日志内容

2.210: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(264896K)] 266340K(579456K), 0.0447797 secs] [Times: user=0.03 sys=0.00, real=0.04 secs] 
2.379: [GC (Allocation Failure) 2.379: [ParNew: 279616K->27687K(314560K), 0.0097857 secs] 279616K->27687K(579456K), 0.0098441 secs] [Times: user=0.16 sys=0.00, real=0.01 secs] 
3.007: [GC (CMS Final Remark) [YG occupancy: 199746 K (314560 K)]3.007: [Rescan (parallel) , 0.0172355 secs]3.024: [weak refs processing, 0.0000130 secs]3.024: [class unloading, 0.0034056 secs]3.028: [scrub symbol table, 0.0027072 secs]3.031: [scrub string table, 0.0003650 secs][1 CMS-remark: 0K(264896K)] 199746K(579456K), 0.0245514 secs] [Times: user=0.17 sys=0.00, real=0.03 secs] 
4.080: [GC (Allocation Failure) 4.080: [ParNew: 307303K->25127K(314560K), 0.0367213 secs] 307303K->49085K(579456K), 0.0367688 secs] [Times: user=0.28 sys=0.02, real=0.04 secs] 
7.301: [GC (Allocation Failure) 7.301: [ParNew: 304743K->34944K(314560K), 0.0201103 secs] 328701K->79250K(579456K), 0.0201647 secs] [Times: user=0.20 sys=0.00, real=0.02 secs] 
7.321: [GC (CMS Initial Mark) [1 CMS-initial-mark: 44306K(264896K)] 79250K(579456K), 0.0020939 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
7.975: [GC (CMS Final Remark) [YG occupancy: 175573 K (314560 K)]7.975: [Rescan (parallel) , 0.0056321 secs]7.981: [weak refs processing, 0.0000512 secs]7.981: [class unloading, 0.0071611 secs]7.988: [scrub symbol table, 0.0091308 secs]7.997: [scrub string table, 0.0008179 secs][1 CMS-remark: 44306K(264896K)] 219880K(579456K), 0.0237342 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
8