問題現(xiàn)象

排查過程

問題現(xiàn)象

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

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

排查過程

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

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

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

Step 2： 使用ps -mp PID -o THREAD,tid,time命令，查詢?cè)撨M(jìn)程的線程情況：

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

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

在這里，我們之所以需要將PID轉(zhuǎn)為十六進(jìn)制是因?yàn)樵诙褩?a target="_blank">信息中，PID是以十六進(jìn)制形式存在的。

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

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

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

而上面之所以會(huì)出現(xiàn) CPU 使用率飆高的情況，則是因?yàn)橛腥嗽谧鰤簻y(cè)。

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

至于為何在 下午3:45 分之后，CPU 的使用率降下來了，則是因?yàn)橥Ｖ沽藟簻y(cè)。

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

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

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

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

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