深入理解Java虚拟机六

1.注解处理器

       注解处理器主要有三个用途。一是定义编译规则，并检查被编译的源文件。二是修改已有源代码。三是生成新的源代码。其中，第二种涉及了Java编译器的内部API，因此并不推荐。第三种较为常见，是OpenJDK工具jcstress，以及JMH生成测试代码的方式。Java源代码的编译过程可分为三个步骤：
       1. 将源文件解析为抽象语法树；
       2. 调用已注册的注解处理器；
       3. 生成字节码。
       如果在第2步调用注解处理器过程中生成了新的源文件，那么编译器将重复第1、2步，解析并且处理新生成的源文件。每次重复我们称之为一轮（Round）。也就是说，第一轮解析、处理的是输入至编译器中的已有源文件。如果注解处理器生成了新的源文件，则开始第二轮、第三轮，解析并且处理这些新生成的源文件。当注解处理器不再生成新的源文件，编译进入最后一轮，并最终进入生成字节码的第3步。所有的注解处理器类都需要实现接口Processor。该接口主要有四个重要方法。其中，init方法用来存放注解处理器的初始化代码。之所以不用构造器，是因为在Java编译器中，注解处理器的实例是通过反射API生成的。也正是因为使用反射API，每个注解处理器类都需要定义一个无参数构造器。通常来说，当编写注解处理器时，我们不声明任何构造器，并依赖于Java编译器，为之插入一个无参数构造器。而具体的初始化代码，则放入init方法之中。在剩下的三个方法中，getSupportedAnnotationTypes方法将返回注解处理器所支持的注解类型，这些注解类型只需用字符串形式表示即可。getSupportedSourceVersion方法将返回该处理器所支持的Java版本，通常，这个版本需要与你的Java编译器版本保持一致；而process方法则是最为关键的注解处理方法。JDK提供了一个实现Processor接口的抽象类AbstractProcessor。该抽象类实现了init、getSupportedAnnotationTypes和getSupportedSourceVersion方法。它的子类可以通过@SupportedAnnotationTypes和@SupportedSourceVersion注解来声明所支持的注解类型以及Java版本。

2.基准测试框架JMH

       Java程序的性能测试存在着许多深坑，有来自Java虚拟机的，有来自操作系统的，甚至有来自硬件系统的。如果没有足够的知识，那么性能测试的结果很有可能是有偏差的。性能基准测试框架JMH是OpenJDK中的其中一个开源项目。它内置了许多功能，来规避由Java虚拟机中的即时编译器或者其他优化对性能测试造成的影响。此外，它还提供了不少策略来降低来自操作系统以及硬件系统的影响。开发人员仅需将所要测试的业务逻辑通过@Benchmark注解，便可以让JMH的注解处理器自动生成真正的性能测试代码，以及相应的性能测试配置文件。

• @Fork允许开发人员指定所要Fork出的Java虚拟机的数目。
• @BenchmarkMode允许指定性能数据的格式。
• @Warmup和@Measurement允许配置预热迭代或者测试迭代的数目，每个迭代的时间以及每个操作包含多少次对测试方法的调用。
• @State允许配置测试程序的状态。测试前对程序状态的初始化以及测试后对程序状态的恢复或者校验可分别通过@Setup和@TearDown来实现。

3.Java虚拟机监控诊断工具

3.1JPS
       JDK中的jps命令（帮助文档）沿用了同样的概念：它将打印所有正在运行的Java进程的相关信息。在默认情况下，jps的输出信息包括Java进程的进程ID以及主类名。我们还可以通过追加参数，来打印额外的信息。例如，-l将打印模块名以及包名；-v将打印传递给Java虚拟机的参数（如-XX:+UnlockExperimental-VMOptions -XX:+UseZGC）；-m将打印传递给主类的参数。具体的示例如下所示：

