Java線(xiàn)程堆棧分析

不知覺(jué)間工作已有一年了半等,閑下來(lái)的時(shí)候總會(huì)思考下,作為一名Java程序員呐萨,不能一直停留在開(kāi)發(fā)業(yè)務(wù)使用框架上面杀饵。老話(huà)說(shuō)得好,機(jī)會(huì)是留給有準(zhǔn)備的人的谬擦,因此切距,開(kāi)始計(jì)劃看一些Java底層一點(diǎn)的東西,嘗試開(kāi)始在學(xué)習(xí)的過(guò)程中寫(xiě)博客惨远,希望和大家一起交流學(xué)習(xí)谜悟。

寫(xiě)在前面: 線(xiàn)程堆棧應(yīng)該是多線(xiàn)程類(lèi)應(yīng)用程序非功能問(wèn)題定位的最有效手段,可以說(shuō)是殺手锏北秽。線(xiàn)程堆棧最擅長(zhǎng)與分析如下類(lèi)型問(wèn)題:

  • 系統(tǒng)無(wú)緣無(wú)故CPU過(guò)高葡幸。
  • 系統(tǒng)掛起,無(wú)響應(yīng)贺氓。
  • 系統(tǒng)運(yùn)行越來(lái)越慢蔚叨。
  • 性能瓶頸(如無(wú)法充分利用CPU等)
  • 線(xiàn)程死鎖、死循環(huán)辙培,餓死等蔑水。
  • 由于線(xiàn)程數(shù)量太多導(dǎo)致系統(tǒng)失敗(如無(wú)法創(chuàng)建線(xiàn)程等)扬蕊。

如何解讀線(xiàn)程堆棧

如下面一段Java源代碼程序:

package org.ccgogoing.study.stacktrace;
/** 
 * @Author: LuoChong400
 * @Description: 測(cè)試線(xiàn)程
 * @Date: Create in 07:27 PM 2017/12/08
 */
public class MyTest {

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

        public void fun1() {
            synchronized (obj1) {
                fun2();
            }
        }
        public void fun2() {
            synchronized (obj2) {
                while (true) { //為了打印堆棧搀别,該函數(shù)堆棧分析不退出
                    System.out.print("");
                }
            }
        }
        public static void main(String[] args) {
            MyTest aa = new MyTest();
            aa.fun1();
        }
    }

在Idea 中運(yùn)行該程序,然后按下CTRL+BREAK鍵尾抑,打印出線(xiàn)程堆棧信息如下:

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

"Service Thread" daemon prio=6 tid=0x000000000c53b000 nid=0xca58 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x000000000c516000 nid=0xd390 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x000000000c515000 nid=0xcbac waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Monitor Ctrl-Break" daemon prio=6 tid=0x000000000c514000 nid=0xd148 runnable [0x000000000caee000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177)
    - locked <0x00000000d7858b50> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:154)
    at java.io.BufferedReader.readLine(BufferedReader.java:317)
    - locked <0x00000000d7858b50> (a java.io.InputStreamReader)
    at java.io.BufferedReader.readLine(BufferedReader.java:382)
    at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)

