前言
在日常工作中,因为编码不规范或者工具类使用不当,会导致cpu负载过高,响应时间变长,面对这样的情况,应该有一套自己的排查方法,下面分享下我个人的排查过程
过程分享
第一步** 寻找病人
通过 ps -ef|grep java 或者 jps -lm 先找出你需要排查的java应用,记录下PID
第二步 找出患病的部位
即找出该进程内最耗费CPU的线程
top -Hp pid (推荐使用) 等价于 top -p pid 然后通过shift +h 切换到线程模式
ps -Lfp pid
ps -mp pid -o THREAD, tid, time
第三步 寻问患病部位的情况
将找到的线程ID转成16进制(printf "%x\n" 18888 //得到16进度的值)通过jstack打印出线程的日志
打出进程相关线程的堆栈信息,进行分析,查看是因为什么原因导致CPU过高
jstack -l 8888 | grep 49c8 -A 100 //得到线程18888相关的后100行日志
*第四步 *分析病因
仔细分析jstack日志,看是否可以定位到出现问题的代码,如果运气好的话, 我们去排查一下相关代码,具体问题具体分析,去解决掉引起问题的代码。
在这一步,我一般会去排查一下wait 和 locked相关的日志,确认是不是线程死锁引起的,从JAVA5之后,线程Dump中可以直接报告出Java级别的死锁
如果在多线程的程序中,大量使用 synchronized,或者不适当的使用了它,会造成大量线程在临界区的入口等待,造成系统的性能大幅下降。如果在线程 DUMP中发现了这个情况,应该审查源码,改进程序。
在分析jstack日志时,主要观察一下用户级别的线程,线程会处在不同的状态,主要关心以下几个状态
Wait on condition
常见情况是该线程在sleep,等待sleep的时间到了时候,将被唤醒。还有一种有可能是网络瓶颈,这需要介绍一些网络工具或网络相关的命令去排查一下
Waiting for monitor entry
对象以“Entry Set”中等待的线程状态是“Waiting for monitor entry”
in Object.wait()
对象在“Wait Set”中等待的线程状态是“in Object.wait()”
第五步 继续寻找原因
jmap –heap 8888 打印堆的统计信息,分析JVM当前使用情况
jstat -gcutil 8888 查看一下GC情况,看是不是因为频繁的GC引起,如果是因为GC引起我会通过命令 jmap -histo:live 8888,去看一下目前堆里在TOP-K存活对象的情况,如果发现在TOP-K中发现有一些项目中的类,我会去排查代码中,在使用该类的地方,是否因为使用不当,产生了一些强引用,导致频繁的GC。
第六步 从其它方面寻找病因
分析堆内存使用情况和YGC FULL GC频率,调优应用启动的JVM参数
Jstat -gc pid /. Stat -gccapacity pid / jmap -heap pid 推荐使用前两个,第三个可能会导致进程状态变为T
在应用启动时候增加相关的GC日志参数,输出更详细的日志,来帮忙我们更准确的找到问题。
dump 日志,使用MAT加载堆文件分析日志
当然引起应用响应缓慢的原因很多,除了从JVM方面排查 ,我们应该优先从应用层面排查,比如打印出每个方法的响应时间 ,如果线上应用,可以通过btrace来定位出现问题的地方,针对响应长的链路进行排查,有可能是因为程序编码不当,有可能是因为DB慢查询引起,这个对于不同的应用,可能会有不同的情况 ,具体问题具体分析了。
常用的JVM命令jmap
jmap -histo 88888 //查看对象创建的数量
jmap -histo 8888 >a.log
jmap -histo:live 8888 查看内存中存活对象的数据和名称
jmap -dump:format=b,file=outfile.bin 8888 //dump出堆内存
jmap –heap 8888 //打印heap的概要信息
jstack
jstack -l 8888
jstat
jstat -gc 8888 2000 20(每隔2秒监控一次GC情况,共做10)