cpu使用率飙高排查过程

1、背景
     最近两周伙拼其中的一台task机器每隔几天老是报警cpu利用率飙高的问题，由于一直在忙项目。因此前几回都是经过重启任务临时解决。这种状况出现两次以后，今天终于抽出时间来排查这个问题，在此分享一下，这个cpu使用率飙高的问题的排查过程，方便你们之后遇到一样的问题能够有参考。


2、排查思路和过程
1.经过top命令查看占用cpu比较高的进程id。
       以下图所示，可以看到进程为164065这个进程cpu占比很高，629.4%，只要能眼睛没毛病的都能看出来，明显164065这个进程有猫腻。




2.既然164065这个进程有猫腻，那咱们就看看这个有猫腻的进程是个什么鬼。
      经过pe  -ef | grep164065 ,能够看到，这是伙拼的一个活动扫描任务。任务的执行内容就不说了。




3.既然164065这个jvm进程有问题，那么咱们就须要定位到这个进程里面具体是什么线程有猫腻。
      经过top -Hp 164065,能够看到原来是164069，164070，164071，164072这四个线程的cpu占比达这么高。




4.咱们再继续深刻，探探这四个线程到底是干吗的
     那么怎么看164069，164070，164071，164072这四个线程是干吗的呢？别急，咱们先转成16进制。转换以后分别是280e5，280e6，280e7，280e8



5.转成16进制之后，再经过jstack 164065能够看到具体的线程信息。
以下图所示，哈哈，终于逮到你了，原来是GC的4个线程在搞鬼。


6.为何GC的这四个线程的cpu使用占比一直这么高？
     既然是进行GC的线程，咱们固然要来看一下堆内存的情况了。经过jmap -heap 164065  咱们来简单看一下堆内存吧。WTF,新生代的空间已经用了100%，老年代的空间的使用也达到了99.87%。看到这里，估计你们都明白了。为啥GC线程会不停的占用cpu。原来是堆内存的新生代和老年代的空间不够了，须要进行fullGC和minorGC，可是每次fullGC和monorGC只能释放一点点空间，而后很快又达到了须要GC的程度。再进行GC，如此循环致使GC的线程疯狂调用。必需要强调的是，这里正好达到了即将发生OOM，可是尚未发生OOM，立马进行GC这么一个平衡。因此GC线程才能如此嚣张的占用CPU.




7. 经过jstat -GC pid，咱们来查看一下GC的频率。
     咦，图呢？很差意思，当时太激动了忘了截图了，总之minorGC和fullGC执行频率之高使人咋舌。

8.咱们继续来分析，为何堆内存会这么不够用呢。
     立马想到的就是分析dump。好，咱们经过jmap -dump:format=b,file=taskDump.bin 生产dump文件，而后经过zprofiler对堆内存进行分析（不要问我为何要手动打印dump，由于这台机器上有N个jvm进程，zprofile貌似不能指定进程）。能够看到这个dump文件里面有三个对象很是大，加在一块儿基本上有300M。而咱们这个进程的jvm 堆内存配置的最大才512M。这三个大对象都是forest包里面的，再联想到两周前才作过viewcache到forest的迁移，这两周开始出现的cpu利用率飙高的谜题终于真相大白了。





2、解决办法
      解决办法很简单，加大JVM的堆内存配置大小。同时通知一下forest那边的团队，大家的常驻堆内存的对象太大了，要不要进行优化一下。


3、总结
       由于两周以前接入了forest，结果forest的三个大对象有300M之大，而咱们的JVM配置的最大可以使用内存才512M.致使JVM堆内存中的新生代和老年代的使用内存达到了一个很巧妙的平衡（即将OOM，可是通过GC还能挽回），在这个平衡下，jvm的GC线程会去疯狂的进行minorGC和fullGC，从而致使CPU利用率飙高。经过仔细分析，把两个看似不相干的问题却联系到了一块儿。这个思路针对于一些JVM应用cpu占用飙高的问题的解决应该有所帮助，因此花了点时间记录下并分享出来。