jvm cpu占用异常问题分析一例

背景

最近在生产环境和本地开发环境中，都出现了应用占用cpu 异常问题，会占满一个cpu。

环境：jdk1.8.0_161 

由于在本地开发环境也出现一样的问题，因此在开发机上进行了分析，以下都是在window机分析。

1. 查找找到jvm 对应cpu占用异常的线程

        在window上可以通过processExplorer工具，找到线程号。

        在Linux上可以使用 top -H -p pid  pid为java进程号

     2.使用jstack 找到该线程的线程执行栈

本次分析找到的线程栈为：

"pool-1-thread-1" #45 prio=5 os_prio=0 tid=0x000000001cff7800 nid=0x29b0 runnable [0x000000001eb9e000]
   java.lang.Thread.State: RUNNABLE
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1261)
	at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.poll(ScheduledThreadPoolExecutor.java:1146)
	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)

   Locked ownable synchronizers:
	- None

此时，分析进入停滞，主要原因是：这些执行代码都是jdk本身的，同时由于线程在不停的运行导致栈顶代码实际在不停的变化，导致分析进入一个错误方向。

但是可以明确的是代码中使用了这样一个线程池导致的，但是无法容易的找到是谁调用或使用的。

因此最开始怀疑是：

数据库连接池、spring-data-redis中redis 异常，通过逐步排查和屏蔽，发现依然存在这个问题，所以这个两个问题应该不是此问题的原因。这个过程花费不少时间。

因此，只剩下一种办法，那就是在ThreadPoolExecutor的构造函数中打断点，找到是什么业务代码开启了线程池。

最终在一个第二方的jar中，发现了值得高度怀疑的代码，开启线程池，具体为

ScheduledExecutorService pool = new ScheduledThreadPoolExecutor(0);

这个0 值得高度怀疑，因为既然开启线程池，但却开启0个线程。

因此另建一个工程，里面仅简单的按照此代码，建立一个demo。

运行后，果然重现此问题，修改线程数为1后，问题消失。

问题找到。

后面通过搜索，发现这是jdk的一个bug（但实际上也算是业务代码写得有问题）。

bug具体信息 https://bugs.openjdk.java.net/browse/JDK-8129861

实际上对于这个问题，应该是可以更快的找到，那就是对这个线程栈从栈顶依次向下对这些关键词进行搜索，就可以更快找到原因。比如：使用这样的关键词"ScheduledThreadPoolExecutor$DelayedWorkQueue.poll cpu" ，进行搜索，第一个结果就是这个异常的原因，当然如何更快的找到是什么业务代码调用，还需要思考？