Java虚拟机六：Java进程占用cpu过高问题分析

Posted 2021-12-30 fengweiweicoder

　　在平时开发过程中，经常会碰到Java进程占用cpu过高的现象，本篇将简单记录一下自己分析该类问题的步骤。

　　1.使用 top -p <pid> 命令（<pid>为Java进程的id号）查看Java进程的cpu占用：

　　

　　该Java进程占用cpu达到92.2%。

　　2.使用 top -Hp <pid>  命令（<pid>为Java进程的id号）查看该Java进程内所有线程的资源占用情况（按shft+p按照cpu占用进行排序，按shift+m按照内存占用进行排序）此处按照cpu排序：

　　

　　可以看到，有两个线程号为97243，97912的线程占用cpu分别达到了69.2%和22.0%

　　3.使用 printf "%x\\n" <tid>  命令（tid指线程的id号）将以上10进制的线程号转换为16进制：

　　

　　转换后的结果分别为17bdb，17e78，由于16进制以0x开头，所以对应的16进制的线程号为0x17bdb和0x17e78。

　　4.使用dk自带命令jstack获取此时的线程快照并输入到文件中： jstack -l <pid> > ./jstack_result.txt 命令（<pid>为Java进程的id号）来获取线程快照结果并输入到指定文件。

　　5.查看第4步生成的txt文件，在其中搜索tid为0x17bdb的线程：

　　

　　可以看到线程号为0x17bdb（10进制线程号97243）对应的是一个"VM Thread"即虚拟机线程，这个不是与我们代码相关的线程，所以暂时忽略。

　　再看0x17e78线程：

　　

　　该线程的堆栈较深，且很明显有调用我们自己代码的逻辑，并且提示了具体的代码行数，我们查看该处代码：

　　

　　发现此处是在一个死循环里边重复的拼接字符串导致的，我们知道，String类使用contact方法拼接字符串其实是创建新的对象并返回，看到这里，似乎可以和占用cpu最高的"VM Thread"联系起来了，因此作出假设：由于代码一直循环创建对象，导致不断有不再被引用的对象产生，虚拟机检测到对象不再被引用之后，就进行垃圾回收，垃圾回收占用了很大一部分cpu资源。

　　为了证明该假设，设置jvisualvm监控，经过一段时间允许，cpu资源监控结果如下：

　　

　　可以看到cpu总占用达到88.5%，而垃圾回收活动占用cpu达到84.0%，因此证明了上述假设。

　　知道了该问题的原因后，我们还想知道此时垃圾回收的频率，耗时等信息，于是可以设置JVM参数 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log （或者使用jinfo命令动态设置GC日志，可参考http://www.importnew.com/15722.html），可以看到日志内容：

　　 

　　gc.log中频繁的打印垃圾回收，不过我们看到的基本都是Minor GC，即新生代的垃圾回收。

　　为了更清晰的查看各个区的垃圾回收情况，可以使用jstat命令 jstat -gc <pid> <period> <count>  （pid为Java进程的id，period指每次监控之间的时间间隔，count指监控次数）来监控垃圾回收，打印内容如下：

　　

　　可以看到，虚拟机在进行频繁的Full GC，每次耗时均在增长。

 

　　总结：

　　分析Java进程占用cpu过高问题时候，基本都可以按照如下步骤进行分析：

　　（1）使用 top -Hp <pid> 命令找出进程中占用cpu最高的前几个线程

　　（2）使用jstack获取线程快照，然后使用线程id搜索分析快照文件

　　（3）如果线程调用了业务相关代码，则分析是否是代码问题导致的cpu占用过高，如果线程是VM Thread，则应该监控检查垃圾回收活动频率，看是否是因为频繁进行垃圾回收导致的。