Linux調試 call trace dump_stuck__Linux

call trace能把當前的函數調用棧列印出來。 核心態call trace

核心態有三種出錯情況，分別是bug, oops和panic。

bug屬於輕微錯誤，比如在spin_lock期間調用了sleep，導致潛在的死結問題，等等。

oops代表某一使用者進程出現錯誤，需要殺死使用者進程。這時如果使用者進程佔用了某些訊號鎖，所以這些訊號鎖將永遠不會得到釋放，這會導致系統潛在的不穩定性。

panic是嚴重錯誤，代表整個系統崩潰。

 

OOPS

先介紹下oops情況的處理。Linux oops時，會進入traps.c中的die函數。

int die(const char *str, struct pt_regs *regs, long err)

       。。。

       show_regs(regs);

 

void show_regs(struct pt_regs * regs)函數中，會調用show_stack函數，這個函數會列印系統的核心態堆棧。

具體原理為：

       從寄存器裡找到當前棧，在棧指標裡會有上一級調用函數的棧指標，根據這個指標回溯到上一級的棧，依次類推。

       在powerpc的EABI標準中，當前棧的棧底（注意是棧底，不是棧頂，即Frame Header的地址）指標儲存在寄存器GPR1中。在GPR1指向的棧空間，第一個DWORD為上一級調用函數的Frame Header指標（Back Chain Word），第二個DWORD是當前函數在上一級函數中的返回地址（LR Save Word）。通過此種方式一級級向上回溯，完成整個call dump。除了這種方法，內建函數__builtin_frame_address函數理論上也應該能用，雖然在核心中沒有見到。（2.6.29的ftrace模組用到了__builtin_return_address函數）。

 

show_regs函數在call trace的時候，只是用printk列印了一下棧中的資訊。如果當前系統沒有終端，那就需要修改核心，把這些棧資訊根據需求儲存到其它地方。

例如，可以在系統的flash中開出一塊空間專門用於列印資訊的儲存。然後，寫一個核心模組，再在die函數中加一個回呼函數。這樣，每當回呼函數被調用，就通知自訂的核心模組，在模組中可以把調用棧還有其它感興趣的資訊儲存到那塊專用flash空間中去。這裡有一點需要注意的是，oops時核心可能不穩定，所以為了確保資訊能被正確寫入flash，在寫flash的函數中盡量不要用中斷，而用輪循的方式。另外訊號量、sleep等可能導致阻塞的函數也不要使用。

此外，由於oops時系統還在運行，所以可以發一個訊息（訊號，netlink等）到使用者空間，通知使用者空間做一些資訊收集工作。

 

Panic

Panic時，Linux處於更最嚴重的錯誤狀態，標誌著整個系統不可用，即中斷、進程調度等都已經停止，但棧還沒被破壞。所以，oops中的棧回溯理論上還是能用。printk函數中因為沒有阻塞，也還是能夠使用。 使用者態call trace

使用者程式可以在以下情形call trace，以方便調試：

l         程式崩潰時，都會收到一個訊號。Linux系統接收到某些訊號時會自動列印call trace。

l         在使用者程式中添加檢查點，類似於assert機制，如果檢查點的條件不滿足，就執行call trace。

使用者態的call trace與核心態相同，同樣滿足EABI標準，原理如下：

在GNU標準中，有一個內建函數__builtin_frame_address。這個函數可以返回當前執行內容的棧底（Frame Header）指標（同時也是指向Back Chain Word的指標），通過這個指標得到當前調用棧。而這個調用棧中，會有上一級調用函數的棧底指標，通過這個指標再回溯到上一級的調用棧。以此類推完成整個call dump過程。

得到函數的地址後，可以通過符號表得到函數名字。如果是動態庫中定義的函數，還可以通過擴充函數dladdr得到這個函數的動態庫資訊。

