使用jstack排查多線程死鎖、阻塞

問題:

　　針對線上多線程死鎖、阻塞，跑着跑着就卡住了

　　查看線上線程池的狀態

　　

jstack用於生成java虛擬機當前時刻的線程快照。

線程快照是當前java虛擬機內每一條線程正在執行的方法堆棧的集合，生成線程快照的主要目的是定位線程出現長時間停頓的原因，如線程間死鎖、死循環、請求外部資源導致的長時間等待等。

 

 

jstack:java堆棧跟蹤工具

jstack用於生成java虛擬機當前時刻的線程快照。

線程快照是當前java虛擬機內每一條線程正在執行的方法堆棧的集合，生成線程快照的主要目的是定位線程出現長時間停頓的原因，如線程間死鎖、死循環、請求外部資源導致的長時間等待等。

命令格式：

jstack [ option ] pid
 
jstack [ option ] executable core
 
jstack [ option ] [server-id@]remote-hostname-or-IP

 

• 執行jstack命令，將得到進程的堆棧信息。我一般使用jstack -l pid來得到長列表，顯示其詳細信息。
• 有時線程掛起的時候，需要執行jstack -F pid來獲取。
• 在實際運行中，往往一次 dump的信息，還不足以確認問題。建議產生三次 dump信息，如果每次 dump都指向同一個問題，我們才確定問題的典型性。
• 堆棧信息只是一種參考，一些正常RUNNING的線程，由於復雜網絡環境和IO的影響，也是有問題的，用jstack就無法定位，需要結合對業務代碼的理解。

 

使用：查看服務進程的線程情況

jstack -l 13109

 

 

 

 

taskExecutor- 為線程詞的名稱

java.lang.Thread.State 線程的狀態

具體為線程的執行到什么動作 代碼行數

 

一個Thread對象可以有多個狀態，在java.lang.Thread.State中，總共定義六種狀態：

1、NEW

線程剛剛被創建，也就是已經new過了，但是還沒有調用start()方法，jstack命令不會列出處於此狀態的線程信息

2、RUNNABLE #java.lang.Thread.State: RUNNABLE

RUNNABLE這個名字很具有欺騙性，很容易讓人誤以為處於這個狀態的線程正在運行。事實上，這個狀態只是表示，線程是可運行的。我們已經無數次提到過，一個單核CPU在同一時刻，只能運行一個線程。

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

線程處於阻塞狀態，正在等待一個monitor lock。通常情況下，是因為本線程與其他線程公用了一個鎖。其他在線程正在使用這個鎖進入某個synchronized同步方法塊或者方法，而本線程進入這個同步代碼塊也需要這個鎖，最終導致本線程處於阻塞狀態。

4、WAITING

等待狀態，調用以下方法可能會導致一個線程處於等待狀態：

Object.wait 不指定超時時間 # java.lang.Thread.State: WAITING (on object monitor)

Thread.join with no timeout

LockSupport.park #java.lang.Thread.State: WAITING (parking)

例如：對於wait()方法，一個線程處於等待狀態，通常是在等待其他線程完成某個操作。本線程調用某個對象的wait()方法，其他線程處於完成之后，調用同一個對象的notify或者notifyAll()方法。Object.wait()方法只能夠在同步代碼塊中調用。調用了wait()方法后，會釋放鎖。

5、TIMED_WAITING

線程等待指定的時間，對於以下方法的調用，可能會導致線程處於這個狀態：

Thread.sleep #java.lang.Thread.State: TIMED_WAITING (sleeping)

Object.wait 指定超時時間 #java.lang.Thread.State: TIMED_WAITING (on object monitor)

Thread.join with timeout

LockSupport.parkNanos #java.lang.Thread.State: TIMED_WAITING (parking)

LockSupport.parkUntil #java.lang.Thread.State: TIMED_WAITING (parking)

6、TERMINATED

線程終止。

 

 

在dump 文件里，寫法可能不太一樣：

