ThreadDump分析筆記（一） 解讀堆疊

1. 概述

隨著系統日益增大，程式碼結構日漸複雜，經過驗收測試的系統可能在實際生產環境下表現的一塌糊塗，也可能非常棒。因此通過QA並不能保證系統不會發生記憶體洩漏，往往流量越大洩露的越快，最後導致系統崩潰。比如在某個時間點系統一直出現TimeOut、或者系統突然處理速度急劇下降等問題。對於開發人員就非常棘手了，很多人根本一頭霧水，基本上就是拍腦袋瞎猜了。其實發現此類問題定位的技術主要有記憶體洩漏定位、執行緒堆疊分析等。

執行緒堆疊概述

執行緒堆疊也就是所謂的執行緒呼叫棧（都是獨立的），在Java執行緒堆疊式JVM執行緒狀態的一個瞬時快照，快照包含了當前時刻所有執行緒的執行狀態，包括每一個執行緒的呼叫棧，鎖的持有等資訊。每個虛擬機器都提供了Thread Dump的後門幫助我們匯出堆疊資訊。藉助執行緒堆疊會幫助我們迅速地縮小問題的範圍， 找到突破口， 命中目標 。

執行緒堆疊一般包含的資訊：
1、執行緒名字，ID，執行緒的數量
2、執行緒執行狀態、鎖的狀態（鎖被哪個執行緒持有，哪個執行緒在等待）
3、函式呼叫層級關係。包括了完整類名，方法名，原始碼行數

執行緒堆疊資訊的多少，依賴於你係統的複雜度，藉助堆疊資訊，可分析很多問題，如執行緒死鎖、鎖競爭、死迴圈、識別耗時操作等。在多執行緒場景下進行穩定問題分析和效能分析他是最有效的方法，多數情況甚至無需瞭解系統就可以進行相應分析。

當然，執行緒堆疊也不是萬能的，因為其是瞬時快照，所以對已消失沒有留下痕跡的資訊，是無法追蹤歷史的。這種情況只能藉助於監控系統和日誌進行分析。如連線池中的連線被哪些執行緒使用了沒有被釋放這類問題。其實也就是說執行緒堆疊分析的都是非功能性的問題。

執行緒堆疊善於分析以下問題：
1、系統無緣無故CPU過高
2、系統掛起，無響應
3、系統執行越來越慢
4、執行緒死鎖、死迴圈、餓死等。
5、由於執行緒數量太多導致系統失敗（如無法建立執行緒等）

輸出堆疊
1、unix/Linux 使用kill -3 pid 進行轉儲
2、可以使用VisualVM等直接檢視轉儲
3、JDK1.5以上的可以使用Thread.getStackTrace() 控制堆疊自動列印

2. 關於執行緒

只有實際操作了你才能更加的理解其概念，上一個DEMO

/**
 * Created by QIANG on 2017/9/29
 */
public class ThreadTest {

    Object obj1 = new Object();
    Object obj2 = new Object();

    public void  fun1(){

        synchronized (obj1){
            fun2();
        }
    }

    public void fun2(){
        synchronized (obj2){
          while (true){
              System.out.println("我要一直跑跑跑。。。");
          }
        }
    }

    public static void main(String[] args){
        ThreadTest aa = new ThreadTest();
        aa.fun1();

    }
}

這裡我是用VisualVM 列印執行緒堆疊，在完整的堆疊資訊中我們可以看到各種系統執行緒，限於篇幅原因只留下我關注的資訊

2017-10-19 10:46:09
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode):  
"main" #1 prio=5 os_prio=0 tid=0x0000000002737000 nid=0x5d1c runnable [0x000000000270f000]
  java.lang.Thread.State: RUNNABLE
        at java.io.FileOutputStream.writeBytes(Native Method)
        at java.io.FileOutputStream.write(FileOutputStream.java:326)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
        - locked <0x0000000081e1c728> (a java.io.BufferedOutputStream)
        at java.io.PrintStream.write(PrintStream.java:482)
        - locked <0x0000000081e1c0a0> (a java.io.PrintStream)
        at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
        at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
        at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
        - locked <0x0000000081e1c058> (a java.io.OutputStreamWriter)
        at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
        at java.io.PrintStream.write(PrintStream.java:527)
        - eliminated <0x0000000081e1c0a0> (a java.io.PrintStream)
        at java.io.PrintStream.print(PrintStream.java:669)
        at java.io.PrintStream.println(PrintStream.java:806)
        - locked <0x0000000081e1c0a0> (a java.io.PrintStream)
        at com.ecej.test.Thread.ThreadTest.fun2(ThreadTest.java:21)
        - locked <0x0000000081e0a300> (a java.lang.Object)
        at com.ecej.test.Thread.ThreadTest.fun1(ThreadTest.java:14)
        - locked <0x0000000081e1c0c0> (a java.lang.Object)
        at com.ecej.test.Thread.ThreadTest.main(ThreadTest.java:28)
  Locked ownable synchronizers:
        - None