Linux Kernel BUG:soft lockup CPU#1 stuck分析 1.線上核心bug日誌

 kernel:Modules linked in: fuse ipv6 power_meter bnx2 sg microcode serio_raw iTCO_wdtiTCO_vendor_support hpilo hpwdt i7core_edac edac_core shpchp ext4 mbcache jbd2sd_mod crc_t10dif hpsa radeon ttm drm_kms_helper drm i2c_algo_bit i2c_coredm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan]

 kernel: Pid:5483, comm: master Not tainted 2.6.32-220.el6.x86_64 #1

 kernel: CallTrace:

 kernel:[<ffffffff81069b77>] ? warn_slowpath_common+0x87/0xc0

 kernel:[<ffffffff81069bca>] ? warn_slowpath_null+0x1a/0x20

 kernel:[<ffffffff810ea8ae>] ? rb_reserve_next_event+0x2ce/0x370

 kernel:[<ffffffff810eab02>] ? ring_buffer_lock_reserve+0xa2/0x160

 kernel:[<ffffffff810ec97c>] ? trace_buffer_lock_reserve+0x2c/0x70

 kernel:[<ffffffff810ecb16>] ? trace_current_buffer_lock_reserve+0x16/0x20

kernel:[<ffffffff8107ae1e>] ? ftrace_raw_event_hrtimer_cancel+0x4e/0xb0

 kernel:[<ffffffff81095e7a>] ? hrtimer_try_to_cancel+0xba/0xd0

kernel:[<ffffffff8106f634>] ? do_setitimer+0xd4/0x220

 kernel:[<ffffffff8106f88a>] ? alarm_setitimer+0x3a/0x60

 kernel:[<ffffffff8107c27e>] ? sys_alarm+0xe/0x20

kernel:[<ffffffff8100b308>] ? tracesys+0xd9/0xde

 kernel: ---[end trace 4d0a1ef2e62cb1a2 ]---

 

2.核心軟死結（soft lockup）bug原因分析

         Soft lockup名稱解釋：所謂，soft lockup就是說，這個bug沒有讓系統徹底死機，但是若干個進程（或者kernel thread）被鎖死在了某個狀態（一般在核心地區），很多情況下這個是由於核心鎖的使用的問題。

         Linux核心對於每一個cpu都有一個監控進程，在技術界這個叫做watchdog（看門狗）。通過ps –ef | grep watchdog能夠看見，進程名稱大概是watchdog/X（數字：cpu邏輯編號1/2/3/4之類的）。這個進程或者線程每一秒鐘運行一次，否則會睡眠和待機。這個進程運行會收集每一個cpu運行時使用資料的時間並且存放到屬於每個cpu自己的核心資料結構。在核心中有很多特定的中斷函數。這些中斷函數會調用soft lockup計數，他會使用當前的時間戳記與特定（對應的）cpu的核心資料結構中儲存的時間對比，如果發現當前的時間戳記比對應cpu儲存的時間大於設定的閥值，他就假設監測進程或看門狗線程在一個相當可觀的時間還沒有執。Cpu軟鎖為什麼會產生，是怎麼產生的。如果linux核心是經過精心設計安排的CPU調度訪問，那麼怎麼會產生cpu軟死結。那麼只能說由於使用者開發的或者第三方軟體引入，看我們伺服器核心panic的原因就是qmgr進程引起。因為每一個無限的迴圈都會一直有一個cpu的執行流程（qmgr進程示一個後台郵件的訊息佇列服務進程），並且擁有一定的優先順序。Cpu調度器調度一個驅動程式來運行，如果這個驅動程式有問題並且沒有被檢測到，那麼這個驅動程式將會暫用cpu的很長時間。根據前面的描述，看門狗進程會抓住（catch）這一點並且拋出一個軟死結（soft lockup）錯誤。軟死結會掛起cpu使你的系統不可用。

         如果是使用者空間的進程或線程引起的問題backtrace是不會有內容的，如果核心線程那麼在soft lockup訊息中會顯示出backtrace資訊。 3.根據linux核心源碼分析錯誤

         根據我們第一部分核心拋出的錯誤資訊和call trace（linux核心的跟蹤子系統）來分析產生的具體原因。

首先根據我們的centos版本安裝相應的linux核心源碼，具體步驟如下：

（1）下載源碼的rpm包kernel-2.6.32-220.17.1.el6.src.rpm

（2）安裝相應的依賴庫，命令：yuminstall rpm-build redhat-rpm-config asciidoc newt-devel

（3）安裝源碼包：rpm -ikernel-2.6.32-220.17.1.el6.src.rpm

