JVM CPU使用率飆高問題的排查分析過程

問題現(xiàn)象

排查過程

問題現(xiàn)象

首先，我們一起看看通過 VisualVM 監(jiān)控到的機器 CPU 使用率圖：

如上圖所示，在 下午3:45 分之前，CPU 的使用率明顯飆高，最高飆到近 100%，為什么會出現(xiàn)這樣的現(xiàn)象呢？

排查過程

Step 1： 使用top命令，查詢資源占用情況：

如上圖所示，顯示了服務(wù)器當(dāng)前的資源占用情況，其中PID為5456的進程占用的資源最多。

在這里，我們也使用top -p PID命令，查詢指定PID的資源占用情況：

Step 2： 使用ps -mp PID -o THREAD,tid,time命令，查詢該進程的線程情況：

在這里，我們也使用ps -mp PID -o THREAD,tid,time | sort -rn命令，將該進程下的線程按資源使用情況倒序展示：

Step 3： 使用printf "%x " PID命令，將PID轉(zhuǎn)為十六進制的TID：

在這里，我們之所以需要將PID轉(zhuǎn)為十六進制是因為在堆棧信息中，PID是以十六進制形式存在的。

Step 4： 使用jstack PID | grep TID -A 100命令，查詢堆棧信息：

如上圖所示，顯示該進程下多個線程均處于TIMED_WAITING狀態(tài)。

雖然線程處于WAITING或者TIMED_WAITING狀態(tài)都不會消耗 CPU，但是線程頻繁的掛起和喚醒卻會消耗 CPU，而且代價高昂。

而上面之所以會出現(xiàn) CPU 使用率飆高的情況，則是因為有人在做壓測。

特別地，在 mock 底層接口的時候，使用了類似TimeUnit.SECONDS.sleep(1)這樣的語句。

至于為何在 下午3:45 分之后，CPU 的使用率降下來了，則是因為停止了壓測。

除此之外，我們還可以使用jinfo和jstat命令來查詢 Java 進程的啟動參數(shù)以及 GC 情況：

使用jinfo PID命令，查詢啟動參數(shù)：

如上圖所示，使用該命令我們主要是為了查詢啟動參數(shù)，如初始化堆大小、垃圾回收器等配置。

使用jstat -gcutil PID 1000命令，查詢 GC 情況：

如上圖所示，顯示了PID為20567的 Java 進程每秒的 GC 情況，其中1000表示 GC 狀態(tài)的更新頻率，單位為毫秒。