虚拟机性能监控与故障处理工具(深入理解java虚拟机三)
JDK自带的工具可以方便的帮助我们处理一些问题，包括查看JVM参数，分析内存变化，查看内存区域，查看线程等信息。
我们熟悉的有java.exe,javac.exe,javap.exe(偶尔用),jps.exe,jmap.exe....等，下面会详细介绍。分别在linux和windows下面介绍。windows与linux下面使用的都是JDK1.7.0_80
windows下的jdk版本如下:
$ java -version java version "1.7.0_80" Java(TM) SE Runtime Environment (build 1.7.0_80-b15) Java HotSpot(TM) 64-Bit Server VM (build 24.80-b11, mixed mode)
linux下的JDK版本如下:
[root@VM_0_12_centos ~]# java -version java version "1.7.0_80" Java(TM) SE Runtime Environment (build 1.7.0_80-b15) Java HotSpot(TM) 64-Bit Server VM (build 24.80-b11, mixed mode)
1.工具简介
1.1windows下面查看
$ dir
appletviewer.exe java-rmi.exe jrunscript.exe pack200.exe
apt.exe javaw.exe jsadebugd.exe policytool.exe
extcheck.exe javaws.exe jstack.exe rmic.exe
idlj.exe jcmd.exe jstat.exe rmid.exe
jabswitch.exe jconsole.exe jstatd.exe rmiregistry.exe
jar.exe jdb.exe jvisualvm.exe schemagen.exe
jarsigner.exe jhat.exe keytool.exe serialver.exe
java.exe jinfo.exe kinit.exe servertool.exe
javac.exe jli.dll klist.exe tnameserv.exe
javadoc.exe jmap.exe ktab.exe unpack200.exe
javafxpackager.exe jmc.exe msvcr100.dll wsgen.exe
javah.exe jmc.ini native2ascii.exe wsimport.exe
javap.exe jps.exe orbd.exe xjc.exe
2.linux下面查看工具
[root@VM_0_12_centos bin]# ls appletviewer javac jconsole jps native2ascii serialver apt javadoc jcontrol jrunscript orbd servertool ControlPanel javafxpackager jdb jsadebugd pack200 tnameserv extcheck javah jhat jstack policytool unpack200 idlj javap jinfo jstat rmic wsgen jar java-rmi.cgi jmap jstatd rmid wsimport jarsigner javaws jmc jvisualvm rmiregistry xjc java jcmd jmc.ini keytool schemagen
其实上面的工具大部分都是jdk/lib/tools.jar 类库的一层包装而已，它们主要的功能代码是在tools.jar中实现的。
2.常见工具简要使用
研究常见的工具的使用。主要有下面工具:
jps---JVM Process Status tool,显示指定系统内所有的HotSpot虚拟机进程
jstat---JVM Statistics Monitoring tool，用于收集HotSpot虚拟机各方面的运行数据
jinfo---Configuration Info For Java,显示虚拟机配置信息
jmap---Memory Map for Java,生成虚拟机的内存转储快照(heapdump文件)
jhat---JVM Heap Dump Browser，用于分析heapdump文件，它会建立一个http/html服务器。让用于可以在浏览器上查看分析结果
jstack---Stack Trace For Java，显示虚拟机的线程快照。
下面研究具体的使用。
2.1 jps---虚拟机进程状况工具(常用)
JDK的很多工具都参考了UNIX系统的命名方式，jps(JVM Process Status)是其中的典型。除了名字像JVM的ps之外，功能也和UNIX的ps差不多:可以列出正在运行的虚拟机进程，并显示虚拟机执行主类(Main Class,main函数所在的类)名称以及这些进程的本地虚拟机唯一ID(Local Vitural Machine Identifier,LVMID)。虽然功能比较单一，但它是使用最频繁的JDK命令行工具，因为其他工具的使用都需要依赖此工具识别处的LVMID作为输入。对于本地虚拟机进程来说，LVMID与操作系统的进行ID(Process Identifier,PID)是一致的，使用windows的任务管理器或者unix的ps命令也可以查询到虚拟机的LVMID，但是如果启动了多个虚拟机进程，无法根据名称定位时，那就只能根据jps来区分了。
jps命令格式:
jps [option] [hostid]
例如:
C:\Users\Administrator>jps -l 2204 org.apache.catalina.startup.Bootstrap 2084 6596 sun.tools.jps.Jps
jps可以通过RMI协议查询开启了RMI服务的远程虚拟机进程状态，hostid为RMI注册表中注册的主机名。jps的常见其他选项如下:
-q 只输出LVMID，省略主类的名称
-m 输出虚拟机进程启动时传递给主类main函数的参数
-l 输出主类的全名，如果进程执行的是jar包，输出Jar路径
-v 输出虚拟机进程启动时JVM参数
自己在windows下面的测试:
C:\Users\Administrator>jps -m -l -v 9772 sun.tools.jps.Jps -m -l -v -Denv.class.path=.;%JAVA_HOME%\lib;%JAVA_HOME%\lib\tools.jar -Dapplication.home=C:\Program Files\Java\jdk1.7.0_80 -Xms8m 2204 org.apache.catalina.startup.Bootstrap start -agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:53302 -Dcatalina.base=E:\xiangmu\.metadata\.plugins\org.eclipse.wst.server.core\tmp1 -Dcatalina.home=E:\tomcat\apache-tomcat-7.0.88 -Dwtp.deploy=E:\xiangmu -Djava.endorsed.dirs=E:\tomcat\apache-tomcat-7.0.88\endorsed -Dfile.encoding=UTF-8 2084 -Dosgi.requiredJavaVersion=1.7 -Xms256m -Xmx1024m -Xloggc:gc.log -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Dsun.lang.ClassLoader.allowArraySyntax=true -XX:MaxPermSize=256m
9772是jps命令自身，可见jps本身也是一个Java程序，其主类位于sun.tools.jps.Jps(该类位于jdk/lib/tools.jar)
2204 是自己启动的一个tomcat程序，主类是Bootstrap，向main函数传递的参数是start，后面是一些设置
2084是Eclipse的PID，后面跟着eclipse.ini中对eclipse的设置(这也可以用来判断eclipse启动参数)
自己在linux下面的测试
[root@VM_0_12_centos ~]# jps -m -l -v 4211 sun.tools.jps.Jps -m -l -v -Denv.class.path=.:/opt/java/jdk1.7.0_80/lib:/opt/java/jdk1.7.0_80/jre/lib -Dapplication.home=/opt/java/jdk1.7.0_80 -Xms8m 21991 org.apache.catalina.startup.Bootstrap start -Djava.util.logging.config.file=/opt/apache-tomcat/apache-tomcat-7.0.72/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djdk.tls.ephemeralDHKeySize=2048 -Djava.endorsed.dirs=/opt/apache-tomcat/apache-tomcat-7.0.72/endorsed -Dcatalina.base=/opt/apache-tomcat/apache-tomcat-7.0.72 -Dcatalina.home=/opt/apache-tomcat/apache-tomcat-7.0.72 -Djava.io.tmpdir=/opt/apache-tomcat/apache-tomcat-7.0.72/temp
4211 是jps命令自身的pid，
21991 是linux下面的一个tomcat的pid，其主类、传递的参数以及配置与上面类似。
2.2 jstat:虚拟机统计信息监视工具
jstat(JVM Statistics Monitoring Machine)是用于监视虚拟机各种运行状态信息的工具。它可以显示本地或者远程虚拟机进程中的类装载、内存、垃圾收集、JID编译等运行时数据，在没有GUI的服务器上，对于定位虚拟机性能问题非常重要。
jstat命令格式为:
jstat [ option vmid [interval [s|ms] [count] ] ]
对于命令格式中的VMID与LVMID需要特别说明一下：如果是本地虚拟机进程，VMID与LVMID是一致的，如果是远程虚拟机进程，那VMID的格式应当如下:
[protocol:][//]lvmid[@hostname[:port]/servername]
参数interval和count代表查询的间隔和次数，如果省略这两个参数，说明只查询一次。假设需要每250ms查询一次pid为 2204 程序的垃圾收集状态，总共查询20次，那么命令应当是:
jstat -gc 2204 250 20
选项option代表着用户希望查询的虚拟机信息，分为3类:类装载、垃圾收集、运行期编译状况，具体作用如下:
-class 监视类装载、卸载数量、总空间以及类装载所耗费的时间
-gc 监视java堆状况，包括Eden区、两个suprivor区、老年代、永久代等的容量、已用空间、GC时间合计等信息(实际在hotspot虚拟机中，永久代不属于堆内存，而且在JDK8已经被元空间MetaSpace所取代)
-gccapacity 监视内容与-gc基本相同，但是输出主要关注的是Java堆各个区域使用的最大、最小空间
-gcutil 监视内容与-gc基本相同，但输出主要关注已使用空间占总空间的比例
-gccause 监视内容与-gc基本相同，但是会额外输出导致上一致gc的原因。
-gcnew 监视新生代GC状况
-gcnewcapacity 监视内容与-gcnew基本相同，但是输出主要关注的是使用的最大、最小空间
-gcold 监视老年代GC状况
-gcoldcapacity 监视内容与-gcold基本相同，但是输出主要关注的是使用的最大、最小空间
-gcpermcapacity 输出永久代最大、最小空间
-compiler 输出JIT编译过的方法、耗时等信息
-printcompilation 输出已经被JIT编译的方法
例如自己windows下面的测试
C:\Users\Administrator>jstat -gcutil 2204 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 33.52 54.34 55.99 15 0.322 1 0.282 0.604
实验结果表明:这台虚拟机的新生代Enen区(E表示Eden)使用了33.52%空间，两个Suprivor区(SO和S1)都是空的，老年代Old(o表示Old)占用了54.34%，永久代(Perm)占用了55.99%。程序运行以爱共发生Minor GC(YGC表示Young GC)15次，总耗时0.322秒。发生FullGC(FGC)1次，FullGC总耗时0.282秒，所有GC耗时(GCT) 0.604秒。
下面是一些其他测试:
C:\Users\Administrator>jstat -gccause 2204 S0 S1 E O P YGC YGCT FGC FGCT GCT LGCC GCC 0.00 0.00 33.52 54.34 55.99 15 0.322 1 0.282 0.604 Allocation Failure No GC C:\Users\Administrator>jstat -class 2204 Loaded Bytes Unloaded Bytes Time 7880 15537.3 0 0.0 13.07 C:\Users\Administrator>jstat -gc 2204 S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT 43520.0 44544.0 0.0 0.0 499200.0 172323.0 120320.0 65384.2 83456.0 46728.6 15 0.322 1 0.282 0.604 C:\Users\Administrator>jstat -compiler 2204 Compiled Failed Invalid Time FailedType FailedMethod 1504 1 0 17.19 1 org/apache/catalina/loader/WebappClassLoaderBase findResourceInternal C:\Users\Administrator>jstat -gccapacity 2204 NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC PGCMN PGCMX PGC PC YGC FGC 43008.0 686080.0 684544.0 43520.0 44544.0 499200.0 85504.0 1372160.0 120320.0 120320.0 21504.0 83968.0 83456.0 83456.0 15 1
自己在linux下面的测试:
[root@VM_0_12_centos ~]# jstat -gcutil 21991 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 9.81 36.74 64.58 99.78 931 8.255 17 2.609 10.865 [root@VM_0_12_centos ~]# jstat -gccause 21991 S0 S1 E O P YGC YGCT FGC FGCT GCT LGCC GCC 0.00 9.81 38.73 64.58 99.78 931 8.255 17 2.609 10.865 Allocation Failure No GC [root@VM_0_12_centos ~]# jstat -class 21991 Loaded Bytes Unloaded Bytes Time 12028 24837.3 48 70.8 66.16 [root@VM_0_12_centos ~]# jstat -compiler 21991 Compiled Failed Invalid Time FailedType FailedMethod 2543 2 0 71.49 1 org/apache/jasper/xmlparser/ParserUtils convert
一些具体的参数解释如下:
S0C：年轻代中第一个survivor（幸存区）的容量 (字节)
S1C：年轻代中第二个survivor（幸存区）的容量 (字节)
S0U：年轻代中第一个survivor（幸存区）目前已使用空间 (字节)
S1U：年轻代中第二个survivor（幸存区）目前已使用空间 (字节)
EC：年轻代中Eden（伊甸园）的容量 (字节)
EU：年轻代中Eden（伊甸园）目前已使用空间 (字节)
OC：Old代的容量 (字节)
OU：Old代目前已使用空间 (字节)
PC：Perm(持久代)的容量 (字节)
PU：Perm(持久代)目前已使用空间 (字节)
YGC：从应用程序启动到采样时年轻代中gc次数
YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
FGC：从应用程序启动到采样时old代(全gc)gc次数
FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
GCT：从应用程序启动到采样时gc用的总时间(s)
NGCMN：年轻代(young)中初始化(最小)的大小 (字节)
NGCMX：年轻代(young)的最大容量 (字节)
NGC：年轻代(young)中当前的容量 (字节)
OGCMN：old代中初始化(最小)的大小 (字节)
OGCMX：old代的最大容量 (字节)
OGC：old代当前新生成的容量 (字节)
PGCMN：perm代中初始化(最小)的大小 (字节)
PGCMX：perm代的最大容量 (字节)
PGC：perm代当前新生成的容量 (字节)
S0：年轻代中第一个survivor（幸存区）已使用的占当前容量百分比
S1：年轻代中第二个survivor（幸存区）已使用的占当前容量百分比
E：年轻代中Eden（伊甸园）已使用的占当前容量百分比
O：old代已使用的占当前容量百分比
P：perm代已使用的占当前容量百分比
S0CMX：年轻代中第一个survivor（幸存区）的最大容量 (字节)
S1CMX ：年轻代中第二个survivor（幸存区）的最大容量 (字节)
ECMX：年轻代中Eden（伊甸园）的最大容量 (字节)
DSS：当前需要survivor（幸存区）的容量 (字节)（Eden区已满）
TT： 持有次数限制
MTT ： 最大持有次数限制
2.3 jinfo Java配置信息工具
jinfo(Configuration Info for Java)的作用是 实时查看和调整虚拟机的各项参数。使用jps -v 可以查看虚拟器启动时候显示指定的参数列表，但是如果想查找未被显示指定的参数的系统的默认值，除了去查阅资料，就只能使用jinfo的 -flag选项进行查询了(如果只限于JDK版本6以上，使用Java -XX:+PrintFlagsFinal 查看默认值也是一个很好的选择),jinfo还可以使用 -sysprops选项把虚拟机进程的System.getProperties（）的内容打印出来，JDK1.6之后，jinfo在windows和linux平台都提供，并且加入了运行期修改参数的能力，可以使用 -flag [+|-] name 或者 -flag name=value修改一部分运行期可写的虚拟机参数值。JDK1.6中，jinfo对于windows平台功能仍然有较大限制，只提供了最基本的-flag选项。
jinfo的命令格式如下:
C:\Users\Administrator>jinfo -flag 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
例如:
(1)查看一个JVM的配置信息，也就是System.getProperties可以获取的信息:
C:\Users\Administrator>jinfo 2084 Attaching to process ID 2084, please wait... Debugger attached successfully. Server compiler detected. JVM version is 24.80-b11 Java System Properties: java.vendor = Oracle Corporation osgi.bundles.defaultStartLevel = 4 org.eclipse.debug.ui.breakpoints.toggleFactoriesUsed = false org.osgi.supports.framework.extension = true sun.management.compiler = HotSpot 64-Bit Tiered Compilers eclipse.p2.profile = epp.package.jee os.name = Windows 8
...
或者
C:\Users\Administrator>jinfo -sysprops 2084 Attaching to process ID 2084, please wait... Debugger attached successfully. Server compiler detected. JVM version is 24.80-b11 java.vendor = Oracle Corporation osgi.bundles.defaultStartLevel = 4 org.eclipse.debug.ui.breakpoints.toggleFactoriesUsed = false org.osgi.supports.framework.extension = true sun.management.compiler = HotSpot 64-Bit Tiered Compilers eclipse.p2.profile = epp.package.jee os.name = Windows 8
...
(2)查看JVM的启动参数信息
C:\Users\Administrator>jinfo -flags 2084 Attaching to process ID 2084, please wait... Debugger attached successfully. Server compiler detected. JVM version is 24.80-b11 -Dosgi.requiredJavaVersion=1.7 -Xms256m -Xmx1024m -Xloggc:gc.log -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Dsun.lang.ClassLoader.allowArraySyntax=true -XX:MaxPermSize=256m
(3)查看是否开启了GC日志的打印：
C:\Users\Administrator>jinfo -flag PrintGC 2084 -XX:+PrintGC C:\Users\Administrator>jinfo -flag PrintGCDetails 2084 -XX:+PrintGCDetails
(4)关闭GC打印功能
C:\Users\Administrator>jinfo -flag -PrintGC 2084 C:\Users\Administrator>jinfo -flag -PrintGCDetails 2084 C:\Users\Administrator>jinfo -flag PrintGC 2084 -XX:-PrintGC C:\Users\Administrator>jinfo -flag PrintGCDetails 2084 -XX:-PrintGCDetails
有一点必须注意：PrintGC必须开启，只开启PrintGCDetails、PrintGCTimeStamps不会输出GC，必须PrintGC同时开启
(5)查看启动参数
C:\Users\Administrator>jinfo -flag MaxHeapSize 2084 -XX:MaxHeapSize=1073741824 C:\Users\Administrator>jinfo -flag PermSize 2084 -XX:PermSize=21757952
2.4 jmap Java内存映像工具 (常用)
jmap(Memory map for java)命令用于生成堆转储快照(一般称为heapdump或dump文件)，如果不使用jmap命令，想要获取java堆转储快照，还有一些比较暴力的手段:比如说用 -XX:+HeapDumpOnOutOfMemoryError参数，可以让虚拟机在发生OOM异常之后自动生成dump文件，通过 -XX:+HeapDumpOnCtrlBreak参数则可以使用 [Ctrl]+[Break]键让虚拟机生成dump文件，又或者在linux下面通过 Kill -3 命令发送进程退出信号"吓唬"一下虚拟机，也能拿到dump文件。
jmap的作用不仅是为了获取dump文件，它还可以查询finalize执行队列、Java堆和永久代的详细信息，如空间使用率、当前使用的是哪种收集器等。
和jinfo一样，jmap有不少功能在windows平台下都是受限的，除了生成dump文件的-dump选项和用于查看每个类的实例、空间占用的-histo选项在所有操作系统都提供之外，其余选项都只能在Linux/Solaris下使用。
jmap的命令格式:
C:\Users\Administrator>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 -permstat to print permanent generation 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
(1)windows下面的测试
- 查看JVM的内存信息:
C:\Users\Administrator>jmap -heap 2084 #查看堆内存 Attaching to process ID 2084, please wait... Debugger attached successfully. Server compiler detected. JVM version is 24.80-b11 using thread-local object allocation. Parallel GC with 4 thread(s) Heap Configuration: MinHeapFreeRatio = 0 MaxHeapFreeRatio = 100 MaxHeapSize = 1073741824 (1024.0MB) NewSize = 1310720 (1.25MB) MaxNewSize = 17592186044415 MB OldSize = 5439488 (5.1875MB) NewRatio = 2 SurvivorRatio = 8 PermSize = 21757952 (20.75MB) MaxPermSize = 268435456 (256.0MB) G1HeapRegionSize = 0 (0.0MB) Heap Usage: PS Young Generation Eden Space: capacity = 295698432 (282.0MB) used = 12552440 (11.970939636230469MB) free = 283145992 (270.02906036376953MB) 4.245014055400875% used From Space: capacity = 13107200 (12.5MB) used = 13080592 (12.474624633789062MB) free = 26608 (0.0253753662109375MB) 99.7969970703125% used To Space: capacity = 10485760 (10.0MB) used = 0 (0.0MB) free = 10485760 (10.0MB) 0.0% used PS Old Generation capacity = 541589504 (516.5MB) used = 211967328 (202.14779663085938MB) free = 329622176 (314.3522033691406MB) 39.13800515602311% used PS Perm Generation capacity = 166199296 (158.5MB) used = 166122072 (158.42635345458984MB) free = 77224 (0.07364654541015625MB) 99.95353530258035% used 44318 interned Strings occupying 4390312 bytes.
- 查看一个JVM中的存活(加上 :live 会只显示存活对象)对象:(我将信息重定向到一个文件中了，存活对象太多，篇幅太长)
C:\Users\Administrator>jmap -histo:live 2084 >> tt.txt
打开文件查看结果:最后有3068个类 (我们也可以发现pring的单例模式，确实使用了CGLIB代理模式生成唯一的代理对象)
- 生成Java堆转储快照文件(对文件的分析在后面介绍)
C:\Users\Administrator>jmap -dump:live,format=b,file=heap.bin 2204 Dumping heap to C:\Users\Administrator\heap.bin ... Heap dump file created
(2)linux下面的测试:
[root@VM_0_12_centos ~]# jmap -heap 21991 #查看内存JVM参数 Attaching to process ID 21991, please wait... Debugger attached successfully. Server compiler detected. JVM version is 24.80-b11 using thread-local object allocation. Mark Sweep Compact GC Heap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 482344960 (460.0MB) NewSize = 1310720 (1.25MB) MaxNewSize = 17592186044415 MB OldSize = 5439488 (5.1875MB) NewRatio = 2 SurvivorRatio = 8 PermSize = 21757952 (20.75MB) MaxPermSize = 85983232 (82.0MB) G1HeapRegionSize = 0 (0.0MB) Heap Usage: New Generation (Eden + 1 Survivor Space): capacity = 78053376 (74.4375MB) used = 12557464 (11.975730895996094MB) free = 65495912 (62.461769104003906MB) 16.088303470691645% used Eden Space: capacity = 69402624 (66.1875MB) used = 11711400 (11.168861389160156MB) free = 57691224 (55.018638610839844MB) 16.874578113934135% used From Space: capacity = 8650752 (8.25MB) used = 846064 (0.8068695068359375MB) free = 7804688 (7.4431304931640625MB) 9.780236446496213% used To Space: capacity = 8650752 (8.25MB) used = 0 (0.0MB) free = 8650752 (8.25MB) 0.0% used tenured generation: capacity = 173322240 (165.29296875MB) used = 111934032 (106.74861145019531MB) free = 61388208 (58.54435729980469MB) 64.58145936724566% used Perm Generation: capacity = 77332480 (73.75MB) used = 77163160 (73.5885238647461MB) free = 169320 (0.16147613525390625MB) 99.78104930813029% used 30082 interned Strings occupying 3502776 bytes. [root@VM_0_12_centos ~]# jmap -histo:live 21991 >> exam.info #查看存活对象信息，重定向到文件中 [root@VM_0_12_centos ~]# jmap -dump:live,format=b,file=heap.bin 21991 #查看堆转储快照信息 Dumping heap to /root/heap.bin ... Heap dump file created
2.5 jhat 虚拟机堆转储快照分析工具
jhat(JVM Heap Analysis Tool)命令与jmap搭配使用，来分析jmap生成的堆转储快照。jhat内置了一个小型的HTTP/HTML分析器，生成dump文件的分析结果之后，可以在浏览器查看。一般也用不到这个工具，主要原因有:一是一般不会在部署应用程序的服务器上直接生成dump文件，即使这样做了，也会尽量将dump文件复制到其他机器进行分析，因为分析工作是一个耗时且消耗硬件资源的工作;二是此工具的分析功能相对比较简陋，比较好的有Visual VM，以及专业用于分析dump文件的Eclipse Memory Analyzer等。
接下来用jhat分析上面jmap生成的dump快照信息:
C:\Users\Administrator>jhat heap.bin Reading from heap.bin... Dump file created Mon Dec 03 15:04:02 CST 2018 Snapshot read, resolving... Resolving 816411 objects... Chasing references, expect 163 dots................................................................................................................................................................... Eliminating duplicate references................................................................................................................................................................... Snapshot resolved. Started HTTP server on port 7000 Server is ready.
可以看到上面在端口7000，建立了http监听，输入http://localhost:7000/ 即可查看分析信息
分析结果默认是以包为单位分组显示，分析内存泄漏问题主要会使用其中的"heap histogram"(与jmap -histo)功能一样可以查看类的统计信息与OQL页签的功能，前者可以找到内存中总容量最大的对象，后者是标准的对象查询语言，使用类似SQL的语法对内存中的对象进行查询统计(这个参考深入JVM虚拟机一书可以方便使用)。
查看heap histogram
点一个类进去再次查看:(这里也解释了spring的cglib代理功能基于继承方式实现)
再次点击DepartmentServiceImpl查看:
2.6 jstack java堆栈跟踪工具
jstack(Stack Trace For Java)命令用于生成虚拟机当前时刻的线程快照(一般成为threaddump或者javacore文件)。线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的目的是为了定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源等待的时间过长等原因。线程出现停顿的时候可以通过jstack来查看各个线程的调用堆栈，就可以知道响应的线程到底在后台做什么或者等待什么资源。
jstack的命令格式如下:
C:\Users\Administrator>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
例如:
C:\Users\Administrator>jstack -l 2204
在JDK1.5中，java.lang.Thread类新增了一个getAllStackTraces()方法用于获取虚拟机中所有线程的StackTraceElement对象。使用这个对象可以通过简单的几行代码就完成jstack的大部分功能，在实际项目中可以用这个做管理界面，可随时查看线程堆栈。如下代码:
<%@ page language="java" contentType="text/html; charset=UTF-8" pageEncoding="UTF-8"%> <%@ page import="java.util.Map"%> <html> <head> <title>服务器线程堆栈信息</title> </head> <body> <% for (Map.Entry<Thread, StackTraceElement[]> stackTrace : Thread.getAllStackTraces().entrySet()) { Thread thread = (Thread) stackTrace.getKey(); StackTraceElement[] stackTraceElements = stackTrace.getValue(); if (thread.equals(Thread.currentThread())) { continue; } out.print("\n 线程->" + thread.getName() + "\n"); for (StackTraceElement s : stackTraceElements) { out.print("\t" + s + "\n"); } } %> </body> </html>
2.7 jcmd 的用法 (重要)
参考： https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/tooldescr006.html
个人理解jcmd 包含了上述工具的相关功能。
对于如下代码：
public class PlainTest { public static void main(String[] args) throws InterruptedException { Thread thread = new Thread(() -> { while (true) { try { Thread.sleep(20); } catch (InterruptedException e) { e.printStackTrace(); } } }); thread.setName("my-thread"); thread.start(); Thread.sleep(200000 * 10000); } }
编译后执行：
[root@redisnode1 javatest]# javac PlainTest.java [root@redisnode1 javatest]# java PlainTest & [1] 14488
1. jcmd 查看命令信息
[root@redisnode1 javatest]# jcmd 14544 sun.tools.jcmd.JCmd 14488 PlainTest [root@redisnode1 javatest]# jcmd 14488 help 14488: The following commands are available: VM.unlock_commercial_features JFR.configure JFR.stop JFR.start JFR.dump JFR.check VM.native_memory ManagementAgent.stop ManagementAgent.start_local ManagementAgent.start VM.classloader_stats GC.rotate_log Thread.print GC.class_stats GC.class_histogram GC.heap_dump GC.finalizer_info GC.heap_info GC.run_finalization GC.run VM.uptime VM.dynlibs VM.flags VM.system_properties VM.command_line VM.version help For more information about a specific command use 'help <command>'. [root@redisnode1 javatest]#
jcmd 等价于jps， 可以列出本机的java 进程； jcmd pid help 可以查看相关帮助信息。
2. VM.version 查看jdk和hotspot 版本信息
(1) openjdk 打印信息如下
[root@redisnode1 javatest]# jcmd 14488 VM.version 14488: OpenJDK 64-Bit Server VM version 25.312-b07 JDK 8.0_312
(2) sunjdk 如下：
C:\Users\XXX>jcmd 71972 VM.version 71972: Java HotSpot(TM) 64-Bit Server VM version 25.291-b10 JDK 8.0_291
3. VM.system_properties 打印JVM 用到的系统属性
[root@redisnode1 javatest]# jcmd 14488 VM.system_properties 14488: #Wed Mar 16 05:45:07 EDT 2022 java.runtime.name=OpenJDK Runtime Environment sun.boot.library.path=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/lib/amd64 java.vm.version=25.312-b07 java.vm.vendor=Red Hat, Inc. java.vendor.url=https\://www.redhat.com/ path.separator=\: java.vm.name=OpenJDK 64-Bit Server VM file.encoding.pkg=sun.io user.country=US sun.java.launcher=SUN_STANDARD ...
4. VM.flags 打印启动用到的参数
[root@redisnode1 javatest]# jcmd 14488 VM.flags 14488: -XX:CICompilerCount=3 -XX:InitialHeapSize=62914560 -XX:MaxHeapSize=989855744 -XX:MaxNewSize=329777152 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=20971520 -XX:OldSize=41943040 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC
3 和 4 加起来等于jinfo pid。
5. VM.uptime 查看JVM 启动的时间
[root@redisnode1 javatest]# jcmd 14488 VM.uptime 14488: 968.110 s
6. GC.class_histogram 打印JVM包含的类信息以及内存信息，按占用内存数量降序排序
[root@redisnode1 javatest]# jcmd 14488 GC.class_histogram 14488: num #instances #bytes class name ---------------------------------------------- 1: 3474 226336 [C 2: 390 125104 [B 3: 771 88320 java.lang.Class 4: 3460 83040 java.lang.String 5: 834 43768 [Ljava.lang.Object; 6: 331 10592 java.util.HashMap$Node 7: 188 10528 java.lang.invoke.MemberName 8: 197 10448 [I 9: 273 8736 java.util.concurrent.ConcurrentHashMap$Node 10: 186 7440 java.lang.ref.SoftReference 。。。
导出到文件中：
jcmd 14488 GC.class_histogram >> 14488.his
这个命令等价于jmap -histo pid
[root@redisnode1 javatest]# jmap -histo 14488 num #instances #bytes class name ---------------------------------------------- 1: 3476 226592 [C 2: 390 125104 [B 3: 771 88320 java.lang.Class 4: 3462 83088 java.lang.String 5: 838 44136 [Ljava.lang.Object; 6: 199 10736 [I 7: 331 10592 java.util.HashMap$Node 8: 188 10528 java.lang.invoke.MemberName 9: 273 8736 java.util.concurrent.ConcurrentHashMap$Node
7. GC.heap_dump Myheapdump 导出堆信息 Create a heap dump (hprof dump)，文件名称为Myheapdump
[root@redisnode1 javatest]# jcmd 14488 GC.heap_dump Myheapdump 14488: Heap dump file created [root@redisnode1 javatest]# ll | grep Myh -rw-------. 1 root root 1774610 Mar 16 06:05 Myheapdump
等价于jmap -dump:file=<file> <pid>
[root@redisnode1 javatest]# jmap -dump:file=Myheapdump1 14488 Dumping heap to /root/javatest/Myheapdump1 ... Heap dump file created [root@redisnode1 javatest]# ll | grep heap -rw-------. 1 root root 1774610 Mar 16 06:05 Myheapdump -rw-------. 1 root root 1774610 Mar 16 06:06 Myheapdump1
可以拿到windows 本地用jvisualvm 装入后进行分析。 相当于将线程信息、内存信息、系统属性信息都导出来，可以用jvisualVM查看。
8. Thread.print 打印线程信息，等价于 jstack pid
[root@redisnode1 javatest]# jcmd 14488 Thread.print 14488: 2022-03-16 06:20:43 Full thread dump OpenJDK 64-Bit Server VM (25.312-b07 mixed mode): "Attach Listener" #10 daemon prio=9 os_prio=0 tid=0x00007f1e00001000 nid=0x38ee waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "my-thread" #9 prio=5 os_prio=0 tid=0x00007f1e441f2800 nid=0x38a7 waiting on condition [0x00007f1e2bffe000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at PlainTest.lambda$main$0(PlainTest.java:7) at PlainTest$$Lambda$1/471910020.run(Unknown Source) at java.lang.Thread.run(Thread.java:748)
...
[root@redisnode1 javatest]# jstack 14488 2022-03-16 06:21:35 Full thread dump OpenJDK 64-Bit Server VM (25.312-b07 mixed mode): "Attach Listener" #10 daemon prio=9 os_prio=0 tid=0x00007f1e00001000 nid=0x38ee waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "my-thread" #9 prio=5 os_prio=0 tid=0x00007f1e441f2800 nid=0x38a7 waiting on condition [0x00007f1e2bffe000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at PlainTest.lambda$main$0(PlainTest.java:7) at PlainTest$$Lambda$1/471910020.run(Unknown Source) at java.lang.Thread.run(Thread.java:748)
...
9. 其他命令
[root@redisnode1 javatest]# jcmd 14488 VM.native_memory # 查看本地内存 14488: Native memory tracking is not enabled [root@redisnode1 javatest]# jcmd 14488 VM.classloader_stats #查看classloader汇总信息 14488: ClassLoader Parent CLD* Classes ChunkSz BlockSz Type 0x000000010000f958 0x000000010000fd00 0x00007f1e4414a410 1 6144 2656 sun.misc.Launcher$AppClassLoader 1 2048 1336 + unsafe anonymous classes 0x000000010000fd00 0x0000000000000000 0x0000000000000000 0 0 0 sun.misc.Launcher$ExtClassLoader 0x0000000000000000 0x0000000000000000 0x00007f1e44065f40 694 4628480 4554384 <boot class loader> 67 137216 77200 + unsafe anonymous classes Total = 3 763 4773888 4635576 ChunkSz: Total size of all allocated metaspace chunks BlockSz: Total size of all allocated metaspace blocks (each chunk has several blocks) [root@redisnode1 javatest]# jcmd 14488 GC.heap_info # 查看堆信息 14488: PSYoungGen total 15872K, used 307K [0x00000000ec580000, 0x00000000ed780000, 0x0000000100000000) eden space 15360K, 2% used [0x00000000ec580000,0x00000000ec5ccd38,0x00000000ed480000) from space 512K, 0% used [0x00000000ed480000,0x00000000ed480000,0x00000000ed500000) to space 1024K, 0% used [0x00000000ed680000,0x00000000ed680000,0x00000000ed780000) ParOldGen total 16384K, used 725K [0x00000000c5000000, 0x00000000c6000000, 0x00000000ec580000) object space 16384K, 4% used [0x00000000c5000000,0x00000000c50b5420,0x00000000c6000000) Metaspace used 4532K, capacity 4662K, committed 4864K, reserved 1056768K class space used 454K, capacity 494K, committed 512K, reserved 1048576K [root@redisnode1 javatest]# jcmd 14488 VM.command_line # 查看命令行参数 14488: VM Arguments: java_command: PlainTest java_class_path (initial): . Launcher Type: SUN_STANDARD [root@redisnode1 javatest]# jcmd 14488 VM.dynlibs # 查看加载的动态库 14488: Dynamic libraries: c5000000-c6000000 rw-p 00000000 00:00 0 c6000000-ec580000 ---p 00000000 00:00 0 ec580000-ed780000 rw-p 00000000 00:00 0 ed780000-100000000 ---p 00000000 00:00 0 100000000-100080000 rw-p 00000000 00:00 0 100080000-140000000 ---p 00000000 00:00 0 559053fef000-559053ff0000 r-xp 00000000 fd:00 39595578 /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/bin/java 5590541ef000-5590541f0000 r--p 00000000 fd:00 39595578 /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/bin/java [root@redisnode1 javatest]# jcmd 14488 PerfCounter.print # 我理解是查看统计信息 14488: java.ci.totalTime=141203055 java.cls.loadedClasses=679 java.cls.sharedLoadedClasses=0 java.cls.sharedUnloadedClasses=0 java.cls.unloadedClasses=5 java.property.java.class.path="." java.property.java.endorsed.dirs="/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/lib/endorsed" java.property.java.ext.dirs="/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/lib/ext:/usr/java/packages/lib/ext" java.property.java.home="/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre" java.property.java.library.path="/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib" java.property.java.version="1.8.0_312" java.property.java.vm.info="mixed mode" 。。。
补充:jstack也可以用来检测死锁
一个死锁程序:
package cn.xm.exam.test; public class test { public static void main(String[] args) { final Integer lock1 = 1; final Integer lock2 = 2; Runnable r1 = new Runnable() { @Override public void run() { synchronized (lock1) { try { System.out.println("lock1-----"); Thread.sleep(2 * 1000); synchronized (lock2) { System.out.println("lock1-----lock2"); } } catch (InterruptedException e) { } } } }; new Thread(r1).start(); Runnable r2 = new Runnable() { @Override public void run() { synchronized (lock2) { try { System.out.println("lock2-----"); Thread.sleep(2 * 1000); synchronized (lock1) { System.out.println("lock2-----lock1"); } } catch (InterruptedException e) { } } } }; new Thread(r2).start(); } }
jps+jstack检测死锁:
C:\Users\liqiang>jps 336164 342476 test 343376 Jps C:\Users\liqiang>jstack 342476 2018-12-10 21:19:47 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode): "DestroyJavaVM" prio=6 tid=0x00000000026a5800 nid=0x53a04 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" prio=6 tid=0x000000000e97e800 nid=0x53134 waiting for monitor entry [0x000000000ef7f000] java.lang.Thread.State: BLOCKED (on object monitor) at cn.xm.exam.test.test$2.run(test.java:33) - waiting to lock <0x00000007c0af8478> (a java.lang.Integer) - locked <0x00000007c0af8488> (a java.lang.Integer) at java.lang.Thread.run(Thread.java:745) "Thread-0" prio=6 tid=0x000000000e97d800 nid=0x53b40 waiting for monitor entry [0x000000000ee7f000] java.lang.Thread.State: BLOCKED (on object monitor) at cn.xm.exam.test.test$1.run(test.java:16) - waiting to lock <0x00000007c0af8488> (a java.lang.Integer) - locked <0x00000007c0af8478> (a java.lang.Integer) at java.lang.Thread.run(Thread.java:745) "Service Thread" daemon prio=6 tid=0x000000000d04b000 nid=0x4e590 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=10 tid=0x000000000d03a000 nid=0x53594 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=10 tid=0x000000000d035000 nid=0x52bd8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Attach Listener" daemon prio=10 tid=0x000000000d034000 nid=0x52d64 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x000000000d030800 nid=0x531f0 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=8 tid=0x000000000278c800 nid=0x53868 in Object.wait() [0x000000000e37f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007c0904858> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000007c0904858> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209) "Reference Handler" daemon prio=10 tid=0x0000000002784800 nid=0x53adc in Object.wait() [0x000000000e27f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007c0904470> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000007c0904470> (a java.lang.ref.Reference$Lock) "VM Thread" prio=10 tid=0x000000000cff3000 nid=0x53ad0 runnable "GC task thread#0 (ParallelGC)" prio=6 tid=0x00000000026bb000 nid=0x53b08 runnable "GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000026bc800 nid=0x53ac4 runnable "GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000026be800 nid=0x53368 runnable "GC task thread#3 (ParallelGC)" prio=6 tid=0x00000000026c0000 nid=0x53acc runnable "VM Periodic Task Thread" prio=10 tid=0x000000000d08e800 nid=0x539a4 waiting on condition JNI global references: 111 Found one Java-level deadlock: ============================= "Thread-1": waiting to lock monitor 0x000000000278c3b8 (object 0x00000007c0af8478, a java.lang.Integer), which is held by "Thread-0" "Thread-0": waiting to lock monitor 0x000000000278af18 (object 0x00000007c0af8488, a java.lang.Integer), which is held by "Thread-1" Java stack information for the threads listed above: =================================================== "Thread-1": at cn.xm.exam.test.test$2.run(test.java:33) - waiting to lock <0x00000007c0af8478> (a java.lang.Integer) - locked <0x00000007c0af8488> (a java.lang.Integer) at java.lang.Thread.run(Thread.java:745) "Thread-0": at cn.xm.exam.test.test$1.run(test.java:16) - waiting to lock <0x00000007c0af8488> (a java.lang.Integer) - locked <0x00000007c0af8478> (a java.lang.Integer) at java.lang.Thread.run(Thread.java:745) Found 1 deadlock.
补充：jstack用于查看线程的锁占用情况以及阻塞情况
1. 如下一个程序synchronized
package arthas; public class ArthasTest { public static void main(String[] args) { MyTask myTask = new MyTask(); for (int i = 0; i < 2; i++) { new Thread(myTask).start(); } } } class MyTask implements Runnable { @Override public void run() { System.out.println(Thread.currentThread().getName() + "开始执行"); synchronized (this) { System.out.println(Thread.currentThread().getName() + " 占用锁"); try { Thread.sleep(1 * 30 * 60 * 1000); } catch (InterruptedException e) { e.printStackTrace(); } } } }
结果：可以看出thread-0占用锁，thread-1等待锁
Thread-0开始执行
Thread-1开始执行
Thread-0 占用锁
jstack查看验证：
C:\Users\qlq>jstack 22220 2021-01-13 10:51:49 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode): "DestroyJavaVM" #16 prio=5 os_prio=0 tid=0x0000000003563800 nid=0x7524 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" #15 prio=5 os_prio=0 tid=0x000000001f1ec000 nid=0x3058 waiting for monitor entry [0x000000002082f000] java.lang.Thread.State: BLOCKED (on object monitor) at arthas.MyTask.run(ArthasTest.java:19) - waiting to lock <0x000000076c4a0b90> (a arthas.MyTask) at java.lang.Thread.run(Thread.java:748) "Thread-0" #14 prio=5 os_prio=0 tid=0x000000001fef0000 nid=0x66d8 waiting on condition [0x000000002072f000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at arthas.MyTask.run(ArthasTest.java:21) - locked <0x000000076c4a0b90> (a arthas.MyTask) at java.lang.Thread.run(Thread.java:748) "Service Thread" #13 daemon prio=9 os_prio=0 tid=0x000000001f041800 nid=0x4650 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread3" #12 daemon prio=9 os_prio=2 tid=0x000000001f00d000 nid=0x5ce0 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread2" #11 daemon prio=9 os_prio=2 tid=0x000000001f00c000 nid=0xe28 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" #10 daemon prio=9 os_prio=2 tid=0x000000001f009800 nid=0x6fb8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #9 daemon prio=9 os_prio=2 tid=0x000000001f003000 nid=0x51a8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Command Reader" #8 daemon prio=10 os_prio=0 tid=0x000000001ee9f800 nid=0x6d0 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Event Helper Thread" #7 daemon prio=10 os_prio=0 tid=0x000000001ee95000 nid=0x1ba0 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Transport Listener: dt_socket" #6 daemon prio=10 os_prio=0 tid=0x000000001ee8b800 nid=0x3f88 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001ee2a000 nid=0x4538 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001ee29800 nid=0x4ae8 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001ee10800 nid=0x2a38 in Object.wait() [0x000000001f2ef000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000076c108ed0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x000000076c108ed0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:212) "Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000001cefd000 nid=0x6144 in Object.wait() [0x000000001edef000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000076c106bf8> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference.tryHandlePending(Reference.java:191) - locked <0x000000076c106bf8> (a java.lang.ref.Reference$Lock) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) "VM Thread" os_prio=2 tid=0x000000001cef8800 nid=0x2298 runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000003579800 nid=0x2a68 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x000000000357b000 nid=0x40d8 runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x000000000357c800 nid=0x7244 runnable "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x000000000357e000 nid=0x3b48 runnable "GC task thread#4 (ParallelGC)" os_prio=0 tid=0x0000000003580000 nid=0x7dc runnable "GC task thread#5 (ParallelGC)" os_prio=0 tid=0x0000000003581800 nid=0x1360 runnable "GC task thread#6 (ParallelGC)" os_prio=0 tid=0x0000000003585800 nid=0x755c runnable "GC task thread#7 (ParallelGC)" os_prio=0 tid=0x0000000003586800 nid=0x1c74 runnable "VM Periodic Task Thread" os_prio=2 tid=0x000000001f044800 nid=0x1b9c waiting on condition JNI global references: 1604
分析：
(1)如下日志：Thread-1 等待 内存地址为 0x000000076c4a0b90 的锁资源，状态为BLOCKED阻塞
"Thread-1" #15 prio=5 os_prio=0 tid=0x000000001f1ec000 nid=0x3058 waiting for monitor entry [0x000000002082f000] java.lang.Thread.State: BLOCKED (on object monitor) at arthas.MyTask.run(ArthasTest.java:19) - waiting to lock <0x000000076c4a0b90> (a arthas.MyTask) at java.lang.Thread.run(Thread.java:748)
(2)如下日志：Thread-0 状态为超时等待，且占有内存地址为 0x000000076c4a0b90 的锁资源
"Thread-0" #14 prio=5 os_prio=0 tid=0x000000001fef0000 nid=0x66d8 waiting on condition [0x000000002072f000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at arthas.MyTask.run(ArthasTest.java:21) - locked <0x000000076c4a0b90> (a arthas.MyTask) at java.lang.Thread.run(Thread.java:748)
2. ReentrantLock程序如下：
package arthas; import java.util.concurrent.locks.ReentrantLock; public class ArthasTest2 { public static void main(String[] args) { MyTask2 myTask = new MyTask2(); for (int i = 0; i < 2; i++) { new Thread(myTask).start(); } } } class MyTask2 implements Runnable { private ReentrantLock lock = new ReentrantLock(); @Override public void run() { System.out.println(Thread.currentThread().getName() + " 开始执行"); lock.lock(); try { System.out.println(Thread.currentThread().getName() + " 占用锁"); Thread.sleep(1 * 30 * 60 * 1000); } catch (InterruptedException e) { e.printStackTrace(); } finally { lock.unlock(); } } }
结果： 可以看到Thread-0 占有锁，Thread-1 等待锁
Thread-0 开始执行
Thread-1 开始执行
Thread-0 占用锁
jps查看线程信息如下：(对于这种锁好像不能通过这种方式查看是哪个线程持有锁)
C:\Users\jxrt>jstack 13292 2021-01-13 11:00:45 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode): "DestroyJavaVM" #16 prio=5 os_prio=0 tid=0x0000000003e53800 nid=0x3a1c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" #15 prio=5 os_prio=0 tid=0x000000001fb57800 nid=0x4e18 waiting on condition [0x00000000209df000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000076c4ab3e0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199) at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209) at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285) at arthas.MyTask2.run(ArthasTest2.java:22) at java.lang.Thread.run(Thread.java:748) "Thread-0" #14 prio=5 os_prio=0 tid=0x000000001fb33000 nid=0x44dc waiting on condition [0x00000000208df000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at arthas.MyTask2.run(ArthasTest2.java:25) at java.lang.Thread.run(Thread.java:748) "Service Thread" #13 daemon prio=9 os_prio=0 tid=0x000000001fa35000 nid=0x3f2c runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread3" #12 daemon prio=9 os_prio=2 tid=0x000000001f9a3000 nid=0x6218 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread2" #11 daemon prio=9 os_prio=2 tid=0x000000001f9a1000 nid=0x7820 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" #10 daemon prio=9 os_prio=2 tid=0x000000001f9a0800 nid=0x980 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #9 daemon prio=9 os_prio=2 tid=0x000000001f99d800 nid=0x6d9c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Command Reader" #8 daemon prio=10 os_prio=0 tid=0x000000001f82d000 nid=0x5bc4 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Event Helper Thread" #7 daemon prio=10 os_prio=0 tid=0x000000001f82b800 nid=0x4170 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Transport Listener: dt_socket" #6 daemon prio=10 os_prio=0 tid=0x000000001f821000 nid=0x2318 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001f810000 nid=0x5440 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001f80f000 nid=0x57d8 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001f7a0800 nid=0x6284 in Object.wait() [0x000000001fc7e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000076c108ed0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x000000076c108ed0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:212) "Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000001d89d000 nid=0x493c in Object.wait() [0x000000001f77f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000076c106bf8> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference.tryHandlePending(Reference.java:191) - locked <0x000000076c106bf8> (a java.lang.ref.Reference$Lock) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) "VM Thread" os_prio=2 tid=0x000000001d898800 nid=0x34c8 runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000003e69800 nid=0x2e98 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000003e6b000 nid=0x2fb0 runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000003e6c800 nid=0x4bec runnable "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x0000000003e6e000 nid=0x569c runnable "GC task thread#4 (ParallelGC)" os_prio=0 tid=0x0000000003e70000 nid=0x1638 runnable "GC task thread#5 (ParallelGC)" os_prio=0 tid=0x0000000003e71800 nid=0x643c runnable "GC task thread#6 (ParallelGC)" os_prio=0 tid=0x0000000003e75800 nid=0x5f80 runnable "GC task thread#7 (ParallelGC)" os_prio=0 tid=0x0000000003e76800 nid=0x3448 runnable "VM Periodic Task Thread" os_prio=2 tid=0x000000001fa4b800 nid=0x7a64 waiting on condition JNI global references: 1628
可以看出Thread-1处于WAITING 状态，等待lock占用锁。
3.JDK的可视化工具的使用 (只在windows下进行测试)
JDK除了上面的大量的命令行工具，还提供了两个可视化工具，JConsole和Visual VM。JConsole是JDL5才有的，而Visual VM是JDK6的Update7中首次发布的，现在已经成为主流的多合一故障处理工具。
3.1Jconsole java监控与管理控制台
JConsole（Java Monitoring and management Console）是基于JMX的可视化监视、管理工具。它管理部分的功能是针对JMX MBean进行管理，由于MBean可以使用代码、中间件服务器的管理控制台或者所有符合JMX规范的软件进行访问。
1.启动JConsole
双击Jdk/bin/jconsole.exe启动即可。启动之后会自动显示本地的LVMID，相当于JPS功能，双击一个打开即可。
也可以使用下面的远程进程进行远程连接。
2.启动之后查看结果:
概述页签显示的是整个虚拟机运行时数据的概览，其中包括"堆使用情况"、"线程"、"类"、"CPU占用率等"，这些曲线图是后面内存、线程、类页签的汇总。
3.内存监控
内存页签相当于可视化的jstat命令。(在这里也可以看出永久代属于非堆区)。也可以看到垃圾收集器以及垃圾收集时间等信息。
4.线程监控
线程页签相当于jstack命令，遇到线程停顿时可以用这个命令进行分析。也可以进行死锁检测。
下面模拟一个线程死锁的线程检测:(一个简单的双同步发生的线程死锁的例子)
package cn.xm.exam.test; public class test { public static void main(String[] args) { final Integer lock1 = 1; final Integer lock2 = 2; Runnable r1 = new Runnable() { @Override public void run() { synchronized (lock1) { try { System.out.println("lock1-----"); Thread.sleep(2 * 1000); synchronized (lock2) { System.out.println("lock1-----lock2"); } } catch (InterruptedException e) { } } } }; new Thread(r1).start(); Runnable r2 = new Runnable() { @Override public void run() { synchronized (lock2) { try { System.out.println("lock2-----"); Thread.sleep(2 * 1000); synchronized (lock1) { System.out.println("lock2-----lock1"); } } catch (InterruptedException e) { } } } }; new Thread(r2).start(); } }
再次检测死锁查看线程死锁信息:(可以看到多处一个死锁签，可以看到发生死锁的当前线程所拥有的锁以及等待的另一个锁被另一个线程锁所拥有)
3.2 jvisualvm.exe :多合一故障处理工具(重要 )
1.启动
位于jdk/bin/jvisualvm.exe,双击即可启动，启动也是会显示JPS类似的功能，双击一个PID进去即可。
2.概述
可以看到参数信息，以及一些配置信息。有jps -ml的功能。其系统属性的页签类似于jinfo功能。也可以看到JVM参数的设置信息。
3.监视页签查看概述信息
也可以dump出堆转储快照。
执行堆dump之后可以进行分析类以及实例信息，类似于jmap -histo的功能 (重要) 。而且堆dump也可以另存为文件。
4.利用JVisualVM分析死锁:(例子还是上面的死锁程序)
会自动检测死锁。
我们dump出快照查看信息:
总结: 至此完成了工具的研究，最常用的是jps -lm + jmap -heap pid + jmap -histo:live 。如果可以使用可视化工具的话jvisualVM是不错的选择。
补充一些JVM中的知识,便于分析类以及其实例:
在Java中，任何类型都有class，包括基本数据类型与void。在Java中 [ 代表数组, [[ 代表二维数组。依次类推。
其他的描述标识符如下:
B---基本数据类型byte
C---基本数据类型char
D---基本数据类型double
F---基本数据类型float
I---基本数据类型int
J---基本数据类型long
S---基本数据类型short
Z---基本数据类型boolean
V---特殊类型void
L---对象类型(也就是引用类型)。例如 Ljava/lang/Object.
需要注意的是八种基本数据类型也有 calss,而且其对应包装类型有一个TYPE成员变量就是其基本数据类型。特殊类型void也有class。基本类型的数组与引用类型数组也都有class
public static final Class<Integer> TYPE = (Class<Integer>) Class.getPrimitiveClass("int");
例如:
System.out.println(int.class); System.out.println(Integer.class); System.out.println(Integer.TYPE); System.out.println(Integer[].class); System.out.println(int[].class); System.out.println(void.class);
结果:
int
class java.lang.Integer
int
class [Ljava.lang.Integer;
class [I
void
注意int不是对象，所以没有getClass方法。只有int.class
【当你用心写完每一篇博客之后,你会发现它比你用代码实现功能更有成就感!】