• 死鎖，Deadlock（重點關注）
• 執行中，Runnable
• 等待資源，Waiting on condition（重點關注）
• 等待獲取監視器，Waiting on monitor entry（重點關注）
• 對象等待中，Object.wait() 或 TIMED_WAITING
• 暫停，Suspended
• 阻塞，Blocked（重點關注）
• 停止，Parked

Runnable

線程正在運行中。

一般指該線程正在執行狀態中，該線程占用了資源，正在處理某個請求，有可能正在傳遞SQL到數據庫執行，有可能在對某個文件操作，有可能進行數據類型等轉換。

Deadlock

1.  
   "t2" prio=6 tid=0x02bcf000 nid=0xc70 waiting for monitor entry [0x02f6f000]
2.  
   java.lang.Thread.State: BLOCKED (on object monitor)
3.  
   at com.demo.DeadLock $2.run(DeadLock.java:40)
4.  
   - waiting to lock <0x22a297a8> (a java.lang.Object)
5.  
   - locked <0x22a297b0> (a java.lang.Object)
6.  
   Locked ownable synchronizers:
7.  
   - None
8.  
   "t1" prio=6 tid=0x02bce400 nid=0xba0 waiting for monitor entry [0x02f1f000]
9.  
   java.lang.Thread.State: BLOCKED (on object monitor)
10.  
    at com.demo.DeadLock $1.run(DeadLock.java:25)
11.  
    - waiting to lock <0x22a297b0> (a java.lang.Object)
12.  
    - locked <0x22a297a8> (a java.lang.Object)
13.  
    Locked ownable synchronizers:
14.  
    - None

 

上面是一個典型的死鎖堆棧，t1線程lock在地址0x22a297a8，同時t2線程在waiting to lock這個地址。

更有意思的是，堆棧也記錄了發生死鎖的代碼行數，這對我們定位問題起到很大的幫助。

Wait on condition

等待資源，或等待某個條件的發生。具體原因需結合 stacktrace來分析。

常見情況是該線程在 sleep，等待 sleep的時間到了時候，將被喚醒。

關鍵字：TIMED_WAITING,sleeping,parking。TIMED_WAITING可能是調用了有超時參數的wait所引起的。

parking指線程處於掛起中。

下面是一個典型的sleep引起的Wait on condition。

 

1.  
   "thread-1" prio=10 tid=0x00007fbe985cd000 nid=0x7bc6 waiting on condition [0x00007fbe65848000]
2.  
   java.lang.Thread.State: TIMED_WAITING (sleeping)
3.  
   at java.lang.Thread.sleep(Native Method)
4.  
   at com.xxx.MonitorManager $2.run(MonitorManager.java:124)
5.  
   at java.util.concurrent.ThreadPoolExecutor $Worker.runTask(ThreadPoolExecutor.java:895)
6.  
   at java.util.concurrent.ThreadPoolExecutor $Worker.run(ThreadPoolExecutor.java:918)
7.  
   at java.lang.Thread.run(Thread.java:662)

• 如果發現有大量的線程都在處在 Wait on condition，從線程 stack看，正等待網絡讀寫，這可能是一個網絡瓶頸的征兆。因為網絡阻塞導致線程無法執行。一種情況是網絡非常忙，幾乎消耗了所有的帶寬，仍然有大量數據等待網絡讀 寫；另一種情況也可能是網絡空閑，但由於路由等問題，導致包無法正常的到達。可以結合其他網絡分析工具定位問題。如下面的堆棧，線程等待在LinkedBlockingQueue上等待數據的生成。

• 如果堆棧信息明確是應用代碼，則證明該線程正在等待資源。一般是大量讀取某資源，且該資源采用了資源鎖的情況下，線程進入等待狀態，等待資源的讀取。

1.  
   "IoWaitThread" prio=6 tid=0x0000000007334800 nid=0x2b3c waiting on condition [0x000000000893f000]
2.  
   java.lang.Thread.State: WAITING (parking)
3.  
   at sun.misc.Unsafe.park(Native Method)
4.  
   - parking to wait for <0x00000007d5c45850> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
5.  
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
6.  
   at java.util.concurrent.locks.AbstractQueuedSynchronizer $ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
