java JVM內存分配原理 JVM監控報警


java JVM內存分配原理
20130219 Chenxin

JAVA_OPTS配置
20130331 Chenxin

一.示例配置信息:
JAVA_OPTS配置,例如以下所示;

JAVA_OPTS=”-server -Xms1536m -Xmx1536m -XX:NewSize=320m -XX:MaxNewSize=320m -XX:PermSize=96m -XX:MaxPermSize=256m -Xmn500m -XX:MaxTenuringThreshold=5″
目前龍之登錄服的配置情況如下:
JAVA_OPTS="-Xms2048m -Xmx4608m -Xss256K -XX:PermSize=256m -XX:MaxPermSize=512m"
/usr/local/jdk1.6.0_31/bin/jmap -heap 11794

JDK 的JVM使用報警
20140508 Chenxin
20140616 update Chenxin

1.添加針對需要監控java的JVM的計划任務報警:
crontab -e
30 */1 * * * /root/admin/jdk_Xmx_monitor.sh #報警監控腳本見附件
原理:
Java程序時使用-Xmx和-Xms參數指定的實際上只是Java堆對象將會占用的內存。
堆只是影響Java程序占用內存數量的一個因素。
要更好的理解你的Java程序將會占用多大的內存需要先了解有哪些因素會影響到內存的占用。
這些因素包括:

  • 對象(Objects)
  • 類(Classes)
  • 線程(Theads)
  • 本地數據結構(Native data structures)
  • 本地代碼(Native code)
    每個因素對內存占用的影響又會隨着應用程序、運行環境和系統平台的不同而變化,那怎樣計算總的內存占用量?
    想得到一個准確的數字不是那么容易,因為你很難控制本地(Native)部分。
    你能控制的部分只有堆大小:-Xmx,
    類占用的內存:-XX:MaxPermSize,
    線程棧:-Xss控制每個線程占用的內存。
    注意當把棧大小設置的太小時會導致StackOverflow異常、程序出錯。
    所以,計算公式為:(java程序最大可能占用的內存總量)
    (-Xmx) + (-XX:MaxPermSize) + 線程數 * (-Xss) + 其它內存
    其它內存部分取決於本地代碼占用的內存,如NIO、socket緩沖區、JNI等。它一般大約是jvm內存的5%左右。所以假設我們有下面的JVM參數和100個線程:
    -Xmx1024m -XX:MaxPermSize=256m -Xss512k
    那么jvm進程至少會占用內存數量為:[1024m(Xmx) + 256m(MaxPermSize) + 100*512k(Xss)] * (0.05+1) = 1396.5m
    我一般使用(1.05 * 堆最大值)來作為一個近似值表示一個tomcat進程會需要的最小內存,如果你有需要增加MaxPermSize到256M以上的應用這個值可以更大些。如果你使用這個來衡量你的系統將會占用多少內存要記住你需要為系統和其它運行在系統上的程序留下足夠的內存,否則會導致系統(應該是操作系統吧)使用過多的虛擬內存,這樣會降低性能。

2.猜測:
在實際使用內存(JVM使用內存)即將達到Xmx設置大小時,應該是頻繁發生YGC和FGC,可以使用以下命令進行驗證.之后采取臨時維護,避免造成更大影響.
JVM工具的使用方法詳見<<java故障排查(jps/jstat/jmap/jinfo/jstack)>>
jstat -gcutil 10194(java pid) 1000(ms) 10(次)
S0 S1 E O P YGC YGCT FGC FGCT GCT
1.65 0.00 95.51 43.79 43.78 16 3.377 12 1.746 5.122
1.65 0.00 96.97 43.79 43.78 16 3.377 12 1.746 5.122
1.65 0.00 99.79 43.79 43.87 16 3.377 12 1.746 5.122
0.00 2.09 3.78 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 8.04 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 11.62 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 15.37 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 19.34 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 22.67 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 27.17 43.80 43.87 17 3.383 12 1.746 5.128
這里發生了一次 YG GC,耗時0.006s,O,P均未變.