"VM Thread" os_prio=2 tid=0x0000000017928800 nid=0x3160 runnable 
"VM Periodic Task Thread" os_prio=2 tid=0x000000001a2d8000 nid=0x3dac waiting on condition 

執行緒堆疊是從下往上看，藉助這些資訊當前系統做了什麼就一目瞭然了。從main執行緒堆疊看出， - locked <0x0000000081e1c0c0> (a java.lang.Object) 這句代表該執行緒已經佔有鎖，鎖ID為0x0000000081e1c0c0，這個ID是系統自動生成的，只需要知道每次列印堆疊同一ID表示同一個鎖就行了。

分析下堆疊第一行資訊
“main” （執行緒名字）#1 prio=5（執行緒優先順序） os_prio=0 tid=0x0000000002737000（執行緒ID） nid=0x5d1c（執行緒對應本地執行緒ID） runnable（執行緒狀態） [0x000000000270f000]（執行緒佔用記憶體地址）

nid=0x5d1c（執行緒對應本地執行緒ID） 這個大家看的有點懵逼，因為java我們開啟一個執行緒就必然對應JVM中一個本地執行緒，也就是說本地執行緒數和java執行緒堆疊執行緒數相同。
在linux下我們可以使用以下方式：
1. 使用ps -ef | grep java 獲得Java程式ID。
2. 使用pstack 獲得Java虛擬機器的本地執行緒的堆疊6。

如獲得Thread 8 (Thread 4067802000 (LWP 3356))，其中Thread 4067802000 (LWP 3356)都是表示為本地執行緒ID。這裡LWP 就對應了ThreadDump中的nid(native thread id ),只是nid用的是16進製表示的。分析得知，java執行緒和本地執行緒是同一個東西，本地執行緒才是真正的執行緒實體。

繼續分析標識，其中“runable”表示當前執行緒處於執行狀態。這個runable標識只能表示在JVM中此執行緒處於執行狀態，熟悉執行緒的同學一定知道，此狀態不代表真的在消耗PU。處於Runable的執行緒只能說明該執行緒沒有被阻塞在java的wait\sleep上，也沒有等待在鎖上。但如果該執行緒呼叫了本地方法，而本地方法處於等待狀態，那JVM是不知道原生程式碼中發生了什麼，儘管當前執行緒實際處於阻塞狀態，但實際顯示出來的還是runable狀態，這種情況不消耗CPU。看個例子：

java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)

在實際中socket的本地方法大多數時間是阻塞的，除非緩衝區有資料。因此我們在分析哪個執行緒在消耗大量CPU時， 不能以這個”runnable”字樣作為判斷該執行緒是否消耗CPU的依據。
我們常線上程堆疊中發現”.init”或者”.clinit”字樣的函式， 比如下面得資訊
at java.util.logging.LogManager.<clinit>(LogManager.java:156)

“.<clinit>”表示當前正在執行類的初始化。“<init>”正在執行物件得建構函式。下面說下兩種初始化：

類初始化:編譯器把類的變數初始化語句和型別得靜態初始化器都收集到cllinit方法內，只能由JVM呼叫並保證執行緒安全。再初始化前必須保證其超類已經被初始化。

並非所有的類都會擁有一個<clinit>() 方法， 在以下條件中該類不會擁有<client>() 方法：
• 該類既沒有宣告任何類變數， 也沒有靜態初始化語句；
• 該類宣告瞭類變數， 但沒有明確使用類變數初始化語句或靜態初始化語句初始化；
• 該類僅包含靜態final 變數的類變數初始化語句， 並且類變數初始化語句是編譯時常量表示式

說白話一點就是類是初始化靜態變數的，final static 直接進常量池了，不在此步驟。這一階段其實就是類載入的最後一階段。物件的初始化是代表了此物件生命週期的開始，只是呼叫了構造方法包括其裡面的內容。

3. 關於鎖

在進行堆疊解讀前再瞭解下鎖的基本常識，大家都知道wait()\sleep()的重大區別吧。相同點就是都釋放CPU，不同點就是wait()釋放鎖而sleep()不釋放。

