在
Java 8 Update 45中,将这些选项添加到java调用中：
-XX:+PrintGCApplicationStoppedTime -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 3679.229: no vm operation [ 72 1 2 ] [ 6016 0 6016 0 0 ] 1 2015-05-22T11:25:27.519+0200: Total time for which application threads were stopped: 6.0168551 seconds,Stopping threads took: 6.0164099 seconds
这里的问题是停止线程的时间很长.在这个例子中,这是6秒,这对我们的应用程序来说已经是一个问题了,但是在一个实例中,我已经看到了更多的时间,但是在一个实例中(没有完整的日志记录))几乎要一分钟.
VM操作(这里：无vm操作)不同.我也看过,例如RevokeBias,G1IncCollectionPause或GCG_Operation.此外,page_trap_count似乎是无关紧要的.我已经看到了0的例子,其他的是2,但是一致的是,时间总是反映在旋转和同步的值中.
我正在寻找对这些时间价值旋转和同步的深入解释,但是我主要感兴趣的是为什么会发生这种情况,以及我能做什么.我在配置中没有意识到任何“邪恶”.机器上有很多无聊的内核和未使用的内存,我们运行纯Java(没有JNI),我们不知道我们的代码中有任何过多的同步.
解决方法
这里的问题是,您的应用程序需要很长时间才能到达安全点.停止线程输出表示JVM在所有线程到达安全点之前发出保护点请求所需的时间.
同步值显示相同的事情 – 这是所有线程到达safeponit所需的时间.
旋转和阻塞值表示阻塞和旋转(执行代码)线程到达安全点所需的时间.
知道这一点,我们可以得出结论,你的问题是,一个线程正忙着旋转,几秒钟内就无法到达它的安全点.
究竟为什么会发生这种情况很难说.一个例子,如this问题所示,它的答案是,JIT编译器可以编译没有检查点的重循环.
您可以尝试使用选项-XX：SafepointTimeout -XX：SafepointTimeoutDelay = 500运行JVM.这将在500 ms之后超时保护点同步,并打印有关未能到达安全点的线程的信息.
