線上應用故障排查之一：高CPU佔用

一個應用佔用CPU很高，除了確實是計算密集型應用以外，一般緣由都是出現了死循環。

（友情提示：本博文章歡迎轉載，但請註明出處：hankchen，http://www.blogjava.net/hankchen）

以咱們最近出現的一個實際故障爲例，介紹怎麼定位和解決這類問題。

 

根據top命令，發現PID爲28555的Java進程佔用CPU高達200%，出現故障。

經過ps aux | grep PID命令，能夠進一步肯定是tomcat進程出現了問題。可是，怎麼定位到具體線程或者代碼呢？

首先顯示線程列表:

ps -mp pid -o THREAD,tid,time

 

找到了耗時最高的線程28802，佔用CPU時間快兩個小時了！

其次將須要的線程ID轉換爲16進制格式：

printf "%x\n" tid

 

最後打印線程的堆棧信息：

jstack pid |grep tid -A 30

 

找到出現問題的代碼了！

如今來分析下具體的代碼：ShortSocketIO.readBytes(ShortSocketIO.java:106)

ShortSocketIO是應用封裝的一個用短鏈接Socket通訊的工具類。readBytes函數的代碼以下：

public byte[] readBytes(int length) throws IOException { if ((this.socket == null) || (!this.socket.isConnected())) { throw new IOException("++++ attempting to read from closed socket"); } byte[] result = null; ByteArrayOutputStream bos = new ByteArrayOutputStream(); if (this.recIndex >= length) { bos.write(this.recBuf, 0, length); byte[] newBuf = new byte[this.recBufSize]; if (this.recIndex > length) { System.arraycopy(this.recBuf, length, newBuf, 0, this.recIndex - length); } this.recBuf = newBuf; this.recIndex -= length; } else { int totalread = length; if (this.recIndex > 0) { totalread -= this.recIndex; bos.write(this.recBuf, 0, this.recIndex); this.recBuf = new byte[this.recBufSize]; this.recIndex = 0; } int readCount = 0; while (totalread > 0) { if ((readCount = this.in.read(this.recBuf)) > 0) { if (totalread > readCount) { bos.write(this.recBuf, 0, readCount); this.recBuf = new byte[this.recBufSize]; this.recIndex = 0; } else { bos.write(this.recBuf, 0, totalread); byte[] newBuf = new byte[this.recBufSize]; System.arraycopy(this.recBuf, totalread, newBuf, 0, readCount - totalread); this.recBuf = newBuf; this.recIndex = (readCount - totalread); } totalread -= readCount; } } }

 

問題就出在標紅的代碼部分。若是this.in.read()返回的數據小於等於0時，循環就一直進行下去了。而這種狀況在網絡擁塞的時候是可能發生的。

至於具體怎麼修改就看業務邏輯應該怎麼對待這種特殊狀況了。

最後，總結下排查CPU故障的方法和技巧有哪些：

一、top命令：Linux命令。能夠查看實時的CPU使用狀況。也能夠查看最近一段時間的CPU使用狀況。

二、PS命令：Linux命令。強大的進程狀態監控命令。能夠查看進程以及進程中線程的當前CPU使用狀況。屬於當前狀態的採樣數據。

三、jstack：Java提供的命令。能夠查看某個進程的當前線程棧運行狀況。根據這個命令的輸出能夠定位某個進程的全部線程的當前運行狀態、運行代碼，以及是否死鎖等等。

四、pstack：Linux命令。能夠查看某個進程的當前線程棧運行狀況。

解決方案

1. 排查應用是否建立了過多的線程

經過jstack肯定應用建立了多少線程？超量建立的線程的堆棧信息是怎樣的？誰建立了這些線程？一旦明確了這些問題，便很容易解決。

2. 調整操做系統線程數閾值 操做系統會限制進程容許建立的線程數，使用ulimit -u命令查看限制。某些服務器上此閾值設置的太小，好比1024。一旦應用建立超過1024個線程，就會遇到java.lang.OutOfMemoryError: unable to create new native thread問題。若是是這種狀況，能夠調大操做系統線程數閾值。

3. 增長機器內存 若是上述兩項未能排除問題，多是正常增加的業務確實須要更多內存來建立更多線程。若是是這種狀況，增長機器內存。

4. 減少堆內存 一個老司機也常常忽略的很是重要的知識點：線程不在堆內存上建立，線程在堆內存以外的內存上建立。因此若是分配了堆內存以後只剩下不多的可用內存，依然可能遇到java.lang.OutOfMemoryError: unable to create new native thread。考慮以下場景：系統總內存6G，堆內存分配了5G，永久代512M。在這種狀況下，JVM佔用了5.5G內存，系統進程、其餘用戶進程和線程將共用剩下的0.5G內存，頗有可能沒有足夠的可用內存建立新的線程。若是是這種狀況，考慮減少堆內存。

5. 減小進程數 這和減少堆內存原理類似。考慮以下場景：系統總內存32G，java進程數5個，每一個進程的堆內存6G。在這種狀況下，java進程總共佔用30G內存，僅剩下2G內存用於系統進程、其餘用戶進程和線程，頗有可能沒有足夠的可用內存建立新的線程。若是是這種狀況，考慮減小每臺機器上的進程數。

6. 減少線程棧大小

線程會佔用內存，若是每一個線程都佔用更多內存，總體上將消耗更多的內存。每一個線程默認佔用內存大小取決於JVM實現。能夠利用-Xss參數限制線程內存大小，下降總內存消耗。例如，JVM默認每一個線程佔用1M內存，應用有500個線程，那麼將消耗500M內存空間。若是實際上256K內存足夠線程正常運行，配置-Xss256k，那麼500個線程將只須要消耗125M內存。（注意，若是-Xss設置的太低，將會產生java.lang.StackOverflowError錯誤）

 

實戰

一、問題背景

 

昨天下午忽然收到運維郵件報警，顯示數據平臺服務器cpu利用率達到了98.94%，並且最近一段時間一直持續在70%以上，看起來像是硬件資源到瓶頸須要擴容了，但仔細思考就會發現我們的業務系統並非一個高併發或者CPU密集型的應用，這個利用率有點太誇張，硬件瓶頸應該不會這麼快就到了，必定是哪裏的業務代碼邏輯有問題。

 

二、排查思路

 

2.1 定位高負載進程 pid

 

首先登陸到服務器使用top命令確認服務器的具體狀況，根據具體狀況再進行分析判斷。

 

 

經過觀察load average，以及負載評判標準（8核），能夠確認服務器存在負載較高的狀況；

 

 

觀察各個進程資源使用狀況，能夠看出進程id爲682的進程，有着較高的CPU佔比

 

2.2 定位具體的異常業務

 

這裏我們可使用 pwdx 命令根據 pid 找到業務進程路徑，進而定位到負責人和項目：

 

 

可得出結論：該進程對應的就是數據平臺的web服務。

 

2.3 定位異常線程及具體代碼行

 

傳統的方案通常是4步：

 

一、top oder by with P：1040 // 首先按進程負載排序找到 maxLoad(pid)

 

二、top -Hp 進程PID：1073 // 找到相關負載 線程PID

 

三、printf 「0x%x 」線程PID： 0x431 // 將線程PID轉換爲 16進制，爲後面查找 jstack 日誌作準備

 

四、jstack 進程PID | vim +/十六進制線程PID - // 例如：jstack 1040|vim +/0x431 -

 

可是對於線上問題定位來講，分秒必爭，上面的 4 步仍是太繁瑣耗時了，以前介紹過淘寶的oldratlee 同窗就將上面的流程封裝爲了一個工具：show-busy-java-threads.sh，能夠很方便的定位線上的這類問題：

 

 

可得出結論：是系統中一個時間工具類方法的執行cpu佔比較高，定位到具體方法後，查看代碼邏輯是否存在性能問題。

 

※ 若是線上問題比較緊急，能夠省略 2.一、2.2 直接執行 2.3，這裏從多角度剖析只是爲了給你們呈現一個完整的分析思路。

 

三、根因分析

 

通過前面的分析與排查，最終定位到一個時間工具類的問題，形成了服務器負載以及cpu使用率的太高。

 

• 異常方法邏輯：是把時間戳轉成對應的具體的日期時間格式；
• 上層調用：計算當天凌晨至當前時間全部秒數，轉化成對應的格式放入到set中返回結果；
• 邏輯層：對應的是數據平臺實時報表的查詢邏輯，實時報表會按照固定的時間間隔來，而且在一次查詢中有屢次（n次）方法調用。

 

那麼能夠獲得結論，若是如今時間是當天上午10點，一次查詢的計算次數就是 10*60*60*n次=36,000*n次計算，並且隨着時間增加，越接近午夜單次查詢次數會線性增長。因爲實時查詢、實時報警等模塊大量的查詢請求都須要屢次調用該方法，致使了大量CPU資源的佔用與浪費。

 

四、解決方案

 

定位到問題以後，首先考慮是要減小計算次數，優化異常方法。排查後發現，在邏輯層使用時，並無使用該方法返回的set集合中的內容，而是簡單的用set的size數值。確認邏輯後，經過新方法簡化計算（當前秒數-當天凌晨的秒數），替換調用的方法，解決計算過多的問題。上線後觀察服務器負載和cpu使用率，對比異常時間段降低了30倍，恢復至正常狀態，至此該問題得已解決。

 

 

五、總結

 

• 在編碼的過程當中，除了要實現業務的邏輯，也要注重代碼性能的優化。一個業務需求，能實現，和能實現的更高效、更優雅實際上是兩種大相徑庭的工程師能力和境界的體現，然後者也是工程師的核心競爭力。
• 在代碼編寫完成以後，多作 review，多思考是否是能夠用更好的方式來實現。
• 線上問題不放過任何一個小細節！細節是魔鬼，技術的同窗須要有刨根問題的求知慾和追求卓越的精神，只有這樣，才能不斷的成長和提高。