JAVA問題定位跟蹤技術

經常使用的JAVA調試技巧： 
線程堆棧解讀 
性能瓶頸分析 
遠程調試 
內存泄露檢測 

經常使用工具集： 
proc工具集 
系統跟蹤命令truss/strace 
Core文件管理coreadm 
進程狀態監控prstat 
網絡狀態監控netstat 
磁盤監控iostat 
CPU和內存監控vmstat抓包工具…… 

輸出線程堆棧： 
Windows:在運行java的控制檯上按ctrl+break組合鍵 
Unix:保留啓動java的控制檯，使用kill -3 <pid> 
*:啓動時進行重定向是一個不錯的習慣：run.sh > start.log 2>@1 

堆棧的做用： 
線程死鎖分析 
輔助CPU太高分析 
線程資源不足分析 
性能瓶頸分析 
關鍵線程異常退出 

解讀線程堆棧： 
wait() ————會釋放監視鎖 
sleep() ————與鎖操做無關，繼續保持監視鎖 
當一個線程佔有一個鎖的時候，會打印- locked <0xe7402c48> 
當該線程正在等待別的線程釋放該鎖，就會打印：waiting to lock <0xe7402c48> 
若是代碼中有wait()調用的話，首先是locked，而後又會打印 - waiting on <0xe7402c48> 
例如： 
"http-0.0.0.0-27443-Processor4" daemon prio=5 tid=0x599a7520 nid=0x1858 in Object.wait() [5c9ef000..5c9efd88] 
at java.lang.Object.wait(Native Method) 
- waiting on <0x1693d2f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable) 
at java.lang.Object.wait(Object.java:429) 
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:655) 
- locked <0x1693d2f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable) 
at java.lang.Thread.run(Thread.java:534) 
其中- waiting on <0x1693d2f8>表示線程正停在該對象的wait上面。同時wait會自動釋放該鎖；- locked <0x1693d2f8>表示該線程鎖住了該鎖。 

"smpp02:Sender-108" daemon prio=5 tid=0x59a751a0 nid=0x13fc waiting for monitor entry [6066f000..6066fd88] 
at org.apache.log4j.Category.callAppenders(Category.java:185) 
- waiting to lock <0x14fdfe98> (a org.apache.log4j.spi.RootCategory) 
at org.apache.log4j.Category.forcedLog(Category.java:372) 
at org.apache.log4j.Category.log(Category.java:864) 
at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:137) 
at com.huawei.uniportal.comm.base.server.AbstractHandler.send(AbstractHandler.java:407) 
at com.huawei.tellin.usr.uc.sendmessage.UCSMPPTransaction.send(UCSMPPTransaction.java:102) 
at com.huawei.tellin.usr.uc.sendmessage.UCServerProxy.synSend(UCServerProxy.java:134) 
at com.huawei.uniportal.comm.base.proxy.SendWorker.run(AbstractProxy.java:666) 
at com.huawei.uniportal.utilities.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748) 
at java.lang.Thread.run(Thread.java:534) 
其中- waiting to lock <0x14fdfe98> waiting to lock <0x14fdfe98> 表示該鎖已經被別的線程使用，正在等待該鎖被釋放。 

線程死鎖分析： 
Found one Java-level deadlock: 
============================= 
"thread1": 
  waiting to lock monitor 0x009fccb4 (object 0x10032710, a java.lang.Object), 
  which is held by "thread1" 
"thread1": 
  waiting to lock monitor 0x009fcc94 (object 0x10032718, a java.lang.Object), 
  which is held by "thread1" 

Java stack information for the threads listed above: 
=================================================== 
"thread0": 
        at DeadLockTest.run(DeadLockTest.java:44) 
        - waiting to lock <0x10032710> (a java.lang.Object) 
        - locked <0x10032718> (a java.lang.Object) 
        at java.lang.Thread.run(Unknown Source) 
