JVM调优（二）——CPU高达90%，如何定位与排查

        昨天先整理了JVM相关的命令，今天接着上次的问题，遇到了一种情况，测试压测服务，其他接口压测过程中CPU在合理范围内，就只有一个接口在压测过程中CPU上升到90%左右，记录一下排查过程。

       可能造成CPU升高的原因有很多，简单分为3大类型，9大场景，如业务类问题，并发类问题，内存类问题，如图：

   

 找出占用cpu最高的堆栈信息

1、先查看哪个进程的CPU最高

top

2、使用命令top -p <pid> ，显示java进程的内存情况，pid是你的java进程号，比如10887

top -p 10887

3、按H，获取每个线程的内存情况

4、也可以直接使用 top –H –n 1 –p 10887，就忽略第一到第三步

top –H –n 1 –p 10887

5、找到内存和cpu占用最高的线程tid，比如10904

6、将线程id 10904转为十六进制得到 dca ,此为线程id的十六进制表示

printf "%x\n" <tid>

 

7、使用jstack生成线程快照

 jstack –l 10887> 10887.log

 

8、分析快照，可以在本地打开搜索该 线程，或直接在服务器查看搜索，使用转换后的16进制线程id

grep "2a98" 10887.log -A 20

如图：

分析线程栈，找到可能导致CPU高占用的代码，如示例，在DemoController的75行

或者直接使用命令

执行 jstack 10887| grep -A 10 2a98，得到线程堆栈信息中2a98这个线程所在行的后面10行

这个示例就是查看CPU高的情况下如何去查看导致的线程及其产生的位置

        然后就是我在实际项目中的场景及其内容，在测试人员压测过程中，发现一个SDK注册接口，首次注册登录，CPU在85%左右；二次登录调用接口，CPU在90%以上，整体的吞吐量也不符合期望，尽管该接口涉及到很多RPC调用，接口涉及的业务非常复杂及多，但评估还是不应该存在现在这种情况。

        命令部分截图就不放了，如上面定位过程一致，还是先找到CPU最高的进程，发现有三个服务CPU较高，刚好是我们这边执行该接口时远程调用的相关服务；优先处理最高的一个，执行压测接口时，找到该进程的占用CPU高的线程ID，通过jstack生成线程快照，分析线程快照

      在这里就举例2个典型的分析内容，线程快照日志如下

             

如图分析，我们可以发现都是存在大量阻塞状态，第一张图，我们可以得出，它是在我们业务类的init方法中操作redis产生了阻塞。通过查看该类 这个方法中的逻辑，发现缓存的使用不规范，在该方法栈中开始的地方写入缓存，方法结束处又删除缓存；其次，该缓存内容明显是不断递增，最终形成bigkey；同样的，另外一个地方是因为分布式锁造成的，锁的使用不当不仅没有达到用锁的初衷数据唯一性，还额外造成了不能释放，CPU升高问题； 具体优化咱就不说了，后面我们分享一个redis缓存优化内容

       针对这些导致CPU升高的问题，处理以后的压测数据，不管是首次没有数据的情况下，还是二次登录，CPU都在65%左右浮动，不超过70%。

       有人可能要说了，这是上下文频繁切换，如何确定是否是和我们常说的内存类问题或并发类问题造成的呢？ 其实这里是可以凭经验给出优先级的，首先熟悉我们自己的服务，它不属于CPU密集型业务，GC来说，当然第一步我就检查了它的内存分配以及full gc次数，发现CPU飙高时以及这几天内都没有发生，所以先排除了内存原因造成的，通过线程定位找到问题，最终进行优化，搞定~

最后总结下来CPU占用很高的排查思路就是：

1、确定java进程ID

2、找到占用CPU高的线程ID

3、将线程ID转换为16进制

4、使用jstack生成线程快照

5、分析线程快照

6、解决问题