从一个实际生产问题出发，教你如何排查Java进程CPU占用过高。
问题描述
最近我开发了一个流量非常大的股票数据分发服务。服务上线后，服务器的CPU占用一直很高。初期考虑到股票流量很大，而且下游支撑了很多服务的分发需求，线程之间切换频繁，CPU占用高似乎也合理。
后来，在一次交易所休市时段，我偶然上服务器top了一下，竟然发现该服务的CPU占比依然非常高：
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2652 prod 20 0 12.0g 7.8g 18008 S 202.0 57.1 117424:06 java
从上边看到，这个Java进程占用了两个CPU核心。而当前是交易所休市阶段，流量非常低，这个CPU占用肯定是不正常。于是我决定好好排查下。
问题推测
服务器负载过高？
首先是怀疑服务的确是处于非常高的负载状态。但查看服务后台监控系统发现实时流量才小十几万帧/分钟，并且这个服务属于IO密集型而不是CPU密集型，这么小的流量完全不可能占用200%CPU。
死循环？
排除掉负载问题后，只能考虑是有些线程出现了死循环。于是尝试查看线程的CPU占用情况。使用命令： top -H -p [JAVA进程号] ，如下：
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2972 prod 20 0 12.0g 7.8g 18008 R 99.9 57.1 54624:29 java
2971 prod 20 0 12.0g 7.8g 18008 R 99.9 57.1 54620:12 java
3233 prod 20 0 12.0g 7.8g 18008 S 0.3 57.1 886:17.26 java
3248 prod 20 0 12.0g 7.8g 18008 S 0.3 57.1 994:43.62 java
8902 prod 20 0 12.0g 7.8g 18008 S 0.3 57.1 511:27.79 java
......
上边的列表打印出来了这个JAVA进程的线程号(PID)、CPU占用（%CPU)等信息。呵！可以看到PID为2971和2972的线程排在前边，两个都几乎占了一个CPU核心！想必就是死循环了吧!
问题诊断
既然明确了是这两个线程的问题，那就把这两个线程找出来，看看代码逻辑便知。
这里要用到 jstack 命令,这个命令在《JVM性能监控工具总结》讲过，这里不重复。
这两个线程的PID从十进制转化为十六进制，分别是b9b和b9c，然后用这两个值去jstack结果里边查找一下，便有如下结果：
[prod@xxxxxxxxxxxx xxxx-xxxxxxxxx-service]$ jstack 2652 |egrep -A 8 "b9b|b9c"
"Pool-Default-schedule-0" #26 prio=5 os_prio=0 tid=0x00007f9eb243e000 nid=0xb9c runnable [0x00007f9e1dff6000]
java.lang.Thread.State: RUNNABLE
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.poll(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
"Pool-Monitor-schedule-0" #25 prio=5 os_prio=0 tid=0x00007f9eb2576000 nid=0xb9b runnable [0x00007f9e1e0f7000]
java.lang.Thread.State: RUNNABLE
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.poll(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
这个查询结果让人非常费解，堆栈显示这明明是java的concurrent包的代码栈，而不是业务逻辑。
然后循着Pool-Default-schedule-0和Pool-Monitor-schedule-0这两个自定义的线程池名字去找线程池调用的地方(这里说明了自定义线程池名字非常重要！)，却发现调用的地方逻辑都非常简单，诸如:
executorService.scheduleAtFixedRate(this::refreshBalancer, 0, 1, TimeUnit.MINUTES);
这根本不可能有死循环产生！
问题解决
后来利用关键字”ScheduledThreadPoolExecutor high cpu”到谷歌一搜，才发现原来是ScheduledThreadPoolExecutor在JDK8版本有bug。参考:《High processor load for ScheduledThreadPoolExecutor with 0 core threads》.
问题就是：在JDK8中，ScheduledThreadPoolExecutor的coreSize为0的话，存在CPU占用100%的BUG。
解决办法：coreSize改为非0值，或者升级到JDK9。
转载请注明来源，欢迎对文章中的引用来源进行考证，欢迎指出任何有错误或不够清晰的表达。可以在下面评论区评论，也可以邮件至 duval1024@gmail.com
