使用jdk的jps、jstack工具檢測代碼問題，提高程式效能

標籤：util   entry   執行   argument   could   mil   tar   cte   top   

??

今天給大家分享怎樣利用jdk的jps和jstack工具結合定位代碼的問題，提高程式的穩定性、健壯性和效能。

在jdk的bin，目錄下面有很多的工具

jps、jstack工具介紹:

jps:

是JDK1.5提供的一個顯示當前所有java進程pid的命令，簡單實用，非常適合在linux/unix平台上簡單察看當前java進程的一些簡單情況。

命令格式：jps [options ] [ hostid ]

[options]選項 ：

-q：僅輸出VM標識符，不包括classname,jar name,arguments in main method 

-m：輸出main method的參數 

-l：輸出完全的包名，應用主類名，jar的完全路徑名 

-v：輸出jvm參數 

-V：輸出通過flag檔案傳遞到JVM中的參數(.hotspotrc檔案或-XX:Flags=所指定的檔案 

-Joption：傳遞參數到vm,例如:-J-Xms1024m

用-l作樣本:

在圖中，第一例是進程號，第二例是進程名（啟動並執行程式），比如activemq（/home/activeMq/apache-activemq-5.5.1/bin/run.jar）、dubbo

服務（com.alibaba.dubbo.container.Main）、tomcat(org.apache.catalina.startup.Bootstrap)等等。

jstack:

jstack是java虛擬機器內建的一種堆疊追蹤工具。jstack用於產生java虛擬機器當前時刻的線程快照。線程快照是當前java虛擬機器內每一條線程正

在執行的方法堆棧的集合，產生線程快照的主要目的是定位線程出現長時間停頓的原因，如線程間死結、死迴圈、請求外部資源導致的長時

間等待等。

 線程出現停頓的時候通過jstack來查看各個線程的呼叫堆疊，就可以知道沒有響應的線程到底在後台做什麼事情，或者等待什麼資源。

命令格式:jstack [ option ] pid

[options]選項 ：

-F :當’jstack [-l] pid’沒有響應的時候強制列印棧資訊;

-l :長列表. 列印關於鎖的附加資訊,例如屬於java.util.concurrent的ownable synchronizers列表.

-m: 列印java和native c/c++架構的所有棧資訊. -h | -help列印協助資訊

pid :需要被列印配置資訊的java進程id,可以用jps工具查詢

用-l作樣本：

命令：

運行結果：

我們可以查看各個線程的呼叫堆疊，就可以知道沒有響應的線程到底在後台做什麼事情，或者等待什麼資源。

jps、jstack尋找代碼問題

原理：

通過jps命令尋找到對應程式的進程，記錄進程號，通過jstack命令把該進程號所在的程式的線程堆棧資訊輸出到檔案，然後對檔案裡面的資訊進行

分析，找到原因並解決問題。

注：這種方式盡量在並發的時候進行使用這樣更容易找出代碼問題。

步驟：

1).進入到jdk的bin目錄，

2).使用jps工具查看tomcat的進程（如果是linux環境建議使用ps命令）；

因為只安裝了一個tomcat，使用jps -m命令（如果安裝了多個tomcat ，請使用jps -v命令，該命令啟動並執行結果中可以看到各個tomcat的路徑）

3).執行jstack命令，並把輸出結果輸出到記錄檔；

命令：

[[email protected] bin]# jstack 28501 >log1.log

開啟檔案log1.log檔案看裡面內容：

