JDK Tools简介

图片来自pixabay.com的StockSnap-894430会员

1. 简介

Oracle JDK在发布的SDK包中,除了核心类库、编译、运行和调试工具,还带了大量的监视查看工具。这些监视工具可以辅助开发者查看Java程序的运行状态,包括环境配置、内存、CPU、线程、堆栈、类加载等各种信息。本文将对这些监视工具进行介绍。

本文的工具介绍将主要参考JDK 8的官方文档,并以jdk 8为运行环境演示命令输出。

2. 官方文档

  1. JDK 10 tools
  2. JDK 9 tools
  3. JDK 8 tools
  4. JDK 5 tools

2. 各个工具简介

2.1 基本工具

  1. java 启动java应用程序命令
  2. javac 编译工具,将java源代码编译为java bytecode文件
  3. jar 打包归档工具,也可以对包进行解压
  4. javadoc 生成java api说明和使用文档工具

    基本工具的使用方法可参考这篇文章

2.1 常用的监控分析工具

  1. jps 查看java进程状态工具
  2. jstat 内存监视工具
  3. jmap 内存查看工具,获取内存快照
  4. jinfo 获取java进程的环境配置信息
  5. jstack 进程中各个线程的调用栈查看工具
  6. jconsole 一个java进程的监视和管理控制台,可以查看进程的CPU、内存、线程运行情况,还可以辅助检测死锁,查看类加载详细情况
  7. jvisualvm.exe 一个可视化的java进程管理工具,可以查看进程的CPU、内存、线程运行情况。

    上述监控分析工具的使用方法见下文。

3. 工具使用方法

3.1 jps

  • 简单的命令,输出进程id:jps
  • 输出进程的id,main程序全package路径名,启动参数:jps -mlvV
  • 还可以配合jstat server/RMI registry,实现查看远程服务器上的java进程列表:jps -l remote.domain

一个命令输出样例如下,

$ jps -mlvV
16552 jdk.jcmd/sun.tools.jps.Jps -mlvV -Dapplication.home=G:\local\java\jdk-9.0.1 -Xms8m -Djdk.module.main=jdk.jcmd

3.2 jstat

检查进程15644的内存使用(garbage collected heap)情况

$ jstat -gc 17152
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
10752.0 10752.0  0.0    0.0   64512.0   2580.5   172032.0     0.0     4480.0 770.2  384.0   75.9       0    0.000   0      0.000    0.000

每隔5秒检查进程15644的内存使用情况,输出中添加timestamp,每隔5行添加header,

$ jstat -gcutil -t -h5 15644 500
Timestamp         S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
         2926.3   0.00  89.58  32.70   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2926.8   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2927.3   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2927.8   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2928.3   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
Timestamp         S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
         2928.8   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2929.3   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2929.8   0.00  89.58  33.13   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2930.3   0.00  89.58  33.93   1.42  94.99  90.00      7    0.025     1    0.012    0.037
         2930.8   0.00  89.58  34.16   1.42  94.99  90.00      7    0.025     1    0.012    0.037

在使用-gc选项来检查内存使用情况时,各个缩写字母的含义为,
- S0C: Current survivor space 0 capacity (KB). 年轻代第一个survivor空间容量
- S1C: Current survivor space 1 capacity (KB). 年轻代第二个survivor空间容量
- S0U: Survivor space 0 utilization (KB). 年轻代第一个survivor空间使用量
- S1U: Survivor space 1 utilization (KB). 年轻代第二个survivor空间使用量
- EC: Current eden space capacity (KB). 年轻代Eden空间容量
- EU: Eden space utilization (KB). 年轻代Eden空间使用量
- OC: Current old space capacity (KB). 年老代空间容量
- OU: Old space utilization (KB). 年老代空间使用量
- MC: Metaspace capacity (KB). 元空间容量
- MU: Metaspace utilization (KB). 元空间使用量
- CCSC: Compressed class space capacity (KB).
- CCSU: Compressed class space used (KB).
- YGC: Number of young generation garbage collection (GC) events. 年轻代空间GC次数
- YGCT: Young generation garbage collection time. 年轻代空间GC时间开销
- FGC: Number of full GC events. 整个堆区FULL GC次数
- FGCT: Full garbage collection time. 整个堆区FULL GC时间开销
- GCT: Total garbage collection time. 总GC时间开销

其它内存检查时所看到的缩写字母类似,更详细可以查看官方文档。

JVM的内存空间模型详细介绍见这里

3.3 jmap

简单命令,输出进程14120的内存使用情况,

$ jmap -heap 14120
Attaching to process ID 14120, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.111-b14

