JVM監控命令詳解(轉)

JVM監控命令基本就是 jps、jstack、jmap、jhat、jstat 幾個命令的使用就能夠了

JDK自己提供了不少方便的JVM性能調優監控工具，除了集成式的VisualVM和jConsole外，還有jps、jstack、jmap、jhat、jstat等小巧的工具，本博客但願能起拋磚引玉之用，讓你們能開始對JVM性能調優的經常使用工具備所瞭解。

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

OutOfMemoryError，內存不足java
內存泄露程序員
線程死鎖算法
鎖爭用（Lock Contention）mongodb
Java進程消耗CPU太高apache
......ubuntu

這些問題在平常開發中可能被不少人忽視（好比有的人遇到上面的問題只是重啓服務器或者調大內存，而不會深究問題根源），但可以理解並解決這些問題是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.

而後就能夠在瀏覽器中輸入主機地址:9998查看了：

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

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

語法格式以下：

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

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

 

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

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

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 
     

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 
     

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 
     

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總耗時

其餘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

原文路徑：http://blog.csdn.net/wisgood/article/details/25343845

對應參數解釋：

各類 Java Thread State 第一分析法則

使用 TDA 工具，看到大量 Java Thread State 的第一反應是：

1，線程狀態爲「waiting for monitor entry」：

意味着它 在等待進入一個臨界區 ，因此它在」Entry Set「隊列中等待。

此時線程狀態通常都是 Blocked：

java.lang.Thread.State: BLOCKED (on object monitor)

2，線程狀態爲「waiting on condition」：

說明它 在等待另外一個條件的發生，來把本身喚醒，或者乾脆它是調用了 sleep(N)。

此時線程狀態大體爲如下幾種：

java.lang.Thread.State: WAITING (parking)：一直等那個條件發生；
java.lang.Thread.State: TIMED_WAITING (parking或sleeping)：定時的，那個條件不到來，也將定時喚醒本身。

3，若是大量線程在 「waiting for monitor entry」：

多是一個全局鎖阻塞住了大量線程。

若是短期內打印的 thread dump 文件反映，隨着時間流逝，waiting for monitor entry 的線程愈來愈多，沒有減小的趨勢，可能意味着 某些線程在臨界區裏呆的時間太長了，以致於愈來愈多新線程遲遲沒法進入臨界區。

4，若是大量線程在 「 waiting on condition 」：

多是它們又跑去獲取第三方資源， 尤爲是第三方網絡資源，遲遲獲取不到Response，致使大量線程進入等待狀態。

因此若是你發現有大量的線程都處在 Wait on condition，從線程堆棧看，正等待網絡讀寫 ，這多是一個網絡瓶頸的徵兆，由於網絡阻塞致使線程沒法執行。

線程狀態爲「in Object.wait()」：

說明它 得到了監視器以後，又調用了 java.lang.Object.wait() 方法。

每一個 Monitor在某個時刻，只能被一個線程擁有，該線程就是「Active Thread」，而其它線程都是「Waiting Thread」，分別在兩個隊列「 Entry Set」和「Wait Set」裏面等候。在「Entry Set」中等待的線程狀態是「Waiting for monitor entry」，而在「Wait Set」中等待的線程狀態是「in Object.wait()」。

當線程得到了 Monitor，若是發現線程繼續運行的條件沒有知足，它則調用對象（通常就是被 synchronized 的對象）的 wait() 方法，放棄了 Monitor，進入「Wait Set」隊列。

此時線程狀態大體爲如下幾種：

java.lang.Thread.State: TIMED_WAITING (on object monitor)；
java.lang.Thread.State: WAITING (on object monitor)；

通常都是RMI相關線程（RMI RenewClean、 GC Daemon、RMI Reaper），GC線程（Finalizer），引用對象垃圾回收線程（Reference Handler）等系統線程處於這種狀態。

圖1 A Java Monitor

示範一：

下面這個線程在等待這個鎖 0x00000000fe7e3b50，等待進入臨界區：

