记一次排查CPU高的问题

背景

将log4j.xml的日志级别从error调整为info后,进行压测发现CPU占用很高达到了90%多(之前也就是50%,60%的样子).

 

 

问题排查

 

排查思路:  看进程中的线程到底执行的是什么,导致CPU占用较高.

 

1. 使用top命令查看到底是哪个应用占用的cpu比较高

 

左边的图是日志级别为info CPU较高的服务器, 右边为输出级别为error cpu正常的服务器.

 

 

2. 使用top -Hp pid 命令查看进程中的线程

可以看到左边运行中的线程比右边要多(实际上左边运行状态的线程常态为30左右),接下来通过jstack命令查看这些线程到底在做什么

 

3. 将步骤2 找到的线程的pid 使用printf %x pid 转换为16进制,第四步使用

 

 

4. 使用jstack命令查找这个线程到底在做什么

jstack [进程]|grep -A 10 [线程的16进制]

示例： jstack 21125|grep -A 10 52f1 

-A 10表示查找到所在行的后10行。21233用计算器转换为16进制52f1，注意字母是小写。

 

这时候就可以看到具体线程执行的堆栈信息了, 可以看到有大量的线程都在执行一下的代码:

按照堆栈信息层层追踪找到了关键的属性:

 

 

查看配置文件:

 

该配置配置为true时log4j2将会获取堆栈的快照（snapshot），并遍历堆栈跟踪以查找位置信息，因此会消耗较多的时间.

 

将该配置关闭,解决了CPU高的问题

 

总结

 

排查CPU高的问题的思路:

1. 先查看对应的进程,看看是哪个进程消耗的多

2. 然后再去看进程中的线程到底在执行什么代码. 

3.找到了具体执行的代码就可以具体问题具体分析了.