fullGC 频繁导致CPU飙高

鄙人上班正在摸鱼中，突然后收到领导电话服务 报 503 好吧吓死了赶紧百度

         http 503 ：因暂时超载或临时维护，您的 Web 服务器目前无法处理 HTTP 请求。 其含义是， 这是一个暂时情况，会有一些延误， 过 后将会得到缓解。 有些服务器在这种情况下也许干脆拒绝套接字（socket） 连接，在这种情况下，可能会由于套接字建立超时而产生不同的错误信息。

说白了 服务压力或者别的原因 忙不过来了

我自己组装了一笔报文 用curl 脚本发送 发现 十多秒都没返回

 

开始下面排查 以下所有截图都不是 demo 而是真实样例

指令TOP

top: 提供实时的对系统处理器的状态监视.它将显示系统中CPU最“敏感”的任务列表.该命令可以按CPU使用.内存使用和执行时间对任务进行排序

 

load average:系统负载，即任务队列的平均长度。 三个数值分别为  1分钟、5分钟、15分钟前到现在的平均值。

 

Cpu(s):显示CPU信息

75.9%us	用户空间占用CPU百分比
0.4%sy	内核和中断占用CPU百分比
0.0%ni	用户进程空间内改变过优先级的进程占用CPU百分比
23.7%id	空闲CPU百分比
0.0%wa	等待输入输出的CPU时间百分比
0.0%hi	硬中断（Hardware IRQ）占用CPU的百分比
0.0%si	软中断（Software Interrupts）占用CPU的百分比

 

查看进程里的线程情况

从此处可以看出 tid(线程)287001 - 287005很耗cpu

 

将线程id转换为16进制得到

 

执行命令 jstack 28699 | grep tid

由这几行结果可知，消耗CPU的是ParallelGC线程

 

也可以执行命令输出到文件 jstack 28699 >>28699.txt

结尾显示的nid 其实就是对应的 转换后的16进制

 

通过以上信息，我推送 最大问题就是 GC 太频繁了，三分猜 七分推理 执行如下命令

jstat -gcutil 28699 1000 1000

监视内容基本与 -gc相同，但是输出主要关注的是已使用空间占用总空间的百分比

 

我的老天 吓死宝宝了，这是什么鬼！！疯狂GC 而且看出来 回收永无止境啊

full GC 发生了 4707997 次 ，此处我参数 jstat 参数写的100毫秒太快了 应该1000合适，但是即使这样我们发现 三百毫秒执行一次full GC，而且O(老年代) 没有明显变化。这肯定不正常

 

 

 

FGCT : fullGC 耗时 单位秒      YGCT：YGC 耗时

粗略计算下 1325643 / 60/60 = 368 小时 再 /24 = 15 天

划重点上线不到一个月

 

揪出真凶

      到这里基本可以确认是有对象没有释放导致即使发生FullGC也回收不了引起的，准备dump进行分析看看Old区都是些什么妖魔鬼怪，执行命令jmap -dump:format=b,file=27641.bin 27641

生成28699.bin文件，我们借助 mat(分析) 以及jdk自带的 VisualVM

点击 文件 -->装入

 

 

 

 

 

全是字符对象

一个字符串对象占用 160多兆 而且输出的字符都是重复的

大胆推测 是不是死循环 或者是字符串拼接重复了 生成新对象，又或者字符串对象被 GCroot 不回收（假如 内存满分100 你自己占用了 95 别人来5分就得回收所以频繁）

 

我们断定是有某处代码 字符串导致的 但是我没发现这个工具怎么找到引用他的地方

再来借助 mat分析工具

这么多大对象

 

上图看到提示 

保留总大小为162565616（13.25%）字节的局部变量。内存累积在“char[]”的一个实例中，该实例由“<system class loader>”加载。

发现了 用 VM 和 mat 都怀疑这个 char,点击 See stacktrace.

 

 

 

找到了自己的代码

for 循环 定义的 index = 0 结果你  i ++  加到后年马月 循环也结束不了啊。 好想锤死写代码那人

而且这个字符串 取的 accountDetailList 和 上面VM 工具找到的字符串 就是同一段报文

 

 

OK，知道问题的根因，想解决问题就比较简单了： 将 i ++ 改成 index++

我们就先不讨论 string 拼接字符串 用 “” + “” 还是用  StringBuilder了

 

虽然短短一篇笔记 但是我折腾了2天才找到，也是第一次接触排查这种事故