JVM性能調優監控工具jps、jstack、jmap、jhat、jstat、hprof使用詳解

  現實企業級Java開發中，有時候咱們會碰到下面這些問題：

• OutOfMemoryError，內存不足

• 內存泄露

• 線程死鎖

• 鎖爭用（Lock Contention）

• Java進程消耗CPU太高

• ......

    這些問題在平常開發中可能被不少人忽視（好比有的人遇到上面的問題只是重啓服務器或者調大內存，而不會深究問題根源），但可以理解並解決這些問題是Java程序員進階的必備要求。本文將對一些經常使用的JVM性能調優監控工具進行介紹，但願能起拋磚引玉之用。本文參考了網上不少資料，難以一一列舉，在此對這些資料的做者表示感謝！關於JVM性能調優相關的資料，請參考文末。

A、 jps(Java Virtual Machine Process Status Tool)      

    jps主要用來輸出JVM中運行的進程狀態信息。語法格式以下：

1	jps [options] [hostid]

    若是不指定hostid就默認爲當前主機或服務器。

    命令行參數選項說明以下：

1	-q 不輸出類名、Jar名和傳入main方法的參數

2	-m 輸出傳入main方法的參數

3	-l 輸出main類或Jar的全限名

4	-v 輸出傳入JVM的參數

   好比下面：

1	root@ubuntu :/# jps -m -l

2	2458 org.artifactory.standalone.main.Main /usr/local/artifactory-2.2.5/etc/jetty.xml

3	29920 com.sun.tools.hat.Main -port 9998 /tmp/dump.dat

4	3149 org.apache.catalina.startup.Bootstrap start

5	30972 sun.tools.jps.Jps -m -l

6	8247 org.apache.catalina.startup.Bootstrap start

7	25687 com.sun.tools.hat.Main -port 9999 dump.dat

8	21711 mrf-center.jar

B、 jstack

    jstack主要用來查看某個Java進程內的線程堆棧信息。語法格式以下：

1	jstack [option] pid

2	jstack [option] executable core

3	jstack [option] [server-id@]remote-hostname-or-ip

    命令行參數選項說明以下：

1	-l long listings，會打印出額外的鎖信息，在發生死鎖時能夠用jstack -l pid來觀察鎖持有狀況

2	-m mixed mode，不只會輸出Java堆棧信息，還會輸出C/C++堆棧信息（好比Native方法）

    jstack能夠定位到線程堆棧，根據堆棧信息咱們能夠定位到具體代碼，因此它在JVM性能調優中使用得很是多。下面咱們來一個實例找出某個Java進程中最耗費CPU的Java線程並定位堆棧信息，用到的命令有ps、top、printf、jstack、grep。

    第一步先找出Java進程ID，我部署在服務器上的Java應用名稱爲mrf-center：

1	root@ubuntu :/# ps -ef | grep mrf-center | grep -v grep

2	root     21711     1  1 14:47 pts/3    00:02:10 java -jar mrf-center.jar

    獲得進程ID爲21711，第二步找出該進程內最耗費CPU的線程，可使用ps -Lfp pid或者ps -mp pid -o THREAD, tid, time或者top -Hp pid，我這裏用第三個，輸出以下：

    TIME列就是各個Java線程耗費的CPU時間，CPU時間最長的是線程ID爲21742的線程，用

1	printf "%x\n" 21742

    獲得21742的十六進制值爲54ee，下面會用到。    

    OK，下一步終於輪到jstack上場了，它用來輸出進程21711的堆棧信息，而後根據線程ID的十六進制值grep，以下：

1	root@ubuntu :/# jstack 21711 | grep 54ee

2	"PollIntervalRetrySchedulerThread" prio=10 tid=0x00007f950043e000 nid=0x54ee in Object.wait() [0x00007f94c6eda000]

    能夠看到CPU消耗在PollIntervalRetrySchedulerThread這個類的Object.wait()，我找了下個人代碼，定位到下面的代碼：

01	// Idle wait

