G1收集器時(shí)JAVA 9正式引入的哼丈。JAVA 10發(fā)布之后宪躯,對(duì)G1收集器的Full GC做了優(yōu)化,優(yōu)化點(diǎn)就是把單線程的Full GC變成了多線程并行Full GC。那我們?cè)趺纯闯鲞@個(gè)優(yōu)化點(diǎn)呢芒珠?下面我們來做個(gè)實(shí)驗(yàn)。
上面的代碼會(huì)往data數(shù)組里面寫數(shù)據(jù)搅裙,重復(fù)十遍皱卓。我們先用JDK 9來看看程序GC情況如何裹芝。啟動(dòng)之前,我們加入JVM啟動(dòng)參數(shù):-Xlog:gc,gc+cpu::uptime -Xmx4g -Xms4g -Xlog:gc*:details.vgc娜汁。注:-Xlog:gc,gc+cpu::uptime就是把GC的每一個(gè)事件和CPU使用情況打印到控制臺(tái)嫂易,使用uptime作為標(biāo)簽打印在最前面。?-Xlog:gc*跟JDK 9之前的-XX:+PrintGCDetails是一樣的意思掐禁,就是打印GC詳細(xì)日志怜械,后面的details.vgc就是GC日志寫入的文件。對(duì)了傅事,我的CPU是4核缕允。
我們先用JDK 9執(zhí)行一遍該程序。執(zhí)行完畢之后分析以下打出來的日志享完。取一個(gè)cycle出來:
[13.886s] GC(106) Pause Initial Mark (G1 Humongous Allocation) 3467M->3459M(4096M) 21.957ms
[13.886s] GC(106) User=0.16s Sys=0.00s Real=0.02s
[13.886s] GC(107) Concurrent Cycle
[13.942s] GC(108) Pause Young (G1 Evacuation Pause) 3669M->3648M(4096M) 38.552ms
[13.943s] GC(108) User=0.22s Sys=0.00s Real=0.03s
[13.993s] GC(109) To-space exhausted
[13.993s] GC(109) Pause Young (G1 Evacuation Pause) 3882M->3894M(4096M) 22.696ms
[13.993s] GC(109) User=0.17s Sys=0.01s Real=0.03s
[13.997s] GC(107) Pause Remark 3914M->3914M(4096M) 1.153ms
[13.997s] GC(107) User=0.00s Sys=0.00s Real=0.00s
[14.019s] GC(110) To-space exhausted
[14.019s] GC(110) Pause Young (G1 Evacuation Pause) 4040M->4034M(4096M) 9.122ms
[14.019s] GC(110) User=0.07s Sys=0.00s Real=0.01s
[14.021s] GC(111) To-space exhausted
[14.021s] GC(111) Pause Young (G1 Evacuation Pause) 4040M->4040M(4096M) 1.599ms
[14.021s] GC(111) User=0.01s Sys=0.00s Real=0.00s
[14.784s] GC(112) Pause Full (Allocation Failure) 4040M->3331M(4096M) 762.372ms
[14.784s] GC(112) User=0.87s Sys=0.00s Real=0.77s
[14.784s] GC(107) Concurrent Cycle 898.093ms
[14.800s] GC(113) Pause Initial Mark (G1 Humongous Allocation) 3418M->3419M(4096M) 10.044ms
[14.800s] GC(113) User=0.08s Sys=0.00s Real=0.01s
[14.800s] GC(114) Concurrent Cycle
[14.839s] GC(115) Pause Young (G1 Evacuation Pause) 3623M->3594M(4096M) 23.689ms
[14.839s] GC(115) User=0.18s Sys=0.00s Real=0.02s
[14.880s] GC(116) Pause Young (G1 Evacuation Pause) 3772M->3725M(4096M) 24.273ms
[14.880s] GC(116) User=0.18s Sys=0.01s Real=0.02s
[14.890s] GC(114) Pause Remark 3813M->3813M(4096M) 1.140ms
[14.890s] GC(114) User=0.01s Sys=0.00s Real=0.00s
我標(biāo)黑了兩段日志灼芭。第一段是新生代的收集日志。user time是0.17秒般又,real time是0.03秒彼绷。user time是指gc花費(fèi)的所有CPU時(shí)間之和,real time是指gc暫停的實(shí)際時(shí)間茴迁。第二段是full gc的日志寄悯。user time是0.87秒,real time是0.77秒堕义,兩者相差無幾猜旬。
換成JDK 10再執(zhí)行一遍。
[13.589s] GC(107) To-space exhausted
[13.589s] GC(107) Pause Young (G1 Evacuation Pause) 4033M->4025M(4096M) 9.213ms
[13.589s] GC(107) User=0.05s Sys=0.01s Real=0.00s
[13.592s] GC(108) To-space exhausted
[13.592s] GC(108) Pause Young (G1 Evacuation Pause) 4033M->4031M(4096M) 2.165ms
[13.592s] GC(108) User=0.00s Sys=0.00s Real=0.00s
[13.593s] GC(109) To-space exhausted
[13.594s] GC(109) Pause Young (G1 Evacuation Pause) 4033M->4033M(4096M) 0.859ms
[13.594s] GC(109) User=0.01s Sys=0.00s Real=0.00s
[14.201s] GC(110) Pause Full (Allocation Failure) 4033M->3275M(4096M) 607.673ms
[14.202s] GC(110) User=3.94s Sys=0.03s Real=0.61s
[14.202s] GC(103) Concurrent Cycle 782.493ms
[14.204s] GC(111) Pause Initial Mark (G1 Humongous Allocation) 3277M->3277M(4096M) 1.856ms
[14.204s] GC(111) User=0.00s Sys=0.00s Real=0.00s
[14.204s] GC(112) Concurrent Cycle
[14.263s] GC(113) Pause Young (G1 Evacuation Pause) 3511M->3490M(4096M) 28.171ms
[14.263s] GC(113) User=0.20s Sys=0.01s Real=0.03s
[14.283s] GC(112) Pause Remark 3662M->3662M(4096M) 2.256ms
[14.283s] GC(112) User=0.01s Sys=0.00s Real=0.00s
[14.314s] GC(114) Pause Young (G1 Evacuation Pause) 3722M->3724M(4096M) 25.194ms
[14.314s] GC(114) User=0.16s Sys=0.00s Real=0.02s
[14.350s] GC(115) To-space exhausted
[14.350s] GC(115) Pause Young (G1 Evacuation Pause) 3910M->3915M(4096M) 18.179ms
[14.350s] GC(115) User=0.12s Sys=0.00s Real=0.02s
[14.368s] GC(116) To-space exhausted
[14.368s] GC(116) Pause Young (G1 Humongous Allocation) 4031M->4003M(4096M) 7.258ms
[14.368s] GC(116) User=0.04s Sys=0.00s Real=0.00s
[14.371s] GC(117) To-space exhausted
[14.372s] GC(117) Pause Young (G1 Evacuation Pause) 4031M->4031M(4096M) 1.698ms
[14.372s] GC(117) User=0.01s Sys=0.00s Real=0.00s
[14.938s] GC(118) Pause Full (Allocation Failure) 4031M->3318M(4096M) 566.566ms
[14.939s] GC(118) User=3.53s Sys=0.03s Real=0.56s
[14.939s] GC(112) Concurrent Cycle 734.758ms
[14.957s] GC(119) Pause Initial Mark (G1 Humongous Allocation) 3391M->3388M(4096M) 10.799ms
[14.957s] GC(119) User=0.05s Sys=0.00s Real=0.01s
[14.957s] GC(120) Concurrent Cycle
[15.005s] GC(121) Pause Young (G1 Evacuation Pause) 3572M->3518M(4096M) 30.110ms
[15.005s] GC(121) User=0.18s Sys=0.01s Real=0.03s
同樣倦卖,我也標(biāo)黑了兩段日志洒擦。第一段跟JDK 9的差不多,但是第二段就不一樣了怕膛,user time是3.53秒熟嫩,real time是0.56秒。這個(gè)差異是怎么來的呢褐捻?就是并行Full GC掸茅。JDK 10利用了CPU的多個(gè)核來做并行full gc,最后user time會(huì)增長(zhǎng)成real time的好幾倍柠逞,上面的日志里user time / real time = 6.2昧狮。