（4）進入建立源碼的目錄：cd~/rpmbuild/SPECS

（5）建立產生源碼目錄：rpmbuild-bp --target=`uname -m` kernel.spec

 

下面開始真正的根據核心bug日誌分析源碼：

（1）第一階段核心錯誤日誌分析（時間在Dec 4 14:03:34這個階段的日誌輸出程式碼分析，其實這部分代碼不會導致cpu軟死結，主要是第二階段錯誤記錄檔顯示導致cpu軟死結）

我們首先通過日誌定位到相關原始碼：看下面日誌：Dec 4 14:03:34 BP-YZH-1-xxxx kernel: WARNING: atkernel/trace/ring_buffer.c:1988 rb_reserve_next_event+0x2ce/0x370() (Not tainted)

根據日誌內容我們可以很容易的定位到kernel/trace/ring_buffer.c這個檔案的1988行代碼如下：WARN_ON(1)。

         先簡單解釋一下WARN_ON的作用：WARN_ON只是列印出當前棧資訊，不會panic。所以會看到後面有一大堆的棧資訊。這個宏定義如下：

#ifndef WARN_ON

#defineWARN_ON(condition) ({                                            \

         int __ret_warn_on = !!(condition);                             \

         if (unlikely(__ret_warn_on))                                         \

                   __WARN();                                                               \

         unlikely(__ret_warn_on);                                              \

})

#endif

這個宏很簡單保證傳遞進來的條件值為0或者1（兩次邏輯非操作的結果），然後使用分支預測技術（保證執行機率大的分支緊鄰上面的指令）判斷是否需要調用__WARN()宏定義。如果滿足條件執行了__WARN()宏定義也接著執行一條空指令;。上面調用WARN_ON宏是傳遞的1，所以會執行__WARN()。下面繼續看一下__WARN()宏定義如下：

#define __WARN()            warn_slowpath_null(__FILE__,__LINE__)

從接下來的call trace資訊中我們也確實發現調用了warn_slowpath_null這個函數。通過在linux核心原始碼中搜尋這個函數的實現，發現在panic.c（核心恐慌時的相關功能實現）中實現如下：

voidwarn_slowpath_null(const char *file, int line)

{

         warn_slowpath_common(file, line,__builtin_return_address(0),

                                TAINT_WARN, NULL);

}

EXPORT_SYMBOL(warn_slowpath_null);//都出這個符號，讓其他模組可以使用這個函數

同樣的我們看到了warn_slowpath_common這個函數，而在call trace當中這個函數在warn_slowpath_null函數之前列印出來，再次印證了這個流程是正確的。同樣在panic.c這個檔案中我發現了warn_slowpath_common這個函數的實現如下：

static voidwarn_slowpath_common(const char *file, int line, void *caller,

                                      unsigned taint, struct slowpath_args *args)

{

         const char *board;

 

         printk(KERN_WARNING "------------[ cut here]------------\n");

         printk(KERN_WARNING "WARNING: at %s:%d %pS()(%s)\n",

                   file, line, caller, print_tainted());

         board = dmi_get_system_info(DMI_PRODUCT_NAME);//得到dmi系統資訊

         if (board)

                   printk(KERN_WARNING "Hardware name:%s\n", board);//通過我們的日誌資訊可以發現我們硬體名稱是ProLiant DL360 G7

 

         if (args)

                   vprintk(args->fmt, args->args);

 

         print_modules();//列印系統模組資訊

         dump_stack();//dump資訊輸出（call trace開始）

         print_oops_end_marker();//列印oops結束

         add_taint(taint);

}

分析這個函數的實現不難發現我們的很多日誌資訊從這裡開始輸出，包括列印一些系統資訊，就不繼續深入分析了（請看代碼注釋，裡面調用相關函數列印對應資訊，通過我分析這些函數的實現和我們的日誌資訊完全能夠對應，其中dump_stack是與cpu體繫結構相關的，我們的伺服器應該是屬於x86體系）。這裡在繼續分析一下dump_stack函數的實現，因為這個是與cpu體繫結構相關的，而且這個函數直接反應出導致核心panic的相關進程。這個函數實現如下：

/*

 * The architecture-independent dump_stackgenerator

 */

void dump_stack(void)

{

         unsigned long stack;