執行緒轉儲分析

執行緒轉儲分析介紹

這小節我們會教你如何分析一個JVM執行緒轉儲以及如何查詢問題的根源。我們的觀點是，對於任何一個涉及Java EE的線上支援，執行緒轉儲分析都是需要掌握的最重要的技能。你從執行緒轉儲快照能拿到的資訊常常比你想象的多。

在我們深入到執行緒轉儲分析問題之前掌握基礎知識是非常重要的。

Java 虛擬機器概覽

Java虛擬機器是任何一個Java EE平臺的基礎。它是中介軟體和應用釋出以及執行的地方。

JVM提供給中介軟體軟體和Java /Java EE 程式：

• 給Java程式一個執行環境 (二進位制格式)。
• 一些程式的特性和功能裝置(IO裝置，資料結構，執行緒管理，安全，監控等)
• 通過垃圾收集來進行動態記憶體分配和管理。

JVM可以裝在很多作業系統上 (Solaris, AIX, Windows 等.)，基於你硬體伺服器的引數指標，你可以為每個物理/虛擬機器安裝多個JVM程序。

JVM 和中介軟體軟體的互動

下面這張圖展示了JVM，中介軟體和應用的概覽。

這裡給你展示了一個JVM，中介軟體和應用的典型的簡易互動圖，你可以看到，一個標準的Java EE應用的執行緒分配主要在中介軟體核心和JVM之間完成（應用本身或者一些APIs直接建立了執行緒屬於例外情況，不過這種情況很少見並且要非常小心）。

另外請記住，某些執行緒是JVM自己內部管理的比如GC(垃圾收集)執行緒，它用於處理併發垃圾收集。

在Java EE容器完成了大部分的執行緒分配之後，對你來說理解和認識執行緒棧蹤跡以及從執行緒轉儲資料里正確識別它是很重要的。這裡會讓你快速瞭解Java EE容器執行的請求型別。

從執行緒轉儲分析裡，你可以學到如何去區分JVM裡不同的執行緒池以及鑑別請求型別。

JVM 執行緒轉儲- 它是什麼?

一個JVM執行緒轉儲是一個快照，它在給定的時間提供給你一個完整的已被建立的Java執行緒列表。

每個Java執行緒給你提供如下資訊：

• 執行緒名字; 經常被中介軟體使用，用於識別執行緒的ID，它伴隨著相關的執行緒池的名字和狀態 (執行，阻塞等)

• Thread 型別 &優先順序 ex: daemon prio=3 * 中介軟體軟體通常建立它們的執行緒作為守護執行緒，這意味著這些執行緒會在後臺執行，為它們的使用者提供服務。比如你的Java EE應用。*

• Java 執行緒ID ex: tid=0x000000011e52a800 * 這是Java執行緒的ID，通過java.lang.Thread.getId()獲取，並且常常以自增的long型來實現。*

• Native 執行緒ID ex: nid=0x251c** 這是一種Native 執行緒ID，能允許你將作業系統層面上的並且在多個CPU上使用的執行緒和你的JVM關聯起來的關鍵資訊。**

• Java 執行緒狀態和詳情 ex: waiting for monitor entry [0xfffffffea5afb000] java.lang.Thread.State: BLOCKED (on object monitor)
  * 可以快速瞭解關於執行緒狀態和它潛在的當前阻塞條件。*

• Java 執行緒棧蹤跡; 這是你到目前為止能從執行緒轉儲裡獲得的最重要的資訊。這也是你在分析上花時間最多的地方，為了找出許多問題型別的根源，你需要很多的資訊，而Java棧蹤跡為你提供了90%的資訊，你可以從之後的訓練部分學到更多。

• Java 堆簡略分析： 我們用HotSpot VM 1.6作為開始,你可以線上程轉儲快照的底部找到HotSpot記憶體區的簡略分析，比如Java堆(年輕代，年老代)和持久代。這對於當頻繁GC被認為是主要原因的時候非常有用，因為它和執行緒資料/模式有很大關係。

  Heap
  PSYoungGen total 466944K, used 178734K [0xffffffff45c00000, 0xffffffff70800000, 
  0xffffffff70800000)
  eden space 233472K, 76% used 
  [0xffffffff45c00000,0xffffffff50ab7c50,0xffffffff54000000)  from space 233472K, 0% used 
  [0xffffffff62400000,0xffffffff62400000,0xffffffff70800000)  to space 233472K, 0% used 
  [0xffffffff54000000,0xffffffff54000000,0xffffffff62400000)
  PSOldGen    total 1400832K, used 1400831K [0xfffffffef0400000, 
  0xffffffff45c00000, 0xffffffff45c00000)  object space 1400832K, 99% used 
  [0xfffffffef0400000,0xffffffff45bfffb8,0xffffffff45c00000)
  PSPermGen    total 262144K, used 248475K [0xfffffffed0400000, 
  0xfffffffee0400000, 0xfffffffef0400000)  object space 262144K, 94% used 
  [0xfffffffed0400000,0xfffffffedf6a6f08,0xfffffffee0400000)
  

