一次Linux系統1分鐘負載5000+的故障排錯

昨天上午查看Zabbix監控界面時，發現其中一臺服務器的進程數量和1分鐘負載已經達到了一個很是驚人的數量，Zabbix默認報警數值是進程數量在5分鐘平均值大於1000，1分鐘系統負載5分鐘平均值大於5。

先大致列一下服務器的軟硬件信息：

服務器硬件：Dell PowerEdge R720, 2 x Intel(R) Xeon(R) CPU E5-2640 v2 @ 2.00GHz；62.87 GB；PERC H710 SAS RAID5

服務器操做系統：Ubuntu 14.04 LTS，內核：3.13.0-24-generic

圖1：Zabbix報警信息（Zabbix消息通知設定的是嚴重（average）級別以上經過Web短信網關發送短信報警）：

圖2：Zabbix上觸發器的報警條件

接着不久，就不斷有同事反映該服務器響應很是慢，有些應用頁面打開好久纔出來。因爲機房遠在天邊並且沒有遠程登陸控制檯的登陸信息（這些信息在客戶處），所以只能用xshell經過SSH登陸到Linux系統，打開top命令看看系統運行狀況，發現當前系統內已經有5800多個進程在運行，其中系統負載（一、五、15分鐘）都達到了5400+，但奇怪的是CPU、內存和硬盤IO都並不高，按照常理，如此高的系統負載，CPU和IO等早已經應該是消耗殆盡了，但top顯示並無。

圖3.1: Linux系統中的top信息

圖3.2 經過iostat、vmstat等命令發現磁盤IO並不高，但系統負載卻很高

有個開發人員說pid爲14898的java進程並無分配這麼大的內存，這個進程有問題，要求負責編寫該程序的另外一個開發人員檢查程序，當時我想，一個java進程也不至於把系統負載搞的這麼高，必定有別的重要的緣由沒有發現。我按照往常的方法，先查看一下系統中究竟運行了什麼樣的程序致使系統內進程這麼多，所以執行ps –ef | more，查看一下系統內所有進程的運行狀況，結果發現此命令根本無法執行，剛輸出了不到一個屏幕就卡死在屏幕上了，趕忙複製一個ssh session，繼續執行，簡單執行ps，看看能不能執行，結果發現ps輸出的內容中有大量的ps進程，此處感想還好ps還能運行只是參數不能加太多了。打開top命令，查看一下一個ps命令對應的pid，用top –p pid打開，發現是Zabbix用戶執行的ps命令，瞬間感受很差，別是由於我以前寫的Zabbix腳本中有問題致使ps命令沒有退出，才致使的系統一分鐘負載這麼高。

圖4：用top查看zabbix用戶的進程信息，top –u zabbix

以前有同事電話問我係統中有個java進程沒法結束，致使某個應用如今有兩個java進程該怎麼辦，我跟他說試試sudo，結果sudo也很差用，root權限也沒法殺死。因爲當時在家裏有事沒在公司所以也沒去查什麼緣由。因此此時，我想用kill殺掉zabbix的ps進程時就遇到了一樣的問題，發現ps進程根本殺不死。不管是使用什麼樣的進程信號，TERM仍是KILL都很差用。仔細一看，原來這些進程的狀態都成了D狀態（上圖中S顯示的那一列）。

關於D狀態：D狀態是一種特殊的進程狀態代碼（PROCESS STATE CODES），其英文示意是Uninterruptible sleep (usually IO)，意思是不可中斷的睡眠（一般是因爲IO問題引發的），這個IO多是多種IO，內存、硬盤、網絡、總線都是可能的。既然是D狀態，那即使是root用戶也沒法殺死的，由於這樣的進程它已經不接受任何進程信號，因此任何方式都將沒法將其殺死，只能從新啓動服務器。但這問題還沒找到根源，不能草草的下結論。

檢查Zabbix的用戶參數中設定的腳本和命令行，發現大部分命令行有ps，但並不沒有任何問題，所以初步排除Zabbix腳本或命令行中存在的問題，以下圖所示：

圖5：Zabbix用戶參數命令行：

所以只能用strace命令找出ps -ef進程卡在那裏。命令是strace -o strace_psef.log –f ps –ef

圖6：經過strace命令找出命令執行中對系統的調用和收到的信號等信息

經過上圖能夠發現到open文件/proc/24602/cmdline時遇到了中止（等待），經過cat /proc/24602/cmdline文件發現也沒法正確執行，也會卡死。中間發現像netstat，ps -p 24602 –o cmd這種命令都沒法使用，甚至ps -p 1 –o cmd都沒法顯示，因爲這些命令都是使用/proc目錄下的文件的，所以/proc目錄存在問題的可能性很是大，所以繼續找緣由，繼續top -p 24602找出這個進程名稱（發現除了top可用之外，pstree一樣也是可用的）。

圖7.1： ps -p 24602 –o cmd

圖7.2：ps -p 1 –o cmd都沒法顯示

 

圖7.3：附加的疑問，pts數值沒法還原至0,

經過top -p 24602命令發現這個pid爲14602的進程也是D狀態的

圖8：經過top -p 24602找出這個進程名稱

可是發現top中不能使用c命令查看這個進程的命令行，所以只能進入/proc 目錄看看有沒有人品能看到該進程使用的一些fd（文件描述符，file descriptor），結果發現人品不錯，經過cp複製出來的/proc/24602中找到了task目錄下的fd，以下圖所示：

圖9：經過fd找到這個進程屬於哪個應用裏面的

發現出問題的這個應用程序就是前天同事問個人那個，也是研發人員說存在問題的那個應用。通過昨天晚上的重啓後發現，此進程的內存佔用率依然很高，初步判斷是程序的問題，固然也要檢查一下IO問題，可是Ubuntu這個系統比較奇怪，系統日誌中對此沒有任何可用的信息，而java程序中產生的日誌太多、信息太雜仍是讓更專業的開發人員去查吧。

到如今，問題的始做俑者算是找到了，可是爲何是因爲IO問題致使還沒找到緣由，從上午開始寫此文到如今，寫此文以前已經告訴有關研發人員去分析代碼去了，如今去問了下，初步定位在程序內部有一個模塊存在死循環（不斷的查詢遠端數據庫）致使的，具體怎麼改和深刻測試還須要一些時間。

圖10.1：昨天晚上該程序（圖中pid爲2988）的內存佔用爲1.4GB左右，符合常理，但今早上就11GB了（截圖以前有過13GB、12GB的記錄）

 

圖10.2：最新截圖，又13GB了。

圖11：問題處理的整體思路以下圖所示：

經過這次事件，總結經驗以下：

1.經過fd判斷進程的cmd，除此以外，top -c，pstree -a，ps -ef等

2.經過strace命令分析進程在哪裏等待

3.瞭解進程的D狀態

tag:strace命令用法,進程狀態D,Linux進程分析,Linux進程調試,strace調試程序

--end--