從上邊例子的堆疊資訊可以看出鎖的重要資訊：
1、當一個執行緒佔有一個鎖時，執行緒堆疊會列印 - locked <0x0000000081e06858> (a java.io.InputStreamReader)
2、當一個執行緒正在等待其它執行緒釋放該鎖， 執行緒堆疊中會列印—waiting to lock <0x0000000081e06858>
3、當一個執行緒佔有一個鎖， 但又執行到該鎖的wait()上， 執行緒堆疊中首先列印locked,然後又會列印—waiting on <0x0000000081e06858>

從解讀中可以看出鎖有三個重要的特徵字：locked,waiting to lock,waiting on,瞭解這三個特徵字， 就能夠對鎖進行分析了 。大多數是有一個 -—waiting to lock就必然有一個locked,當然有時候你也會找不到locked，因為一個執行緒釋放鎖和另一個執行緒被喚醒有一個空窗期，這時候轉儲就會發生此種情況。

4. 關於狀態

藉助堆疊可以分析很多型別問題，CPU消耗分析是堆疊的一個重要內容，先看下java的執行緒流轉圖（圖來源於網路）

下面說下堆疊中的執行緒狀態

RUNABLE 從JVM來說，此狀態就是執行緒正在執行，但是咧，實際上他不一定消耗CPU，有可能是正在進行網路IO，此時執行緒大多數是被掛起的，只有當資料到達後，執行緒才會重新被喚醒，掛起發生在原生程式碼（Native）中,JVM其實根本就不知道（可不是呼叫wait/sleep）。

來個例子，下面的堆疊表示了當前程式正在從網路讀取資料。

Thread-39" daemon prio=1 tid=0x08646590 nid=0x666d runnable [5beb7000..5beb88b8]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)

下面這個堆疊表示了執行緒實實在在的在消耗CPU

"Thread-444" prio=1 tid=0xa4853568 nid=0x7ade runnable [0xafcf7000..0xafcf8680]
java.lang.Thread.State: RUNNABLE
at org.apache.commons.collections.ReferenceMap.getEntry(Unknown Source)
at org.apache.commons.collections.ReferenceMap.get(Unknown Source)

TIMED_WAITING(on object monitor) 表示當前執行緒被掛起一段時間，正在執行obj.wait(int time)方法

"JMX server connection timeout 16" #16 daemon prio=5 os_prio=0 tid=0x000000001a59f000 nid=0x5a74 in Object.wait() [0x000000001b7df000]
  java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x0000000081f218e0> (a [I)
        at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:168)
        - locked <0x0000000081f218e0> (a [I)
        at java.lang.Thread.run(Thread.java:748)

TIMED_WAITING(sleeping) 表示當前執行緒被掛起一段時間,即正在執行Thread.sleep(intt ime)方法

"Comm thread" daemon prio=10 tid=0x00002aaad4107400 nid=0x649f waiting on condition
[0x000000004133b000..0x000000004133ba00]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.hadoop.mapred.Task$1.run(Task.java:282)
at java.lang.Thread.run(Thread.java:619)

TIMED_WAITING(parking) 當前執行緒被掛起一段時間,即正在執行Thread.sleep(int time)方法 ，就是執行本地方法的sleep

"RMI TCP" daemon prio=6 tid=0x0ae3b800 nid=0x958 waiting on condition [0x17eff000..0x17effa94]
java.lang.Thread.State: TIMED_WAITING (parking ）

WAINTING(on object monitor) 當前執行緒被掛起， 即正在執行obj.wait()方法
(無引數的wait()方法)

"IPC Client" daemon prio=10 tid=0x00002aaad4129800 nid=0x649d in Object.wait() [0x039000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)

SO,處於TIMED_WAITING、 WAINTING狀態的執行緒一定不消耗CPU. 處於RUNNABLE的執行緒， 要結合當前執行緒程式碼的性質判斷， 是否消耗CPU.
• 如果是純Java運算程式碼， 則消耗CPU.
• 如果是網路IO,很少消耗CPU.
• 如果是原生程式碼， 結合原生程式碼的性質判斷(可以通過pstack/gstack獲取本地執行緒堆疊)，如果是純運算程式碼， 則消耗CPU, 如果被掛起， 則不消耗CPU,如果是IO,則不怎麼消耗CPU。

小結：此次從執行緒、鎖、狀態這三方面做了基礎概念的筆記整理，下面將結合實際問題進行分析。