Java內存泄漏分析系列之四：jstack生成的Thread Dump日誌線程狀態

時間  2019-12-14
標籤 java 內存 泄漏 分析 系列 之四 jstack 生成 thread dump 日誌 線程 狀態 欄目 Java 简体版
原文   原文鏈接

原文地址：http://www.javatang.comhtml

Thread Dump日誌的線程信息

如下面的日誌爲例：java

"resin-22129" daemon prio=10 tid=0x00007fbe5c34e000 nid=0x4cb1 waiting on condition [0x00007fbe4ff7c000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:315)
    at com.caucho.env.thread2.ResinThread2.park(ResinThread2.java:196)
    at com.caucho.env.thread2.ResinThread2.runTasks(ResinThread2.java:147)
    at com.caucho.env.thread2.ResinThread2.run(ResinThread2.java:118)


"Timer-20" daemon prio=10 tid=0x00007fe3a4bfb800 nid=0x1a31 in Object.wait() [0x00007fe3a077a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006f0620ff0> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0x00000006f0620ff0> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

 

以上依次是：
  • "resin-22129" 線程名稱：若是使用 java.lang.Thread 類生成一個線程的時候，線程名稱爲 Thread-(數字) 的形式，這裏是resin生成的線程；
  • daemon 線程類型：線程分爲守護線程 (daemon) 和非守護線程 (non-daemon) 兩種，一般都是守護線程；
  • prio=10 線程優先級：默認爲5，數字越大優先級越高；
  • tid=0x00007fbe5c34e000 JVM線程的id：JVM內部線程的惟一標識，經過 java.lang.Thread.getId()獲取，一般用自增的方式實現；
  • nid=0x4cb1 系統線程id：對應的系統線程id（Native Thread ID)，能夠經過 top 命令進行查看，現場id是十六進制的形式；
  • waiting on condition 系統線程狀態：這裏是系統的線程狀態，具體的含義見下面 系統線程狀態 部分；
  • [0x00007fbe4ff7c000] 起始棧地址：線程堆棧調用的其實內存地址；
  • java.lang.Thread.State: WAITING (parking) JVM線程狀態：這裏標明瞭線程在代碼級別的狀態，詳細的內容見下面的 JVM線程運行狀態 部分。
  • 線程調用棧信息：下面就是當前線程調用的詳細棧信息，用於代碼的分析。堆棧信息應該從下向上解讀，由於程序調用的順序是從下向上的。

系統線程狀態 (Native Thread Status)

系統線程有以下狀態：數據庫

deadlock

死鎖線程，通常指多個線程調用期間進入了相互資源佔用，致使一直等待沒法釋放的狀況。api

runnable

通常指該線程正在執行狀態中，該線程佔用了資源，正在處理某個操做，如經過SQL語句查詢數據庫、對某個文件進行寫入等。網絡

blocked

線程正處於阻塞狀態，指當前線程執行過程當中，所須要的資源長時間等待卻一直未能獲取到，被容器的線程管理器標識爲阻塞狀態，能夠理解爲等待資源超時的線程。多線程

waiting on condition

線程正處於等待資源或等待某個條件的發生，具體的緣由須要結合下面堆棧信息進行分析。oracle

（1）若是堆棧信息明確是應用代碼，則證實該線程正在等待資源，通常是大量讀取某種資源且該資源採用了資源鎖的狀況下，線程進入等待狀態，等待資源的讀取，或者正在等待其餘線程的執行等。socket

（2）若是發現有大量的線程都正處於這種狀態，而且堆棧信息中得知正等待網絡讀寫，這是由於網絡阻塞致使線程沒法執行，頗有多是一個網絡瓶頸的徵兆：工具

  • 網絡很是繁忙，幾乎消耗了全部的帶寬，仍然有大量數據等待網絡讀寫；
  • 網絡多是空閒的，但因爲路由或防火牆等緣由，致使包沒法正常到達；

因此必定要結合系統的一些性能觀察工具進行綜合分析，好比netstat統計單位時間的發送包的數量，看是否很明顯超過了所在網絡帶寬的限制；觀察CPU的利用率，看系統態的CPU時間是否明顯大於用戶態的CPU時間。這些都指向因爲網絡帶寬所限致使的網絡瓶頸。oop

（3）還有一種常見的狀況是該線程在 sleep，等待 sleep 的時間到了，將被喚醒。

waiting for monitor entry 或 in Object.wait()

Moniter 是Java中用以實現線程之間的互斥與協做的主要手段，它能夠當作是對象或者class的鎖，每一個對象都有，也僅有一個 Monitor。

從上圖能夠看出，每一個Monitor在某個時刻只能被一個線程擁有，該線程就是 "Active Thread"，而其餘線程都是 "Waiting Thread"，分別在兩個隊列 "Entry Set"和"Waint Set"裏面等待。其中在 "Entry Set" 中等待的線程狀態是 waiting for monitor entry，在 "Wait Set" 中等待的線程狀態是 in Object.wait()。

（1）"Entry Set"裏面的線程。
咱們稱被 synchronized 保護起來的代碼段爲臨界區，對應的代碼以下：

synchronized(obj) {

}

當一個線程申請進入臨界區時，它就進入了 "Entry Set" 隊列中，這時候有兩種可能性：

  • 該Monitor不被其餘線程擁有，"Entry Set"裏面也沒有其餘等待的線程。本線程即成爲相應類或者對象的Monitor的Owner，執行臨界區裏面的代碼；此時在Thread Dump中顯示線程處於 "Runnable" 狀態。
  • 該Monitor被其餘線程擁有，本線程在 "Entry Set" 隊列中等待。此時在Thread Dump中顯示線程處於 "waiting for monity entry" 狀態。

臨界區的設置是爲了保證其內部的代碼執行的原子性和完整性，但由於臨界區在任什麼時候間只容許線程串行經過，這和咱們使用多線程的初衷是相反的。若是在多線程程序中大量使用synchronized，或者不適當的使用它，會形成大量線程在臨界區的入口等待，形成系統的性能大幅降低。若是在Thread Dump中發現這個狀況，應該審視源碼並對其進行改進。

（2）"Wait Set"裏面的線程
當線程得到了Monitor，進入了臨界區以後，若是發現線程繼續運行的條件沒有知足，它則調用對象（一般是被synchronized的對象）的wait()方法，放棄Monitor，進入 "Wait Set"隊列。只有當別的線程在該對象上調用了 notify()或者notifyAll()方法，"Wait Set"隊列中的線程才獲得機會去競爭，可是隻有一個線程得到對象的Monitor，恢復到運行態。"Wait Set"中的線程在Thread Dump中顯示的狀態爲 in Object.wait()。一般來講，

一般來講，當CPU很忙的時候關注 Runnable 狀態的線程，反之則關注 waiting for monitor entry 狀態的線程。

JVM線程運行狀態 (JVM Thread Status)

在 java.lang.Thread.State 中定義了線程的狀態：

NEW

至今還沒有啓動的線程的狀態。線程剛被建立，但還沒有啓動。

RUNNABLE

可運行線程的線程狀態。線程正在JVM中執行，有可能在等待操做系統中的其餘資源，好比處理器。

BLOCKED

受阻塞而且正在等待監視器的某一線程的線程狀態。處於受阻塞狀態的某一線程正在等待監視器鎖，以便進入一個同步的塊/方法，或者在調用 Object.wait 以後再次進入同步的塊/方法。
在Thread Dump日誌中一般顯示爲 java.lang.Thread.State: BLOCKED (on object monitor) 。

WAITING

某一等待線程的線程狀態。線程正在無期限地等待另外一個線程來執行某一個特定的操做，線程由於調用下面的方法之一而處於等待狀態：

  • 不帶超時的 Object.wait 方法，日誌中顯示爲 java.lang.Thread.State: WAITING (on object monitor)
  • 不帶超時的 Thread.join 方法
  • LockSupport.park 方法，日誌中顯示爲 java.lang.Thread.State: WAITING (parking)

TIMED_WAITING

指定了等待時間的某一等待線程的線程狀態。線程正在等待另外一個線程來執行某一個特定的操做，並設定了指定等待的時間，線程由於調用下面的方法之一而處於定時等待狀態：

  • Thread.sleep 方法
  • 指定超時值的 Object.wait 方法
  • 指定超時值的 Thread.join 方法
  • LockSupport.parkNanos
  • LockSupport.parkUntil 

TERMINATED

線程處於終止狀態。

根據Java Doc中的說明，在給定的時間上，一個只能處於上述的一種狀態之中，而且這些狀態都是JVM的狀態，跟操做系統中的線程狀態無關。

線程狀態樣例

等待狀態樣例

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

 

上面例子中，IoWaitThread 線程保持等待狀態並從 LinkedBlockingQueue 接收消息，若是 LinkedBlockingQueue 一直沒有消息，該線程的狀態將不會改變。

阻塞狀態樣例

"BLOCKED_TEST pool-1-thread-1" prio=6 tid=0x0000000006904800 nid=0x28f4 runnable [0x000000000785f000]
   java.lang.Thread.State: RUNNABLE
                at java.io.FileOutputStream.writeBytes(Native Method)
                at java.io.FileOutputStream.write(FileOutputStream.java:282)
                at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
                at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
                - locked <0x0000000780a31778> (a java.io.BufferedOutputStream)
                at java.io.PrintStream.write(PrintStream.java:432)
                - locked <0x0000000780a04118> (a java.io.PrintStream)
                at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
                at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
                at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:85)
                - locked <0x0000000780a040c0> (a java.io.OutputStreamWriter)
                at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:168)
                at java.io.PrintStream.newLine(PrintStream.java:496)
                - locked <0x0000000780a04118> (a java.io.PrintStream)
                at java.io.PrintStream.println(PrintStream.java:687)
                - locked <0x0000000780a04118> (a java.io.PrintStream)
                at com.nbp.theplatform.threaddump.ThreadBlockedState.monitorLock(ThreadBlockedState.java:44)
                - locked <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
                at com.nbp.theplatform.threaddump.ThreadBlockedState$1.run(ThreadBlockedState.java:7)
                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                at java.lang.Thread.run(Thread.java:662)
   Locked ownable synchronizers:
                - <0x0000000780a31758> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
