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占用奇高无比。

六、其实没什么好说的,定位了问题,就分析下如何解决了。

posted @ 2020-04-21 14:44  ChanixChen  阅读(1917)  评论(0编辑  收藏  举报