[[email protected] bin]# tail -200f log1.log        - locked <0x00000007058fc4b0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)        at java.lang.Thread.run(Thread.java:662)"http-8090-11" daemon prio=10 tid=0x00002aaab4047000 nid=0x7181 in Object.wait() [0x000000004238b000]   java.lang.Thread.State: WAITING (on object monitor)        at java.lang.Object.wait(Native Method)        - waiting on <0x00000007056433f0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at java.lang.Object.wait(Object.java:485)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)        - locked <0x00000007056433f0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)        at java.lang.Thread.run(Thread.java:662)"http-8090-10" daemon prio=10 tid=0x00002aaab46ec000 nid=0x7180 in Object.wait() [0x000000004228a000]   java.lang.Thread.State: WAITING (on object monitor)        at java.lang.Object.wait(Native Method)        - waiting on <0x0000000705643610> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at java.lang.Object.wait(Object.java:485)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)        - locked <0x0000000705643610> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)        at java.lang.Thread.run(Thread.java:662)"http-8090-9" daemon prio=10 tid=0x00002aaab4525800 nid=0x717f in Object.wait() [0x000000004078a000]   java.lang.Thread.State: WAITING (on object monitor)        at java.lang.Object.wait(Native Method)        - waiting on <0x0000000705643898> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at java.lang.Object.wait(Object.java:485)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)        - locked <0x0000000705643898> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)        at java.lang.Thread.run(Thread.java:662)

4).記錄檔進行分析

由於上面的tomcat沒有進行壓力測試，所以看到的都是tomcat的線程沒有自己程式碼的線程。因此使用前段時間的進過

壓力測試後匯出的日誌進行分析。部分日誌內容如下：

"DubboClientHandler-192.168.6.162:2099-thread-2" daemon prio=10 tid=0x00002aaac069a000 nid=0x14c1 waiting on condition [0x000000004867f000]   java.lang.Thread.State: TIMED_WAITING (parking)at sun.misc.Unsafe.park(Native Method)- parking to wait for  <0x0000000782c4d8e0> (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)"DubboClientHandler-192.168.6.162:2099-thread-2" daemon prio=10 tid=0x000000005be86000 nid=0x14c0 waiting on condition [0x000000004863e000]   java.lang.Thread.State: TIMED_WAITING (parking)at sun.misc.Unsafe.park(Native Method)- parking to wait for  <0x0000000782c61ac0> (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)"http-portal%2F192.168.6.162-8097-184" daemon prio=10 tid=0x00002aaab0ecc800 nid=0x2d7a waiting for monitor entry [0x0000000045fa9000]    java.lang.Thread.State: BLOCKED (on object monitor)      at org.apache.log4j.Category.callAppenders(Category.java:204)      - waiting to lock <0x00000007800020a0> (a org.apache.log4j.spi.RootLogger)      at org.apache.log4j.Category.forcedLog(Category.java:391)      at org.apache.log4j.Category.log(Category.java:856)      at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:304)  

從最後的日誌中我們可以看出這個日誌線程處於BLOCKED狀態，進入org.apache.log4j.Category類的callAppenders方法，

代碼如下：

/**     Call the appenders in the hierrachy starting at     <code>this</code>.  If no appenders could be found, emit a     warning.     <p>This method calls all the appenders inherited from the     hierarchy circumventing any evaluation of whether to log or not     to log the particular log request.     @param event the event to log.  */  public void callAppenders(LoggingEvent event) {    int writes = 0;    for(Category c = this; c != null; c=c.parent) {      // Protected against simultaneous call to addAppender, removeAppender,...      synchronized(c) {if(c.aai != null) {  writes += c.aai.appendLoopOnAppenders(event);}if(!c.additive) {  break;}      }    }    if(writes == 0) {      repository.emitNoAppenderWarning(this);    }  }

從上面可以看出在該方法中有synchronized同步鎖，同步鎖會導致線程競爭，那麼在大並發情況下將會出現效能問題，同時

會引起線程BLOCKED問題。

可以使用Apache log 解決這個問題，代碼如下：

private static final Log log = LogFactory.getLog("xxx");  

通過測試,org.apache.log4j.Category.callAppenders線程BLOCKED問題沒有了。

上面只是一個非常簡單的樣本，現實開發過程中可以根據線程的狀態能夠找出很多問題。大家不妨嘗試一下。

---------------------------------------------------------------------------著作權聲明------------------------------------------------------------------------------------------

著作權聲明：本文為博主原創文章，未經博主允許不得轉載。部落格地址:http://blog.csdn.net/mr_smile2014

使用jdk的jps、jstack工具檢測代碼問題，提高程式效能