線上應用故障排查之一:高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故障的方法和技巧有哪些:

1、top命令:Linux命令。可以查看實時的CPU使用情況。也可以查看最近一段時間的CPU使用情況。

2、PS命令:Linux命令。強大的進程狀態監控命令。可以查看進程以及進程中線程的當前CPU使用情況。屬於當前狀態的采樣數據。

3、jstack:Java提供的命令。可以查看某個進程的當前線程棧運行情況。根據這個命令的輸出可以定位某個進程的所有線程的當前運行狀態、運行代碼,以及是否死鎖等等。

4、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錯誤)

 

實戰

1、問題背景

 

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

 

2、排查思路

 

2.1 定位高負載進程 pid

 

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

 

 

通過觀察load average,以及負載評判標准(8核),可以確認服務器存在負載較高的情況;

 

 

觀察各個進程資源使用情況,可以看出進程id為682的進程,有着較高的CPU占比

 

2.2 定位具體的異常業務

 

這里咱們可以使用 pwdx 命令根據 pid 找到業務進程路徑,進而定位到負責人和項目:

 

 

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

 

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

 

傳統的方案一般是4步:

 

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

 

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

 

3、printf “0x%x ”線程PID: 0x431 // 將線程PID轉換為 16進制,為后面查找 jstack 日志做准備

 

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

 

但是對於線上問題定位來說,分秒必爭,上面的 4 步還是太繁瑣耗時了,之前介紹過淘寶的oldratlee 同學就將上面的流程封裝為了一個工具:show-busy-java-threads.sh,可以很方便的定位線上的這類問題:

 

 

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

 

※ 如果線上問題比較緊急,可以省略 2.1、2.2 直接執行 2.3,這里從多角度剖析只是為了給大家呈現一個完整的分析思路。

 

3、根因分析

 

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

 

  • 異常方法邏輯:是把時間戳轉成對應的具體的日期時間格式;
  • 上層調用:計算當天凌晨至當前時間所有秒數,轉化成對應的格式放入到set中返回結果;
  • 邏輯層:對應的是數據平台實時報表的查詢邏輯,實時報表會按照固定的時間間隔來,並且在一次查詢中有多次(n次)方法調用。

 

那么可以得到結論,如果現在時間是當天上午10點,一次查詢的計算次數就是 10*60*60*n次=36,000*n次計算,而且隨着時間增長,越接近午夜單次查詢次數會線性增加。由於實時查詢、實時報警等模塊大量的查詢請求都需要多次調用該方法,導致了大量CPU資源的占用與浪費。

 

4、解決方案

 

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

 

 

5、總結

 

  • 在編碼的過程中,除了要實現業務的邏輯,也要注重代碼性能的優化。一個業務需求,能實現,和能實現的更高效、更優雅其實是兩種截然不同的工程師能力和境界的體現,而后者也是工程師的核心競爭力。
  • 在代碼編寫完成之后,多做 review,多思考是不是可以用更好的方式來實現。
  • 線上問題不放過任何一個小細節!細節是魔鬼,技術的同學需要有刨根問題的求知欲和追求卓越的精神,只有這樣,才能不斷的成長和提升。

 


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM