JVM飆高排查腳本-結構分析

大家都有過遇到線上程序LOAD突然狂飆的場景，要排查到為何狂飆，我們當務之急就是要找到導致CPU飆升的原因。如果是進程級的應用，如Nginx、Apache等都還比較容易排查，但如果是JVM中的某個線程導致的，估計有人就要開始抓瞎了。

很多人都或多或少的知道有這麼一個腳本，能幫你大致定位到現場導致LOAD飆升的JVM線程，腳本大概如下。

#!/bin/ksh

# write by    : oldmanpushcart@gmail.com
# date        : 2014-01-16
# version     : 0.07

typeset top=${1:-10}
typeset pid=${2:-$(pgrep -u $USER java)}
typeset tmp_file=/tmp/java_${pid}_$$.trace

$JAVA_HOME/bin/jstack $pid > $tmp_file
ps H -eo user,pid,ppid,tid,time,%cpu --sort=%cpu --no-headers\
        | tail -$top\
        | awk -v "pid=$pid" '$2==pid{print $4"\t"$6}'\
        | while read line;
do
        typeset nid=$(echo "$line"|awk '{printf("0x%x",$1)}')
        typeset cpu=$(echo "$line"|awk '{print $2}')
        awk -v "cpu=$cpu" '/nid='"$nid"'/,/^$/{print $0"\t"(isF++?"":"cpu="cpu"%");}' $tmp_file
done

rm -f $tmp_file

現在我們就來拆解其中的原理，以及說明下類似腳本的適用範圍。

步驟1：dump當前JVM線程，保存現場

$JAVA_HOME/bin/jstack $pid > $tmp_file

​保存現場是相當的重要，因為問題轉瞬之間就會從手中熘走（但其實LOAD的統計機製也決定了，事實也並不是那麼嚴格）

​步驟2：找到當前CPU使用占比高的線程

ps H -eo user,pid,ppid,tid,time,%cpu --sort=%cpu

 

 

列說明

USER：進程歸屬用戶

PID：進程號

PPID：父進程號

TID：線程號

%CPU：線程使用CPU占比（這裏要提醒下各位，這個CPU占比是通過/proc計算得到，存在時間差）

步驟3：合並相關信息

我們需要關注的大概是3列：PID、TID、%CPU，我們通過PS拿到了TID，可以通過進製換算10-16得到jstack出來的JVM線程號​

typeset n$(echo "$line"|awk '{print $1}'|xargs -I{} echo "obase=16;{}"|bc|tr 'A-Z' 'a-z')

最後再將ps和jstack出來的信息進行一個匹配與合並。終於，得到我們最想要的信息

 

 

適用範圍說明

看似這個腳本很牛X的樣子，能直接定位到最耗費CPU的線程，開發再也不用擔心找不到線上最有問題的代碼～但，且慢，姑且注意下輸出的結果，State: WAITING 這是這個啥節奏～

這是因為ps中的%CPU數據統計來自於/proc/stat，這個份數據並非實時的，而是取決於OS對其更新的頻率，一般為1S。所以你看到的數據統計會和jstack出來的信息不一致也就是這個原因～但這份信息對持續LOAD由少數幾個線程導致的問題排查還是非常給力的，因為這些固定少數幾個線程會持續消耗CPU的資源，即使存在時間差，反正也都是這幾個線程所導致。

這裏分享下淘寶內部經常排查到的幾個有問題線程，大家如果用到了又遇到LOAD突然飆高，可以優先懷疑他們。

Forest、CatServer、Notify