內核Panic和soft lockup分析及排錯

1、概述

       衆所周知，從事linux內核開發的工程師或多或少都會遇到內核panic，亦或者是soft lockup，前者多半是由於內存泄露、內存互踩、訪問空地址等錯誤致使的，然後者能夠確定是由於代碼的邏輯不當，進而致使內核進入一個死循環。問題可大可小，當問題足夠隱蔽又難以復現時一般會讓程序猿們十分抓狂，我前些日子有幸體驗了一把，足足花費了我一週時間才成功找到問題，爲了讓本身之後能從容的面對內核panic，也爲了能積累更多的經驗，仍是用文字記錄下來纔是最好的形式。

       提到內核panic就不得不提kdump，這是對付內核panic的利器，kdump其實是一個工具集，包括一個帶有調試信息的內核鏡像(捕獲內核)，以及kexec、kdump、crash三個部分，kdump本質上是一個內核崩潰轉儲工具，即在內核崩潰時捕獲儘可能多的信息生成內核core文件。工做原理以下：

       (1) kexec分爲內核態的kexec_load和用戶態的kexec-tools，系統啓動時將原內核加載到內存中，kexec_load將捕獲內核也一塊兒加載到內存中，加載地址可在grub.conf中配置，默認爲auto，kexec-tools則將捕獲內核的加載地址傳給原內核；

       (2) 原內核系統崩潰的觸發點設置在die()、die_nmi()、panic()，前二者最終都會調用panic()，發生崩潰時dump出進程信息、函數棧、寄存器、日誌等信息，並使用ELF文件格式編碼保存在內存中，調用machine_kexec(addr)啓動捕獲內核，捕獲內核最終轉儲core文件。捕獲內核一般能夠採用兩種方式訪問原內核的內存信息，一種是/dev/oldmem，另外一種則是/proc/vmcore；

       (3) crash工具提供一些調試命令，能夠查看函數棧，寄存器，以及內存信息等，這也是分析問題的關鍵，下面列舉幾個經常使用命令。

       log：顯示日誌；

       bt：加參數-a時顯示各任務棧信息；

       sym：顯示虛擬地址對應的標誌符，或相反；

       ps：顯示進程信息；

       dis：反彙編函數或者虛擬地址，經過與代碼對比，結合寄存器地址找出出錯代碼中相關變量的地址；

       kmem：顯示內存地址對應的內容，或slab節點的信息，若出錯地方涉及slab，經過kmem則可看到slab的分配釋放狀況；

       rd：顯示指定內存的內容；

       struct:顯示虛擬地址對應的結構體內容，-o參數顯示結構體各成員的偏移；

       下面借用一下別人畫的內核panic流程框圖：

       一般內核soft lockup問題不會致使內核崩潰，只有設置softlockup_panic纔會觸發panic，因此若未設置可在崩潰前自行查看系統日誌查找緣由，若是查找不出緣由，再借助人爲panic轉儲core文件，這時經過crash分析問題。

       linux中藉助看門狗來檢測soft lockup問題，每一個cpu對應一個看門狗進程，當進程出現死鎖或者進入死循環時看門狗進程則得不到調度，系統檢測到某進程佔用cpu超過20秒時會強制打印soft lockup警告，警告中包含佔用時長和進程名及pid。

       linux內核設置不一樣錯誤來觸發panic，其觸發選項均在/proc/sysy/kernel目錄下，包含sysrq、softlockup_panic、panic、panic_on_io_nmi、panic_on_io_nmi、panic_on_oops、panic_on_unrecovered_nmi、unknown_nmi_panic等。

2、panic實例分析

       涉及的代碼是處理DNS請求，在DNS請求中須要對重複出現的域名進行壓縮，以達到節約帶寬的目的，壓縮的思想很簡單，採用最長匹配算法，偏移量基於DNS頭地址。系統中每一個cpu維護一個偏移鏈表，每次處理一個域名前都會到鏈表中查詢這個域名是否已經處理過，若處理過這時會使用一個偏移值。

       例如：www.baidu.com，鏈表中會存儲www.baidu.com、baidu.com、com三個節點，以後每次查詢鏈表時若查到則使用節點中的偏移，若未查到則將新出現的域名按照這個規律加到鏈表中。

