JVM的安全点学习与代码测试
监控安全点(打印JVM停顿时间,不止GC,处理毛刺):
-XX:+PrintGC -XX:+PrintGCApplicationStoppedTime
取消偏向锁:
-XX:-UseBiasedLocking
1.Code
public class SafepointTest { static double sum = 0 ; public static void foo(){
for (int i = 0 ; i < 0x77777777 ; i++) {
sum += Math.sqrt(i);
}
} public static void bar() {
for (int i = 0 ; i < 50_000_000 ; i++) {
new Object().hashCode();
}
} public static void main(String[] args) {
new Thread(SafepointTest::foo).start();
new Thread(SafepointTest::bar).start();
}
}
2.安全点进入测试 VM参数设置
安全点进入,日志详情查看:-XX:+PrintSafepointStatistics
返回结果:
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count
0.289: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 1 ] 1
0.359: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 0 ] 1
0.422: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 0 ] 1
0.482: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 1 ] 1
0.566: ParallelGCFailedAllocation [ 12 1 2 ] [ 0 0 0 0 1 ] 1
0.634: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 1 ] 1
0.785: ParallelGCFailedAllocation [ 12 1 2 ] [ 0 0 0 0 5 ] 1
0.963: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 0 ] 1
1.302: ParallelGCFailedAllocation [ 12 1 2 ] [ 0 0 0 0 0 ] 1
1.589: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 0 ] 1
1.857: ParallelGCFailedAllocation [ 12 1 1 ] [ 0 0 0 0 0 ] 1
4.200: EnableBiasedLocking [ 11 1 1 ] [ 0 0 0 0 0 ] 1
5.674: no vm operation [ 9 0 1 ] [ 0 0 0 0 495 ] 0
结果分析:
JVM-GC日志解析:
此日志分为二段,第一段是时间戳,VM Operation的类型,以及线程概况
total:安全点里的总线程数
initially_running:安全点时开始时正在运行状态的线程数
wait_to_block:在VM Operation开始前需要等待其暂停的线程数
第二段是到达安全点时的各个阶段以及执行操作所花的时间,其中最重要的是vmop
spin:等待线程响应safepoint号召的时间
block:暂停所有线程所用的时间
sync:等于spin + block , 这是从开始到进入安全点所耗的时间,可用于判断进入安全点耗时
cleanup:清理所有时间
vmop:真正执行VM Operation的时间
3.生产上安全点日志记录问题
生产上需要将安全点日志打印到独立文件,VM配置如下:
-XX:+UnlockDiagnosticVMOptions
-XX:-DisplayVMOutput
-XX:+LogVMOutput
-XX:LogFile=/dev/nya/vm.log
打开Diagnostic(只是开放了更多的flag可选,不会主动激活某个flag),关掉输出VM日志到stdout,输出到独立文件,/dev/nya目录(内存文件系统)。