记录一次 CPU飙高排查过程

2,152 阅读2分钟

定位问题

早上阿里云报警,上服务器top看了下,一个java程序的进程cpu占用到了126%。 先看一下到底是哪个线程cpu占用过高,一般cpu过高可能是线程过多或者单线程中有死循环导致cpu一直占用。

  1. 用arthas看了一下,线程数量和堆栈和堆外内存使用率正常,可以排除线程太多导致的问题。
  2. 通过top -Hp <pid>的命令,可以看到该java进程中哪一个线程cpu使用率最高。可以看到是22283线程占用比较最高。
  3. 可以直接通过jdk自带的jstack -l 看一下线程的堆栈,但是这个就是又点儿麻烦,需要吧22283转成十六进制在进行搜索线程才行,正好最近公司在试用PerfMa这个分析的工具,可以体验社区版,那不妨就试试。使用命令jstack -l > jstatck_xxx.txt将线程信息dump出来。

分析线程栈

上传到PerfMa上分析一下,然后就可以看到线程的一个大体情况。因为之前已经知道占用cpu的线程是22283,所以直接看一下这个线程的堆栈是怎么样的。

这里可以看到调用的原始方法名以及调用堆栈,其实整个方法就是在访问数据库获取数据,这里其实方法的调用栈还是比较深的,看下代码为什么会导致数据库飙高。

解决问题

通过查看代码可以看到,其实逻辑就是先获取了主表的数据,然后再去根据主表的数据查了三张子表,但是是循环去查的,主表数据又比较大,最大的时候可能3-4k行。解决方式就是将主表和子表的数据都先查出来,然后转换成map在进行循环拼装。修改之后cpu使用率下降了30%左右。

猜测是因为mybatis查询调用方法栈比较深,中间的参数装配和参数替换又会用到反射等操作,其实子表的查询还是比较快的,所以应该是cpu命令太多数据也很多导致的CPU飙高,因为直接遍历数据不进行查询其实CPU并没有飙到那么高。