在JVM中记录世界停顿

不同的事件可能导致JVM暂停所有应用程序线程。这种暂停称为世界停止（STW）暂停。触发STW暂停的最常见原因是垃圾回收（例如github中的示例），但是不同的JIT操作（示例），偏向锁吊销（示例），某些JVMTI操作以及更多其他操作也需要停止应用程序。

可以安全停止应用程序线程的点称为“意外点”。该术语也经常用于指代所有STW暂停。

启用GC日志或多或少是常见的。但是，这不会捕获所有安全点上的信息。要获得全部信息，请使用以下JVM选项：

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime

如果您想知道显式引用GC的命名，请不要惊慌-启用这些选项会记录所有安全点，而不仅仅是垃圾收集暂停。如果您运行下面的示例（ github中的源代码），并带有上面指定的标志

public class FullGc {private static final Collection<Object> leak = new ArrayList<>();private static volatile Object sink;public static void main(String[] args) {while (true) {try {leak.add(new byte[1024 * 1024]);sink = new byte[1024 * 1024];} catch (OutOfMemoryError e) {leak.clear();}}}
}

您应该在标准输出中看到类似于以下内容的条目：

Application time: 0.3440086 seconds
Total time for which application threads were stopped: 0.0620105 seconds
Application time: 0.2100691 seconds
Total time for which application threads were stopped: 0.0890223 seconds

读取起来很容易（尤其是与GC日志进行比较）–从上面您可以看到应用程序在前344毫秒内成功完成了有用的工作，将所有线程暂停了62毫秒，接着是210毫秒的有用工作和另外89毫秒的暂停。

您可以将这些标志与GC标志结合使用，例如，当再次运行同一程序并添加-XX：+ PrintGCDetails时 ，输出将类似于以下内容：

[Full GC (Ergonomics) [PSYoungGen: 1375253K->0K(1387008K)] [ParOldGen: 2796146K->2049K(1784832K)] 4171400K->2049K(3171840K), [Metaspace: 3134K->3134K(1056768K)], 0.0571841 secs] [Times: user=0.02 sys=0.04, real=0.06 secs] 
Total time for which application threads were stopped: 0.0572646 seconds, Stopping threads took: 0.0000088 seconds

基于以上内容，我们看到应用程序线程被迫停止57毫秒以进行垃圾回收。等待所有应用程序线程到达安全点所花的时间为8微秒。但是，如果我们再举一个示例（ github中的源代码）并使用相同的选项运行它，我们可能会看到以下输出：

Total time for which application threads were stopped: 0.0001273 seconds, Stopping threads took: 0.0000196 seconds
Total time for which application threads were stopped: 0.0000648 seconds, Stopping threads took: 0.0000174 seconds

由此，我们实际上无法推断出导致暂停的原因，因为没有垃圾收集活动。如果您想更详细地了解其他安全点，这里有几个JVM参数供您选择：

-XX:+PrintSafepointStatistics  -XX:PrintSafepointStatisticsCount=1

启用它们会使JVM将其他信息记录到标准输出中，类似于以下内容：

5.141: RevokeBias                       [      13          0              2    ]      [     0     0     0     0     0    ]  0  
Total time for which application threads were stopped: 0.0000782 seconds, Stopping threads took: 0.0000269 seconds

根据以下顺序显示有关安全点的信息：