3.實際服務器發生YGC和FGC的情況.
122.112.3.54 王道IOS5服:
進程如下:
/bin/java -Djava.util.logging.config.file=/home/sftproot/home/wdupdate/gameserver/wd_gs_ios_cncs_005/conf/logging.properties -Dja...ger -server -Xms1024M -Xmx1600M -Xmn360M -XX:PermSize=64M -XX:MaxPermSize=120M -XX:Survi...
抓取的GC情況如下:
while true;
do {
date +%Y/%m/%d-%H:%M:%S;
jstat -gcutil 1076 20000 10;
cat /proc/1076/status |grep VmRSS;
sleep 600;
}
done
如果是僅僅YGC的情況:
2014/05/10-19:48:55
S0 S1 E O P YGC YGCT FGC FGCT GCT
2.77 0.00 29.28 67.48 68.41 2418 14.699 6 0.194 14.893
2.77 0.00 42.45 67.48 68.41 2418 14.699 6 0.194 14.893
2.77 0.00 62.04 67.48 68.41 2418 14.699 6 0.194 14.893
2.77 0.00 73.37 67.48 68.41 2418 14.699 6 0.194 14.893
2.77 0.00 86.25 67.48 68.41 2418 14.699 6 0.194 14.893
0.00 3.71 5.75 67.48 68.41 2419 14.704 6 0.194 14.898
0.00 3.71 19.63 67.48 68.41 2419 14.704 6 0.194 14.898
0.00 3.71 30.64 67.48 68.41 2419 14.704 6 0.194 14.898
0.00 3.71 39.12 67.48 68.41 2419 14.704 6 0.194 14.898
0.00 3.71 52.29 67.48 68.41 2419 14.704 6 0.194 14.898
VmRSS: 1499164 kB
S0和S1變化,E區釋放了內存.O(old區),P(常駐內存)均無變化.
如果是FGC的情況:
2014/05/11-08:28:58
S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 3.48 52.51 69.99 68.71 3087 17.998 6 0.194 18.192
3.92 0.00 1.40 70.00 68.71 3088 18.003 6 0.194 18.196
3.92 0.00 47.40 70.00 68.71 3088 18.003 6 0.194 18.196
3.92 0.00 77.96 70.00 68.71 3088 18.003 6 0.194 18.196
3.92 0.00 99.70 70.00 68.71 3088 18.003 6 0.194 18.196
0.00 4.12 33.07 59.03 60.00 3089 18.007 8 0.228 18.235
0.00 4.12 66.25 59.03 60.01 3089 18.007 8 0.228 18.235
4.06 0.00 13.97 59.04 60.04 3090 18.012 8 0.228 18.240
4.06 0.00 57.92 59.04 60.09 3090 18.012 8 0.228 18.240
4.06 0.00 93.97 59.04 60.13 3090 18.012 8 0.228 18.240
VmRSS: 1513164 kB (進程曾經占用的最高內存,區別於VmHWM為進程當前占用的內存)
在紅色字體部分,時隔20s,發生了1次YGC,2次FGC.YGC了1次用了0.004s,FGC了2次用了0.034s.
O區和P區均有內存釋放的情況.

4.更新報警策略:(20140616)
JVM內存使用情況日志路徑:
/tmp/java_monitor_alarm_sz/
JVM報警策略修改如下:
110%以下不報警;
本次檢測小於110,上次大於110,則發送一個"No problem"的恢復提示短信;
如果超過110%,則報警;
如果上次檢測超過110,本次和上次相同,則不報警;
如果本次超過110,上次也超過110,但本次與上次值不同,則報警;
每次報警均把id,時間,占用內存百分百都記錄到日志文件里;
20140618調整:
本次比上次高2個百分點及以上才報警,否則不報;
比上次檢測記錄到的值多1個百分點,不報;
本次檢測比上次檢測值低,不報警,除非到100以內;
程序如下:

10 14 * * * killall jdk_Xmx_monitor.sh;/root/admin/jdk_Xmx_monitor.sh

cat jdk_Xmx_monitor.sh

!/bin/bash

For JDK memory Monitor

201405 By Wanglin Chenxin

201405 Modify By Chenxin

20140616 Modify By Chenxin alarm only and log

second_number=$(($RANDOM%30))

sleep "$second_number"

[ -f /etc/init.d/functions ] && . /etc/init.d/functions || . /lib/lsb/init-functions
export PATH=$PATH:/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin
which curl || yum install curl -y || apt-get install curl;

Mail alarm

function mail_alarm () {
alarm_date=date +%Y%m%d-%H:%M
curl -i -d "s=$1 $2 JDK size alarm Pid $2 $3 $4 $5 $6" -d "msg=date $alarm_date game is $1 ip is $2 pid $3 JDKusedPercent is $4 $5 $6 " http://114.112.69.229:8088/mail.php?sn=73652
}

Sms alarm /root/admin/send_sms.sh

function sms_alarm () {
alarm_date=date +%Y%m%d-%H:%M
/root/admin/send_sms.sh "$alarm_date"game"$1" ip_"$2" pid_"$3" JDKusedPercent_"$4""$5"_"$6"
}

Get Wan ip

ip=curl dbca.cn/tool/ip.php || curl ifconfig.me || curl icanhazip.com

monitor log directory and remove old log files

mkdir /tmp/java_monitor_alarm_sz/ -p
cd /tmp/java_monitor_alarm_sz/
rm -rf *_jdk_monitor.log

only allows the sigle of a jdk_Xmx_monitor.sh process at the same time

process_nums=ps -e|grep "jdk_Xmx_monitor.sh"|wc -l
if (("$process_nums" > 1));then
exit;
fi

while true;do

Judge game name,set GameName

JavaProcess=ps -ef|grep java|grep -v grep
if [ -z "$JavaProcess" ];then
exit
fi
{ echo $JavaProcess|grep xbtd >/dev/null && GameName=XBTD;} ||
{ echo $JavaProcess|grep lzll >/dev/null && GameName=LZLL;} ||
{ echo $JavaProcess|grep wdupdate >/dev/null && GameName=WDSG;} ||
{ echo $JavaProcess|grep galaxy >/dev/null && GameName=JZYH;} ||
{ GameName=Unknown;}

JavaPid=ps -e|grep java|awk '{print $1}'

for pid in echo $JavaPid
do
# Get real used mem size
#CurrMemMB=$(($(cat /proc/$i/status |grep VmHWM|awk '{print $2}')/1024))
CurrMemMB=$(($(cat /proc/$pid/status |grep VmRSS|awk '{print $2}')/1024))

# Get default JDK define size, and goto MB
JdkDefSet=`ps -ef|grep java|grep $pid|awk -F"-Xmx" '{print $2}'|awk '{print $1}'` ### MB or GB
if [ -z $JdkDefSet ];then
  MemTotal=$(($(cat /proc/meminfo|grep MemTotal|awk '{print $2}')))
  JdkDefSetMB=$(($MemTotal/1024/4))
else
  {(echo "$JdkDefSet"|grep -E "G|g") && JdkDefSetMB=$(($(echo "$JdkDefSet"|sed 's/.$//')*1024));}>/dev/null\
  ||\
  {(echo "$JdkDefSet"|grep -E "M|m") && JdkDefSetMB=$(($(echo "$JdkDefSet"|sed 's/.$//')));}>/dev/null
fi

#Calculate percent,and Judge send sms.
UsedPercent=$(($CurrMemMB*100/$JdkDefSetMB))
#echo $UsedPercent%

touch "$pid"_jdk_monitor.log
Previous_UsedPercent=`tail -n 1 "$pid"_jdk_monitor.log|awk '{ print $NF }'`
if [ -z "$Previous_UsedPercent" ];then
  Previous_UsedPercent=0
fi

if (($UsedPercent <= 110 ));then
  if (( $Previous_UsedPercent > 110 ));then
    echo $pid `date +%Y%m%d-%H:%M:%S` $UsedPercent >> "$pid"_jdk_monitor.log
    mail_alarm $GameName $ip $pid $UsedPercent % No_problem
    sms_alarm $GameName $ip $pid $UsedPercent % No_problem
  else
    continue
  fi
elif (($UsedPercent > 110 && $UsedPercent != $Previous_UsedPercent && $(($UsedPercent-$Previous_UsedPercent)) >= 2));then
  echo $pid `date +%Y%m%d-%H:%M:%S` $UsedPercent >> "$pid"_jdk_monitor.log
  mail_alarm $GameName $ip $pid $UsedPercent %
  sms_alarm $GameName $ip $pid $UsedPercent %
fi

sleep 30

done
sleep 600
done

JVM監控工具介紹
VisualVM是一種集成了多個JDK命令行工具的可視化工具,它能為您提供強大的分析能力。所有這些都是免費的!它囊括的命令行工具包括jps,jstat,jmap,jinfo,jstack,JConsole,這些工具與JDK的標准版本是一致的。

http://www.cnblogs.com/redcreen/archive/2011/05/09/2040977.html

java故障排查(jps/jstat/jmap/jinfo/jstack)
20120901 Chenxin
20140509 update

jstat 查看指定pid的java進程其GC情況 jstat -gcutil pid 5s 每隔5s打印jvm垃圾回收情況;
jmap 查看java進程內存使用相關信息;
jstack 觀察到jvm中當前所有線程的運行情況和線程當前狀態(慎用,非java進程會造成該進程以下的所有子進程被"kill"掉);
jinfo 查看和修改jvm參數;