"BLOCKED_TEST pool-1-thread-2" prio=6 tid=0x0000000007673800 nid=0x260c waiting for monitor entry [0x0000000008abf000]
   java.lang.Thread.State: BLOCKED (on object monitor)
                at com.nbp.theplatform.threaddump.ThreadBlockedState.monitorLock(ThreadBlockedState.java:43)
                - waiting to lock <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
                at com.nbp.theplatform.threaddump.ThreadBlockedState$2.run(ThreadBlockedState.java:26)
                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                at java.lang.Thread.run(Thread.java:662)
   Locked ownable synchronizers:
                - <0x0000000780b0c6a0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
"BLOCKED_TEST pool-1-thread-3" prio=6 tid=0x00000000074f5800 nid=0x1994 waiting for monitor entry [0x0000000008bbf000]
   java.lang.Thread.State: BLOCKED (on object monitor)
                at com.nbp.theplatform.threaddump.ThreadBlockedState.monitorLock(ThreadBlockedState.java:42)
                - waiting to lock <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
                at com.nbp.theplatform.threaddump.ThreadBlockedState$3.run(ThreadBlockedState.java:34)
                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                at java.lang.Thread.run(Thread.java:662)
   Locked ownable synchronizers:
                - <0x0000000780b0e1b8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

在上面的例子中，BLOCKED_TEST pool-1-thread-1 線程佔用了 <0x0000000780a000b0> 鎖，然而 BLOCKED_TEST pool-1-thread-2 和 BLOCKED_TEST pool-1-thread-3 threads 正在等待獲取鎖。

死鎖狀態樣例

"DEADLOCK_TEST-1" daemon prio=6 tid=0x000000000690f800 nid=0x1820 waiting for monitor entry [0x000000000805f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)
                - waiting to lock <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)
                - locked <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

   Locked ownable synchronizers:
                - None

"DEADLOCK_TEST-2" daemon prio=6 tid=0x0000000006858800 nid=0x17b8 waiting for monitor entry [0x000000000815f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)
                - waiting to lock <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)
                - locked <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

   Locked ownable synchronizers:
                - None

"DEADLOCK_TEST-3" daemon prio=6 tid=0x0000000006859000 nid=0x25dc waiting for monitor entry [0x000000000825f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)
                - waiting to lock <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)
                - locked <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

   Locked ownable synchronizers:
                - None

上面的例子中，當線程 A 須要獲取線程 B 的鎖來繼續它的任務，然而線程 B 也須要獲取線程 A 的鎖來繼續它的任務的時候發生的。在 thread dump 中，你能看到 DEADLOCK_TEST-1 線程持有 0x00000007d58f5e48 鎖，而且嘗試獲取 0x00000007d58f5e60 鎖。你也能看到 DEADLOCK_TEST-2 線程持有 0x00000007d58f5e60，而且嘗試獲取 0x00000007d58f5e78，同時 DEADLOCK_TEST-3 線程持有 0x00000007d58f5e78，而且在嘗試獲取 0x00000007d58f5e48 鎖，如你所見，每一個線程都在等待獲取另一個線程的鎖，這狀態將不會被改變直到一個線程丟棄了它的鎖。

無限等待的Runnable狀態樣例

"socketReadThread" prio=6 tid=0x0000000006a0d800 nid=0x1b40 runnable [0x00000000089ef000]
   java.lang.Thread.State: RUNNABLE
                at java.net.SocketInputStream.socketRead0(Native Method)
                at java.net.SocketInputStream.read(SocketInputStream.java:129)
                at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
                at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
                at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
                - locked <0x00000007d78a2230> (a java.io.InputStreamReader)
                at sun.nio.cs.StreamDecoder.read0(StreamDecoder.java:107)
                - locked <0x00000007d78a2230> (a java.io.InputStreamReader)
                at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:93)
                at java.io.InputStreamReader.read(InputStreamReader.java:151)
                at com.nbp.theplatform.threaddump.ThreadSocketReadState$1.run(ThreadSocketReadState.java:27)
                at java.lang.Thread.run(Thread.java:662)

上例中線程的狀態是RUNNABLE，但在下面的堆棧日誌中發現socketReadThread 線程正在無限等待讀取 socket，所以不能單純經過線程的狀態來肯定線程是否處於阻塞狀態，應該根據詳細的堆棧信息進行分析。

下一節將講述常見的Thread Dump日誌案例分析。

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程