"thread1": 
        at DeadLockTest.run(DeadLockTest.java:24) 
        - waiting to lock <0x10032718> (a java.lang.Object) 
        - locked <0x10032710> (a java.lang.Object) 
        at java.lang.Thread.run(Unknown Source) 
0x10032710 和 0x10032718 都在等待對方釋放，雙方都被餓死. 

用戶代碼致使CPU太高/熱點線程分析： 

首先能夠經過kill -3 pid(unix下) 或 <ctrl>+<break>( windows下) 獲取一個堆棧信息， 
幾分鐘以後再獲取一個，經過兩個堆棧信息對比，將一直在忙的線程找出來。 
經過分析對應的代碼，確認不正常的線程。 

第一步：經過kill -3 java_pid 獲取當前堆棧信息。 
第二步：等待一段時間後。再獲取一下當前堆棧信息。 
第三步：預處理前兩個獲取的堆棧信息，去掉處於sleeping或waiting的狀態的線程。 
例如以下線程處於wait或者sleep狀態， 
這種線程是不消耗CPU的，所以這些線程能夠直接忽略掉，重點關注其它線程： 
"EventManager-Worker-1" daemon prio=8 tid=0x00c3ea58 nid=0x14a in Object.wait() [935ff000..935ffc28] 
at java.lang.Object.wait(Native Method)   //該線程已掛起，忽略掉 
- waiting on <0xbb9515a8> (a org.exolab.core.util.FifoQueue) 
at java.lang.Object.wait(Object.java:429) 
第五步：對比預處理後的1，2堆棧信息，找出處於busy狀態的線程，該類線程多是致使cpu高佔用率的可疑線程。 
例如：(下面的是在第一個堆棧信息中找到的處於active 活躍狀態的線程) 

"http-80-Processor6" daemon prio=5 tid=0x013ea770 nid=0x143 runnable [92eff000..92f019c0] 
at com.huawei.u_sys.common.licmgr.LicenseIntf.nativeCheckLicense(Native Method) 
at com.huawei.u_sys.common.licmgr.LicenseIntf.checkLicense(LicenseIntf.java:168) 
at com.huawei.u_sys.meetingone.sysmgr.ejb.LicRelateBean.updateLic(LicRelateBean.java:80) 

同一個線程在第二個堆棧信息中仍處於活躍狀態。 
"http-80-Processor6" daemon prio=5 tid=0x013ea770 nid=0x143 runnable [92eff000..92f019c0] 
at com.huawei.u_sys.common.licmgr.LicenseIntf.nativeCheckLicense(Native Method) 
at com.huawei.u_sys.common.licmgr.LicenseIntf.checkLicense(LicenseIntf.java:168) 
at com.huawei.u_sys.meetingone.sysmgr.ejb.LicRelateBean.updateLic(LicRelateBean.java:80) 
兩次打印堆棧該線程一直在運行，說明該線程已運行了5分鐘，請在代碼中檢查該線程是否屬於長時間運行線程？若是屬於暫態線程，如此長時間運行說明可能有死循環等致使的CPU太高。

性能瓶頸分析 

高性能的含義： 
有的場合高性能意味着用戶速度體驗，如界面操做。- 適合使用OptimizeIt分析 
還有的場合，高吞吐量意味着高性能，如短信。 - 適合使用堆棧分析 
還有的場合是兩者的結合，如IP電話- 適合使用堆棧分析 

性能瓶頸問題產生的源頭分析 
常見架構和設計問題： 
   不恰當的線程同步 
不良的架構（同步／異步使用不當） 
併發設計不當－資源搶佔致使的資源競爭, 鏈接池和線程池等應用不當等 
效率低下的通訊方式 
數據庫鏈接等競爭資源參數設置不當 
    內存泄漏/不恰當的虛擬機運行參數 
    緩慢的磁盤/網絡 IO 

