JDK11发布了,ZGC的相关描述很诱人,体验了一下。
一共测试了三次,分别使用JDK8和JDK11。使用JMeter做压力测试,比较G1和ZGC的差别。
JDK8下的G1
JAVA_OPTS=" -Xms2g -Xmx2g -Xmn1400m -XX:+UseG1GC -XX:InitiatingHeapOccupancyPercent=60 "
JAVA_OPTS="$JAVA_OPTS -XX:MaxGCPauseMillis=50 -XX:+PrintGCDetails -verbose:gc -Xloggc:./g1-gc.log"
大约测试了半个小时,使用visualvm_142查看CPU和内存使用情况:
GC情况:
可见,G1的性能还是不错的。
一共收集467次。一共耗时2405毫秒,平均每次5.15毫秒。
JDK11下的ZGC(2G内存)
JAVA_OPTS=" -server -Xms2g -Xmx2g -XX:ConcGCThreads=4 -XX:+UnlockExperimentalVMOptions -XX:+UseZGC "
JAVA_OPTS="$JAVA_OPTS -Xlog:gc*:file=gis-gc.txt "
同样使用2G内存,测试半小时。
visualvm_142不支持ZGC,所以,使用JDK11自带的jconsole查看:
一共972次收集,耗时1373毫秒。平均每次1.41毫秒。
JDK11的ZGC(8G内存)
据Oracle的宣传,ZGC特别适合大内存的情况。
于是,增大内存配置,继续测试半小时。
JAVA_OPTS=" -server -Xms8g -Xmx8g -XX:ConcGCThreads=4 -XX:+UnlockExperimentalVMOptions -XX:+UseZGC "
JAVA_OPTS="$JAVA_OPTS -Xlog:gc*:file=gis-gc.txt "
jconsole输出如下:
813次收集,耗时1113毫秒。平均每次1.37毫秒。
测试比较失败,因为虽然配置了8G内存,但是,实际使用的内存很少超过1.5G。
以后试试怎么提升程序使用的内存量。
可以看出来,ZGC的性能相比G1还是提高很多的。
JDK8下的G1和JDK11下的ZGC,CPU利用率基本没差别。
下面贴一段ZGC的收集日志:
[1131.279s][info][gc,start ] GC(502) Garbage Collection (Proactive)
[1131.280s][info][gc,phases ] GC(502) Pause Mark Start 0.719ms
[1131.314s][info][gc,phases ] GC(502) Concurrent Mark 34.151ms
[1131.315s][info][gc,phases ] GC(502) Pause Mark End 0.066ms
[1131.315s][info][gc,phases ] GC(502) Concurrent Process Non-Strong References 0.564ms
[1131.315s][info][gc,phases ] GC(502) Concurrent Reset Relocation Set 0.008ms
[1131.315s][info][gc,phases ] GC(502) Concurrent Destroy Detached Pages 0.001ms
[1131.317s][info][gc,phases ] GC(502) Concurrent Select Relocation Set 1.367ms
[1131.317s][info][gc,phases ] GC(502) Concurrent Prepare Relocation Set 0.030ms
[1131.317s][info][gc,phases ] GC(502) Pause Relocate Start 0.565ms
[1131.319s][info][gc,phases ] GC(502) Concurrent Relocate 1.343ms
[1131.319s][info][gc,load ] GC(502) Load: 6.96/7.15/7.00
[1131.319s][info][gc,mmu ] GC(502) MMU: 2ms/25.6%, 5ms/70.2%, 10ms/85.1%, 20ms/92.1%, 50ms/95.8%, 100ms/97.5%
[1131.319s][info][gc,marking ] GC(502) Mark: 4 stripe(s), 3 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
[1131.319s][info][gc,reloc ] GC(502) Relocation: Successful, 7M relocated
[1131.319s][info][gc,nmethod ] GC(502) NMethods: 5130 registered, 1910 unregistered
[1131.319s][info][gc,metaspace] GC(502) Metaspace: 59M used, 59M capacity, 59M committed, 60M reserved
[1131.319s][info][gc,ref ] GC(502) Soft: 6431 encountered, 0 discovered, 0 enqueued
[1131.319s][info][gc,ref ] GC(502) Weak: 4778 encountered, 538 discovered, 0 enqueued
[1131.319s][info][gc,ref ] GC(502) Final: 32 encountered, 7 discovered, 0 enqueued
[1131.319s][info][gc,ref ] GC(502) Phantom: 306 encountered, 238 discovered, 0 enqueued
[1131.319s][info][gc,heap ] GC(502) Mark Start Mark End Relocate Start Relocate End High Low
[1131.319s][info][gc,heap ] GC(502) Capacity: 8192M (100%) 8192M (100%) 8192M (100%) 8192M (100%) 8192M (100%) 8192M (100%)
[1131.319s][info][gc,heap ] GC(502) Reserve: 42M (1%) 42M (1%) 42M (1%) 42M (1%) 42M (1%) 42M (1%)
[1131.319s][info][gc,heap ] GC(502) Free: 7116M (87%) 7102M (87%) 7974M (97%) 8026M (98%) 8026M (98%) 7100M (87%)
[1131.319s][info][gc,heap ] GC(502) Used: 1034M (13%) 1048M (13%) 176M (2%) 124M (2%) 1050M (13%) 124M (2%)
[1131.319s][info][gc,heap ] GC(502) Live: - 59M (1%) 59M (1%) 59M (1%) - -
[1131.319s][info][gc,heap ] GC(502) Allocated: - 14M (0%) 18M (0%) 32M (0%) - -
[1131.319s][info][gc,heap ] GC(502) Garbage: - 974M (12%) 98M (1%) 44M (1%) - -
[1131.319s][info][gc,heap ] GC(502) Reclaimed: - - 876M (11%) 930M (11%) - -
[1131.319s][info][gc ] GC(502) Garbage Collection (Proactive) 1034M(13%)->124M(2%)
还有GC统计信息
[1130.680s][info][gc,stats ] === Garbage Collection Statistics =======================================================================================================================
[1130.681s][info][gc,stats ] Last 10s Last 10m Last 10h Total
[1130.681s][info][gc,stats ] Avg / Max Avg / Max Avg / Max Avg / Max
[1130.681s][info][gc,stats ] Collector: Garbage Collection Cycle 37.112 / 39.642 39.446 / 79.870 38.985 / 108.249 38.985 / 108.249 ms
[1130.681s][info][gc,stats ] Contention: Mark Segment Reset Contention 0 / 0 0 / 4 0 / 4 0 / 4 ops/s
[1130.681s][info][gc,stats ] Contention: Mark SeqNum Reset Contention 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[1130.681s][info][gc,stats ] Contention: Relocation Contention 0 / 0 0 / 15 1 / 397 1 / 397 ops/s
[1130.681s][info][gc,stats ] Critical: Allocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Critical: Allocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[1130.681s][info][gc,stats ] Critical: GC Locker Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Critical: GC Locker Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[1130.681s][info][gc,stats ] Memory: Allocation Rate 489 / 526 538 / 618 532 / 618 532 / 618 MB/s
[1130.681s][info][gc,stats ] Memory: Heap Used After Mark 1084 / 1150 1320 / 2916 1310 / 3724 1310 / 3724 MB
[1130.681s][info][gc,stats ] Memory: Heap Used After Relocation 121 / 124 121 / 180 119 / 180 119 / 180 MB
[1130.681s][info][gc,stats ] Memory: Heap Used Before Mark 1069 / 1134 1303 / 2898 1294 / 3694 1294 / 3694 MB
[1130.681s][info][gc,stats ] Memory: Heap Used Before Relocation 178 / 210 184 / 260 183 / 750 183 / 750 MB
[1130.681s][info][gc,stats ] Memory: Out Of Memory 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[1130.681s][info][gc,stats ] Memory: Page Cache Flush 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[1130.681s][info][gc,stats ] Memory: Page Cache Hit L1 246 / 257 270 / 285 265 / 288 265 / 288 ops/s
[1130.681s][info][gc,stats ] Memory: Page Cache Hit L2 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[1130.681s][info][gc,stats ] Memory: Page Cache Miss 0 / 0 0 / 0 1 / 255 1 / 255 ops/s
[1130.681s][info][gc,stats ] Memory: Undo Object Allocation Failed 0 / 0 0 / 0 0 / 1 0 / 1 ops/s
[1130.681s][info][gc,stats ] Memory: Undo Object Allocation Succeeded 0 / 0 0 / 15 1 / 397 1 / 397 ops/s
[1130.681s][info][gc,stats ] Memory: Undo Page Allocation 0 / 1 0 / 2 0 / 3 0 / 3 ops/s
[1130.681s][info][gc,stats ] Phase: Concurrent Destroy Detached Pages 0.001 / 0.001 0.001 / 0.001 0.001 / 0.019 0.001 / 0.019 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Mark 31.185 / 33.047 32.399 / 69.008 31.824 / 69.008 31.824 / 69.008 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Mark Continue 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Prepare Relocation Set 0.032 / 0.037 0.042 / 0.244 0.061 / 7.368 0.061 / 7.368 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Process Non-Strong References 0.640 / 0.821 0.729 / 2.334 0.741 / 4.196 0.741 / 4.196 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Relocate 1.812 / 2.377 2.302 / 6.325 2.393 / 31.625 2.393 / 31.625 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Reset Relocation Set 0.008 / 0.009 0.012 / 0.351 0.014 / 1.204 0.014 / 1.204 ms
[1130.681s][info][gc,stats ] Phase: Concurrent Select Relocation Set 1.395 / 1.570 1.533 / 2.617 1.541 / 4.508 1.541 / 4.508 ms
[1130.681s][info][gc,stats ] Phase: Pause Mark End 0.077 / 0.087 0.076 / 0.148 0.077 / 0.616 0.077 / 0.616 ms
[1130.681s][info][gc,stats ] Phase: Pause Mark Start 0.697 / 0.747 0.692 / 1.219 0.713 / 1.219 0.713 / 1.219 ms
[1130.681s][info][gc,stats ] Phase: Pause Relocate Start 0.603 / 0.699 0.578 / 0.699 0.607 / 1.488 0.607 / 1.488 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Mark 30.755 / 33.018 31.715 / 68.387 31.037 / 68.387 31.037 / 68.387 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Mark Idle 1.062 / 1.115 1.103 / 2.300 1.107 / 12.119 1.107 / 12.119 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Mark Try Flush 0.044 / 0.090 0.174 / 14.243 0.165 / 14.243 0.165 / 14.243 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Mark Try Terminate 0.645 / 1.116 0.731 / 2.302 0.737 / 12.129 0.737 / 12.129 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent References Enqueue 0.000 / 0.000 0.000 / 0.022 0.000 / 0.022 0.000 / 0.022 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent References Process 0.094 / 0.192 0.126 / 1.273 0.121 / 1.273 0.121 / 1.273 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Weak Roots 0.440 / 0.705 0.434 / 2.049 0.446 / 3.622 0.446 / 3.622 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Weak Roots JNIWeakHandles 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Weak Roots StringTable 0.429 / 0.674 0.446 / 2.030 0.457 / 3.620 0.457 / 3.620 ms
[1130.681s][info][gc,stats ] Subphase: Concurrent Weak Roots VMWeakHandles 0.034 / 0.145 0.052 / 1.025 0.054 / 1.128 0.054 / 1.128 ms
[1130.681s][info][gc,stats ] Subphase: Pause Mark Try Complete 0.000 / 0.000 0.001 / 0.003 0.001 / 0.003 0.001 / 0.003 ms
[1130.681s][info][gc,stats ] Subphase: Pause Remap TLABS 0.001 / 0.002 0.001 / 0.012 0.001 / 0.012 0.001 / 0.012 ms
[1130.681s][info][gc,stats ] Subphase: Pause Retire TLABS 0.010 / 0.018 0.010 / 0.043 0.010 / 0.043 0.010 / 0.043 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots 0.375 / 0.642 0.362 / 1.119 0.376 / 1.354 0.376 / 1.354 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots ClassLoaderDataGraph 0.101 / 0.595 0.090 / 0.689 0.091 / 1.336 0.091 / 1.336 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots CodeCache 0.415 / 0.520 0.401 / 0.980 0.423 / 0.980 0.423 / 0.980 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots JNIHandles 0.001 / 0.002 0.001 / 0.013 0.001 / 0.052 0.001 / 0.052 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots JNIWeakHandles 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots JRFWeak 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots JVMTIExport 0.000 / 0.001 0.000 / 0.013 0.000 / 0.013 0.000 / 0.013 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots JVMTIWeakExport 0.000 / 0.001 0.000 / 0.001 0.000 / 0.001 0.000 / 0.001 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots Management 0.001 / 0.002 0.001 / 0.003 0.001 / 0.008 0.001 / 0.008 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots ObjectSynchronizer 0.000 / 0.000 0.000 / 0.000 0.000 / 0.016 0.000 / 0.016 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots Setup 0.042 / 0.087 0.040 / 0.138 0.040 / 0.138 0.040 / 0.138 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots StringTable 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots SystemDictionary 0.008 / 0.010 0.008 / 0.081 0.008 / 0.081 0.008 / 0.081 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots Teardown 0.001 / 0.003 0.001 / 0.003 0.001 / 0.015 0.001 / 0.015 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots Threads 0.041 / 0.078 0.044 / 0.171 0.046 / 0.621 0.046 / 0.621 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots Universe 0.002 / 0.003 0.003 / 0.527 0.003 / 0.527 0.003 / 0.527 ms
[1130.681s][info][gc,stats ] Subphase: Pause Roots VMWeakHandles 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots 0.000 / 0.001 0.000 / 0.004 0.000 / 0.011 0.000 / 0.011 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots JFRWeak 0.000 / 0.000 0.000 / 0.004 0.000 / 0.004 0.000 / 0.004 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots JNIWeakHandles 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots JVMTIWeakExport 0.000 / 0.000 0.000 / 0.001 0.000 / 0.011 0.000 / 0.011 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots Setup 0.000 / 0.000 0.000 / 0.001 0.000 / 0.001 0.000 / 0.001 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots StringTable 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots SymbolTable 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots Teardown 0.001 / 0.001 0.001 / 0.001 0.001 / 0.001 0.001 / 0.001 ms
[1130.681s][info][gc,stats ] Subphase: Pause Weak Roots VMWeakHandles 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[1130.681s][info][gc,stats ] System: Java Threads 33 / 33 33 / 33 33 / 37 33 / 37 threads
[1130.681s][info][gc,stats ] =========================================================================================================================================================