jstat
jstat -gc pid_number 1000(ms) 2(次)
./jstat -gc 28997 1000 2 (正常)
S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
61632.0 61632.0 61632.0 0.0 925312.0 507306.8 1048576.0 289542.5 262144.0 25006.5 10 1.055 0 0.000 1.055
61632.0 61632.0 61632.0 0.0 925312.0 507306.8 1048576.0 289542.5 262144.0 25006.5 10 1.055 0 0.000 1.055
./jstat -gc 19360 1000 2 (攻擊)
S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
61440.0 61440.0 562.6 0.0 491520.0 371155.6 1701092.0 508697.9 65536.0 34627.7 736 12.428 18 0.345 12.773
61440.0 61440.0 562.6 0.0 491520.0 406063.7 1701092.0 508697.9 65536.0 34627.7 736 12.428 18 0.345 12.773
./jstat -gcutil 10194 1000 10
S0 S1 E O P YGC YGCT FGC FGCT GCT
1.65 0.00 95.51 43.79 43.78 16 3.377 12 1.746 5.122
1.65 0.00 96.97 43.79 43.78 16 3.377 12 1.746 5.122
1.65 0.00 99.79 43.79 43.87 16 3.377 12 1.746 5.122
0.00 2.09 3.78 43.80 43.87 17 3.383 12 1.746 5.128 這里發生了一次 YG GC,耗時0.006s(秒)
0.00 2.09 8.04 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 11.62 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 15.37 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 19.34 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 22.67 43.80 43.87 17 3.383 12 1.746 5.128
0.00 2.09 27.17 43.80 43.87 17 3.383 12 1.746 5.128
jstat工具特別強大,有眾多的可選項,詳細查看堆內各個部分的使用量,以及加載類的數量。使用時,需加上查看進程的進程id,和所選參數。以下詳細介紹各個參數的意義。
jstat -class pid:顯示加載class的數量,及所占空間等信息。
jstat -compiler pid:顯示VM實時編譯的數量等信息。
jstat -gc pid:可以顯示gc的信息,查看gc的次數,及時間。其中最后五項,分別是young gc的次數,young gc的時間,full gc的次數,full gc的時間,gc的總時間。
jstat -gccapacity:可以顯示,VM內存中三代(young,old,perm)對象的使用和占用大小,如:PGCMN顯示的是最小perm的內存使 用量,PGCMX顯示的是perm的內存最大使用量,PGC是當前新生成的perm內存占用量,PC是但前perm內存占用量。其他的可以根據這個類推, OC是old內純的占用量。
jstat -gcnew pid:new對象的信息。
jstat -gcnewcapacity pid:new對象的信息及其占用量。
jstat -gcold pid:old對象的信息。
jstat -gcoldcapacity pid:old對象的信息及其占用量。
jstat -gcpermcapacity pid: perm對象的信息及其占用量。
jstat -gcutil pid:統計gc信息。
jstat -printcompilation pid:當前VM執行的信息。
除了以上一個參數外,還可以同時加上 兩個數字,如:jstat -printcompilation 3024 250 6是每250毫秒打印一次,一共打印6次,還可以加上-h3每三行顯示一下標題。

實例使用1:

jstat -gcutil 25444

S0 S1 E O P YGC YGCT FGC FGCT GCT
11.63 0.00 56.46 66.92 98.49 162 0.248 6 0.331 0.579
實例使用2:(25444是java的進程號,ps -ef | grep java)

jstat -gcutil 25444 1000 5

S0 S1 E O P YGC YGCT FGC FGCT GCT
73.54->0.00 99.04 67.52 98.49 166 0.252 6 0.331 0.583
73.54 0.00 99.04 67.52 98.49 166 0.252 6 0.331 0.583
73.54 0.00 99.04 67.52 98.49 166 0.252 6 0.331 0.583
73.54 0.00 99.04 67.52 98.49 166 0.252 6 0.331 0.583
73.54 0.00 99.04 67.52 98.49 166 0.252 6 0.331 0.583
我們可以看到,5次young gc之后,垃圾內存被從Eden space區(E)放入了Old space區(O),並引起了百分比的變化,導致Survivor space使用的百分比從73.54%(S0)降到0%(S1)。有效釋放了內存空間。綠框中,我們可以看到,一次full gc之后,Old space區(O)的內存被回收,從99.05%降到67.52%。
圖中同時打印了young gc和full gc的總次數、總耗時。而,每次young gc消耗的時間,可以用相間隔的兩行YGCT相減得到。每次full gc消耗的時間,可以用相隔的兩行FGCT相減得到。例如紅框中表示的第一行、第二行之間發生了1次young gc,消耗的時間為0.252-0.252=0.0秒。
常駐內存區(P)的使用率,始終停留在98.49%左右,說明常駐內存沒有突變,比較正常。
如果young gc和full gc能夠正常發生,而且都能有效回收內存,常駐內存區變化不明顯,則說明java內存釋放情況正常,垃圾回收及時,java內存泄露的幾率就會大大降低。但也不能說明一定沒有內存泄露。
GCT 是YGCT 和FGCT的時間總和。
以上,介紹了Jstat按百分比查看gc情況的功能。其實,它還有功能,例如加載類信息統計功能、內存池信息統計功能等,那些是以絕對值的形式打印出來的,比較少用,在此就不做介紹。