"Attach Listener" daemon prio=10 tid=0x000000000ad4a000 nid=0xd24c runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x000000000c1a8800 nid=0xd200 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x000000000ace6000 nid=0xcd74 in Object.wait() [0x000000000c13f000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000d7284858> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000d7284858> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=10 tid=0x000000000ace4800 nid=0xce34 in Object.wait() [0x000000000bf4f000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000d7284470> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000000d7284470> (a java.lang.ref.Reference$Lock)

"main" prio=6 tid=0x000000000238e800 nid=0xc940 runnable [0x00000000027af000]
   java.lang.Thread.State: RUNNABLE
    at org.ccgogoing.study.stacktrace.MyTest.fun2(MyTest.java:22)
    - locked <0x00000000d77d50c8> (a java.lang.Object)
    at org.ccgogoing.study.stacktrace.MyTest.fun1(MyTest.java:15)
    - locked <0x00000000d77d50b8> (a java.lang.Object)
    at org.ccgogoing.study.stacktrace.MyTest.main(MyTest.java:29)

"VM Thread" prio=10 tid=0x000000000ace1000 nid=0xd0a8 runnable 

"GC task thread#0 (ParallelGC)" prio=6 tid=0x00000000023a4000 nid=0xd398 runnable 

"GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000023a5800 nid=0xcc20 runnable 

"GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000023a7000 nid=0xb914 runnable 

"GC task thread#3 (ParallelGC)" prio=6 tid=0x00000000023a9000 nid=0xd088 runnable 

"VM Periodic Task Thread" prio=10 tid=0x000000000c53f000 nid=0xc1b4 waiting on condition 

JNI global references: 138

Heap
 PSYoungGen      total 36864K, used 6376K [0x00000000d7280000, 0x00000000d9b80000, 0x0000000100000000)
  eden space 31744K, 20% used [0x00000000d7280000,0x00000000d78ba0d0,0x00000000d9180000)
  from space 5120K, 0% used [0x00000000d9680000,0x00000000d9680000,0x00000000d9b80000)
  to   space 5120K, 0% used [0x00000000d9180000,0x00000000d9180000,0x00000000d9680000)
 ParOldGen       total 83456K, used 0K [0x0000000085800000, 0x000000008a980000, 0x00000000d7280000)
  object space 83456K, 0% used [0x0000000085800000,0x0000000085800000,0x000000008a980000)
 PSPermGen       total 21504K, used 3300K [0x0000000080600000, 0x0000000081b00000, 0x0000000085800000)
  object space 21504K, 15% used [0x0000000080600000,0x0000000080939290,0x0000000081b00000)

在上面這段堆棧輸出中歇父,可以看到有很多后臺(tái)線(xiàn)程和main線(xiàn)程蒂培,其中只有main線(xiàn)程屬于Java用戶(hù)線(xiàn)程,其他幾個(gè)都是虛擬機(jī)自動(dòng)創(chuàng)建的榜苫,我們分析的過(guò)程中毁渗,只關(guān)心用戶(hù)線(xiàn)程即可。

從上面的main線(xiàn)程中可以很直觀(guān)的看到當(dāng)前線(xiàn)程的調(diào)用上下文单刁,其中一個(gè)線(xiàn)程的某一層調(diào)用含義如下:

at MyTest.fun1(MyTest.java:15)
    |     |     |              |
    |     |     |              +-----當(dāng)前正在調(diào)用的函數(shù)所在的源代碼文件的行號(hào)
    |     |     +------------當(dāng)前正在調(diào)用的函數(shù)所在的源代碼文件
    |     +---------------------當(dāng)前正在調(diào)用的方法名
    +---------------------------當(dāng)前正在調(diào)用的類(lèi)名

另外灸异,堆棧中有:- locked <0x00000000d77d50b8> (a java.lang.Object)語(yǔ)句,表示該線(xiàn)程已經(jīng)占有柯鎖<0x00000000d77d50b8>,尖括號(hào)中表示鎖ID羔飞,這個(gè)事系統(tǒng)自動(dòng)產(chǎn)生的肺樟,我們只需要知道每次打印的堆棧,同一個(gè)ID表示是同一個(gè)鎖即可逻淌。每一個(gè)線(xiàn)程堆棧的第一行含義如下:

"main" prio=1 tid=0x000000000238e800 nid=0xc940 runnable [0x00000000027af000]
    |       |   |                       |           |           |
    |       |   |                       |           |           +--線(xiàn)程占用內(nèi)存地址
    |       |   |                       |           +-----------線(xiàn)程的狀態(tài)
    |       |   |                       +----線(xiàn)程對(duì)應(yīng)的本地線(xiàn)程id號(hào)
    |       |   +-------------------線(xiàn)程id
    |       +--------------------------線(xiàn)程優(yōu)先級(jí)
    +-------------------------------線(xiàn)程名稱(chēng)
    
其中需要說(shuō)明的是么伯,線(xiàn)程對(duì)應(yīng)的本地線(xiàn)程id號(hào),是指Java線(xiàn)程所對(duì)應(yīng)的虛擬機(jī)中的本地線(xiàn)程卡儒。由于Java是解析型語(yǔ)言田柔,執(zhí)行的實(shí)體是Java虛擬機(jī),因此Java語(yǔ)言中的線(xiàn)程是依附于虛擬機(jī)中的本地線(xiàn)程來(lái)運(yùn)行的骨望,實(shí)際上是本地線(xiàn)程在執(zhí)行Java線(xiàn)程代碼硬爆。

鎖的解讀

從上面的線(xiàn)程堆棧看擎鸠,線(xiàn)程堆棧中包含的直接信息為:線(xiàn)程的個(gè)數(shù)缀磕,每個(gè)線(xiàn)程調(diào)用的方法堆棧,當(dāng)前鎖的狀態(tài)劣光。線(xiàn)程的個(gè)數(shù)可以直接數(shù)出來(lái)袜蚕;線(xiàn)程調(diào)用的方法堆棧,從下向上看绢涡,即表示當(dāng)前的線(xiàn)程調(diào)用了哪個(gè)類(lèi)上的哪個(gè)方法牲剃。而鎖得狀態(tài)看起來(lái)稍微有一點(diǎn)技巧。與鎖相關(guān)的信息如下:

  • 當(dāng)一個(gè)線(xiàn)程占有一個(gè)鎖的時(shí)候雄可,線(xiàn)程的堆棧中會(huì)打印--locked<0x00000000d77d50c8>
  • 當(dāng)一個(gè)線(xiàn)程正在等待其它線(xiàn)程釋放該鎖凿傅,線(xiàn)程堆棧中會(huì)打印--waiting to lock<0x00000000d77d50c8>
  • 當(dāng)一個(gè)線(xiàn)程占有一個(gè)鎖,但又執(zhí)行到該鎖的wait()方法上滞项,線(xiàn)程堆棧中首先打印locked狭归,然后又會(huì)打印--waiting on <0x00000000d77d50c8>

線(xiàn)程狀態(tài)的解讀

借助線(xiàn)程堆棧夭坪,可以分析很多類(lèi)型的問(wèn)題文判,CPU的消耗分析即是線(xiàn)程堆棧分析的一個(gè)重要內(nèi)容;

處于TIMED_WAITING室梅、WAITING狀態(tài)的線(xiàn)程一定不消耗CPU戏仓。處于RUNNABLE的線(xiàn)程疚宇,要結(jié)合當(dāng)前代碼的性質(zhì)判斷,是否消耗CPU赏殃。

  • 如果是純Java運(yùn)算代碼敷待,則消耗CPU。
  • 如果是網(wǎng)絡(luò)IO仁热,很少消耗CPU榜揖。
  • 如果是本地代碼,要結(jié)合本地代碼的性質(zhì)判斷(可以通過(guò)pstack抗蠢、gstack獲取本地線(xiàn)程堆棧)举哟,如果是純運(yùn)算代碼,則消耗CPU迅矛,如果被掛起妨猩,則不消耗CPU,如果是IO秽褒,則不怎么消耗CPU壶硅。

如何借助線(xiàn)程堆棧分析問(wèn)題

線(xiàn)程堆棧在定位如下類(lèi)型的問(wèn)題上非常有幫助:

  • 線(xiàn)程死鎖的分析
  • Java代碼導(dǎo)致的CPU過(guò)高分析
  • 死循環(huán)分析
  • 資源不足分析
  • 性能瓶頸分析

線(xiàn)程死鎖分析

死鎖的概念就不做過(guò)多解釋了,不明白的可以去網(wǎng)上查查销斟;

兩個(gè)或超過(guò)兩個(gè)線(xiàn)程因?yàn)榄h(huán)路的鎖依賴(lài)關(guān)系而形成的鎖環(huán)庐椒,就形成了真正的死鎖,如下為死鎖喉打印的堆棧:

Found one Java-level deadlock:
=============================
"org.ccgogoing.study.stacktrace.deadlock.TestThread2":
  waiting to lock monitor 0x000000000a9ad118 (object 0x00000000d77363d0, a java.lang.Object),
  which is held by "org.ccgogoing.study.stacktrace.deadlock.TestThread1"
"org.ccgogoing.study.stacktrace.deadlock.TestThread1":
  waiting to lock monitor 0x000000000a9abc78 (object 0x00000000d77363e0, a java.lang.Object),
  which is held by "org.ccgogoing.study.stacktrace.deadlock.TestThread2"

Java stack information for the threads listed above:
===================================================
"org.ccgogoing.study.stacktrace.deadlock.TestThread2":
    at org.ccgogoing.study.stacktrace.deadlock.TestThread2.fun(TestThread2.java:35)
    - waiting to lock <0x00000000d77363d0> (a java.lang.Object)
    - locked <0x00000000d77363e0> (a java.lang.Object)
    at org.ccgogoing.study.stacktrace.deadlock.TestThread2.run(TestThread2.java:22)
"org.ccgogoing.study.stacktrace.deadlock.TestThread1":
    at org.ccgogoing.study.stacktrace.deadlock.TestThread1.fun(TestThread1.java:33)
    - waiting to lock <0x00000000d77363e0> (a java.lang.Object)
    - locked <0x00000000d77363d0> (a java.lang.Object)
    at org.ccgogoing.study.stacktrace.deadlock.TestThread1.run(TestThread1.java:20)

Found 1 deadlock.

從打印的堆棧中我們能看到"Found one Java-level deadlock:",即如果存在死鎖情況,堆棧中會(huì)直接給出死鎖的分析結(jié)果.

當(dāng)一組Java線(xiàn)程發(fā)生死鎖的時(shí)候,那么意味著Game Over,這些線(xiàn)程永遠(yuǎn)得被掛在那里了,永遠(yuǎn)不可能繼續(xù)運(yùn)行下去蚂踊。當(dāng)發(fā)生死鎖的線(xiàn)程在執(zhí)行系統(tǒng)的關(guān)鍵功能時(shí)扼睬,那么這個(gè)死鎖可能會(huì)導(dǎo)致整個(gè)系統(tǒng)癱瘓,要想恢復(fù)系統(tǒng)悴势,臨時(shí)也是唯一的規(guī)避方法是將系統(tǒng)重啟窗宇。然后趕快去修改導(dǎo)致這個(gè)死鎖的Bug。

注意:死鎖的兩個(gè)或多個(gè)線(xiàn)程是不消耗CPU的特纤,有的人認(rèn)為CPU100%的使用率是線(xiàn)程死鎖導(dǎo)致的军俊,這個(gè)說(shuō)法是完全錯(cuò)誤的。死循環(huán)捧存,并且在循環(huán)中代碼都是CPU密集型粪躬,才有可能導(dǎo)致CPU的100%使用率,像socket或者數(shù)據(jù)庫(kù)等IO操作是不怎么消耗CPU的昔穴。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末镰官,一起剝皮案震驚了整個(gè)濱河市,隨后出現(xiàn)的幾起案子吗货,更是在濱河造成了極大的恐慌泳唠,老刑警劉巖,帶你破解...
    沈念sama閱讀 222,590評(píng)論 6 517
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件宙搬,死亡現(xiàn)場(chǎng)離奇詭異笨腥,居然都是意外死亡拓哺,警方通過(guò)查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 95,157評(píng)論 3 399
  • 文/潘曉璐 我一進(jìn)店門(mén)脖母,熙熙樓的掌柜王于貴愁眉苦臉地迎上來(lái)士鸥,“玉大人,你說(shuō)我怎么就攤上這事谆级】窘福” “怎么了?”我有些...
    開(kāi)封第一講書(shū)人閱讀 169,301評(píng)論 0 362
  • 文/不壞的土叔 我叫張陵肥照,是天一觀(guān)的道長(zhǎng)鸽凶。 經(jīng)常有香客問(wèn)我,道長(zhǎng)建峭,這世上最難降的妖魔是什么玻侥? 我笑而不...
    開(kāi)封第一講書(shū)人閱讀 60,078評(píng)論 1 300
  • 正文 為了忘掉前任,我火速辦了婚禮亿蒸,結(jié)果婚禮上凑兰,老公的妹妹穿的比我還像新娘。我一直安慰自己边锁,他們只是感情好姑食,可當(dāng)我...
    茶點(diǎn)故事閱讀 69,082評(píng)論 6 398
  • 文/花漫 我一把揭開(kāi)白布。 她就那樣靜靜地躺著茅坛,像睡著了一般音半。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上贡蓖,一...
    開(kāi)封第一講書(shū)人閱讀 52,682評(píng)論 1 312
  • 那天曹鸠,我揣著相機(jī)與錄音,去河邊找鬼斥铺。 笑死彻桃,一個(gè)胖子當(dāng)著我的面吹牛,可吹牛的內(nèi)容都是我干的晾蜘。 我是一名探鬼主播邻眷,決...
    沈念sama閱讀 41,155評(píng)論 3 422
  • 文/蒼蘭香墨 我猛地睜開(kāi)眼,長(zhǎng)吁一口氣:“原來(lái)是場(chǎng)噩夢(mèng)啊……” “哼剔交!你這毒婦竟也來(lái)了纯出?” 一聲冷哼從身側(cè)響起贾漏,我...
    開(kāi)封第一講書(shū)人閱讀 40,098評(píng)論 0 277
  • 序言:老撾萬(wàn)榮一對(duì)情侶失蹤澎羞,失蹤者是張志新(化名)和其女友劉穎萤皂,沒(méi)想到半個(gè)月后,有當(dāng)?shù)厝嗽跇?shù)林里發(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 46,638評(píng)論 1 319
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡阿宅,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,701評(píng)論 3 342
  • 正文 我和宋清朗相戀三年,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了笼蛛。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片洒放。...
    茶點(diǎn)故事閱讀 40,852評(píng)論 1 353
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡,死狀恐怖滨砍,靈堂內(nèi)的尸體忽然破棺而出往湿,到底是詐尸還是另有隱情,我是刑警寧澤惋戏,帶...
    沈念sama閱讀 36,520評(píng)論 5 351
  • 正文 年R本政府宣布领追,位于F島的核電站,受9級(jí)特大地震影響响逢,放射性物質(zhì)發(fā)生泄漏绒窑。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 42,181評(píng)論 3 335
  • 文/蒙蒙 一舔亭、第九天 我趴在偏房一處隱蔽的房頂上張望些膨。 院中可真熱鬧,春花似錦钦铺、人聲如沸订雾。這莊子的主人今日做“春日...
    開(kāi)封第一講書(shū)人閱讀 32,674評(píng)論 0 25
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽(yáng)洼哎。三九已至,卻和暖如春沼本,著一層夾襖步出監(jiān)牢的瞬間噩峦,已是汗流浹背。 一陣腳步聲響...
    開(kāi)封第一講書(shū)人閱讀 33,788評(píng)論 1 274
  • 我被黑心中介騙來(lái)泰國(guó)打工抽兆, 沒(méi)想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留壕探,地道東北人。 一個(gè)月前我還...
    沈念sama閱讀 49,279評(píng)論 3 379
  • 正文 我出身青樓郊丛,卻偏偏與公主長(zhǎng)得像李请,于是被迫代替她去往敵國(guó)和親。 傳聞我的和親對(duì)象是個(gè)殘疾皇子厉熟,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,851評(píng)論 2 361

推薦閱讀更多精彩內(nèi)容