執行緒轉儲分析概覽

為了讓你更好的理解，下面的圖展示了一個視覺化的HotSpot虛擬機器執行緒轉儲分析，它是從普通的執行緒池裡找到的： 

這兒有一些你可以從虛擬機器執行緒轉儲裡找到的資訊。有一些資訊比其他資訊更有用，這取決於不同的問題。

現在，對於每個執行緒轉儲部分，我們都在下面列出來了詳細的分析：

Full thread dump 識別符號

這是基本的唯一識別符號，一旦產生了執行緒轉儲(比如: via kill -3 for UNIX).，你就可以從Java標準輸出日誌裡看到它。這也是執行緒轉儲快照資料的開始。

Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.0-b11 mixed mode):

Java EE 中介軟體,第三方和定製化的應用執行緒

這部分是執行緒轉儲的核心，通常會花更多時間來分析。能找到的執行緒數和你的中介軟體，第三方庫(或許有自己的執行緒)以及應用(如果建立自定義的執行緒，通常不是做好的實踐)有關。

在我們的例子中，使用的是Weblogic中介軟體。用Weblogic 9.2作為開始，它用了可以自動調節的執行緒池，並帶有“‘weblogic.kernel.Default (self-tuning)”唯一識別符號。

"[STANDBY] ExecuteThread: '414' for queue: 'weblogic.kernel.Default (selftuning)'" daemon prio=3 tid=0x000000010916a800 nid=0x2613 in Object.wait() 
[0xfffffffe9edff000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
-   waiting on <0xffffffff27d44de0> (a weblogic.work.ExecuteThread)         at java.lang.Object.wait(Object.java:485)
        at weblogic.work.ExecuteThread.waitForRequest(ExecuteThread.java:160)
-   locked <0xffffffff27d44de0> (a weblogic.work.ExecuteThread)         at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

HotSpot VM 執行緒

這是HotSpot自己管理的內部執行緒，用於服務內部的Native操作。通常你不用擔心這個，除非你的CPU佔用率很高(通過執行緒轉儲和prstat/native執行緒ID關聯)。

"VM Periodic Task Thread" prio=3 tid=0x0000000101238800 nid=0x19 waiting on condition

HotSpot GC 執行緒

當使用HotSpot的parallel GC(當使用物理多核的硬體時很常見)的時候，JVM預設會自動建立，或者根據JVM自動調整到某種GC執行緒。這些GC執行緒允許虛擬機器用並行的方式去實現週期性的GC清理，用CPU利用率作為代價，這樣可以使GC時間整體減少。

"GC task thread#0 (ParallelGC)" prio=3 tid=0x0000000100120000 nid=0x3 runnable 
"GC task thread#1 (ParallelGC)" prio=3 tid=0x0000000100131000 nid=0x4 runnable

當發生GC相關的問題比如頻繁GC，記憶體溢位等，這些資料非常關鍵，你可以使用native id值將任何一個CPU佔用高的問題和這些執行緒關聯起來。

JNI 全域性引用計數

JNI (Java Native Interface) 全域性引用是一種從native 程式碼到Java物件的基本的物件引用，由Java垃圾收集管理。它的作用是為了阻止一個物件被回收，而這個物件仍然被native程式碼使用，但是在Java程式碼裡卻沒有活的引用。

同樣重要的是為了檢測JNI相關的洩露，要時刻注意JNI引用。如果你的程式碼直接使用了JNI或者用了第三方工具比如監控工具，就會很容易導致native記憶體洩露。

JNI global references: 1925

Java 堆利用概覽

這部分資料從JDK1.6開始便加入了，它可以給你一個簡短快速的關於堆的預覽。這對於解決這種伴隨著高使用率CPU的GC相關問題非常有用。一旦你在一個快照裡得到了執行緒轉儲和堆轉儲，你就可以在同一個時間某個Java堆記憶體空間來確定(或排除)任何一個問題。在我們的例子執行緒轉儲裡，你可以看到老年代已經達到最大了！

Heap
 PSYoungGen      total 466944K, used 178734K [0xffffffff45c00000, 
0xffffffff70800000, 0xffffffff70800000)   eden space 233472K, 76% used 
[0xffffffff45c00000,0xffffffff50ab7c50,0xffffffff54000000)   from space 233472K, 0% used 
[0xffffffff62400000,0xffffffff62400000,0xffffffff70800000)   to   space 233472K, 0% used 
[0xffffffff54000000,0xffffffff54000000,0xffffffff62400000)
 PSOldGen        total 1400832K, used 1400831K [0xfffffffef0400000, 
0xffffffff45c00000, 0xffffffff45c00000)   object space 1400832K, 99% used 
[0xfffffffef0400000,0xffffffff45bfffb8,0xffffffff45c00000)
 PSPermGen       total 262144K, used 248475K [0xfffffffed0400000, 
0xfffffffee0400000, 0xfffffffef0400000)   object space 262144K, 94% used 
[0xfffffffed0400000,0xfffffffedf6a6f08,0xfffffffee0400000)

為了讓你能夠快速的從執行緒轉儲裡找到問題，你第一個要做的是理解如何去閱讀一個執行緒棧蹤跡以及如何拿到正確的資訊。意思就是說，如果我讓你告訴我執行緒#38在做什麼，你應該能知道正確答案，包括這個執行緒棧蹤跡是在一個正常環境下還是在一個阻塞環境下。

Java 棧蹤跡回顧

大多數人對Java棧蹤跡很熟悉。當發生Java異常的時候，從服務端或者應用的日誌檔案裡能找到這種典型的資料。在這裡，Java棧蹤跡給我們提供了執行緒程式碼的執行路徑，這個執行緒觸發了Java異常比如java.lang.NoClassDefFoundError, java.lang.NullPpointerException 等。這種程式碼執行路徑允許我們看到最終導致Java異常的程式碼的不同層級。

Java棧蹤跡必須從下往上讀:

• 最下面的行顯示了請求的最原始位置，比如一個Java/Java EE 容器執行緒。
• 棧蹤跡頂部第一行展示了最後一個觸發的異常Java類

讓我們通過一個簡單例子來深入這個過程。我們建立一個例子程式，簡單的執行了一些類方法並丟擲了一個異常。這個程式產生的輸出如下：

JavaStrackTraceSimulator
Author: Pierre-Hugues Charbonneau http://javaeesupportpatterns.blogspot.com
Exception in thread "main" java.lang.IllegalArgumentException: 
     at org.ph.javaee.training.td.Class2.call(Class2.java:12)      at org.ph.javaee.training.td.Class1.call(Class1.java:14)
     at org.ph.javaee.training.td.JavaSTSimulator.main(JavaSTSimulator.java:20)

• 程式JavaSTSimulator被呼叫 (通過”main”執行緒)
• 從Class1裡呼叫方法call()
• Class1的方法call()呼叫Class2的方法call()
• Class2 方法 call() 丟擲了一個異常java.lang.IllegalArgumentException
• 這個異常此時出現在了日誌或者標準輸出中。

你可以看到，指向了異常的程式碼執行路徑總是從下往上顯示的。

執行緒轉儲：執行緒棧蹤跡分析

從JVM產生的執行緒轉儲可以為你提供整個JVM程序中所有已建立執行緒的程式碼級別的執行快照。已建立的執行緒不是說所有的執行緒都在工作。產生的執行緒轉儲快照一般來自於Java EE的容器 JVM：

• 一些執行緒可以執行原始計算任務比如XML解析，IO/磁碟訪問等。
• 一些執行緒可以等待某些阻塞的IO呼叫比如遠端Web Service呼叫，資料庫查詢等。
• 一些執行緒可以在垃圾回收的時候被呼叫，比如GC執行緒。S
• 一些執行緒可能會等待任務(執行緒在進入wait()狀態時候通常不做任何工作)
• 一些執行緒會等待其他執行緒的工作然後一起完成，比如，執行緒在某些物件上等待獲取一個鎖(synchronized block{})。

執行緒棧蹤跡給你提供了當前執行的快照。通常第一行包括了執行緒的native資訊比如名字，地址等。當前執行棧蹤跡要從下往上讀。請跟著下面的分析過程一步步來。你從執行緒轉儲分析裡學到的經驗越多，你就越能更快的閱讀和定位出每個執行緒所做的工作：

• 從底部開始閱讀執行緒棧蹤跡。
• 首先，找出起始地方(Java EE容器執行緒，定製的執行緒，GC執行緒，JVM內部執行緒，單獨的Java“main”執行緒)。
• 下一步是找出這個執行緒正在執行的請求的型別 (WebApp, Web Service, JMS, Remote EJB (RMI), 內部Java EE容器等)。
• 下一步是從執行棧蹤跡裡找出你應用模組涉及的並且由這個執行緒執行的實際核心任務。分析的複雜性取決於中介軟體環境和應用的抽象層次。
• 下一步是看第一行後面10-20行。找出這個執行緒有關的協議或者任務，比如HTTP呼叫，Socket通訊，JDBC或者原始資料計算任務如磁碟訪問，類載入等。
• 下一步是看第一行。第一行通常會告知你拿到的快照裡當前程式碼塊執行時的執行緒狀態的LOT。
• 最後2個步驟的組合會給你提供重要的總結資訊，即當前執行緒有關的工作狀態或者阻塞狀態。

下面這張視覺化分析圖包括了上面的所有步驟，它用了一個真實的從JBoss 5的生成環境捕獲的執行緒轉儲例子。在這個例子中，許多執行緒顯示了一個同樣的問題，當建立新的JAX-WS Service例項的時候有頻繁的IO操作。

你可以看到，第一行後面的10行告訴了我們和執行緒有關的阻塞或者慢狀態，後面的行告訴了我們初始執行緒的詳細資訊和請求型別。