本文來自博客園，作者：T-BARBARIANS，博文嚴禁轉載，轉載必究！

前言

　　進程在運行過程中會在執行，阻塞，就緒狀態下來回切換。簡單介紹下各個狀態的切換原因吧。

　　從執行->阻塞，一般是進程發生某種事件，例如IO，資源申請等。

　　從阻塞->就緒，是進程等待的事件已完成，為接下來的執行做好了準備。

　　從就緒->執行，處于就緒的進程得到了系統的調度，獲得了時間片，實現了該進程在CPU上的執行。

　　從執行->就緒，進程被系統調度，失去了CPU的執行權。一般是時間片使用完畢，或者被其他高優先級的進程搶占。

圖 1

一、問題現象

　　如下圖，程序直接卡死。。。

圖 2

　　進程處于阻塞狀態，所有業務線程均被阻塞，失去了CPU執行權。阻塞時長，短的時候在幾十秒，長的時候長達2-3分鐘，然后又自行恢復，周而復始。

　　這可是已經上線的實時業務，這不是要了開發的命了。看到這個情況，自己著急得像熱鍋上的螞蟻，趕緊在家里開始著手排查。

二、排查思路

　　看到了問題的現象，可是問題的排查該從哪著手呢？

　　首先懷疑了自己的業務代碼里是否有長時間的業務處理流程。可是就算是有長時間的業務處理，所有線程的cpu不可能都為零呀；其次，難道業務代碼里有鎖，產生了競爭？不，我們的業務代碼里沒有互斥使用的對象，也就沒有鎖。即使有鎖，那也至少有一個線程cpu不為0，而且不可能這樣長時間為0。

　　一頭霧水啊，到底該從哪里著手分析呢？

　　從現實回到理論，只有進程被阻塞，未被系統調度的時候，才有可能出現所有線程的CPU使用率為0。

　　朝著這個大方向開始往下分析，那到底是什么事件，導致了所有線程被阻塞。

　　有網絡IO？不，我們不是一個有大量網絡請求的服務端。

　　有磁盤IO？不，線上業務流量規模不至于導致產生大量磁盤讀寫，而且通過iotop查看，在阻塞時，系統IO讀寫帶寬還遠遠未達到磁盤IO的瓶頸。

　　內存不夠啦？但是阻塞的時候查看可用內存也還有1GB以上呀。

　　機器壞啦？哈哈哈，在實在沒有思路的時候，真的出現過這種想法。可是經驗告訴我，不到萬不得已，懷疑啥都別懷疑系統，甚至懷疑硬件，必定是自己的業務代碼問題，或者是某些方法使用不當帶來的問題。

　　那到底是啥導致了所有業務線程的阻塞？這里可以確定的是，線程被阻塞，一定是有事件導致的阻塞。用戶態可能性不大，那很有可能是系統調用阻塞在了內核態，那有沒有該進程對應的內核態相關信息呢，從哪里看呢？

三、問題排查

　　如何查看進程運行態相關的內核態信息呢？

　　Linux其實很完備啊，Linux內核提供了pro 文件系統，系統中當前運行的每一個進程在proc下都有一個對應的目錄，且以進程的PID號為目錄名，用戶可以通過進程對應的PID目錄得到對應進程的相關運行態信息。

　　比如ID為93571的進程，有如下示例的一些信息：

圖 3

　　例如fd目錄記錄了當前進程打開的文件id，status文件記錄了進程的內存使用和其它眾多信息，task目錄則包含了該進程及其所有子線程的信息。

　　那哪個文件記錄了進程當前的系統調用鏈呢？那就是我要找的stack文件，stack會記錄當前進程在內核的調用棧，且是實時更新的！打開文件，會有某個進程當前在內核態的調用鏈信息，比如：

　　但是問題來了，進程是一個多線程結構，如何查看每一個業務線程當前的內核態調用鏈呢？答案就是通過task目錄獲得想要查看的線程內核調用信息。

　　先看看task里記錄的線程id：

　　再具體查看某個線程id的信息：

 　　發現了嗎，上圖的記錄項與圖三里的記錄項一模一樣，就是說我們也可以具體的了解到某個線程的運行態信息！比如某個業務線程的內核態調用鏈：

　　另外，其實只要知道了某個線程的id號，直接通過cat /proc/$[thread_id]/stack也是可以的，而不需要通過進程ID下的task查看。例如：

　　到這里，查看每一個業務線程對應的實時系統調用鏈的方法知道了，但是第二個問題來了：并行的業務線程很多，我怎么才能捕獲到某個線程阻塞發生時的調用鏈信息？

　　這確實是個問題，業務線程數量多，而且多種系統調用信息轉瞬即逝，不可能一直在那不停的手動cat吧，這不跟大海撈針一樣么。

　　那該如何解決呢？是時候拿出另外一個秘籍了！

　　日志是個好東西，通過watch和cat命令配合實現，一個記錄時間，一個記錄調用信息，不斷的向日志文件追加信息。沒錯，就是實時記錄所有業務線程的內核調用鏈信息，在阻塞發生后，再在日志中查看線程被阻塞對應時間段的系統調用鏈！

　　操作步驟：

　　（1）準備好要記錄日志的所有線程id。例如圖1中的68616、68618、68620、68622、68624、68626、68628、68630、68632，一共九個業務線程。

　　（2）分別執行記錄所有線程日志的命令行。注意每一個窗口執行一條命令。

watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68616.log;cat /proc/68616/stack >> /root/68616.log" 
                                                        
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68618.log;cat /proc/68618/stack >> /root/68618.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68620.log;cat /proc/68620/stack >> /root/68620.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68622.log;cat /proc/68622/stack >> /root/68622.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68624.log;cat /proc/68624/stack >> /root/68624.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68626.log;cat /proc/68626/stack >> /root/68626.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68628.log;cat /proc/68628/stack >> /root/68628.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68630.log;cat /proc/68630/stack >> /root/68630.log" 
                                                                 
watch -n 1 "date '+%Y-%m-%d %H:%M:%S' >> /root/68632.log;cat /proc/68632/stack >> /root/68632.log" 

　　（3）等待阻塞事件發生后，結束所有日志記錄。

　　萬事俱備，只欠東風。到這里，一切安排妥當，坐等阻塞上鉤！說實話，還擔心你不出現呢！

　　不出所料，當業務線程再次阻塞時，非常急切的打開了記錄的日志信息！9個線程，有8個都在同一時間段打印了相同的調用鏈（卡住了），另外一個業務線程也是在這段時間出現了非常關鍵的，與眾不同的調用信息：　

 圖 4

　　what the fuck？

　　alloc_pages_vma，do_try_to_free_pages，xfs_buf_iowait，是什么意思？這是在向系統請求內存分配啊，且最后內存分配出現了等待，而且都走到讓buff/cache模塊去釋放內存了，這不就是線程阻塞的真相么！找到這樣的關鍵信息真是欣喜萬分!

　　內存真的不足了么？再次阻塞時，趕緊查看了一下系統可供用戶態程序使用的內存信息：

圖 5

圖 6

　　可用內存真的不多了，只有300MB+，而且這300MB會通過buddy算法拆分為很多小塊內存，并不是一個完整連續的空間。另外一個非常重要的信息是：阻塞時，系統無法滿足應用程序向系統申請一個大于32KB的內存塊。

　　好了，終于真相大白了！我的業務線程在內存不足時向系統申請了一個比較大，可能超過32KB的內存，但是此時內存池（tcmalloc）無法提供該內存塊大小，向系統申請內存時應該進行了加鎖，導致了其它線程全部阻塞，然后申請內存的線程又長時間得不到返回，就出現了文章開頭提到的長時間阻塞，問題終于找到了！

四、解決方法

　　阻塞業務的原因找到了，業務程序的內存使用并不大，但是為什么會出現這個問題，以及如何避免這個問題呢？畢竟現網業務可不能停啊！

　　在后來的調查中，發現了造成程序阻塞的背后真兇。我們系統里另外一個業務程序“XXX”，會定時大量計算某些內容，存在內存開銷沖高現象，同時導致系統供用戶態程序使用的內存急劇下降。若某程序此時剛好碰上稍微大一點的內存申請，那就會因為內存不夠而直接阻塞。

　　解決方法：

　　（1）優化了“XXX”的內存使用，某個時間點定時多任務并發執行，改為定時串行執行，降低內存開銷。

　　（2）優化了自己的業務程序，盡可能的減小內存申請的大小。

　　（3）通過腳本釋放buffer/cache占用內存，釋放的內存會被還原到buddy管理的內存結構上，使得用戶態程序可以申請到更多，更大的內存塊。如上面圖5所示，某個時間，buff/cache所占用的內存也非常高（buff/cache本質還是使用的物理內存，具體概念在這里就不再展開了），可以通過一個定時執行的腳本去釋放這部分內存。

　　在這也把腳本奉獻給大家吧！不過需要注意，對buffer/cache的釋放需要謹慎，有可能造成某些還未落盤的文件丟失，這部分還沒有去考證過。

 1 #! /bin/bash
 2 
 3 # 內存使用百分比，可以傳參，默認是20%
 4 
 5 log_dir=/root/log
 6 
 7 if [ ! -d ${log_dir} ]; then
 8     sudo mkdir -p ${log_dir}
 9 fi 
10 
11 log=/root/log/memory.log
12 
13 max_rate=$1
14 
15 if [ ! "$max_rate" ] ; then
16         max_rate=20
17 fi
18 
19 #echo "max_rate: $max_rate"
20 
21 total=`free -g | awk 'NR==2' | awk '{print $2}'`
22 used=`free -g | awk 'NR==2' | awk '{print $3}'`
23 free=`free -g | awk 'NR==2' | awk '{print $4}'`
24 buffer_cache=`free -g | awk 'NR==2' | awk '{print $6}'`
25 
26 rate=$(($buffer_cache*100/$total));
27 
28 echo "===========================" >> $log
29 date >> $log
30 echo "buffer_cache_usage_rate: $rate%" >> $log
31 echo "Memory information:" >> $log
32 echo "Total: ${total}GB" >> $log
33 echo "Use: ${used}GB" >> $log
34 echo "Free: ${free}GB" >> $log
35 echo "buff_cache: ${buffer_cache}GB" >> $log
36 
37 if [ "$rate" -ge "$max_rate" ] ; then
38         echo 1 > /proc/sys/vm/drop_caches
39         echo "buffer and cache release over" >> $log
40 fi
41 
42 echo -e "===========================\n" >> $log

五、結語

　　為了診斷一個線上業務阻塞問題，就像中醫一樣經歷了“望聞問切”四個過程，望（看到了進程阻塞），聞（IO？內存不足？硬件損壞？），問（此類問題的病理范圍是什么？確定排查方向：看內核信息），切（把脈出是系統調用阻塞，且是內存不足引起），胸有成竹后，開了處方，來了個對癥下藥，最后徹底治愈。

　　技術也是不斷實踐積累的，在此分享出來與大家一起共勉！

　　如果文章對你有些許幫助，還請各位技術愛好者登錄點贊呀，謝謝！

　　本文來自博客園，作者：T-BARBARIANS，博文嚴禁轉載，轉載必究！