使用jstack分析cpu消耗過高的問題
http://www.iteye.com/topic/1114219
我們使用jdk自帶的jstack來分析。當linux出現cpu被java程序消耗過高時,以下過程說不定可以幫上你的忙:

1.top查找出哪個進程消耗的cpu高
21125 co_ad2 18 0 1817m 776m 9712 S 3.3 4.9 12:03.24 java
5284 co_ad 21 0 3028m 2.5g 9432 S 1.0 16.3 6629:44 java
21994 mysql 15 0 449m 88m 5072 S 1.0 0.6 67582:38 mysqld
8657 co_sparr 19 0 2678m 892m 9220 S 0.3 5.7 103:06.13 java

這里我們分析21125這個java進程。

2.top中shift+h查找出哪個 線程消耗的cpu高
先輸入top,然后再按shift+h
21233 co_ad2 15 0 1807m 630m 9492 S 1.3 4.0 0:05.12 java
20503 co_ad2_s 15 0 1360m 560m 9176 S 0.3 3.6 0:46.72 java
21134 co_ad2 15 0 1807m 630m 9492 S 0.3 4.0 0:00.72 java
22673 co_ad2 15 0 1807m 630m 9492 S 0.3 4.0 0:03.12 java

這里我們分析21233這個線程,並且注意的是,這個線程是屬於21125這個 進程的。

3.jstack查找這個線程的信息
jstack [進程]|grep -A 10 [線程的16進制]
即:
Java代碼
jstack 21125|grep -A 10 52f1
-A 10表示查找到所在行的后10行。21233用計算器轉換為16進制52f1,注意字母是小寫。
結果:
Java代碼
"http-8081-11" daemon prio=10 tid=0x00002aab049a1800 nid=0x52bb in Object.wait() [0x0000000042c75000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)

JVM中對象的內存的占用情況

在查看JVM內存狀況時,除了要知道每個代的占用情況外,很多時候更要知道其中各個對象占用的內存大小,這樣便於分析對象的內存占用情況,在分析OutOfMemory的場景中尤其適用。
輸入jmap -histo [pid]即可查看jvm堆中對象的詳細占用情況。
./jmap -histo 1624
num #instances #bytes class name

