Java常用的命令行工具有jps、jinfo、jstat、jstack、jmap、jhat,以下面的一个简单的Java应用程序为例分析下这几个工具的使用。
一个简单的java应用程序可能的目录结构如下:
start.sh为一个简单的程序启动脚本
- #!/bin/sh
- APP_HOME=/export/home/process/JavaGuide
- APP_MAIN=com.fit.test.Test
- JAVA_OPTS="-Xms256m -Xmx512m"
- CLASSPATH=$APP_HOME
- for jar in "$APP_HOME"/lib/*.jar;
- do
- CLASSPATH="$CLASSPATH":"$jar"
- done
- nohup java $JAVA_OPTS -classpath $CLASSPATH $APP_MAIN &
Java-Guide-1.0.jar为测试类打成的jar包,测试类代码如下
- package com.fit.test;
- import java.io.BufferedReader;
- import java.io.IOException;
- import java.io.InputStreamReader;
- import java.net.ServerSocket;
- import java.net.Socket;
- import java.util.concurrent.atomic.AtomicInteger;
- import org.slf4j.Logger;
- import org.slf4j.LoggerFactory;
- public class Test {
- private static final Logger logger = LoggerFactory.getLogger(Test.class);
- private static boolean running = true;
- public static void main(String[] args) throws IOException {
- final AtomicInteger counter = new AtomicInteger();
- new Thread("my-thread") {
- @Override
- public void run() {
- while (running) {
- logger.info("Hello World - {}", counter.getAndIncrement());
- try {
- Thread.sleep(1000);
- } catch (InterruptedException e) {
- logger.error("my-thread error", e);
- }
- }
- }
- }.start();
- ServerSocket server = new ServerSocket(8001);
- Socket socket = server.accept();
- BufferedReader buffer = new BufferedReader(new InputStreamReader(socket.getInputStream()));
- String line = null;
- while (running && (line = buffer.readLine()) != null && "bye".equals(line)) {
- logger.info("receive command : bye");
- running = false;
- }
- buffer.close();
- socket.close();
- server.close();
- }
- }
logback-classic-1.2.3.jar logback-core-1.2.3.jar slf4j-api-1.7.25.jar三个jar为slf4j+logback的日志实现。由于只演示一个java命令行工具的使用,没有配置logback.xml
依赖jar包maven左边为
- <dependency>
- <groupId>ch.qos.logback</groupId>
- <artifactId>logback-classic</artifactId>
- <version>1.2.3</version>
- </dependency>
程序的功能很简单,启动一个名字为my-thread的线程,打印hello world,同时启动一个监听端口,接收客户端的消息,如果为bye则终止程序的运行。
启动demo,在Linux服务器上直接执行start.sh
如上,程序正常运行
jps:列出正在执行的JVM进程
上面显示有2个进程正在运行,进程id分别是2713和2622.jps的运行也是一个进程,过滤掉jps进程本身可以看到只有一个进程了
进程id和启动的类Test,正是我们的示例程序类
除了-l,可能的选项为-q -m -v -V
jinfo:列出jvm进程相关配置信息
- [root@localhost process]# jinfo 2622
- Attaching to process ID 2622, please wait...
- Debugger attached successfully.
- Server compiler detected.
- JVM version is 25.65-b01
- Java System Properties:
- java.runtime.name = Java(TM) SE Runtime Environment
- java.vm.version = 25.65-b01
- sun.boot.library.path = /export/home/tool/jdk1.8.0_65/jre/lib/amd64
- java.vendor.url = http://java.oracle.com/
- java.vm.vendor = Oracle Corporation
- path.separator = :
- file.encoding.pkg = sun.io
- java.vm.name = Java HotSpot(TM) 64-Bit Server VM
- sun.os.patch.level = unknown
- sun.java.launcher = SUN_STANDARD
- user.country = CN
- user.dir = /export/home/process/JavaGuide
- java.vm.specification.name = Java Virtual Machine Specification
- java.runtime.version = 1.8.0_65-b17
- java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
- os.arch = amd64
- java.endorsed.dirs = /export/home/tool/jdk1.8.0_65/jre/lib/endorsed
- java.io.tmpdir = /tmp
- line.separator =
- java.vm.specification.vendor = Oracle Corporation
- os.name = Linux
- sun.jnu.encoding = UTF-8
- java.library.path = /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
- java.specification.name = Java Platform API Specification
- java.class.version = 52.0
- sun.management.compiler = HotSpot 64-Bit Tiered Compilers
- os.version = 2.6.32-431.el6.x86_64
- user.home = /root
- user.timezone = Asia/Shanghai
- java.awt.printerjob = sun.print.PSPrinterJob
- file.encoding = UTF-8
- java.specification.version = 1.8
- user.name = root
- java.class.path = /export/home/process/JavaGuide:/export/home/process/JavaGuide/lib/Java-Guide-1.0.jar:/export/home/process/JavaGuide/lib/logback-classic-1.2.3.jar:/export/home/process/JavaGuide/lib/logback-core-1.2.3.jar:/export/home/process/JavaGuide/lib/slf4j-api-1.7.25.jar
- java.vm.specification.version = 1.8
- sun.arch.data.model = 64
- sun.java.command = com.fit.test.Test
- java.home = /export/home/tool/jdk1.8.0_65/jre
- user.language = zh
- java.specification.vendor = Oracle Corporation
- awt.toolkit = sun.awt.X11.XToolkit
- java.vm.info = mixed mode
- java.version = 1.8.0_65
- java.ext.dirs = /export/home/tool/jdk1.8.0_65/jre/lib/ext:/usr/java/packages/lib/ext
- sun.boot.class.path = /export/home/tool/jdk1.8.0_65/jre/lib/resources.jar:/export/home/tool/jdk1.8.0_65/jre/lib/rt.jar:/export/home/tool/jdk1.8.0_65/jre/lib/sunrsasign.jar:/export/home/tool/jdk1.8.0_65/jre/lib/jsse.jar:/export/home/tool/jdk1.8.0_65/jre/lib/jce.jar:/export/home/tool/jdk1.8.0_65/jre/lib/charsets.jar:/export/home/tool/jdk1.8.0_65/jre/lib/jfr.jar:/export/home/tool/jdk1.8.0_65/jre/classes
- java.vendor = Oracle Corporation
- file.separator = /
- java.vendor.url.bug = http://bugreport.sun.com/bugreport/
- sun.io.unicode.encoding = UnicodeLittle
- sun.cpu.endian = little
- sun.cpu.isalist =
- VM Flags:
- Non-default VM flags: -XX:CICompilerCount=2 -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=536870912 -XX:MaxNewSize=178913280 -XX:MinHeapDeltaBytes=196608 -XX:NewSize=89456640 -XX:OldSize=178978816 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops
- Command line: -Xms256m -Xmx512m
- [root@localhost process]#
可以看到程序所在目录,jdk版本,操作系统、jvm内存配置信息等等信息.
通过java -Dkey=value 也可以设置一些属性传递给JVM,可以在程序中通过System.getProperty("key")获取
可能的选项
- [root@localhost ~]# jinfo
- Usage:
- jinfo [option] <pid>
- (to connect to running process)
- jinfo [option] <executable <core>
- (to connect to a core file)
- jinfo [option] [server_id@]<remote server IP or hostname>
- (to connect to remote debug server)
- where <option> is one of:
- -flag <name> to print the value of the named VM flag
- -flag [+|-]<name> to enable or disable the named VM flag
- -flag <name>=<value> to set the named VM flag to the given value
- -flags to print VM flags
- -sysprops to print Java system properties
- <no option> to print both of the above
- -h | -help to print this help message
- [root@localhost ~]#
jstat:JVM进程的内存信息统计
可以看到各个区的内存占用情况,以及YGC和FGC的次数、耗时。 3s表示3秒钟打印一次
可能的选项
- [root@localhost ~]# jstat -options
- -class
- -compiler
- -gc
- -gccapacity
- -gccause
- -gcmetacapacity
- -gcnew
- -gcnewcapacity
- -gcold
- -gcoldcapacity
- -gcutil
- -printcompilation
- [root@localhost ~]#
JVM内存配置见JVM内存模型和垃圾收集
jstack:列出JVM进程的堆栈信息
- [root@localhost process]# jstack 2622
- 2017-07-05 22:04:46
- Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.65-b01 mixed mode):
- "Attach Listener" #9 daemon prio=9 os_prio=0 tid=0x00007f8fb0001000 nid=0xbb4 waiting on condition [0x0000000000000000]
- java.lang.Thread.State: RUNNABLE
- "my-thread" #8 prio=5 os_prio=0 tid=0x00007f8fd8176800 nid=0xa48 waiting on condition [0x00007f8fdd325000]
- java.lang.Thread.State: TIMED_WAITING (sleeping)
- at java.lang.Thread.sleep(Native Method)
- at com.fit.test.Test$1.run(Test.java:29)
- "Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f8fd80b2800 nid=0xa46 runnable [0x0000000000000000]
- java.lang.Thread.State: RUNNABLE
- "C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f8fd80ad800 nid=0xa45 waiting on condition [0x0000000000000000]
- java.lang.Thread.State: RUNNABLE
- "C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f8fd80ab000 nid=0xa44 waiting on condition [0x0000000000000000]
- java.lang.Thread.State: RUNNABLE
- "Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f8fd80a9800 nid=0xa43 runnable [0x0000000000000000]
- java.lang.Thread.State: RUNNABLE
- "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f8fd8074000 nid=0xa42 in Object.wait() [0x00007f8fdd971000]
- java.lang.Thread.State: WAITING (on object monitor)
- at java.lang.Object.wait(Native Method)
- - waiting on <0x00000000e00070b8> (a java.lang.ref.ReferenceQueue$Lock)
- at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- - locked <0x00000000e00070b8> (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)
- "Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f8fd8072000 nid=0xa41 in Object.wait() [0x00007f8fdda72000]
- java.lang.Thread.State: WAITING (on object monitor)
- at java.lang.Object.wait(Native Method)
- - waiting on <0x00000000e0006af8> (a java.lang.ref.Reference$Lock)
- at java.lang.Object.wait(Object.java:502)
- at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
- - locked <0x00000000e0006af8> (a java.lang.ref.Reference$Lock)
- "main" #1 prio=5 os_prio=0 tid=0x00007f8fd8008800 nid=0xa3f runnable [0x00007f8fdf573000]
- java.lang.Thread.State: RUNNABLE
- at java.net.PlainSocketImpl.socketAccept(Native Method)
- at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
- at java.net.ServerSocket.implAccept(ServerSocket.java:545)
- at java.net.ServerSocket.accept(ServerSocket.java:513)
- at com.fit.test.Test.main(Test.java:38)
- "VM Thread" os_prio=0 tid=0x00007f8fd806c800 nid=0xa40 runnable
- "VM Periodic Task Thread" os_prio=0 tid=0x00007f8fd80b6000 nid=0xa47 waiting on condition
- JNI global references: 31
- [root@localhost process]#
其他可能的选项
- [root@localhost ~]# jstack
- Usage:
- jstack [-l] <pid>
- (to connect to running process)
- jstack -F [-m] [-l] <pid>
- (to connect to a hung process)
- jstack [-m] [-l] <executable> <core>
- (to connect to a core file)
- jstack [-m] [-l] [server_id@]<remote server IP or hostname>
- (to connect to a remote debug server)
- Options:
- -F to force a thread dump. Use when jstack <pid> does not respond (process is hung)
- -m to print both java and native frames (mixed mode)
- -l long listing. Prints additional information about locks
- -h or -help to print this help message
- [root@localhost ~]#
可以利用jhat根据生成的mythread.bin文件分析虚拟机的内存里都有哪些对象,也可以利用MAT分析堆转储快照
其他可能的选项
- [root@localhost ~]#
- [root@localhost ~]# jmap
- Usage:
- jmap [option] <pid>
- (to connect to running process)
- jmap [option] <executable <core>
- (to connect to a core file)
- jmap [option] [server_id@]<remote server IP or hostname>
- (to connect to remote debug server)
- where <option> is one of:
- <none> to print same info as Solaris pmap
- -heap to print java heap summary
- -histo[:live] to print histogram of java object heap; if the "live"
- suboption is specified, only count live objects
- -clstats to print class loader statistics
- -finalizerinfo to print information on objects awaiting finalization
- -dump:<dump-options> to dump java heap in hprof binary format
- dump-options:
- live dump only live objects; if not specified,
- all objects in the heap are dumped.
- format=b binary format
- file=<file> dump heap to <file>
- Example: jmap -dump:live,format=b,file=heap.bin <pid>
- -F force. Use with -dump:<dump-options> <pid> or -histo
- to force a heap dump or histogram when <pid> does not
- respond. The "live" suboption is not supported
- in this mode.
- -h | -help to print this help message
- -J<flag> to pass <flag> directly to the runtime system
- [root@localhost ~]#
jhat:和jmap配合使用,以上面的mythread.bin为例
此时可以利用web浏览器访问7000端口
下面再以一小段程序演示jmap+MAT(Memory Analyzer Tool)分析JVM堆内存快照
- import java.util.ArrayList;
- import java.util.List;
- public class Test {
- static class OOMObject {
- }
- public static void main(String[] args) {
- List<OOMObject> list = new ArrayList<OOMObject>();
- for (;;) {
- list.add(new OOMObject());
- System.out.println("create an object.");
- }
- }
- }
程序启动脚本稍做修改
- #!/bin/sh
- APP_HOME=/export/home/process/JavaGuide
- APP_MAIN=com.fit.test.Test
- #JAVA_OPTS="-Xms256m -Xmx512m"
- JAVA_OPTS="-Xms256m -Xmx512m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof"
- CLASSPATH=$APP_HOME
- for jar in "$APP_HOME"/lib/*.jar;
- do
- CLASSPATH="$CLASSPATH":"$jar"
- done
- nohup java $JAVA_OPTS -classpath $CLASSPATH $APP_MAIN &
启动程序,可以用jstat查看内存回收情况
- [root@localhost JavaGuide]# jstat -gcutil 1928 3s
- S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
- 100.00 0.00 19.99 66.44 55.92 56.32 18 2.613 2 1.882 4.495
- 100.00 0.00 47.98 66.44 55.92 56.32 18 2.613 2 1.882 4.495
- 100.00 0.00 77.97 66.44 55.92 56.32 18 2.613 2 1.882 4.495
- 0.00 100.00 6.00 72.16 55.92 56.32 19 2.839 2 1.882 4.721
- 0.00 100.00 35.99 72.16 55.92 56.32 19 2.839 2 1.882 4.721
- 0.00 100.00 63.98 72.16 55.92 56.32 19 2.839 2 1.882 4.721
- 80.97 0.00 80.60 77.15 55.92 56.32 20 3.035 2 1.882 4.917
- 80.97 44.91 100.00 77.44 55.92 56.32 21 3.438 3 1.882 5.319
- 0.00 0.00 17.88 87.31 55.92 56.32 21 3.438 3 3.574 7.012
- 0.00 0.00 47.69 87.31 55.92 56.32 21 3.438 3 3.574 7.012
- 0.00 0.00 69.55 87.31 55.92 56.32 21 3.438 3 3.574 7.012
- 0.00 0.00 91.41 87.31 55.92 56.32 21 3.438 3 3.574 7.012
- 100.00 0.00 15.93 88.02 55.92 56.32 22 3.582 3 3.574 7.157
- 100.00 0.00 43.82 88.02 55.92 56.32 22 3.582 3 3.574 7.157
- 100.00 0.00 71.70 88.02 55.92 56.32 22 3.582 3 3.574 7.157
- 100.00 48.08 100.00 88.02 55.92 56.32 23 3.582 3 3.574 7.157
- 0.00 100.00 25.93 93.74 55.92 56.32 23 3.958 3 3.574 7.532
- 0.00 100.00 53.85 93.74 55.92 56.32 23 3.958 3 3.574 7.532
- 0.00 100.00 81.78 93.74 55.92 56.32 23 3.958 3 3.574 7.532
- 0.00 100.00 100.00 93.74 55.92 56.32 24 3.958 4 3.574 7.533
- 0.00 0.00 27.09 100.00 55.92 56.32 24 3.958 4 6.037 9.995
- 0.00 0.00 55.04 100.00 55.92 56.32 24 3.958 4 6.037 9.995
- 0.00 0.00 82.99 100.00 55.92 56.32 24 3.958 4 6.037 9.995
- 0.00 63.77 100.00 100.00 55.92 56.32 24 3.958 4 6.037 9.995
- 0.00 0.00 29.59 100.00 55.92 56.32 24 3.958 5 7.960 11.918
- 0.00 0.00 57.56 100.00 55.92 56.32 24 3.958 5 7.960 11.918
- 0.00 0.00 85.53 100.00 55.92 56.32 24 3.958 5 7.960 11.918
- 0.00 71.68 100.00 100.00 55.92 56.32 24 3.958 5 7.960 11.918
- 0.00 0.00 43.73 100.00 55.92 56.32 24 3.958 6 9.939 13.897
- 0.00 0.00 55.17 100.00 55.92 56.32 24 3.958 7 9.939 13.897
- 0.00 0.00 40.29 100.00 55.92 56.32 24 3.958 8 14.489 18.447
- 0.00 0.00 40.29 100.00 55.92 56.32 24 3.958 8 14.489 18.447
- 0.00 0.00 40.29 100.00 55.92 56.32 24 3.958 8 14.489 18.447
- 0.00 0.00 43.72 100.00 55.92 56.32 24 3.958 8 14.489 18.447
- [root@localhost JavaGuide]#
最终进程因为内存不足发生OOM,导致进程终止,生成的gc日志和堆转储快照如下
部分gc日志如下
- [root@localhost JavaGuide]# more gc.log
- Java HotSpot(TM) 64-Bit Server VM (25.65-b01) for linux-amd64 JRE (1.8.0_65-b17), built on Oct 6 2015 17:16:12 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
- Memory: 4k page, physical 3923884k(3586120k free), swap 3186680k(3186680k free)
- CommandLine flags: -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=536870912 -XX:+PrintGC -XX:+PrintGCDetails
- -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops
- 5.338: [GC (Allocation Failure) 5.338: [DefNew: 69273K->8704K(78656K), 0.0556826 secs] 69273K->10831K(253440K), 0.0558633 secs] [Times: user=0.04 sys=0.00, real=0.06 s
- ecs]
- 10.576: [GC (Allocation Failure) 10.576: [DefNew: 78656K->8704K(78656K), 0.0945850 secs] 80783K->22331K(253440K), 0.0947550 secs] [Times: user=0.09 sys=0.00, real=0.10
- secs]
- 15.350: [GC (Allocation Failure) 15.350: [DefNew: 78656K->8703K(78656K), 0.0741344 secs] 92283K->33681K(253440K), 0.0742307 secs] [Times: user=0.07 sys=0.00, real=0.07
- secs]
- 20.696: [GC (Allocation Failure) 20.696: [DefNew: 78655K->8466K(78656K), 0.0709679 secs] 103633K->45709K(253440K), 0.0710625 secs] [Times: user=0.06 sys=0.00, real=0.0
- 7 secs]
- 24.945: [GC (Allocation Failure) 24.945: [DefNew: 65350K->7986K(78656K), 0.0969427 secs] 102593K->53695K(253440K), 0.0970485 secs] [Times: user=0.10 sys=0.00, real=0.1
- 0 secs]
- 29.118: [GC (Allocation Failure) 29.118: [DefNew: 77938K->7703K(78656K), 0.1222260 secs] 123647K->77423K(253440K), 0.1223351 secs] [Times: user=0.11 sys=0.01, real=0.1
- 2 secs]
- 34.692: [GC (Allocation Failure) 34.692: [DefNew: 77655K->8704K(78656K), 0.0998633 secs] 147375K->87416K(253440K), 0.0999584 secs] [Times: user=0.10 sys=0.00, real=0.1
- 0 secs]
- 38.305: [GC (Allocation Failure) 38.305: [DefNew: 78656K->6559K(78656K), 0.1783014 secs] 157368K->118012K(253440K), 0.1783989 secs] [Times: user=0.14 sys=0.03, real=0.
- 17 secs]
- 43.733: [GC (Allocation Failure) 43.733: [DefNew: 76511K->8704K(78656K), 0.1092944 secs] 187964K->128005K(253440K), 0.1093922 secs] [Times: user=0.09 sys=0.01, real=0.
- 11 secs]
- 49.208: [GC (Allocation Failure) 49.208: [DefNew: 78656K->8704K(78656K), 0.1259278 secs] 197957K->137998K(253440K), 0.1260240 secs] [Times: user=0.11 sys=0.02, real=0.
- 12 secs]
- 54.215: [GC (Allocation Failure) 54.215: [DefNew: 72956K->8704K(78656K), 0.1228309 secs] 202251K->147171K(253440K), 0.1229528 secs] [Times: user=0.10 sys=0.02, real=0.
- 13 secs]
- 57.007: [GC (Allocation Failure) 57.007: [DefNew: 78656K->4842K(78656K), 0.2508670 secs]57.258: [Tenured: 183226K->137324K(210840K), 0.7880213 secs] 217123K->137324K(2
- 89496K), [Metaspace: 2719K->2719K(1056768K)], 1.0391507 secs] [Times: user=0.95 sys=0.08, real=1.03 secs]
对于heap.hprof文件使用MAT分析一下,File-->open heap dump-->选择down下来的heap.hprof
如果打开异常,可能是由于MAT配置的内存不足,修改下MAT目录下的MemoryAnalyzer.ini配置文件中的-Xmx2048m,再打开就可以了
提供的分析功能都可以点进去看看,看一下Reports中的Leak Suspects
可以看到占用内存的对象是OOMObject,功能比较多,需要摸索下
总结一下:
jps:进程列表
jinfo:进程配置信息
jstat:内存配置信息
jstack:堆栈信息
jmap:dump堆内存快照
jhat:和jmap配合使用,分析堆内存快照文件
另外,JDK还自带有可视化的工具JConsole和VisualVM,可以用来监控分析本地以及远程JVM进程状况,有兴趣的可以打开实验一下。。。