认识达内从这里开始

JVM的日志分析是对Java应用运行监控调试的关键依据，以小的垃圾回收导致暂停时间获得大吞吐量，针对不同应用类型有不同的目标，本文武汉达内java培训为大家介绍通过JVM日志进行安全点分析的方式，希望对大家有帮助：

许多事件都可能会导致JVM暂停所有的应用线程。这类暂停又被称为"stop-the-world"(STW)暂停。触发STW暂停常见的原因就是垃圾回收了(github中的一个例子)，但不同的JIT活动(例子)，偏向锁擦除(例子)，特定的JVMTI操作，以及许多场景也可能会导致应用程序暂停。

应用程序线程可以被安全地停止掉的那个时间点，就叫做安全点。这一术语也通常用来指代SWT暂停。

通常来讲GC日志都是打开的。然而，并非所有安全点的信息都能完整地记录下来。想获取到完整的日志，可以使用下列的JVM选项：

-XX:+PrintGCApplicationStoppedTime-XX:+PrintGCApplicationConcurrentTime

从参数名字来看你可能会觉得是与GC相关的，其实不然——打开这些选项能够记录下所有的安全点，而不止是GC暂停的。如果你用上述的选项来运行下这个例子(github源码)

你会在标准输出中看到如下信息：

Applicationtime:0.3440086seconds

Totaltimeforwhichapplicationthreadswerestopped:0.0620105seconds

Applicationtime:0.2100691seconds

Totaltimeforwhichapplicationthreadswerestopped:0.0890223seconds

很通俗易懂(和GC日志相比来说)——从中你可以得知应用程序在前344毫秒中是在处理实际工作的，然后将所有线程暂停了62毫秒，紧接着又工作了210ms，然后又暂停了89ms。

你还可以将这些选项与GC的选项结合起来使用，比如将上面这个程序加上-XX:+PrintGCDetails选项后再运行一次，输出则变成这样了;

[FullGC(Ergonomics)[PSYoungGen:1375253K->0K(1387008K)][ParOldGen:2796146K->2049K(1784832K)]4171400K->2049K(3171840K),[Metaspace:3134K->3134K(1056768K)],0.0571841secs][Times:user=0.02sys=0.04,real=0.06secs]

Totaltimeforwhichapplicationthreadswerestopped:0.0572646seconds,Stoppingthreadstook:0.0000088seconds

综上可知，应用线程被强制暂停了57ms来进行垃圾回收。其中又有8ms是用来等待所有的应用线程都到达安全点。如果我们用同样的选项运行另一个例子(Github源码)的话，输出又变成这样的了：

Totaltimeforwhichapplicationthreadswerestopped:0.0001273seconds,Stoppingthreadstook:0.0000196seconds

Totaltimeforwhichapplicationthreadswerestopped:0.0000648seconds,Stoppingthreadstook:0.0000174seconds

光从这些信息我们无从得知是什么导致的暂停，因为看不出有任何的垃圾回收的活动。如果你想更详细地了解安全点的信息的话，可以使用这组JVM参数：

-XX:+PrintSafepointStatistics-XX:PrintSafepointStatisticsCount=1

启用这些参数使得JVM会将一些额外的信息记录到标准输出中，大概类似这样：

5.141:RevokeBias[1302][00000]0

Totaltimeforwhichapplicationthreadswerestopped:0.0000782seconds,Stoppingthreadstook:0.0000269seconds

关于安全点的信息是按照如下的顺序进行显示的：

JVM启动之后所经历的毫秒数(上例中是5.141)

触发这次暂停的操作名(RevokeBias)。如果你看见"novmoperation"，就说明这是一个"保证安全点"。JVM默认每秒会触发一次安全点来处理那些非紧急的排队的操作。GuaranteedSafepointInterval选项可以用来调整这一行为(设置为0的话就会禁用该功能)

停在安全点的线程的数量(13)

在安全点开始时仍在运行的线程的数量(0)

虚拟机操作开始执行前仍处于阻塞状态的线程的数量(2)

到达安全点时的各个阶段以及执行操作所花的时间(0)

因此我们可以看出，使用了偏向锁会导致大量的STW暂停，尽管它们只花了几十毫秒。在如今这个大量使用并发的年代，禁用它们也不是什么罕见的事情。

武汉达内java培训认为，不管怎样，多打印些日志总会减少一些麻烦事的。你可以使用如下的JVM参数：

-XX:+LogVMOutput-XX:LogFile=vm.log