- 前言
Java Thread Dump 是一個非常有用的應(yīng)用診斷工具, 通過thread dump出來的信息, 可以定位到你需要了解的線程, 以及這個線程的調(diào)用棧. 如果配合linux的top命令, 可以找到你的系統(tǒng)中的最耗CPU的線程代碼段, 這樣才能有針對性地進行優(yōu)化.
- 場景和實踐
? ? 2.1. 后臺系統(tǒng)一直是在黑盒運行, 除了能暫停一部分任務(wù)的執(zhí)行, 根本無法知道哪些任務(wù)耗CPU過多。所以一直以為是業(yè)務(wù)代碼的問題, 經(jīng)過各種優(yōu)化(刪減沒必要的邏輯, 合并寫操作)等等優(yōu)化, 系統(tǒng)負載還是很高. 沒什么訪問量, 后臺任務(wù)處理也就是每天幾百萬的級別, load還是達到了15以上. CPU只有4核，天天收到load告警卻無從下手, 于是乎就被迫來分析一把線程.
?
? ?2.2 系統(tǒng)跑的是java tomcat, 要觸發(fā)tomcat thread dump很簡單, 先找到tomcat對應(yīng)的進程id, 我們設(shè)置為PID
? ?【linux 命令】： ?ps -ef | grep tomcat
? ?可以找到, 然后給這個進程發(fā)送一個QUIT的信號量, 讓其觸發(fā)線程的dump, ?下面的操作先別急著動手, 等到看完2.3再動手不遲
? ? 【linux 命令】： kill -3 $PID ? / ?kill -QUIT $PID
tomcat會把thread dump的內(nèi)容輸出到控制臺
? ? ?【linux 命令】：cd $tomcathome/logs/
查看 catalina.out 文件, 把最后的跟thread相關(guān)的內(nèi)容獲取出來.
大致內(nèi)容如下:
2012
-
04
-
13
16
:
30
:
41
Full thread dump OpenJDK
64
-Bit Server VM (
1
.
6
.
0
-b09 mixed mode):
"
TP-Processor12
"
daemon prio=
10
tid=0x00000000045acc00 nid=0x7f19
in
Object.
wait
() [0x00000000483d0000..0x00000000483d0a90]
java.lang.Thread.
State:
WAITING (on object
monitor
)
at java.lang.Object.
wait
(Native Method)
- waiting on <0x00002aaab5bfce70> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.
wait
(Object.
java:
502
)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.
java:
662
)
- locked <0x00002aaab5bfce70> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.
java:
636
)
"
TP-Processor11
"
daemon prio=
10
tid=0x00000000048e3c00 nid=0x7f18
in
Object.
wait
() [0x00000000482cf000..0x00000000482cfd10]
java.lang.Thread.
State:
WAITING (on object
monitor
)
....
"
VM Thread
"
prio=
10
tid=0x00000000042ff400 nid=0x77de runnable
"
GC task thread#0 (ParallelGC)
"
prio=
10
tid=0x000000000429c400 nid=0x77d9 runnable
"
GC task thread#1 (ParallelGC)
"
prio=
10
tid=0x000000000429d800 nid=0x77da runnable
"
GC task thread#2 (ParallelGC)
"
prio=
10
tid=0x000000000429ec00 nid=0x77db runnable
"
GC task thread#3 (ParallelGC)
"
prio=
10
tid=0x00000000042a0000 nid=0x77dc runnable
"
VM Periodic Task Thread
"
prio=
10
tid=0x0000000004348400 nid=0x77e5 waiting on condition
JNI global
references:
815
Heap
PSYoungGen total
320192K
, used
178216K
[0x00002aaadce00000, 0x00002aaaf1800000, 0x00002aaaf1800000)
eden space
303744K
,
55
% used [0x00002aaadce00000,0x00002aaae718e048,0x00002aaaef6a0000)
from space
16448K
,
65
% used [0x00002aaaf0690000,0x00002aaaf110c1b0,0x00002aaaf16a0000)
to space
16320K
,
0
% used [0x00002aaaef6a0000,0x00002aaaef6a0000,0x00002aaaf0690000)
PSOldGen total
460992K
, used
425946K
[0x00002aaab3a00000, 0x00002aaacfc30000, 0x00002aaadce00000)
object space
460992K
,
92
% used [0x00002aaab3a00000,0x00002aaacd9f6a30,0x00002aaacfc30000)
PSPermGen total
56192K
, used
55353K
[0x00002aaaae600000, 0x00002aaab1ce0000, 0x00002aaab3a00000)
object space
56192K
,
98
% used [0x00002aaaae600000,0x00002aaab1c0e520,0x00002aaab1ce0000)
最后一段是系統(tǒng)的對內(nèi)存的使用情況.
?
2.3. 要知道thread dump是不會告訴你每個線程的負載情況的, 需要知道每個線程的負載情況, 還得靠top命令來查看.
? ? 【linux 命令】：top -H -p $PID
這時候, 可以看到j(luò)ava進程下各個線程的負載和內(nèi)存等使用情況. 也不用全部搞下來, 只要top幾個負載過高的記錄即可（最好按下SHIFT+T 按CPU耗時總時間倒序排序，這樣找到的top幾個是最耗CPU時間的，而且系統(tǒng)啟動時間應(yīng)該持續(xù)15分鐘以上，這樣容易看出哪個線程耗時多。）
? ? ?大致內(nèi)容如下:
Tasks:
118
total,
2
running,
116
sleeping,
0
stopped,
0
zombie
Cpu(s):
92
.
6
%us,
2
.
3
%sy,
0
.
0
%ni,
3
.
8
%id,
0
.
7
%wa,
0
.
1
%hi,
0
.
7
%si,
0
.
0
%st
Mem:
4054168k
total,
3892212k
used,
161956k
free,
115816k
buffers
Swap:
4192956k
total,
294448k
used,
3898508k
free,
2156024k
cachedPID USER PR NI VIRT RES
SHR
S %CPU %MEM TIME+ COMMAND
8091
admin
16
0
1522m 814m
9660
R
22
.
3
20
.
6
4
:
05
.
61
java
8038
admin
16
0
1522m 814m
9660
R
10
.
3
20
.
6
2
:
46
.
31
java
8043
admin
15
0
1522m 814m
9660
S
3
.
7
20
.
6
1
:
52
.
04
java
8039
admin
15
0
1522m 814m
9660
S
0
.
7
20
.
6
2
:
10
.
98
java
8041
admin
15
0
1522m 814m
9660
S
0
.
7
20
.
6
1
:
39
.
66
java
8009
admin
15
0
1522m 814m
9660
S
0
.
3
20
.
6
0
:
27
.
05
java
8040
admin
15
0
1522m 814m
9660
S
0
.
3
20
.
6
0
:
51
.
46
java
7978
admin
25
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
00
.
00
java
7980
admin
19
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
05
.
05
java
7981
admin
16
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
06
.
31
java
7982
admin
15
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
06
.
50
java
7983
admin
15
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
06
.
66
java
7984
admin
15
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
06
.
87
java
7985
admin
15
0
1522m 814m
9660
S
0
.
0
20
.
6
0
:
33
.
82
java
幾個字段跟top的字段意思是一致的, 就是這里的 PID是 線程在系統(tǒng)里面的ID, 也就是進程每創(chuàng)建一個線程, 不僅進程自己會分配ID, 系統(tǒng)也會的. 接下來的問題排查就是主要根據(jù)這個PID來走的.
?
看到上面的部分數(shù)據(jù), 當(dāng)前正在跑的任務(wù)中, CPU占用最高的幾個線程ID
?
2.4. 如果不借助工具, 自己分析的話, 可以把PID字段從10進制數(shù)改為 16進制, 然后到threaddump日志中去查找一把, 找對對應(yīng)的線程上下文信息, 就可以知道哪段代碼耗CPU最多了.
?
比如?8091? 的16進制是?1F9B, 查找 thread dump 日志中, nid=0x1F9B 的線程( 這里的nid意思是nativeid, 也就是上面講的系統(tǒng)為線程分配的ID), 然后找到相關(guān)的代碼段, 進行優(yōu)化即可.
比如
"
鏈路檢測
"
prio=
10
tid=0x00002aaafa498000 nid=0x1F9B runnable [0x0000000045fac000..0x0000000045facd10]</
div
>
java.lang.Thread.
State:
RUNNABLE
at cn.emay.sdk.communication.socket.AsynSocket$CheckConnection.run(AsynSocket.
java:
112
)
at java.lang.Thread.run(Thread.
java:
636
)
可以看出, 這是一個 發(fā)短信的客戶端的鏈路檢測引擎的系統(tǒng)負載飆升. (實際上這個線程引起的負載絕不止這么一點.)
?
2.5 第三方的jar包, 我感到頓時淚奔. 接下來是反編譯, 看詳細的代碼… 果然是有一段死循環(huán)監(jiān)聽的… 目前是像他們要一份SDK的源代碼， 或者要他們進行優(yōu)化。
?
2.6 使用工具的話, 可以看到更多一點的信息, java的tda工具就是專門分析thread dump的.
?
具體功能自己去挖掘啦.
--------------------------------------------------------------------------------------------
轉(zhuǎn)載自：
tomcat thread dump 分析
（http://www.jiacheo.org/blog/279）
更多文章、技術(shù)交流、商務(wù)合作、聯(lián)系博主
微信掃碼或搜索：z360901061
微信掃一掃加我為好友
QQ號聯(lián)系： 360901061
您的支持是博主寫作最大的動力，如果您喜歡我的文章，感覺我的文章對您有幫助，請用微信掃描下面二維碼支持博主2元、5元、10元、20元等您想捐的金額吧，狠狠點擊下面給點支持吧，站長非常感激您！手機微信長按不能支付解決辦法：請將微信支付二維碼保存到相冊，切換到微信，然后點擊微信右上角掃一掃功能，選擇支付二維碼完成支付。
【本文對您有幫助就好】元