… … 
常見編碼問題 
String +，getByte()的不恰當使用：不少時侯可使用StringBuf 
過大的同步範圍 
ＳＱＬ語句設計不當 
… … 

性能瓶頸分析手段和方法之一－線程堆棧剖析 
原理：經過分析JVM線程運行狀況，定位性能問題 
方法：　kill -3 <pid> (UNIX)  ctrl+break (windows) 打印出當前的虛擬機的一個運行剖面，進行分析 

"WorkerThread-8" ... in Object.wait() ... 
... - locked <0xf14213c8> (a Queue) ... 
"WorkerThread-10" ... in Object.wait() ... 
... - locked <0xf14213c8> (a Queue) ... 
"WriterThread-3" ... in Object.wait() ... 
... - locked <0xf14213c8> (a Queue) ... 

可以發現的性能問題： 
(1) 資源爭用 
(2) 鎖的粒度過大
(3) sleep的濫用 

適用場合： 
識別只有在高負載的時候纔出現的性能瓶頸。 
多線程場合 

不適用的場合： 
單操做單線程下的代碼段耗時分析,如一次界面點擊，感受遲緩。 

性能瓶頸分析手段和方法之一     －兩種典型的性能瓶頸的堆棧特徵 
1.絕大多數線程都在作相同的事情，不多有空閒線程。 
   如： 90%的Sender線程都在執行callAppender 
    "smpp02:Sender-108" daemon prio=5 tid=0x59a751a0 nid=0x13fc waiting for monitor entry   [6066f000..6066fd88] 
at org.apache.log4j.Category.callAppenders(Category.java:185) 
- waiting to lock <0x14fdfe98> (a org.apache.log4j.spi.RootCategory) 
at org.apache.log4j.Category.forcedLog(Category.java:372) 
at org.apache.log4j.Category.log(Category.java:864) 
可能的緣由： 
線程數量太小 
鎖粒度過大 
資源競爭（數據庫鏈接池等） 
耗時操做（大量的磁盤IO，最終是串行操做） 

2.絕大多數線程處於等待狀態，只有幾個線程在工做，整體性能上不去。 
可能的緣由： 
系統存在關鍵路徑，該關鍵路徑沒有足夠的能力給下個階段輸送大量輸送任務，致使其餘地方空閒 
如：在消息分發系統，消息分發通常是一個線程，而處理是多線程，這時候消息分發是瓶頸的話，觀察到的線程堆棧就會出現上面的現象。 

性能瓶頸分析手段和方法之二 －虛擬機參數調優 
原理： 
觀察垃圾回收狀況而且進行調整，使JVM的垃圾回收更加平滑和高效率 

方法：　Java 命令行中增長 –verbose:gc 運行參數 
[Full GC 792332K->412757K(1040896K), 8.9157secs] 
[Full GC 799898K->221096K(1040896K), 5.3018secs] 
若是每次回收完成後可用的內存持續減小則可能存在內存泄漏。 
可以發現的性能問題： 
垃圾回收參數設置不合理致使的嚴重的性能問題． 
內存泄漏 

能夠調節的JVM 垃圾回收參數 
IBM JDK：主要參數： -Xconcurrentbackground  –Xconcurrentlevel, 以及堆大小。 
SUN，HP JDK 主要是 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction 
JVM調優是個系統工程，和運行環境主要是內存配置密切相關，須要酌情配置處理 

適用場合： 
高負載但實時性要求不高的系統，如 Web 類應用，如移動彩鈴應用，以及大容量且實時性要求很是高的系統，好比呼叫類應用。 

下列JVM參數可用於獲取gc日誌 

-verbose:gc 或 
-Xloggc:filename 

一些參考資料 
http://www-128.ibm.com/developerworks/cn/java/j-jtp11253/ 
http://www-128.ibm.com/developerworks/cn/java/j-perf05214/ 
http://www-128.ibm.com/developerworks/cn/java/j-perf06304/ 

