每次都感觉idea启动奇慢,决定对其进行一次优化。当前使用的idea版本为2017.2.6,jre版本为1.8.0_152。
- 首先确认idea当前的vm参数,增加gc日志来观察是哪里出了问题。找到idea64.exe.vmoptions,查看默认参数配置。
#idea默认参数配置
-Xms128m
-Xmx1024m
-XX:ReservedCodeCacheSize=240m
-XX:+UseConcMarkSweepGC
-XX:SoftRefLRUPolicyMSPerMB=50
-ea
-Dsun.io.useCanonCaches=false
-Djava.net.preferIPv4Stack=true
-XX:+HeapDumpOnOutOfMemoryError
-XX:-OmitStackTraceInFastThrow
-javaagent:D:/JetbrainsCrack-2.6.2.jar
增加如下配置:
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:D:\\ftp\\gcc.log
-XX:+PrintGCDetails 打印GC的详细信息。
-XX:+PrintGCTimeStamps 打印GC发生的时间点
-Xloggc:[path] 配置GC日志的输出路径
- 打开idea,待启动完成后,查看gcc.log日志信息,这里截取部分日志。
0.424: [GC (Allocation Failure) 0.424: [ParNew: 34944K->4352K(39296K), 0.0080627 secs] 34944K->6216K(126720K), 0.0081804 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
0.539: [GC (Allocation Failure) 0.539: [ParNew: 39296K->4352K(39296K), 0.0133345 secs] 41160K->13269K(126720K), 0.0133851 secs] [Times: user=0.05 sys=0.01, real=0.01 secs]
0.652: [GC (Allocation Failure) 0.652: [ParNew: 39296K->4352K(39296K), 0.0093016 secs] 48213K->17210K(126720K), 0.0093513 secs] [Times: user=0.03 sys=0.02, real=0.01 secs]
1.081: [GC (Allocation Failure) 1.081: [ParNew: 39296K->4352K(39296K), 0.0254282 secs] 52154K->26484K(126720K), 0.0255273 secs] [Times: user=0.06 sys=0.00, real=0.03 secs]
2.294: [GC (Allocation Failure) 2.294: [ParNew: 39288K->4352K(39296K), 0.0151094 secs] 61421K->33870K(126720K), 0.0151726 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2.905: [GC (Allocation Failure) 2.905: [ParNew: 39169K->4352K(39296K), 0.0129252 secs] 68688K->44114K(126720K), 0.0129829 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2.939: [GC (CMS Initial Mark) [1 CMS-initial-mark: 39762K(87424K)] 46971K(126720K), 0.0133274 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2.952: [CMS-concurrent-mark-start]
2.981: [CMS-concurrent-mark: 0.028/0.028 secs] [Times: user=0.06 sys=0.00, real=0.03 secs]
2.981: [CMS-concurrent-preclean-start]
2.981: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2.981: [CMS-concurrent-abortable-preclean-start]
3.674: [CMS-concurrent-abortable-preclean: 0.127/0.692 secs] [Times: user=1.90 sys=0.28, real=0.69 secs]
3.674: [GC (CMS Final Remark) [YG occupancy: 27201 K (39296 K)]3.674: [Rescan (parallel) , 0.0098238 secs]3.684: [weak refs processing, 0.0001229 secs]3.684: [class unloading, 0.0041969 secs]3.688: [scrub symbol table, 0.0040776 secs]3.692: [scrub string table, 0.0004669 secs][1 CMS-remark: 39762K(87424K)] 66964K(126720K), 0.0192316 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
3.694: [CMS-concurrent-sweep-start]
3.710: [CMS-concurrent-sweep: 0.016/0.016 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
3.710: [CMS-concurrent-reset-start]
3.711: [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
GC (Allocation Failure) 这个是发生了Minor GC,共计64次。
GC (CMS Initial Mark) 使用的CMS收集器,这个并不是发生了Full GC,而只是回收老年代,共计6次。
Allocation Failure是引起此次垃圾收集的原因,它代表年轻代中没有合适的区域能够存放需要分配的数据结构。由此判断应该默认的新生代值太小,导致不断触发Minor GC,修改-Xms,增加到512m,并添加-Xmn参数,设置年轻代大小为512m。
CMS收集器被触发了6次,仅知道是老年代不够用触发,但不能明确具体原因,考虑到想获取触发原因,因此使用ParNew + Serial Old收集器来代替ParNew + CMS,将"-XX:+UseConcMarkSweepGC"改为"-XX:+UseParNewGC"。改完配置后,再次重启idea并观察日志。
2.530: [Full GC (Metadata GC Threshold) 2.530: [Tenured: 0K->63K(64K), 0.0601792 secs] 218590K->21540K(471872K), [Metaspace: 20730K->20730K(1069056K)], 0.0603396 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
12.117: [Full GC (Metadata GC Threshold) 12.117: [Tenured: 63K->63K(64K), 0.1180218 secs] 210795K->43598K(471872K), [Metaspace: 34512K->34512K(1081344K)], 0.1181035 secs] [Times: user=0.11 sys=0.00, real=0.12 secs]
33.384: [GC (GCLocker Initiated GC) 33.384: [ParNew: 407680K->52416K(471808K), 0.0611222 secs] 407744K->64526K(483968K), 0.0611735 secs] [Times: user=0.14 sys=0.03, real=0.06 secs]
33.691: [Full GC (Metadata GC Threshold) 33.691: [Tenured: 12110K->12159K(12160K), 0.1581007 secs] 77428K->40464K(483968K), [Metaspace: 56170K->56170K(1101824K)], 0.1582591 secs] [Times: user=0.16 sys=0.00, real=0.16 secs]
54.056: [Full GC (Metadata GC Threshold) 54.056: [Tenured: 12159K->20267K(20268K), 0.2098952 secs] 212089K->65884K(492076K), [Metaspace: 92503K->92503K(1134592K)], 0.2100943 secs] [Times: user=0.22 sys=0.00, real=0.21 secs]
65.958: [GC (Allocation Failure) 65.958: [ParNew: 419392K->52416K(471808K), 0.0928508 secs] 439659K->85131K(505588K), 0.0929796 secs] [Times: user=0.28 sys=0.00, real=0.09 secs]
82.492: [GC (Allocation Failure) 82.492: [ParNew: 471808K->49436K(471808K), 0.0769481 secs]82.569: [Tenured: 79908K->77902K(79956K), 0.2455576 secs] 504523K->77902K(551764K), [Metaspace: 154160K->154160K(1189888K)], 0.3228020 secs] [Times: user=0.45 sys=0.00, real=0.32 secs]
103.663: [GC (Allocation Failure) 103.663: [ParNew: 419392K->48676K(471808K), 0.0362700 secs] 497294K->126578K(601648K), 0.0363482 secs] [Times: user=0.13 sys=0.00, real=0.04 secs]
这次共有4次Full GC,且原因相同,都是Metadata GC Threshold。idea使用jre版本为1.8,而在1.8中没有了PermGen永久代,改由Metaspace利用本地内存来存储类元信息。由此可知metaspace空间不足导致Full GC,增加如下参数来增加Metaspace空间大小。
-XX:MetaspaceSize=256m
再次重启idea,并观察GC日志信息。
15.486: [GC (Allocation Failure) 15.486: [ParNew: 419392K->51877K(471808K), 0.0410669 secs] 419392K->51877K(471872K), 0.0411566 secs] [Times: user=0.11 sys=0.01, real=0.04 secs]
45.959: [GC (Allocation Failure) 45.959: [ParNew: 471269K->48760K(471808K), 0.0753159 secs]46.034: [Tenured: 36343K->36407K(36408K), 0.1311271 secs] 471269K->43365K(508216K), [Metaspace: 67169K->67169K(1112064K)], 0.2067049 secs] [Times: user=0.33 sys=0.05, real=0.21 secs]
78.220: [GC (Allocation Failure) 78.220: [ParNew: 419392K->52416K(471808K), 0.0545238 secs] 455799K->100226K(532488K), 0.0545795 secs] [Times: user=0.20 sys=0.00, real=0.05 secs]
88.687: [GC (Allocation Failure) 88.687: [ParNew: 471808K->32818K(471808K), 0.0736899 secs]88.761: [Tenured: 82232K->71912K(82376K), 0.2735211 secs] 519618K->71912K(554184K), [Metaspace: 144025K->144025K(1179648K)], 0.3475460 secs] [Times: user=0.47 sys=0.02, real=0.35 secs]
119.428: [GC (Allocation Failure) 119.428: [ParNew: 419392K->48337K(471808K), 0.0473413 secs] 491304K->120249K(591664K), 0.0474673 secs] [Times: user=0.12 sys=0.00, real=0.05 secs]
120.514: [GC (Allocation Failure) 120.514: [ParNew: 467729K->30408K(471808K), 0.0402752 secs] 539641K->134118K(591664K), 0.0403302 secs] [Times: user=0.09 sys=0.03, real=0.04 secs]
这一次只有6次Minor GC,没有Full GC。改回使用CMS收集器,至此优化动作暂告结束。