记一次cpu飙升问题排查

5,147 阅读4分钟

哈喽大家好,好久不见,工作开之后比较繁忙,在昨天线上容器突然cpu飙升,也是第一次排查这种问题所以记录一下~

前言

 首先问题是这样的,周五正在写文档,突然收到了线上报警,发现cpu占用达到了90多,上平台监控系统查看容器,在jvm监控中发现有一个pod在两个小时内产生了61次youngGc一次fullGc,这个问题特别严重且少见,由于我之前也没有排查过此类问题,所以也是百度,但整个过程也有一些自己的思考,所以跟大家分享一下~

当时场景

 我先给大家看一下一副正常的gc曲线监控(为保密性,我自己按照平台监控画了出来):

1.正常的jvm监控曲线图

2.产生问题的jvm监控曲线图

image.png 可以看的出来,正常情况下该系统很少gc(具体看业务系统使用情况、jvm内存分配),但是在图二中出现了大量异常的gc情况甚至触发了fullGc,所以我当时立马进行了分析。

具体分析

首先异常gc的情况只出现在一个pod上(系统有多个pod),在监控系统找到对应的pod,进入pod内部查看问题原因,排查问题一定要冷静

  1. 进入pod之后,输入top查看各linux进程对系统资源的使用情况(因我这是事后补稿,资源使用不高,大家看步骤即可)
  2. 分析资源使用情况在当时的情况下,image.png当时我的pid为1的进程cpu上到了130(多核)那我认定就是java应用出问题了,control+c退出继续往下走
  3. 输入top -H -p pid 通过此命令可以查看实际占用CPU最高的的线程的id,pid为刚才资源使用高的pid号
  4. 出现具体线程的资源使用情况,表格里的pid代表线程的id,我们称他为tidimage.png
  5. 我记得当时的tip为746(上述图片只是我给大家重复步骤),使用命令printf "%x\n" 746,将线程tid转换为16进制image.png,因为我们线程id号在堆栈里是16进制的所以需要做一个进制转换
  6. 输入jstack pid | grep 2ea >gc.stackimage.png解释一下,jstack是jdk给提供的监控调优小工具之一,jstack会生成JVM当前时刻的线程快照,然后我们可以通过它查看某个Java进程内的线程堆栈信息,之后我们把堆栈信息通过管道收集2ea线程的信息,然后将信息生成为gc.stack文件,我随便起的,随意
  7. 当时我先cat gc.stack 发现数据有点多在容器里看不方便,于是我下载到本地浏览,因为公司对各个机器的访问做了限制,我只能用跳板机先找到一台没用的机器a,把文件下载到a然后我再把a里的文件下载到本地(本地访问跳板机OK),先输入python -m SimpleHTTPServer 8080,linux自带python,这个是开启一个简单http服务供外界访问,image.png,然后登录跳板机,使用curl下载curl -o http://ip地址/gcInfo.stack 为方便演示,我在图中把ip换了一个假的image.png之后用同样的方法从本地下载跳板机就可以了,记得关闭python开启的建议服务嗷
  8. 把文件下载到了本地,打开查看编辑器搜索2ea,找到nid为2ea的堆栈信息, image.png,之后找到对应的impl根据行数分析程序
  9. 发现是在文件异步导出excel的时候,导出接口使用了公共列表查询接口,列表接口查询数据最多为分页200一批,而导出数据量每个人的权限几万到十几万不等image.png并且该判断方法使用了嵌套循环里判断,且结合业务很容易get不到value,guawa下的newArrayList就是返回一个newArrayList(好像不用说这么细 (;一_一 ),在整个方法结束之前,产生的lists生命周期还在所以发生多次gc触发重启之后还影响到了别的pod。然后对代码进行了fix,紧急上线,问题解决~

结束语

刚开始遇到这个情况也是比较害怕,报警直接开始循环了,自己也没有遇到过这种问题,经过这次的经历,自我感觉处理的还好,遇到问题先保证服务是否可用,如果所有pod都出现这个问题是否需要扩容pod或者重启pod,还好这个只是一个pod出现了这个问题,解决完心里也很开心。 当时心理历程就是我宁愿犯错也不愿什么都不做,太哈人了 = =,勤能补拙是良训,继续加油~