02	getLog().info("Thread [" + getName() + "] is idle waiting...");

03	schedulerThreadState = PollTaskSchedulerThreadState.IdleWaiting;

04	long now = System.currentTimeMillis();

05	long waitTime = now + getIdleWaitTime();

06	long timeUntilContinue = waitTime - now;

07	synchronized(sigLock) {

08

try {

09	if(!halted.get()) {

10	sigLock.wait(timeUntilContinue);

11

}

12

}

13	catch (InterruptedException ignore) {

14

}

15

}

    它是輪詢任務的空閒等待代碼，上面的sigLock.wait(timeUntilContinue)就對應了前面的Object.wait()。

C、 jmap（Memory Map）和jhat（Java Heap Analysis Tool）

    jmap用來查看堆內存使用情況，通常結合jhat使用。

    jmap語法格式以下：

1	jmap [option] pid

2	jmap [option] executable core

3	jmap [option] [server-id@]remote-hostname-or-ip

    若是運行在64位JVM上，可能須要指定-J-d64命令選項參數。

1	jmap -permstat pid

    打印進程的類加載器和類加載器加載的持久代對象信息，輸出：類加載器名稱、對象是否存活（不可靠）、對象地址、父類加載器、已加載的類大小等信息，以下圖：

   使用jmap -heap pid查看進程堆內存使用狀況，包括使用的GC算法、堆配置參數和各代中堆內存使用狀況。好比下面的例子：

01	root@ubuntu :/# jmap -heap 21711

02	Attaching to process ID 21711, please wait...

03	Debugger attached successfully.

04	Server compiler detected.

05	JVM version is 20.10-b01

06

07	using thread-local object allocation.

08	Parallel GC with 4 thread(s)

09

10	Heap Configuration:

11	MinHeapFreeRatio = 40

12	MaxHeapFreeRatio = 70

13	MaxHeapSize      = 2067791872 (1972.0MB)

14	NewSize          = 1310720 (1.25MB)

15	MaxNewSize       = 17592186044415 MB

16	OldSize          = 5439488 (5.1875MB)

17	NewRatio         = 2

18	SurvivorRatio    = 8

19	PermSize         = 21757952 (20.75MB)

20	MaxPermSize      = 85983232 (82.0MB)

21

22	Heap Usage:

23	PS Young Generation

24	Eden Space:

25	capacity = 6422528 (6.125MB)

26	used     = 5445552 (5.1932830810546875MB)

27	free     = 976976 (0.9317169189453125MB)

28	84.78829520089286% used

29	From Space:

30	capacity = 131072 (0.125MB)

31	used     = 98304 (0.09375MB)

32	free     = 32768 (0.03125MB)

33	75.0% used

34

To Space:

35	capacity = 131072 (0.125MB)

36	used     = 0 (0.0MB)

37	free     = 131072 (0.125MB)

38

0.0% used

39	PS Old Generation

40	capacity = 35258368 (33.625MB)

41	used     = 4119544 (3.9287033081054688MB)

42	free     = 31138824 (29.69629669189453MB)

43	11.683876009235595% used

44	PS Perm Generation

45	capacity = 52428800 (50.0MB)

46	used     = 26075168 (24.867218017578125MB)

47	free     = 26353632 (25.132781982421875MB)

48	49.73443603515625% used

49

....

    使用jmap -histo[:live] pid查看堆內存中的對象數目、大小統計直方圖，若是帶上live則只統計活對象，以下：

01	root@ubuntu :/# jmap -histo:live 21711 | more

02

03	num     #instances         #bytes  class name

04	----------------------------------------------

05	1:         38445        5597736  <constMethodKlass>

06	2:         38445        5237288  <methodKlass>

07	3:          3500        3749504  <constantPoolKlass>

08	4:         60858        3242600  <symbolKlass>

09	5:          3500        2715264  <instanceKlassKlass>

10	6:          2796        2131424  <constantPoolCacheKlass>

