前几日早上打开邮箱收到一封监控报警邮件:某某 ip 服务器 CPU 负载较高,请研发尽快排查解决,发送时间正好是凌晨。java
其实早在去年我也处理过相似的问题,并记录下来:《一次生产 CPU 100% 排查优化实践》git
不过本次问题产生的缘由却和上次不太同样,你们能够接着往下看。github
收到邮件后我立刻登录那台服务器,看了下案发现场还在(负载依然很高)。数据库
因而我便利用这类问题的排查套路定位一遍。服务器
首先利用 top -c
将系统资源使用状况实时显示出来 (-c
参数能够完整显示命令)。工具
接着输入大写 P
将应用按照 CPU
使用率排序,第一个就是使用率最高的程序。测试
果不其然就是咱们的一个 Java
应用。优化
这个应用简单来讲就是定时跑一些报表使的,天天凌晨会触发任务调度,正常状况下几个小时就会运行完毕。spa
常规操做第二步天然是得知道这个应用中最耗 CPU
的线程到底再干吗。线程
利用 top -Hp pid
而后输入 P
依然能够按照 CPU
使用率将线程排序。
这时咱们只须要记住线程的 ID 将其转换为 16 进制存储起来,经过 jstack pid >pid.log
生成日志文件,利用刚才保存的 16 进制进程 ID
去这个线程快照中搜索便可知道消耗 CPU
的线程在干啥了。
若是你嫌麻烦,我也强烈推荐阿里开源的问题定位神器 arthas
来定位问题。
好比上述操做即可精简为一个命令 thread -n 3
便可将最忙碌的三个线程快照打印出来,很是高效。
更多关于 arthas 使用教程请参考官方文档。
因为以前忘记截图了,这里我直接得出结论吧:
最忙绿的线程是一个 GC
线程,也就意味着它在忙着作垃圾回收。
排查到这里,有经验的老司机必定会想到:多半是应用内存使用有问题致使的。
因而我经过 jstat -gcutil pid 200 50
将内存使用、gc 回收情况打印出来(每隔 200ms 打印 50次)。
从图中能够获得如下几个信息:
Eden
区和 old
区都快占满了,可见内存回收是有问题的。fgc
回收频次很高,10s 以内发生了 8 次回收((866493-866485)/ (200 *5)
)。既然是初步定位是内存问题,因此仍是得拿一分内存快照分析才能最终定位到问题。
经过命令 jmap -dump:live,format=b,file=dump.hprof pid
能够导出一份快照文件。
这时就得借助 MAT
这类的分析工具出马了。
经过这张图其实很明显能够看出,在内存中存在一个很是大的字符串,而这个字符串正好是被这个定时任务的线程引用着。
大概算了一下这个字符串所占的内存为 258m 左右,就一个字符串来讲已是很是大的对象了。
那这个字符串是咋产生的呢?
其实看上图中的引用关系及字符串的内容不难看出这是一个 insert
的 SQL
语句。
这时不得不赞叹 MAT
这个工具,他还能帮你预测出这个内存快照可能出现问题地方同时给出线程快照。
最终经过这个线程快照找到了具体的业务代码:
他调用一个写入数据库的方法,而这个方法会拼接一个 insert
语句,其中的 values
是循环拼接生成,大概以下:
<insert id="insert" parameterType="java.util.List">
insert into xx (files)
values
<foreach collection="list" item="item" separator=",">
xxx
</foreach>
</insert>
复制代码
因此一旦这个 list 很是大时,这个拼接的 SQL 语句也会很长。
经过刚才的内存分析其实能够看出这个 List
也是很是大的,也就致使了最终的这个 insert
语句占用的内存巨大。
既然找到问题缘由那就好解决了,有两个方向:
List
的大小,这个 List
也是从某张表中获取的数据,能够分页获取;这样后续的 insert
语句就会减少。SQL
长度降下来。本次问题从分析到解决花的时间并不长,也还比较典型,其中的过程再总结一下:
CPU
进程。CPU
的具体线程。dump
出快照进行分析。最后愿你们都别接到生产告警。
你的点赞与分享是对我最大的支持