$ jps -mlv
    18331 org.example.Foo Hello World
    18332 jdk.jcmd/sun.tools.jps.Jps -mlv 
    -Dapplication.home=/Library/Java/JavaVirtualMachines/jdk-11.jdk/Contents/Home 
    -Xms8m -Djdk.module.main=jdk.jcmd

       注意：如果某Java进程关闭了默认开启的UsePerfData参数（即使用参数-XX:-UsePerfData），那么jps命令（以及下面介绍的jstat）将无法探知该Java进程。当获得Java进程的进程ID之后，我们便可以调用接下来介绍的各项监控及诊断工具了。
3.2JSTAT
       jstat命令（帮助文档）可用来打印目标Java进程的性能数据。它包括多条子命令，如下所示：

$ jstat -options
-class
-compiler
-gc
-gccapacity
-gccause
-gcmetacapacity
-gcnew
-gcnewcapacity
-gcold
-gcoldcapacity
-gcutil
-printcompilation

       在这些子命令中，-class将打印类加载相关的数据，-compiler和-printcompilation将打印即时编译相关的数据。剩下的都是以-gc为前缀的子命令，它们将打印垃圾回收相关的数据。默认情况下，jstat只会打印一次性能数据。我们可以将它配置为每隔一段时间打印一次，直至目标Java进程终止，或者达到我们所配置的最大打印次数。具体示例如下所示：

# Usage: jstat -outputOptions [-t] [-hlines] VMID [interval [count]]
$ jstat -gc 22126 1s 4
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT   
17472,0 17472,0  0,0    0,0   139904,0 47146,4   349568,0   21321,0   30020,0 28001,8 4864,0 4673,4     22    0,080   3      0,270   0      0,000    0,350
17472,0 17472,0 420,6   0,0   139904,0 11178,4   349568,0   21321,0   30020,0 28090,1 4864,0 4674,2     28    0,084   3      0,270   0      0,000    0,354
17472,0 17472,0  0,0   403,9  139904,0 139538,4  349568,0   21323,4   30020,0 28137,2 4864,0 4674,2     34    0,088   4      0,359   0      0,000    0,446
17472,0 17472,0  0,0    0,0   139904,0   0,0     349568,0   21326,1   30020,0 28093,6 4864,0 4673,4     38    0,091   5      0,445   0      0,000    0,536

当监控本地环境的Java进程时，VMID可以简单理解为PID。如果需要监控远程环境的Java进程，你可以参考jstat的帮助文档。

       在上面这个示例中，22126进程是一个使用了CMS垃圾回收器的Java进程。我们利用jstat的-gc子命令，来打印该进程垃圾回收相关的数据。命令最后的1s 4表示每隔1秒打印一次，共打印4次。在-gc子命令的输出中，前四列分别为两个Survivor区的容量（Capacity）和已使用量（Utility）。我们可以看到，这两个Survivor区的容量相等，而且始终有一个Survivor区的内存使用量为0。当使用默认的G1 GC时，输出结果则有另一些特征：