性能瓶頸分析手段和方法之三 － 性能調優工具  

OptimizeIt或JProfile － 提供全面的內存泄漏分析，函數調用CPU時間和內存佔用分析 

適用場合： 
（1） 單操做單線程下的代碼段耗時分析,如一次界面點擊，感受遲緩。 

不適用的場合： 
（1）運行期間，同一段代碼被不一樣線程執行時，因爲線程是變化的，沒法找出對應的線程。 
（2）大容量應用下出現的瓶頸, 由於啓動這個工具性能會有幾十倍甚至上百倍的的性能降低，難以支撐大容量狀況下的測試分析。只有在大容量下出現的鎖競爭也許不會出現，頻繁的磁盤IO、數據庫訪問等致使的瓶頸也不會出現。現象不充分暴露，天然也就談不上分析。 

JAVA 遠程調試 

虛擬機遠程調試開關： 

-Xdebug -Xrunjdwp:transport=dt_socket,server=y,address=%DEBUG_PORT%,suspend=n；suspend設爲n時JVM會在打開調試端口後正常啓動，若設爲y則JVM啓動後會等候調試器鏈接後才繼續啓動 

JAVA 內存泄漏檢測 

內存泄露產生 
2.1      java的垃圾回收機制 
java虛擬機的垃圾回收算法要作兩件事情。首先，它必須檢測出垃圾對象。 
其次，它必須回收垃圾對象所使用的堆空間並還給程序。 
垃圾檢測一般經過創建一個根對象的集合而且檢查從這些根對象開始的可觸及性來實現。 
若是正在執行的程序能夠訪問到的根對象和某個對象之間存在引用路徑，這個對象就是可觸及的。 
對於程序來講，根對象老是能夠訪問的。從這些跟對象開始， 
任何能夠被觸及的對象都被認爲是「活動」對象。沒法被觸及的對象被認爲是垃圾， 
由於它們再也不影響程序的將來執行。 

2.2      內存泄漏的產生 
若是系統中存在愈來愈多的再也不影響程序將來執行的對象，且這些對象和根對象之間存在引用路徑， 
內存泄漏產生了。 

2.3      內存泄漏的消除 
根據 內存泄漏的產生 所述。發生內存泄漏要知足以下兩個條件： 
1. 系統中存在愈來愈多的再也不影響程序將來執行的對象。 
2. 這些對象和根對象之間存在引用路徑。 
從這兩個條件中能很容易找出消除內存泄漏的方法：截斷系統中存在的不影響程序將來執行的對象與 
根對象之間的引用路徑。這樣，這些對象就成了「垃圾」對象，javm就能正常回收它們。 

常見的內存泄露陷阱 
常見的內存泄露 
（1） 全局HashMap等容器，在對象不須要後沒有及時從容器中remove掉 
       特別是在拋出異常的時候，必定要確保remove方法執行到。 

（2） Runnable對象new了就必須使用線程來Run等 

Java內存泄漏的初步肯定 
下面是使用GC輸出分析內存泄漏的原理: 
 [GC 65.233: [DefNew: 12949K->1434K(13824K), 0.0122730 secs] 87703K->76189K(134892K), 0.0123500 secs] 
     (87703K->76189K(134892K), 87703K表示系統使用了多少內存(咱們稱之爲當前使用內存), 
     76189K表示進行此次垃圾回收以後使用的內存數量(咱們稱之爲垃圾回收後內存),134892K上兩個數據相減)    
  
   能夠按照以下思路分析GC輸出,可以初步比較準確地判斷系統是否存在內存泄漏: 
   (1) 首先要確保系統已經穩定運行(如初使化等已經完成等) (這個條件很重要) 
   (2) 而後取一個時間段的GC 輸出做爲分析數據，只分析FULL GC的行，以垃圾回收後的值爲分析對象 
   (3) 而後根據GC分析內存的使用狀況: 
       A. 若是當前使用內存持續增加, 而垃圾回收後內存也持續增加, 有一直增加到Xmx設置的內存的趨勢, 
       那麼這個時侯基本上就能夠判定有內存泄漏問題了. 
       B. 若是當前使用內存增加到一個值以後,又能回落, 達到一個動態平衡, 那麼就沒有內存泄漏的狀況. 

