模拟 Linux 因 Java 服务导致 CPU 高占用

模拟分析

Java 制造 CPU 高占用代码

@RequestMapping("/test/cpu")
@RestController
public class TestCpuController {

    @GetMapping("/while")
    public R testHeightCpu() {
        if (ShiroUtils.getUserId().toString().equals("1")) {
            List<WmsAsnSku> skus = new ArrayList<>();
            System.out.println("开始死循环制造高CPU环境……");
            while (true) {
                WmsAsnSku sku = new WmsAsnSku();
                skus.add(sku);
            }
        }
        return R.ok();
    }
}

将写好的服务在 Linux 中运行，并且调用高占用代码
输入 Linux 命令
```
top
```
发现出现 Java 服务 CPU 高占用的情况

输入 jstack 命令

jstack [pid] >jstack.txt

可能会出现：

Unable to open socket file: target process not responding or HotSpot
VM not loaded The -F option can be used when the target process is not responding

输入 jstack -F 命令（重点）
```
jstack -F [pid] >jstack-f.txt
```
在 jstack-f.txt 文本中会出现类似的日志：
```
……
Thread 382910: (state = BLOCKED)
 - io.renren.modules.wms.web.TestCpuController.testHeightCpu() @bci=30, line=27 (Compiled frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) @bci=0 (Compiled frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=100, line=62 (Compiled frame)
 - sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=6, line=43 (Compiled frame)
……
```
日志中 state = BLOCKED 表明当前这个线程处于锁定的状态。不过日志中可能会出现非常多这样的线程，但是可以使用关键字检索文本的方式来快速的获取和自身编写的代码有关的日志，比如：
```
io.renren.modules.wms.web
```
这种方式的本质其实直接搜索项目中有关接口的包，因为如果是自身代码出现逻辑问题，那么极大可能存在用户发送请求然后调用到相关代码出现的，那么就必然会经过接口的包

其次同时，在 Java 服务的控制日志中，会出现 jstack [pid] 命令的信息。（注意是在控制台日志，不是 logback 日志，所以要谨慎重启服务。重启服务前先将控制台日志备份出来）。控制台日志可能会出现如下类似的日志：
```
……
"http-nio-5699-exec-3" #43 daemon prio=5 os_prio=0 tid=0x00007f367d0f0000 nid=0x5d7be runnable [0x00007f36eb4f3000]
   java.lang.Thread.State: RUNNABLE
	at io.renren.modules.wms.web.TestCpuController.testHeightCpu(TestCpuController.java:29)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
……
```
可以看到是该线程处于 java.lang.Thread.State: RUNNABLE 的状态。

我们可以比较控制台的线程日志和 jstack 日志，两边都出现的代码在某种程度上极大可能是问题所在。剩下的就应该找到嫌疑代码，进行具体的分析。

与此同时我们可以输出如下指令，通过进程 ID 来获取高占用的线程 ID
```
top -Hp [pid]
```
获取来的线程 ID 是十进制的，需要转化为十六进制。然后可以在控制台日志中进行检索。

但是在我经历过的真实环境中（生产环境）出现了非常多的高占用，并且进行检索后发现全是 GC 相关的线程。我推断出来的理由是：我在服务启动时加入的 Xmx（Xms）参数限制了内存大小，然后因为超出了这个限制，导致 GC 开始回收对象（释放内存）。同时也得益于设置了 -Xms2g -Xmx2g -XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=1024m 参数，在 CPU 爆满的时候服务器还是可登录可执行命令的状态。