$ jstat -gc 22208 1s
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT   
0,0   16384,0  0,0   16384,0 210944,0 192512,0  133120,0    5332,5   28848,0 26886,4 4864,0 4620,5     19    0,067   1      0,016   2      0,002    0,084
0,0   16384,0  0,0   16384,0 210944,0 83968,0   133120,0    5749,9   29104,0 27132,8 4864,0 4621,0     21    0,078   1      0,016   2      0,002    0,095
0,0    0,0    0,0    0,0   71680,0  18432,0   45056,0    20285,1   29872,0 27952,4 4864,0 4671,6     23    0,089   2      0,063   2      0,002    0,153
0,0   2048,0  0,0   2048,0 69632,0  28672,0   45056,0    18608,1   30128,0 28030,4 4864,0 4672,4     32    0,093   2      0,063   2      0,002    0,158
...

       在上面这个示例中，jstat每隔1s便会打印垃圾回收的信息，并且不断重复下去。你可能已经留意到，S0C和S0U始终为0，而且另一个Survivor区的容量（S1C）可能会下降至0。这是因为，当使用G1 GC时，Java虚拟机不再设置Eden区、Survivor区，老年代区的内存边界，而是将堆划分为若干个等长内存区域。每个内存区域都可以作为Eden区、Survivor区以及老年代区中的任一种，并且可以在不同区域类型之间来回切换。（参考链接）换句话说，逻辑上我们只有一个Survivor区。当需要迁移Survivor区中的数据时（即Copying GC），我们只需另外申请一个或多个内存区域，作为新的Survivor区。因此，Java虚拟机决定在使用G1 GC时，将所有Survivor内存区域的总容量以及已使用量存放至S1C和S1U中，而S0C和S0U则被设置为0。当发生垃圾回收时，Java虚拟机可能出现Survivor内存区域内的对象 全 被回收或晋升的现象。在这种情况下，Java虚拟机会将这块内存区域回收，并标记为可分配的状态。这样子做的结果是，堆中可能完全没有Survivor内存区域，因而相应的S1C和S1U将会是0。jstat还有一个非常有用的参数-t，它将在每行数据之前打印目标Java进程的启动时间。例如，在下面这个示例中，第一列代表该Java进程已经启动了10.7秒。

$ jstat -gc -t 22407
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT   
           10,7  0,0    0,0    0,0    0,0   55296,0  45056,0   34816,0    20267,8   30128,0 27975,3 4864,0 4671,6     33    0,086   3      0,111   2      0,001    0,198

       我们可以比较Java进程的启动时间以及总GC时间（GCT列），或者两次测量的间隔时间以及总GC时间的增量，来得出GC时间占运行时间的比例。如果该比例超过20%，则说明目前堆的压力较大；如果该比例超过90%，则说明堆里几乎没有可用空间，随时都可能抛出OOM异常。jstat还可以用来判断是否出现内存泄漏。在长时间运行的Java程序中，我们可以运行jstat命令连续获取多行性能数据，并取这几行数据中OU列（即已占用的老年代内存）的最小值。然后，我们每隔一段较长的时间重复一次上述操作，来获得多组OU最小值。如果这些值呈上涨趋势，则说明该Java程序的老年代内存已使用量在不断上涨，这意味着无法回收的对象在不断增加，因此很有可能存在内存泄漏。

上面没有涉及的列（或者其他子命令的输出），你可以查阅帮助文档了解具体含义。至于文档中漏掉的CGC和CGCT，它们分别代表并发GC Stop-The-World的次数和时间。

3.3JMAP
       在这种情况下，我们便可以请jmap命令（帮助文档）出马，分析Java虚拟机堆中的对象。jmap同样包括多条子命令。
       1. -clstats，该子命令将打印被加载类的信息。
       2. -finalizerinfo，该子命令将打印所有待finalize的对象。
       3. -histo，该子命令将统计各个类的实例数目以及占用内存，并按照内存使用量从多至少的顺序排列。此外，-histo:live只统计堆中的存活对象。
       4. -dump，该子命令将导出Java虚拟机堆的快照。同样，-dump:live只保存堆中的存活对象。
       我们通常会利用jmap -dump:live,format=b,file=filename.bin命令，将堆中所有存活对象导出至一个文件之中。这里format=b将使jmap导出与hprof（在Java9中已被移除）、-XX:+HeapDumpAfterFullGC、-XX:+HeapDumpOnOutOfMemory-Error格式一致的文件。这种格式的文件可以被其他GUI工具查看，具体我会在下一篇中进行演示。下面我贴了一段-histo子命令的输出：