1: 9331421 579571728 [C
2: 5511325 407975136 [B
3: 8640858 276507456 java.lang.String
4: 1389214 100023408 com.xd100.lzll.login.db.po.District
5: 1855350 89056800 java.nio.HeapByteBuffer
6: 1762316 84591168 java.nio.HeapCharBuffer
7: 32673 59783248 [I
8: 1892359 45446872 [[B
9: 1837555 44101320 com.mysql.jdbc.ByteArrayRow
10: 990440 39617600 java.lang.ref.SoftReference
11: 453713 29037632 sun.nio.cs.ext.GBK$Decoder
12: 453833 25414648 sun.nio.cs.ext.GBK$Encoder
13: 511274 24541152 sun.nio.cs.UTF_8$Encoder
14: 1003539 24084936 java.lang.StringCoding$StringEncoder
15: 495469 15855008 java.lang.ref.WeakReference
輸出內容按照占用空間的大小排序,例如上面的[C,表示char類型的對象在jvm中總共有243 707個實例,占用了501 638 784 bytes的空間。

導出整個JVM中的內存信息
通過以上方法能查看到JVM中對象內存的占用情況,但很多時候還要知道這個對象到底是誰創建的。例如上面顯示出來的[C,只知道它占用了那么多的空間,但不知道是什么對象創建出的[C,於是jmap提供了導出整個jvm中的內存信息的支持。基於一些jvm內存的分析工具,例如sun JDK 6中的jhat、Eclipse Memory Analyzer,可以分析jvm中內存的詳細信息,例如[C是哪些對象創建的。
執行如下命令即可導出整個jvm中的內存信息:
jmap -dump:format=b,file=文件名 [pid]
dump文件可以通過MemoryAnalyzer分析查看,網址:http://www.eclipse.org/mat/ (MemoryAnalyzer 的使用見其他筆記),可以查看dump時對象數量,內存占用,線程情況等。

jmap
./jmap -heap 24727
是一個可以輸出所有內存中對象的工具.
JVM的配置參數:
-Xms2g -Xmx2g -Xmn1024m -XX:PermSize=256m -XX:MaxPermSize=256m
Attaching to process ID 24727, please wait...
Debugger attached successfully.
Server compiler detected.
...
capacity = 1073741824 (1024.0MB)
used = 169096640 (161.26312255859375MB)
free = 904645184 (862.7368774414062MB)
15.748351812362671% used
Perm Generation:
capacity = 268435456 (256.0MB)
used = 27876864 (26.58544921875MB)
free = 240558592 (229.41455078125MB)
10.384941101074219% used

jinfo
./jinfo 24727
...

使用jstack分析cpu消耗過高的問題
1.top查找出哪個進程消耗的cpu高
21125 co_ad2 18 0 1817m 776m 9712 S 3.3 4.9 12:03.24 java
5284 co_ad 21 0 3028m 2.5g 9432 S 1.0 16.3 6629:44 java
21994 mysql 15 0 449m 88m 5072 S 1.0 0.6 67582:38 mysqld
8657 co_sparr 19 0 2678m 892m 9220 S 0.3 5.7 103:06.13 java

這里我們分析21125這個java進程。

2.top中shift+h查找出哪個 線程消耗的cpu高
先輸入top,然后再按shift+h
21233 co_ad2 15 0 1807m 630m 9492 S 1.3 4.0 0:05.12 java
20503 co_ad2_s 15 0 1360m 560m 9176 S 0.3 3.6 0:46.72 java
21134 co_ad2 15 0 1807m 630m 9492 S 0.3 4.0 0:00.72 java
22673 co_ad2 15 0 1807m 630m 9492 S 0.3 4.0 0:03.12 java

這里我們分析21233這個線程,並且注意的是,這個線程是屬於21125這個進程的。

3.jstack查找這個線程的信息
jstack [進程]|grep -A 10 [線程的16進制]
即:
jstack 21125|grep -A 10 52f1 -A 10表示查找到所在行的后10行。21233用計算器轉換為16進制52f1,注意字母是小寫。
結果:
"http-8081-11" daemon prio=10 tid=0x00002aab049a1800 nid=0x52bb in Object.wait() [0x0000000042c75000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)
說不定可以一下子定位到出問題的代碼。

排查java占用cpu過高問題:
排查步驟:
一、使用之前的top或者jdk自帶的jps,找到這個java進程的PID,假設為 2370.

二、繼續使用top命令,但這次是看這個進程包含的線程cpu使用情況,命令:top -H -P 2370 -d 1 -n 3>javaTop.log,這樣就把這個java進程包含的線程資源使用情況重定向到文件了,-d 1表示1秒刷新一次,且加上它才能重定向到文件 。-n 3 表示采樣3次。

三、使用kill -3 2370 趕緊做次threadDump,看java線程棧情況,當然也可以自己寫個腳本連續間隔着做幾次,這樣更好排除問題。做完threadDump后,把它們復制出來,可以直接用文本工具分析,大概像這樣:
圖中與公司信息相關的包名已經抹掉了。圖中的nid,是根據第二步的top中的PID轉換為16進制后,查到的。

四、其實就是第3圖中定位方法。在第二步獲取的結果中,找幾個PID,都轉換為16進制,然后到第三步的threadDump中查找,它對應的是threadDump中的nid,多查幾個更能准確說明問題。像我這定位下來,就是第三步圖中的結果,即我們去獲取某個目錄下的文件目錄個數消耗了較多的CPU。

五、這里就是根據第四步分析的threadDump,看那個類的哪行代碼是在做什么事。我們這就是IO操作,去計算某個目錄下文件個數。我叫現場人員看了下那個目錄,有幾萬個文件,而我們的代碼又是個遞歸的判斷,在這里性能非常低下,並導致CPU占用奇高無比。

六、其實沒什么好說的,定位了問題,就分析下如何解決了。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM