在Security Manager演讲中,我演示了如何使用Attach API。使用时需要知道准备附加的JVM PID。因为我的好友Evgeny Mandrikov没能参加上次的会议,所以单独为他做了一次演示。
要获取目标JVM的PID,我使用了ps -ef | grep java命令。Evgeny向我介绍了很多jps命令的知识,我发现除了常见JDK命令外,还有很多JDK命令不了解。下面列表中的命令可以帮助修复已部署应用中的问题。
jps:列出正在运行的JVM
使用jps命令行工具可以显示正在运行的JVM列表,根据需要决定输出信息的详细程度。
jps命令可以列出目标系统上instrumented JVM。这是一个实验性命令,不提供支持。
为了获取目标JVM的PID,我用了 ps -ef | grep java 命令。Evgeny这时向我介绍了jps命令,我发现解除了最常见的JDK命令,还有很多我不知道的命令。下面列表中的命令可以帮助修复已部署应用中的问题。
注意:Java 6加入了jps。这充分说明了“实验性”的真正含义。
jps
列表默认仅显示PID和启动类的简单名(或已启动的JAR名):
560 Jps
99714 spring-petclinic-2.0.0.BUILD-SNAPSHOT.jar
95689 CommandServer
使用选项可以展示更多数据:
开启上述选项后输出如下:
99714 target/spring-petclinic-2.0.0.BUILD-SNAPSHOT.jar
679 sun.tools.jps.Jps -lvm -Xms8m \
-Dapplication.home=/Library/Java/JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home
95689 org.asciidoctor.diagram.CommandServer -Djava.awt.headless=true
jinfo:输出JVM启动数据
要解决生产环境中的问题,还需要提供运行中JVM的其他信息。包括完整的JVM标志、参数和系统属性。
使用jinfo命令可以为指定Java进程生成Java配置信息。这是一个实验性命令,不提供支持。
jinfo 95689
下面是示例输出(为了提高可读性,对结果进行了提取和格式化):
Java System Properties:
#Fri Dec 07 16:22:25 CET 2018
gopherProxySet=false
awt.toolkit=sun.lwawt.macosx.LWCToolkit
java.specification.version=11
sun.cpu.isalist=
sun.jnu.encoding=UTF-8
...
java.class.version=55.0
socksNonProxyHosts=local|*.local|169.254/16|*.169.254/16
VM Flags:
-XX:CICompilerCount=3
-XX:ConcGCThreads=1
-XX:G1ConcRefinementThreads=4
-XX:G1HeapRegionSize=1048576
-XX:GCDrainStackTargetSize=64
-XX:InitialHeapSize=268435456
-XX:MarkStackSize=4194304
-XX:MaxHeapSize=4294967296
-XX:MaxNewSize=2576351232
-XX:MinHeapDeltaBytes=1048576
-XX:NonNMethodCodeHeapSize=5830092
-XX:NonProfiledCodeHeapSize=122914074
-XX:ProfiledCodeHeapSize=122914074
-XX:ReservedCodeCacheSize=251658240
-XX:+SegmentedCodeCache
-XX:+UseCompressedClassPointers
-XX:+UseCompressedOops
-XX:+UseFastUnorderedTimeStamps
-XX:+UseG1GC
VM Arguments:
jvm_args:
-Djava.awt.headless=true
java_command:
org.asciidoctor.diagram.CommandServer
java_class_path (initial):
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/server-1.3.13.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/ditaa-1.3.13.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/ditaamini-0.11.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/plantuml-1.3.13.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/plantuml.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/jlatexmath-minimal-1.0.5.jar:
~/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/asciidoctor-diagram-1.5.9/lib/batik-all-1.7.jar
Launcher Type: SUN_STANDARD
下面这些选项可以控制输出内容:
jmap:输出JVM上与类相关的数据
接下来,有必要深入了解JVM上与类相关的数据:class loader统计数据、等待finalize的对象和对象堆。
可以使用jmap命令输出进程的详细信息。这是一个实验性命令,不提供支持。。
使用不同的选项会得到对应输出。输出class loader统计信息
jmap -clstats 95689
Index Super InstBytes KlassBytes annotations CpAll MethodCount Bytecodes MethodAll ROAll RWAll Total ClassName
1 -1 1686600 504 0 0 0 0 0 24 616 640 [B
2 -1 485288 504 0 0 0 0 0 24 616 640 [I
3 20 420984 616 128 14224 109 4577 64472 18640 62104 80744 java.lang.String
4 -1 375216 504 0 0 0 0 0 24 616 640 [C
5 20 374448 672 0 22120 139 5682 46936 24616 47008 71624 java.lang.Class
6 -1 238888 504 0 0 0 0 0 24 616 640 [Ljava.lang.Object;
7 20 165440 584 0 1392 7 149 1864 1152 3008 4160 java.util.HashMap$Node
8 20 141856 592 0 1368 9 213 2776 1488 3584 5072 java.util.concurrent.ConcurrentHashMap$Node
9 20 71120 584 0 1400 7 171 2264 1208 3384 4592 java.util.TreeMap$Entry
...
3085 3084 0 632 0 808 5 71 960 640 1920 2560 sun.util.resources.TimeZoneNamesBundle
3086 20 0 600 0 1256 5 159 1000 856 2264 3120 sun.util.resources.provider.NonBaseLocaleDataMetaInfo
5147912 1947360 10656 6473512 31831 1647775 9869272 6170712 13100408 19271120 Total
26.7% 10.1% 0.1% 33.6% - 8.6% 51.2% 32.0% 68.0% 100.0%
Index Super InstBytes KlassBytes annotations CpAll MethodCount Bytecodes MethodAll ROAll RWAll Total ClassName
输出Java对象堆的直方图
jmap -histo 95689
num #instances #bytes class name (module)
-------------------------------------------------------
1: 2578716 182530328 [I (java.base@11.0.1)
2: 261988 71251184 [Z (java.base@11.0.1)
3: 798811 57514392 java.util.regex.Matcher (java.base@11.0.1)
4: 413769 28433240 [B (java.base@11.0.1)
5: 296086 26055568 java.util.regex.Pattern (java.base@11.0.1)
6: 301073 16858024 [Ljava.lang.Object; (java.base@11.0.1)
7: 276719 15496264 [Ljava.util.regex.Pattern$GroupHead; (java.base@11.0.1)
8: 798811 13032760 [Ljava.util.regex.IntHashSet; (java.base@11.0.1)
9: 318781 7650744 java.util.regex.Pattern$BmpCharProperty (java.base@11.0.1)
10: 289648 6951552 java.util.ArrayList (java.base@11.0.1)
...
1616: 1 16 sun.util.logging.PlatformLogger (java.base@11.0.1)
1617: 1 16 sun.util.resources.LocaleData$LocaleDataStrategy (java.base@11.0.1)
1618: 1 16 sun.util.resources.cldr.provider.CLDRLocaleDataMetaInfo (jdk.localedata@11.0.1)
Total 10605127 526098920
jstack:输出JVM线程信息
如果发生与线程相关的问题(例如死锁或活锁),线程详细信息会派上用场。
使用jstack命令可以打印指定Java进程中的线程堆栈跟踪信息。这是一个实验性命令,不提供支持。
jstack 95689
2018-12-07 19:06:01
Full thread dump OpenJDK 64-Bit Server VM (11.0.1+13 mixed mode):
Threads class SMR info:
_java_thread_list=0x00007fd1212fb270, length=13, elements={
0x00007fd120015800, 0x00007fd120051000, 0x00007fd120053800, 0x00007fd11e89c000,
0x00007fd120045800, 0x00007fd11f00f800, 0x00007fd12004a800, 0x00007fd11e8d9800,
0x00007fd120065000, 0x00007fd11f883000, 0x00007fd11f075800, 0x00007fd11ed4b000,
0x00007fd11f30e800
}
"main" #1 prio=5 os_prio=31 cpu=314567.92ms elapsed=2035.03s tid=0x00007fd120015800 nid=0x2403 runnable [0x000070000bbac000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.1/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.1/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.1/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.1/SocketInputStream.java:140)
at java.io.BufferedInputStream.fill(java.base@11.0.1/BufferedInputStream.java:252)
at java.io.BufferedInputStream.read(java.base@11.0.1/BufferedInputStream.java:271)
- locked <0x00000007000d0558> (a java.io.BufferedInputStream)
at org.asciidoctor.diagram.HTTPInputStream.readLine(HTTPInputStream.java:20)
at org.asciidoctor.diagram.HTTPInputStream.readRequest(HTTPInputStream.java:56)
at org.asciidoctor.diagram.CommandServer.proce***equests(CommandServer.java:61)
at org.asciidoctor.diagram.CommandServer.main(CommandServer.java:25)
...
"process reaper" #109 daemon prio=10 os_prio=31 cpu=538.50ms elapsed=1683.17s tid=0x00007fd11f30e800 nid=0x6507 waiting on condition [0x000070000ba4e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.1/Native Method)
- parking to wait for <0x000000070016fe20> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.1/LockSupport.java:234)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.base@11.0.1/SynchronousQueue.java:462)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.base@11.0.1/SynchronousQueue.java:361)
at java.util.concurrent.SynchronousQueue.poll(java.base@11.0.1/SynchronousQueue.java:937)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.1/ThreadPoolExecutor.java:1053)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
"VM Thread" os_prio=31 cpu=1139.30ms elapsed=2035.01s tid=0x00007fd11f88e000 nid=0x4b03 runnable
"GC Thread#0" os_prio=31 cpu=1888.39ms elapsed=2035.03s tid=0x00007fd11e805000 nid=0x5203 runnable
"GC Thread#1" os_prio=31 cpu=1951.89ms elapsed=2034.53s tid=0x00007fd11e8e1800 nid=0x9903 runnable
"GC Thread#2" os_prio=31 cpu=1897.20ms elapsed=2034.53s tid=0x00007fd11e8e2800 nid=0x5f03 runnable
"GC Thread#3" os_prio=31 cpu=1901.78ms elapsed=2034.53s tid=0x00007fd11e90d000 nid=0x6103 runnable
"G1 Main Marker" os_prio=31 cpu=0.57ms elapsed=2035.03s tid=0x00007fd11e84a000 nid=0x5003 runnable
"G1 Conc#0" os_prio=31 cpu=36.31ms elapsed=2035.03s tid=0x00007fd11e84a800 nid=0x3003 runnable
"G1 Refine#0" os_prio=31 cpu=8.48ms elapsed=2035.03s tid=0x00007fd11f882000 nid=0x3203 runnable
"G1 Refine#1" os_prio=31 cpu=2.95ms elapsed=2034.52s tid=0x00007fd11e9b1000 nid=0x9703 runnable
"G1 Refine#2" os_prio=31 cpu=0.06ms elapsed=2034.36s tid=0x00007fd11f939800 nid=0x6303 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=898.32ms elapsed=2035.03s tid=0x00007fd11e858800 nid=0x3303 runnable
"VM Periodic Task Thread" os_prio=31 cpu=933.68ms elapsed=2034.94s tid=0x00007fd11f00c800 nid=0xa603 waiting on condition
JNI global refs: 98, weak refs: 5
需要检查锁信息,可以使用-l选项。输出内容如下:
...
"main" #1 prio=5 os_prio=31 cpu=489307.36ms elapsed=3019.58s tid=0x00007fd120015800 nid=0x2403 runnable [0x000070000bbac000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.1/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.1/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.1/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.1/SocketInputStream.java:140)
at java.io.BufferedInputStream.fill(java.base@11.0.1/BufferedInputStream.java:252)
at java.io.BufferedInputStream.read(java.base@11.0.1/BufferedInputStream.java:271)
- locked <0x00000007000d0558> (a java.io.BufferedInputStream)
at org.asciidoctor.diagram.HTTPInputStream.readLine(HTTPInputStream.java:20)
at org.asciidoctor.diagram.HTTPInputStream.readRequest(HTTPInputStream.java:56)
at org.asciidoctor.diagram.CommandServer.proce***equests(CommandServer.java:61)
at org.asciidoctor.diagram.CommandServer.main(CommandServer.java:25)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.94ms elapsed=3019.55s tid=0x00007fd120051000 nid=0x3603 waiting on condition [0x000070000c2c1000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.1/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.1/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.1/Reference.java:213)
Locked ownable synchronizers:
- None
...
没有加锁!
jconsole:监视JVM
通过图形查看正在运行中的JVM可以节省很多时间。
使用jconsole命令启动图形控制台可以监视和管理Java应用。
在我看来,JConsole是Java开发人员工具箱中最重要的工具之一。
它为JVM运行过程中的关键数据提供了图形展示:
Memory:console能够展示不同的内存图示:heap、non-heap、old gen、eden、survivor区等等。
JConsole能展示指定时间范围内的线程数量变化。它还可以单独显示每个线程信息,以及线程名称、状态和堆栈。
Classes:显示已加载的类数量。
VM Summary显示JVM相关数据:
VM arguments
Class path
Library path
Boot class path
Heap size
等等
MBeans:JConsole能够按照树型结构展示所有可用的MBean信息,包括属性和方法。此外,还可以设置属性值并调用方法。
JConsole基于插件架构设计。
总结
JDK包含了许多内置工具供开发者使用。无论否使用IDE,它们都是开发人员日常工作的宝贵资源。