using thread-local object allocation.
Parallel GC with 4 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 0
   MaxHeapFreeRatio         = 100
   MaxHeapSize              = 4208984064 (4014.0MB)
   NewSize                  = 88080384 (84.0MB)
   MaxNewSize               = 1402994688 (1338.0MB)
   OldSize                  = 176160768 (168.0MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
   capacity = 31981568 (30.5MB)
   used     = 21396720 (20.405502319335938MB)
   free     = 10584848 (10.094497680664062MB)
   66.90328629290471% used
From Space:
   capacity = 1048576 (1.0MB)
   used     = 524288 (0.5MB)
   free     = 524288 (0.5MB)
   50.0% used
To Space:
   capacity = 1048576 (1.0MB)
   used     = 0 (0.0MB)
   free     = 1048576 (1.0MB)
   0.0% used
PS Old Generation
   capacity = 176160768 (168.0MB)
   used     = 68010784 (64.86013793945312MB)
   free     = 108149984 (103.13986206054688MB)
   38.60722496396019% used

6179 interned Strings occupying 524264 bytes.

导出进程14120的内存使用情况到文件dump.tmp中,
jmap -dump:format=b,file=dump.tmp 14120
然后就可以使用 eclipse memory analyzer 进行分析,查看是否有内存泄露。

3.4 jinfo

获取进程14120的环境配置信息

$ jinfo 14120
Attaching to process ID 14120, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.111-b14
Java System Properties:

java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.111-b14
sun.boot.library.path = C:\Program Files\Java\jdk1.8.0_111\jre\bin
...
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
java.runtime.version = 1.8.0_111-b14
java.library.path = C:\Program Files\Java\jdk1.8.0_111\bin;
java.class.version = 52.0
...
os.name = Windows 7
sun.cpu.isalist = amd64

VM Flags:
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=264241152 -XX:MaxHeapSize=4208984064 -XX:MaxNewSize=1402994688 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=88080384 -XX:OldSize=176160768 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
Command line:

3.5 jstack

获取进程14120的线程调用堆栈信息,通过查看线程堆栈,可以了解是否有死锁情况在发生(可以使用jconsole来辅助查看)。

$ jstack -l 14120
2018-08-22 17:49:07
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.111-b14 mixed mode):

"RMI TCP Connection(35)-172.20.16.89" #47 daemon prio=5 os_prio=0 tid=0x000000001d685000 nid=0x50f0 runnable [0x0000000021aee000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        - locked <0x00000006c9442578> (a java.io.BufferedInputStream)
        at java.io.FilterInputStream.read(FilterInputStream.java:83)
        at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:550)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$1/1179263329.run(Unknown Source)
        at java.security.AccessController.doPrivileged(Native Method)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   Locked ownable synchronizers:
        - <0x000000076cd9db08> (a java.util.concurrent.ThreadPoolExecutor$Worker)
...
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001bfa9000 nid=0x468c in Object.wait() [0x000000001d3be000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
        - locked <0x00000006c54ddeb0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
...
"main" #1 prio=5 os_prio=0 tid=0x000000000253f000 nid=0x45d0 waiting on condition [0x000000000295f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at com.pphh.demo.Application.main(Application.java:23)
   Locked ownable synchronizers:
        - None

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x000000000238c800 nid=0x4404 runnable
...

JNI global references: 252

一个jinfo使用问题的解决 can’t determine target’s VM version

1. 问题

在使用jinfo查看进程所运行的环境变量信息时,报can't determine target's VM version的错误。

$ jinfo -sysprops 15444
Attaching to process ID 15444, please wait...
Error attaching to process: java.lang.RuntimeException: can't determine target's VM version : field "_reserve_for_allocation_prefetch" not found in type Abstract_VM_Version
sun.jvm.hotspot.debugger.DebuggerException: java.lang.RuntimeException: can't determine target's VM version : field "_reserve_for_allocation_prefetch" not found in type Abstract_VM_Version
        at sun.jvm.hotspot.HotSpotAgent.setupVM(HotSpotAgent.java:435)
        at sun.jvm.hotspot.HotSpotAgent.go(HotSpotAgent.java:305)
        at sun.jvm.hotspot.HotSpotAgent.attach(HotSpotAgent.java:140)
        at sun.jvm.hotspot.tools.Tool.start(Tool.java:185)
        at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118)
        at sun.jvm.hotspot.tools.JInfo.main(JInfo.java:138)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at sun.tools.jinfo.JInfo.runTool(JInfo.java:108)
        at sun.tools.jinfo.JInfo.main(JInfo.java:76)
Caused by: java.lang.RuntimeException: can't determine target's VM version : field "_reserve_for_allocation_prefetch" not found in type Abstract_VM_Version
        at sun.jvm.hotspot.runtime.VM.<init>(VM.java:291)
        at sun.jvm.hotspot.runtime.VM.initialize(VM.java:370)
        at sun.jvm.hotspot.HotSpotAgent.setupVM(HotSpotAgent.java:431)
        ... 11 more

2. 解决方法

  1. 刚开始认为是应用程序打包时没有指定编译的目标JDK,检查后排除了这个问题。
  2. 然后网上查找,有文说是权限问题,在Linux下使用su命令可以解决问题,但是我的是在windows下,应该不是权限问题。
  3. 然后想了想,会不会是jdk8/jdk9的配置不对,重新配置后,问题依然在,无论使用jdk8的jinfo,还是jdk9的jinfo都报同样问题。
  4. 最后觉得会不会是环境变量配置问题,然后使用set命令查看了下环境变量,发现path对应有如下设置,
    Path=...;G:\local\java-1.8.0-openjdk-1.8.0.151\bin;...
    

    在path中定义的java路径为open jdk 8。

    将oracle jdk 9的路径指定到path中后,问题得到解决。

    set JDK_HOME=G:\local\java\jdk-9.0.1
    set PATH=%JDK_HOME%\bin;%PATH%
    

    上面看到的问题应该是open jdk 8和oracle jdk 9之间的匹配问题。