[Full GC 912526K->614350K(912576K), 2.5546922 secs] 
[Full GC 912526K->623890K(912576K), 2.5777505 secs] 
[Full GC 912575K->625359K(912576K), 2.5620272 secs] 
[Full GC 912575K->648552K(912576K), 2.5632979 secs] 
[Full GC 912532K->688576K(912576K), 2.5211377 secs] 
[Full GC 912532K->714354K(912576K), 2.6212585 secs] 
[Full GC 912538K->784362K(912576K), 2.5190768 secs] 
（1） 只有FULL GC的行纔有分析價值 
（2） 只須要檢查徹底垃圾後剩餘的內存值是否一直再增大。 

JAVA 內存泄漏精肯定位 
藉助一些工具，如：Optimizeit JProfiler、JRockit等， 
甚至可使用Java虛擬機自帶的工具HProf進行問題的定位；使用HProf的方法以下： 

java -Xrunhprof 其它參數 要運行的系統main函所在的類 
具體的參數列表以下： 
Hprof usage: -Xrunhprof[:help]|[:<option>=<value>, ...] 
Option Name and Value  Description                Default 
---------------------  ----------------------     ------- 
heap=dump|sites|all    heap profiling             all 
cpu=samples|times|old  CPU usage                  off 
monitor=y|n            monitor contention         n 
format=a|b             ascii or binary output     a 
file=<file>           write data to file         java.hprof(.txt for ascii) 
net=<host>:<port>      send data over a socket    write to file 
depth=<size>           stack trace depth          4 
cutoff=<value>         output cutoff point        0.0001 
lineno=y|n             line number in traces?     y 
thread=y|n             thread in traces?          n 
doe=y|n                dump on exit?              y 
gc_okay=y|n            GC okay during sampling    y 
Example: java -Xrunhprof:cpu=samples,file=log.txt,depth=3 FooClass 
使用HProf定位內存泄漏問題時，能夠經過經過增長參數「heap=sites」來輸出堆棧信息到文件中， 
而後經過分析堆棧信息h和線程信息來判斷內存泄漏的位置； 

JAVA 內存泄漏檢測-OptimizeIt 
使用OptimizeIt定位內存泄露確切位置的步驟： 

（1） 系統穩定運行一段時間，即按照從業務邏輯來說， 
      不該該再有大的內存需求波動。這個很是重要。 
（2） 點擊OptimizeIt上的垃圾回收按鈕，而後立刻再點mark按鈕。 
      將當前實際對象的數量做爲基準點。 
（3） 過一段時間（如一個小時或者更多） 
（4） 點擊OptimizeIt上的垃圾回收按鈕，檢查是否有大量的對象增長， 
      若是有增長，主要是哪些對象 
肯定可疑範圍，經過結合閱讀代碼進行分析。 

Unix下調試利器-Proc工具介紹 
/proc文件系統不是普通意義上的文件系統，它是一個到運行中進程地址空間的訪問接口。經過/proc，能夠用標準Unix系統調用(好比open()、read()、write()、ioctl()等等)訪問進程地址空間。 
大多數Unix(/Linux)操做系統在帶一系列的工具集，藉助這些工具，能夠對進行進行剖析，從而協助定位相關問題。 
Windows下可使用Taskinfo工具分析相似的內容 
Linux下直接到/Proc下面，大部分數據可讀。 可結合lsof進行分析 

Proc工具列表 
pcred 
pfiles 
pflags 
pldd 
pmap 
prun 
psig 
pstack 
pstop 
ptime 
ptree 
pwait 
pwdx 
plimit