記一次進程阻塞診斷
本文來自博客園，作者：T-BARBARIANS，轉載請註明原文鏈接：//www.cnblogs.com/t-bar/p/16626951.html 謝謝！
前言
進程在運行過程中會在執行，阻塞，就緒狀態下來回切換。簡單介紹下各個狀態的切換原因吧。
從執行->阻塞，一般是進程發生某種事件，例如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’s 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管理的內存結構上，使得用戶態程序可以申請到更多，更大的內存塊。如上面圖6所示，某個時間，buff/cache所佔用的內存也非常高（buff/cache本質還是使用的物理內存，具體概念在這裡就不再展開了），可以通過一個定時執行的腳本去釋放這部分內存。在這也把腳本奉獻給大家吧！不過需要注意，對buffer/cache的釋放需要謹慎，有可能造成某些還未落盤的文件丟失，這部分還沒有去考證過。
1 #! /bin/bash 2 3 # 內存使用百分比，可以傳參，默認是20% 4 log=/root/log/memory.log 5 6 max_rate=$1 7 8 if [ ! "$max_rate" ] ; then 9 max_rate=20 10 fi 11 12 #echo "max_rate: $max_rate" 13 14 total=`free -g | awk 'NR==2' | awk '{print $2}'` 15 used=`free -g | awk 'NR==2' | awk '{print $3}'` 16 free=`free -g | awk 'NR==2' | awk '{print $4}'` 17 buffer_cache=`free -g | awk 'NR==2' | awk '{print $6}'` 18 19 rate=$(($buffer_cache*100/$total)); 20 21 echo "===========================" >> $log 22 date >> $log 23 echo "buffer_cache_usage_rate: $rate%" >> $log 24 echo "Memory information:" >> $log 25 echo "Total: ${total}GB" >> $log 26 echo "Use: ${used}GB" >> $log 27 echo "Free: ${free}GB" >> $log 28 echo "buff_cache: ${buffer_cache}GB" >> $log 29 30 if [ "$rate" -ge "$max_rate" ] ; then 31 echo 1 > /proc/sys/vm/drop_caches 32 echo "buffer and cache release over" >> $log 33 fi 34 35 echo -e "===========================\n" >> $log
五、結語
為了診斷一個線上業務阻塞問題，就像中醫一樣經歷了「望聞問切」四個過程，望（看到了進程阻塞），聞（IO？內存不足？硬件損壞？），問（此類問題的病理範圍是什麼？確定排查方向：看內核信息），切（把脈出是系統調用阻塞，且是內存不足引起），胸有成竹後，開了處方，來了個對症下藥，最後徹底治癒。
技術也是不斷實踐積累的，在此分享出來與大家一起共勉！
如果文章對你有些許幫助，還請各位技術愛好者登錄點贊呀，謝謝！
本文來自博客園，作者：T-BARBARIANS，轉載請註明原文鏈接：//www.cnblogs.com/t-bar/p/16626951.html 謝謝！