3. 总结

依次类推,在使用jdk tools查看进程和内存时,下面的查看可能出现类似问题,

  • 在path中定义java路径为openjdk 8,使用oracle jdk 8/9 tools查看运行在oracle jdk 8/9环境中的java应用程序
  • 使用oracle jdk 8 tools查看运行在oracle jdk 9环境中的应用程序

下面的匹配将运行正常,

  • 在path中定义java路径为oracle jdk 9,使用oracle jdk 9 tools 查看运行在oracle jdk 8/9环境中的应用程序
  • 在path中定义java路径为oracle jdk 8,使用oracle jdk 8 tools 查看运行在oracle jdk 8环境中的应用程序

此记以参考。

一个spring boot程序的启动报错问题: Unable to read meta-data for class

1. 问题描述

Spring Boot Application在启动时报如下错误,

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.5.8.RELEASE)

 ...
 2018-08-02 10:46:59.333  WARN 12168 --- [           main] ationConfigEmbeddedWebApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanDefinitionStoreException: Failed to process import candidates for configuration class [com.pphh.oauth.sample.App]; nested exception is java.lang.IllegalStateException: Unable to read meta-data for class  com.pphh.oauth.config.FilterAutoConfiguration

 org.springframework.beans.factory.BeanDefinitionStoreException: Failed to process import candidates for configuration class [com.pphh.oauth.sample.App]; nested exception is java.lang.IllegalStateException: Unable to read meta-data for class  com.pphh.oauth.config.FilterAutoConfiguration

 Caused by: java.lang.IllegalStateException: Unable to read meta-data for class  com.pphh.oauth.config.FilterAutoConfiguration
     at org.springframework.boot.autoconfigure.AutoConfigurationSorter$AutoConfigurationClass.getAnnotationMetadata(AutoConfigurationSorter.java:217) ~[spring-boot-autoconfigure-1.5.8.RELEASE.jar:1.5.8.RELEASE]
     ... 14 common frames omitted
 Caused by: java.io.FileNotFoundException: class path resource [ com/pphh/oauth/config/FilterAutoConfiguration.class] cannot be opened because it does not exist
     at org.springframework.core.io.ClassPathResource.getInputStream(ClassPathResource.java:172) ~[spring-core-4.3.12.RELEASE.jar:4.3.12.RELEASE]
     ... 22 common frames omitted

 Disconnected from the target VM, address: '127.0.0.1:64322', transport: 'socket'

 Process finished with exit code 1

2. 问题查看和解决

错误消息中告知无法找到com/pphh/oauth/config/FilterAutoConfiguration.class这个class。但是,这个依赖包肯定是加载进来了,这个类也一定有,但是为什么找不到?

先看异常抛出的地方,

org.springframework.core.io.ClassPathResource.getInputStream(ClassPathResource.java:172)

执行的代码如下,

InputStream is;
if(this.clazz != null) {
    is = this.clazz.getResourceAsStream(this.path);
} else if(this.classLoader != null) {
    is = this.classLoader.getResourceAsStream(this.path);
} else {
    is = ClassLoader.getSystemResourceAsStream(this.path);
}

if(is == null) {
    throw new FileNotFoundException(this.getDescription() + " cannot be opened because it does not exist");
} else {
    return is;
}

可以看到,原因就是无法加载类文件,这里设置一个断点,准备调试看下。

在调试模式中,进入上面的执行代码,发现确实is加载后为null。我觉得很奇怪,类明明在class加载路径上,怎么为null。于是我在调试框手动执行类加载,

ClassLoader.getSystemResourceAsStream("com/pphh/oauth/config/FilterAutoConfiguration.class");

上面的手动执行能够正确加载。

最后比较了下两次ClassLoader命令的文件路径,发现了问题,this.path所指向的class path resource路径前面有一个空格。

  • 错误的class path resource [ com/pphh/oauth/config/..Configuration.class]
  • 正常的class path resource [com/pphh/oauth/config/..Configuration.class]

然后定位问题到相应的spring.factories配置文件中,

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
com.pphh.oauth.config.ClientAutoConfiguration, \
com.pphh.oauth.config.FilterAutoConfiguration

将其更新为,

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
com.pphh.oauth.config.ClientAutoConfiguration,\
com.pphh.oauth.config.FilterAutoConfiguration

问题得到解决,此记以参考。

3. 后记

很多时候,代码没有问题,却由于配置出错导致应用启动失败,这种问题非常多,防不胜防,也是比较头疼的问题。多加细心,同时对于配置问题的容错报错,也有助于问题的解决。

就以上面的例子,spring boot在加载auto configuration类之前,若能够自动去掉类名的前后空格,就不会导致上述问题。毕竟,在编写spring.factories的时候,很难确保不人为的添加空格。