11	7:          5543        1317400  [I

12	8:         13714        1010768  [C

13	9:          4752        1003344  [B

14	10:          1225         639656  <methodDataKlass>

15	11:         14194         454208  java.lang.String

16	12:          3809         396136  java.lang.Class

17	13:          4979         311952  [S

18	14:          5598         287064  [[I

19	15:          3028         266464  java.lang.reflect.Method

20	16:           280         163520  <objArrayKlassKlass>

21	17:          4355         139360  java.util.HashMap$Entry

22	18:          1869         138568  [Ljava.util.HashMap$Entry;

23	19:          2443          97720  java.util.LinkedHashMap$Entry

24	20:          2072          82880  java.lang.ref.SoftReference

25	21:          1807          71528  [Ljava.lang.Object;

26	22:          2206          70592  java.lang.ref.WeakReference

27	23:           934          52304  java.util.LinkedHashMap

28	24:           871          48776  java.beans.MethodDescriptor

29	25:          1442          46144  java.util.concurrent.ConcurrentHashMap$HashEntry

30	26:           804          38592  java.util.HashMap

31	27:           948          37920  java.util.concurrent.ConcurrentHashMap$Segment

32	28:          1621          35696  [Ljava.lang.Class;

33	29:          1313          34880  [Ljava.lang.String;

34	30:          1396          33504  java.util.LinkedList$Entry

35	31:           462          33264  java.lang.reflect.Field

36	32:          1024          32768  java.util.Hashtable$Entry

37	33:           948          31440  [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;

    class name是對象類型，說明以下：

1

B  byte

2

C  char

3

D  double

4

F  float

5

I  int

6

J  long

7	Z  boolean

8	[  數組，如[I表示int[]

9	[L+類名 其餘對象

    還有一個很經常使用的狀況是：用jmap把進程內存使用狀況dump到文件中，再用jhat分析查看。jmap進行dump命令格式以下：

1	jmap -dump:format=b,file=dumpFileName

    我同樣地對上面進程ID爲21711進行Dump：

1	root@ubuntu :/# jmap -dump:format=b,file=/tmp/dump.dat 21711

2	Dumping heap to /tmp/dump.dat ...

3	Heap dump file created

   dump出來的文件能夠用MAT、VisualVM等工具查看，這裏用jhat查看：

01	root@ubuntu :/# jhat -port 9998 /tmp/dump.dat

02	Reading from /tmp/dump.dat...

03	Dump file created Tue Jan 28 17:46:14 CST 2014

04	Snapshot read, resolving...

05	Resolving 132207 objects...

06	Chasing references, expect 26 dots..........................

07	Eliminating duplicate references..........................

08	Snapshot resolved.

09	Started HTTP server on port 9998

10	Server is ready.

     注意若是Dump文件太大，可能須要加上-J-Xmx512m這種參數指定最大堆內存，即jhat -J-Xmx512m -port 9998 /tmp/dump.dat。而後就能夠在瀏覽器中輸入主機地址:9998查看了：

    上面紅線框出來的部分你們能夠本身去摸索下，最後一項支持OQL（對象查詢語言）。

D、jstat（JVM統計監測工具）

    語法格式以下：

1	jstat [ generalOption | outputOptions vmid [interval[s|ms] [count]] ]

    vmid是Java虛擬機ID，在Linux/Unix系統上通常就是進程ID。interval是採樣時間間隔。count是採樣數目。好比下面輸出的是GC信息，採樣時間間隔爲250ms，採樣數爲4：

1	root@ubuntu :/# jstat -gc 21711 250 4

2	S0C    S1C    S0U    S1U      EC       EU        OC         OU       PC     PU    YGC     YGCT    FGC    FGCT     GCT

3	192.0  192.0   64.0   0.0    6144.0   1854.9   32000.0     4111.6   55296.0 25472.7    702    0.431   3      0.218    0.649

4	192.0  192.0   64.0   0.0    6144.0   1972.2   32000.0     4111.6   55296.0 25472.7    702    0.431   3      0.218    0.649

5	192.0  192.0   64.0   0.0    6144.0   1972.2   32000.0     4111.6   55296.0 25472.7    702    0.431   3      0.218    0.649

6	192.0  192.0   64.0   0.0    6144.0   2109.7   32000.0     4111.6   55296.0 25472.7    702    0.431   3      0.218    0.649

    要明白上面各列的意義，先看JVM堆內存佈局：

    能夠看出：

1	堆內存 = 年輕代 + 年老代 + 永久代

2	年輕代 = Eden區 + 兩個Survivor區（From和To）

    如今來解釋各列含義：

1	S0C、S1C、S0U、S1U：Survivor 0/1區容量（Capacity）和使用量（Used）

2	EC、EU：Eden區容量和使用量

3	OC、OU：年老代容量和使用量

4	PC、PU：永久代容量和使用量

5	YGC、YGT：年輕代GC次數和GC耗時

6	FGC、FGCT：Full GC次數和Full GC耗時

7

GCT：GC總耗時

E、hprof（Heap/CPU Profiling Tool）

    hprof可以展示CPU使用率，統計堆內存使用狀況。

    語法格式以下：

1	java -agentlib:hprof[=options] ToBeProfiledClass

2	java -Xrunprof[:options] ToBeProfiledClass

3	javac -J-agentlib:hprof[=options] ToBeProfiledClass

    完整的命令選項以下：

01	Option Name and Value  Description                    Default

02	---------------------  -----------                    -------

03	heap=dump|sites|all    heap profiling                 all

04	cpu=samples|times|old  CPU usage                      off

05	monitor=y|n            monitor contention             n

06	format=a|b             text(txt) or binary output     a

07	file=<file>            write data to file             java.hprof[.txt]

08	net=<host>:<port>      send data over a socket        off

09	depth=<size>           stack trace depth              4

10	interval=<ms>          sample interval in ms          10

11	cutoff=<value>         output cutoff point            0.0001

12	lineno=y|n             line number in traces?         y

13	thread=y|n             thread in traces?              n

14	doe=y|n                dump on exit?                  y

15	msa=y|n                Solaris micro state accounting n

16	force=y|n              force output to <file>         y

17	verbose=y|n            print messages about dumps     y

    來幾個官方指南上的實例。

    CPU Usage Sampling Profiling(cpu=samples)的例子：

1	java -agentlib:hprof=cpu=samples,interval=20,depth=3 Hello

    上面每隔20毫秒採樣CPU消耗信息，堆棧深度爲3，生成的profile文件名稱是java.hprof.txt，在當前目錄。 

    CPU Usage Times Profiling(cpu=times)的例子，它相對於CPU Usage Sampling Profile可以得到更加細粒度的CPU消耗信息，可以細到每一個方法調用的開始和結束，它的實現使用了字節碼注入技術（BCI）：

1	javac -J-agentlib:hprof=cpu=times Hello.java

    Heap Allocation Profiling(heap=sites)的例子：

1	javac -J-agentlib:hprof=heap=sites Hello.java

    Heap Dump(heap=dump)的例子，它比上面的Heap Allocation Profiling能生成更詳細的Heap Dump信息：

1	javac -J-agentlib:hprof=heap=dump Hello.java

    雖然在JVM啓動參數中加入-Xrunprof:heap=sites參數能夠生成CPU/Heap Profile文件，但對JVM性能影響很是大，不建議在線上服務器環境使用。

其餘JVM性能調優參考資料：

《Java虛擬機規範》

《Java Performance》

《Trouble Shooting Guide for JavaSE 6 with HotSpot VM》: http://www.oracle.com/technetwork/java/javase/tsg-vm-149989.pdf 

《Effective Java》

VisualVM: http://docs.oracle.com/javase/7/docs/technotes/guides/visualvm/

jConsole: http://docs.oracle.com/javase/1.5.0/docs/guide/management/jconsole.html

Monitoring and Managing JavaSE 6 Applications: http://www.oracle.com/technetwork/articles/javase/monitoring-141801.html

BTrace：https://kenai.com/projects/btrace