"RMI TCP Connection(64896)-172.16.52.118" daemon prio=10 tid=0x00000000405a6000 nid=0x68fe waiting for monitor entry [0x00007f2be65a3000]

java.lang.Thread.State: BLOCKED (on object monitor)

at com.xyz.goods.service.impl.GoodsServiceImpl. findChanellGoodsCountWithCache(GoodsServiceImpl.java:1734)

- waiting to lock <0x00000000fe7e3b50> (a java.lang.String)

那麼誰持有這個鎖呢？

是另外一個先調用了 findChanellGoodsCountWithCache 函數的線程：

"RMI TCP Connection(64878)-172.16.52.117" daemon prio=10 tid=0x0000000040822000 nid=0x6841 runnable [0x00007f2be76b3000]

java.lang.Thread.State: RUNNABLE

at java.net.SocketInputStream.socketRead0(Native Method)

at java.net.SocketInputStream.read(SocketInputStream.java:129)

at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)

at java.io.BufferedInputStream.read(BufferedInputStream.java:317)

- locked <0x00000000af4ed638> (a java.io.BufferedInputStream)

at org.bson.io.Bits.readFully(Bits.java:35)

at org.bson.io.Bits.readFully(Bits.java:28)

at com.mongodb.Response.<init>(Response.java:35)

at com.mongodb.DBPort.go(DBPort.java:110)

- locked <0x00000000af442d48> (a com.mongodb.DBPort)

at com.mongodb.DBPort.go(DBPort.java:75)

- locked <0x00000000af442d48> (a com.mongodb.DBPort)

at com.mongodb.DBPort.call(DBPort.java:65)

at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)

at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:296)

at com.mongodb.DB.command(DB.java:152)

at com.mongodb.DBCollection.getCount(DBCollection.java:760)

at com.mongodb.DBCollection.getCount(DBCollection.java:731)

at com.mongodb.DBCollection.count(DBCollection.java:697)

at com.xyz.goods.manager.MongodbManager.count(MongodbManager.java:202)

at com.xyz.goods.service.impl.GoodsServiceImpl.findChanellGoodsCount(GoodsServiceImpl.java:1787)

at com.xyz.goods.service.impl.GoodsServiceImpl. findChanellGoodsCountWithCache(GoodsServiceImpl.java:1739)

- locked <0x00000000fe7e3b50> (a java.lang.String)

示範二：

等待另外一個條件發生來將本身喚醒：

"RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2 waiting on condition [0x00007fd4f1a59000]

java.lang.Thread.State: TIMED_WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

- parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)

at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)

at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)

at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)

at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)

at java.lang.Thread.run(Thread.java:662)

1）「 TIMED_WAITING (parking)」中的 timed_waiting 指等待狀態，但這裏指定了時間，到達指定的時間後自動退出等待狀態；parking指線程處於掛起中。

2）「 waiting on condition」須要與堆棧中的「 parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)」結合來看。首先，本線程確定是在等待某個條件的發生，來把本身喚醒。其次，SynchronousQueue 並非一個隊列，只是線程之間移交信息的機制，當咱們把一個元素放入到 SynchronousQueue 中時必須有另外一個線程正在等待接受移交的任務，所以這就是本線程在等待的條件。

示範三：

"RMI RenewClean-[172.16.50.182:4888]" daemon prio=10 tid=0x0000000040d2c800 nid=0x97e in Object.wait() [0x00007f9ccafd0000]

java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

- waiting on <0x0000000799b032d8> (a java.lang.ref.ReferenceQueue$Lock)

at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)

- locked <0x0000000799b032d8> (a java.lang.ref.ReferenceQueue$Lock)

at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)

at java.lang.Thread.run(Thread.java:662)

參考資源：

1）CUBRID，2012， How to Analyze Java Thread Dumps；

2）鄭昀，2013，三個實例演示Java THread Dump日誌分析；

原文地址： http://www.cnblogs.com/zhengyun_ustc/archive/2013/03/18/tda.html