這裏貼出基本的數據結構：

       struct data_buf {
           unsigned char* buf;
           u16 buflen;
           u16 pos;
       };

       struct dns_buf {
           struct data_buf databuf;
           struct sk_buff* skb;
           u32 cpuid;
       };

       代碼中靜態分配了50個節點，每處理一個域名時取一個節點掛入鏈表中，每次panic都發生在查詢節點函數get_offset_map(data_buf *dbuf, char *domain)的list_for_each()中。所以，猜想其多是因爲遍歷到空指針或非法地址致使的，緣由應該是因爲內存溢出致使的內存互踩，每次panic都是發生在晚上，通常會發生幾回。

       起初的辦法是在函數中加入判斷條件來調用BUG_ON()函數來提早觸發panic，經過驗證發現有時會出現list_head節點地址爲空，有時會出現遍歷節點數超過50次，用反彙編dis命令打印出錯節點的地址，最終也只看出了某個節點爲空，不過對第二種狀況有了一些猜想，壓縮時所指向的域名可能出現了問題，在這個函數中徘徊了好久都沒有定論，最終得出結論：單純從這個函數入手是不可能找到緣由的，只有打印出原始請求信息和響應信息才能進一步分析，但這個函數所傳入的信息頗有限，最後只能把全部信息都存儲在data_buf這個結構體中，這是我能想到的最直接也是代碼改動最小的辦法，隨着問題的深刻這個結構體已經達到了幾十個變量，甚至超過了2k大小，也就是超過了函數棧的大小。問題向上追溯到了pskb_expand_head()函數，在這個函數以前打印原始的skb內容，以後打印當前處理的skb內容，發現兩次skb的內容不一樣，當時就誤認爲問題出在pskb_expand_head()函數上，下面貼出當時的分析報告：

       從目前分析是由於收到請求包中的edns選項部分數據不正確，幷包含大量垃圾數據，這些請求一般來自巴西(200.13.144.4),當請求累積到必定數量時可能就會致使死機，定位到出錯代碼位於expand_dnsbuf()中，這個函數中又調用了pskb_expand_head()函數，初步推測問題出在pskb_expand_head()函數中。

       出錯現象表現爲擴展前的SKB數據正確，而擴展後SKB數據已經改變，如原始數據包長度爲500(長度不定，240~500不等，正常請求不該該爲這麼長)，請求中dnsid爲0x7ebf，問題區和附加區計數均爲1，請求域名爲lbs.moji.com,擴展後dnsid仍爲0x7ebf，問題區仍爲1，附加區則變爲0，請求域名則變爲zj.dcys.ksmobile.com，也就是可能另外一個正常請求(不帶edns)覆蓋了當前(帶edns，幷包含大師垃圾數據)的dnsbuf，但DNSID卻未被覆蓋，同時覆蓋的域名都比原始域名長，當查詢到答案後putwired請求域名，此時原域名的'\0'被覆蓋，在壓縮請求域名時檢測不到'\0'，所以致使offset數組溢出或者地址錯誤，最終死在get_offset_map()函數中。

       兩次skb內容對好比下：

       紅框中依次爲dnsid，附加區數量，請求域名('\0')，pos爲當前要寫的位置，很顯然'\0'已被覆蓋，pos以後爲edns選項，00 29正確，表示edns選項，10 00表示負載長度4096，80 00爲Z標誌，通常爲0，以後是edns長度，這裏爲0，通常爲11或者12，因此由此看來edns選項數據不正確，以後還有不少垃圾數據。

       其它問題：在本機進行構造這種數據包時並未致使服務器死機，有時有迴應，有時則無迴應，但迴應的數據包依然存在錯誤，有時是權威區中域名被更改，有時附加段的edns出如今了應答區或者權威區，以下圖：

       根本緣由：由於這是偶然現象，而且當請求量特別大時纔可能出現，在不死機的狀況下很難打印信息，因此目前並未找到根本緣由。

       解決辦法：對這種請求能夠校驗edns選項的合法性以及檢驗數據長度，如出現這種數據包直接丟掉；或將請求域名存入數組中，必要時能夠在迴應響應包時從DNS頭部重寫數據，但不知此種辦法是否會致使其它內存錯誤。

       當時基本上已經快放棄了，剛開始覺得這是由於內存互踩致使的，因此現象應該很差復現，不事後來經過發送大量帶有垃圾數據的請求已經可以復現了，可見這不是偶爾現象，而是必然現象。當時一直認爲是內存被修改，而沒有考慮地址的指向是否錯誤，由於響應時數據是部分出錯，而dnsid，問題區的域名只有讀的操做卻沒有寫的操做，最大的迷惑是未找到內存是在何處被修改的，因此猜想應該是在擴展skb函數中數據拷貝後被修改的，沒有辦法只能把內核中的pskb_expand_head()函數搬到模塊中，在這個函數中排錯，結果意外的發現，拷貝一直到退出這個函數後數據都沒有改變，接着又迷惑了。再後來無心中打印原始的dnsbuf地址，發現其與擴展前的ip頭地址相差很大，這時才發現dnsbuf的地址可能在某處被修改了，通過不斷的復現現象，最終定位在skb_linearize()函數中，真是忽然之間柳暗花明，問題的根本緣由是由於skb線性化函數使用後沒有更改地址致使的。

        在skb_linearize()函數中

        1）若是是正常請求，通常head到end之間的線性空間就夠用，而且大多也不存在分片的狀況，線性化後線性化地址和內存空間保護不變；

        2）若是請求中帶有大量垃圾數據，那麼線性空間一般會不夠用，而且存在分片內容，此時在線性化函數中會從新分配線性空間。

       第二種即爲異常狀況，此時skb中head，data，iph等指針已發生變化，而原代碼中一直在使用已經被釋放的地址，若被釋放的地址沒被從新分配，此時返回的多是部分出錯的響應包，當收到大量這種請求包時系統一般會死機。

       具體代碼以下：

       在代碼中加入iph = ip_hdr(skb);這行代碼便可解決問題，小小的一行代碼害苦了好多人，固然我是受傷最重的，在這裏要牢記skb線性化後必定要從新獲取ip頭。

       總結：排錯經驗就是crash vmcore鏡像+猜想緣由+多加打印信息+想辦法重現現象。先從致使內核崩潰的代碼入手，由於是線上環境致使的，因此很難測試，所以必定要猜想哪些因素致使的，選擇好要打印的信息，並想辦法傳入最終崩潰的函數中，在崩潰的函數中加入判斷崩潰的條件，打印完信息後調用BUG_ON()讓系統崩潰生成crash文件。原本已經到了分析的瓶頸了，由於以前一直覺得skb內存地址在某處被修改，並一度覺得是在pskb_expand_head()處致使的，後來還把內核中的函數搬到模塊中，以便輸出信息，沿着這條路最終發現是一條死路，以後只能從skb中各指針的地址，以及dnsbuf的地址，ip頭的地址開始排查，終於發現是ip頭的地址發生了改變，最終才找到問題的根本緣由。另外一個最大的感覺就是必定要想辦法復現現象，由於線上的環境很複雜，並且這個現象是偶爾現象，天天都是晚上才發生兩三次，這也致使問題更加難解決，最終經過構造這種數據包，並大量的發送給服務器才復現了現象。

3、soft lockup實例

       同事最近遇到一個soft lockup問題，他就藉助了dis反彙編，並與原代碼進行對比

       從彙編中看出出錯的節點地址存在r10寄存器中，r10的地址爲88085076de40，接着藉助struct命令查看結構體中成員的賦值狀況

       到這裏發現了原來是在遍歷鏈表時遍歷到某個節點時它的前驅和後繼都指向本身，所以發生了死循環，順着代碼的流程發現，原來是這個節點執行了兩次list_add_tail()，問題迎刃而解。

這個案例相對上面那個panic案例的狀況要簡單一些，出錯的問題是圍繞着鏈表的操做，最後發現是代碼的邏輯問題，相對來講問題不那麼隱蔽。經過這兩個案例我學到了很多排錯經驗，有一個清晰的排錯思路很關鍵，不然在煩躁中很難定位出問題的所在。