7.  
   at java.util.concurrent.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:440)
8.  
   at java.util.concurrent.LinkedBlockingDeque.take(LinkedBlockingDeque.java:629)
9.  
   at com.xxx.ThreadIoWaitState $IoWaitHandler2.run(ThreadIoWaitState.java:89)
10.  
    at java.lang.Thread.run(Thread.java:662)

Waiting on monitor entry和Object.wait()

意味着線程在等待進入一個臨界區
Monitor是 Java中用以實現線程之間的互斥與協作的主要手段，它可以看成是對象或者 Class的鎖。

每一個對象都有，也僅有一個 monitor。

• 所有期待獲得鎖的線程，在鎖已經被其它線程擁有的時候，這些期待獲得鎖的線程就進入了Object Lock的entry set區域。
• 所有曾經獲得過鎖，但是由於其它必要條件不滿足而需要wait的時候，線程就進入了Object Lock的wait set區域 。
• 在wait set區域的線程獲得notify/notifyAll通知的時候，隨機的一個Thread（notify）或者是全部的Thread（notifyALL）從Object Lock的wait set區域進入了entry set中。
• 在當前擁有鎖的線程釋放掉鎖的時候，處於該Object Lock的entryset區域的線程都會搶占該鎖，但是只能有任意的一個Thread能取得該鎖，而其他線程依然在entry set中等待下次來搶占到鎖之后再執行。

看下面的堆棧，線程在等待數據庫連接池返回一個可用的鏈接

1.  
   " DB-Processor-13" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f000]
2.  
   java.lang.Thread.State: BLOCKED (on object monitor)
3.  
   at beans.ConnectionPool.getConnection(ConnectionPool.java:102)
4.  
   - waiting to lock <0xe0375410> (a beans.ConnectionPool)
5.  
   at xxx.getTodayCount(ServiceCnt.java:111)
6.  
   at xxx.ServiceCnt.insertCount(ServiceCnt.java:43)
7.  
   "DB-Processor-14" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f020]
8.  
   java.lang.Thread.State: BLOCKED (on object monitor)
9.  
   at beans.ConnectionPool.getConnection(ConnectionPool.java:102)
10.  
    - waiting to lock <0xe0375410> (a beans.ConnectionPool)
11.  
    at xxx.ServiceCnt.getTodayCount(ServiceCnt.java:111)
12.  
    at xxx.ServiceCnt.insertCount(ServiceCnt.java:43)
13.  
    " DB-Processor-3" daemon prio=5 tid=0x00928248 nid=0x8b waiting for monitor entry [0x000000000825d080]
14.  
    java.lang.Thread.State: RUNNABLE
15.  
    at oracle.jdbc.driver.OracleConnection.isClosed(OracleConnection.java:570)
16.  
    - waiting to lock <0xe03ba2e0> (a oracle.jdbc.driver.OracleConnection)
17.  
    at beans.ConnectionPool.getConnection(ConnectionPool.java:112)
18.  
    - locked <0xe0386580> (a java.util.Vector)
19.  
    - locked <0xe0375410> (a beans.ConnectionPool)
20.  
    at xxx.Cue_1700c.GetNationList(Cue_1700c.java:66)
21.  
    at org.apache.jsp.cue_1700c_jsp._jspService(cue_1700c_jsp.java:120)

 

Blocked

線程阻塞，是指當前線程執行過程中，所需要的資源長時間等待卻一直未能獲取到，被容器的線程管理器標識為阻塞狀態，可以理解為等待資源超時的線程。
如果線程處於Blocked狀態，但是原因不清楚。可以使用jstack -m pid得到線程的mixed信息。

1.  
   ----------------- t@13 -----------------
2.  
   0xff31e8b8 ___lwp_cond_wait + 0x4
3.  
   0xfea8c810 void ObjectMonitor::EnterI(Thread*) + 0x2b8
4.  
   0xfeac86b8 void ObjectMonitor::enter2(Thread*) + 0x250

 

例如，以上信息表明，線程在嘗試進入同步塊時阻塞了。