$ jmap -histo 22574
 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:        500004       20000160  org.python.core.PyComplex
   2:        570866       18267712  org.python.core.PyFloat
   3:        360295       18027024  [B (java.base@11)
   4:        339394       11429680  [Lorg.python.core.PyObject;
   5:        308637       11194264  [Ljava.lang.Object; (java.base@11)
   6:        301378        9291664  [I (java.base@11)
   7:        225103        9004120  java.math.BigInteger (java.base@11)
   8:        507362        8117792  org.python.core.PySequence$1
   9:        285009        6840216  org.python.core.PyLong
  10:        282908        6789792  java.lang.String (java.base@11)
  ...
2281:             1             16  traceback$py
2282:             1             16  unicodedata$py
Total       5151277      167944400

       由于jmap将访问堆中的所有对象，为了保证在此过程中不被应用线程干扰，jmap需要借助安全点机制，让所有线程停留在不改变堆中数据的状态。也就是说，由jmap导出的堆快照必定是安全点位置的。这可能导致基于该堆快照的分析结果存在偏差。举个例子，假设在编译生成的机器码中，某些对象的生命周期在两个安全点之间，那么:live选项将无法探知到这些对象。另外，如果某个线程长时间无法跑到安全点，jmap将一直等下去。上一小节的jstat则不同。这是因为垃圾回收器会主动将jstat所需要的摘要数据保存至固定位置之中，而jstat只需直接读取即可。关于这种长时间等待的情况，你可以通过下面这段程序来复现：

// 暂停时间较长，约为二三十秒，可酌情调整。
// CTRL+C的SIGINT信号无法停止，需要SIGKILL。
static double sum = 0;

public static void main(String[] args) {
  for (int i = 0; i < 0x77777777; i++) { // counted loop
    sum += Math.log(i); // Math.log is an intrinsic
  }
}

       jmap（以及接下来的jinfo、jstack和jcmd）依赖于Java虚拟机的Attach API，因此只能监控本地Java进程。一旦开启Java虚拟机参数DisableAttachMechanism（即使用参数-XX:+DisableAttachMechanism），基于Attach API的命令将无法执行。反过来说，如果你不想被其他进程监控，那么你需要开启该参数。
3.4JINFO
       jinfo命令（帮助文档）可用来查看目标Java进程的参数，如传递给Java虚拟机的-X（即输出中的jvm_args）、-XX参数（即输出中的VM Flags），以及可在Java层面通过System.getProperty获取的-D参数（即输出中的System Properties）。具体的示例如下所示：

$ jinfo 31185
Java System Properties:

gopherProxySet=false
awt.toolkit=sun.lwawt.macosx.LWCToolkit
java.specification.version=11
sun.cpu.isalist=
sun.jnu.encoding=UTF-8
...

VM Flags:
-XX:CICompilerCount=4 -XX:ConcGCThreads=3 -XX:G1ConcRefinementThreads=10 -XX:G1HeapRegionSize=2097152 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=536870912 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=8589934592 -XX:MaxNewSize=5152702464 -XX:MinHeapDeltaBytes=2097152 -XX:NonNMethodCodeHeapSize=5835340 -XX:NonProfiledCodeHeapSize=122911450 -XX:ProfiledCodeHeapSize=122911450 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC

VM Arguments:
jvm_args: -Xlog:gc -Xmx1024m
java_command: org.example.Foo
java_class_path (initial): .
Launcher Type: SUN_STANDARD

       jinfo还可以用来修改目标Java进程的“manageable”虚拟机参数。举个例子，我们可以使用jinfo -flag +HeapDumpAfterFullGC <PID>命令，开启<PID>所指定的Java进程的HeapDumpAfterFullGC参数。你可以通过下述命令查看其他"manageable"虚拟机参数：

$ java -XX:+PrintFlagsFinal -version | grep manageable   
     intx CMSAbortablePrecleanWaitMillis           = 100                                    {manageable} {default}
     intx CMSTriggerInterval                       = -1                                     {manageable} {default}
     intx CMSWaitDuration                          = 2000                                   {manageable} {default}
     bool HeapDumpAfterFullGC                      = false                                  {manageable} {default}
     bool HeapDumpBeforeFullGC                     = false                                  {manageable} {default}
     bool HeapDumpOnOutOfMemoryError               = false                                  {manageable} {default}
    ccstr HeapDumpPath                             =                                        {manageable} {default}
    uintx MaxHeapFreeRatio                         = 70                                     {manageable} {default}
    uintx MinHeapFreeRatio                         = 40                                     {manageable} {default}
     bool PrintClassHistogram                      = false                                  {manageable} {default}
     bool PrintConcurrentLocks                     = false                                  {manageable} {default}
java version "11" 2018-09-25
Java(TM) SE Runtime Environment 18.9 (build 11+28)
Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11+28, mixed mode)

3.5JSTACK
       jstack命令（帮助文档）可以用来打印目标Java进程中各个线程的栈轨迹，以及这些线程所持有的锁。jstack的其中一个应用场景便是死锁检测。这里我用jstack获取一个已经死锁了的Java程序的栈信息。具体输出如下所示：

$ jstack 31634
...

"Thread-0" #12 prio=5 os_prio=31 cpu=1.32ms elapsed=34.24s tid=0x00007fb08601c800 nid=0x5d03 waiting for monitor entry  [0x000070000bc7e000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at DeadLock.foo(DeadLock.java:18)
 - waiting to lock <0x000000061ff904c0> (a java.lang.Object)
 - locked <0x000000061ff904b0> (a java.lang.Object)
 at DeadLock$$Lambda$1/0x0000000800060840.run(Unknown Source)
 at java.lang.Thread.run(java.base@11/Thread.java:834)

"Thread-1" #13 prio=5 os_prio=31 cpu=1.43ms elapsed=34.24s tid=0x00007fb08601f800 nid=0x5f03 waiting for monitor entry  [0x000070000bd81000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at DeadLock.bar(DeadLock.java:33)
 - waiting to lock <0x000000061ff904b0> (a java.lang.Object)
 - locked <0x000000061ff904c0> (a java.lang.Object)
 at DeadLock$$Lambda$2/0x0000000800063040.run(Unknown Source)
 at java.lang.Thread.run(java.base@11/Thread.java:834)

...

JNI global refs: 6, weak refs: 0


Found one Java-level deadlock:
=============================
"Thread-0":
  waiting to lock monitor 0x00007fb083015900 (object 0x000000061ff904c0, a java.lang.Object),
  which is held by "Thread-1"
"Thread-1":
  waiting to lock monitor 0x00007fb083015800 (object 0x000000061ff904b0, a java.lang.Object),
  which is held by "Thread-0"

Java stack information for the threads listed above:
===================================================
"Thread-0":
 at DeadLock.foo(DeadLock.java:18)
 - waiting to lock <0x000000061ff904c0> (a java.lang.Object)
 - locked <0x000000061ff904b0> (a java.lang.Object)
 at DeadLock$$Lambda$1/0x0000000800060840.run(Unknown Source)
 at java.lang.Thread.run(java.base@11/Thread.java:834)
"Thread-1":
 at DeadLock.bar(DeadLock.java:33)
 - waiting to lock <0x000000061ff904b0> (a java.lang.Object)
 - locked <0x000000061ff904c0> (a java.lang.Object)
 at DeadLock$$Lambda$2/0x0000000800063040.run(Unknown Source)
 at java.lang.Thread.run(java.base@11/Thread.java:834)

Found 1 deadlock.

       我们可以看到，jstack不仅会打印线程的栈轨迹、线程状态（BLOCKED）、持有的锁（locked …）以及正在请求的锁（waiting to lock …），而且还会分析出具体的死锁。
3.5JCMD
       还可以直接使用jcmd命令（帮助文档），来替代前面除了jstat之外的所有命令。具体的替换规则你可以参考下表。至于jstat的功能，虽然jcmd复制了jstat的部分代码，并支持通过PerfCounter.print子命令来打印所有的Performance Counter，但是它没有保留jstat的输出格式，也没有重复打印的功能。因此，感兴趣的同学可以自行整理。