深入理解 kernel panic 的流程

我們在項目開發(fā)過程中，很多時候會出現(xiàn)由于某種原因經(jīng)常會導(dǎo)致手機系統(tǒng)死機重啟的情況（重啟分Android重啟跟kernel重啟，而我們這里只討論kernel重啟也就是 kernel panic 的情況），死機重啟基本算是影響最嚴重的系統(tǒng)問題了，有穩(wěn)定復(fù)現(xiàn)的，也有概率出現(xiàn)的，解題難度也千差萬別，出現(xiàn)問題后，通常我們會拿到類似這樣的kernel log信息（下面log僅以調(diào)用BUG()為例，其它異常所致的死機log信息會有一些不同之處）：

[????2.052157]?<2>-(2)[1:swapper/0]------------[?cut?here?]------------
[????2.052163]?<2>-(2)[1:swapper/0]Kernel?BUG?at?c04289dc?[verbose?debug?info?unavailable]
[????2.052169]?<2>-(2)[1:swapper/0]Internal?error:?Oops?-?BUG:?0?[#1]?PREEMPT?SMP?ARM
[????2.052178]?<2>-(2)[1:swapper/0]disable?aee?kernel?api[????3.052192]?<2>-(2)[1:swapper/0]Non-crashing?CPUs?did?not?react?to?IPI
[????3.052204]?<2>-(2)[1:swapper/0]CPU:?2?PID:?1?Comm:?swapper/0?Tainted:?G????????W??????3.18.35+?#3
[????3.052211]?<2>-(2)[1:swapper/0]task:?df060000?ti:?df04a000?task.ti:?df04a000
[????3.052227]?<2>-(2)[1:swapper/0]PC?is?at?ltr553_i2c_probe+0x94/0x9c
[????3.052233]?<2>-(2)[1:swapper/0]LR?is?at?0x0
[????3.052242]?<2>-(2)[1:swapper/0]pc?:?[<c04289dc>]????lr?:?[<00000000>]????psr:?a0000113
[????3.052242]?<2>sp?:?df04bd30??ip?:?00000000??fp?:?df04bd4c
[????3.052249]?<2>-(2)[1:swapper/0]r10:?00000003??r9?:?de348fc0??r8?:?c0428948
[????3.052255]?<2>-(2)[1:swapper/0]r7?:?dea1bc00??r6?:?dea1bc04??r5?:?dea1bc20??r4?:?c0b53358
[????3.052262]?<2>-(2)[1:swapper/0]r3?:?c115ef4c??r2?:?00000000??r1?:?00000000??r0?:?de366a00
[????4.354655]?<2>-(2)[1:swapper/0]?oops_end,?1,?11
[????4.354740]?<2>-(2)[1:swapper/0]Kernel?panic?-?not?syncing:?Fatal?exception

這是linux 內(nèi)核在死機之前輸出的相關(guān)重要信息，包括PC指針、調(diào)用棧等在內(nèi)的非常重要的便于Debug的線索，比如我們可以借助GUN tools（add2Line）工具結(jié)合內(nèi)核符號映射表vmlinux來定位當(dāng)前PC指針所在的代碼具體行數(shù)(定位到出錯代碼行并不意味著就找到了問題的根本原因跟修復(fù)異常，這個需要根據(jù)異常的復(fù)雜程度而論)。深入理解這些關(guān)鍵打印log信息的含義和機制非常有助于我們對于此類死機問題的定位和分析（對于內(nèi)存被踩、硬件不穩(wěn)定導(dǎo)致的一類問題分析有局限性），這也是我們需要深入學(xué)習(xí)內(nèi)核異常流程的初衷。

這里我們必須弄清楚幾個問題：

這些死機前留下的關(guān)鍵register信息是怎么來的，有什么用，具體含義是什么？

如何利用這些遺留的線索找到出問題代碼具體在哪支文件，在哪一行？

內(nèi)核發(fā)生致命異常到死機的總流程是怎樣的，類似死機問題應(yīng)該如何著手分析？

為此，本文就從最常見的主動觸發(fā)BUG()為例解析上面的疑問及分析整個kernel panic流程。

什么是BUG() ?

有過驅(qū)動調(diào)試經(jīng)驗的人肯定都知道這個東西，這里的BUG跟我們一般認為的“軟件缺陷”可不是一回事，這里說的BUG()其實是linux kernel中用于攔截內(nèi)核程序超出預(yù)期的行為，屬于軟件主動匯報異常的一種機制。這里有個疑問，就是什么時候會用到呢？一般來說有兩種用到的情況，一是軟件開發(fā)過程中，若發(fā)現(xiàn)代碼邏輯出現(xiàn)致命fault后就可以調(diào)用BUG()讓kernel死掉(類似于assert)，這樣方便于定位問題，從而修正代碼執(zhí)行邏輯;另外一種情況就是，由于某種特殊原因（通常是為了debug而需抓ramdump），我們需要系統(tǒng)進入kernel panic的情況下使用。

BUG()跟BUG_ON(1)其實本質(zhì)是一回事，后者只是在前者的基礎(chǔ)上做了簡單的封裝而已，BUG()的實現(xiàn) 本質(zhì)是埋入一條未定義指令:0xe7f001f2，觸發(fā)ARM發(fā)起Undefined Instruction異常（PS：ARM有分10種異常類型，詳細可以復(fù)習(xí)ARM異常模型章節(jié)）。

<kernel-3.18/arch/arm/include/asm/bug.h>
#define?BUG_INSTR_VALUE?0xe7f001f2
#define?BUG_INSTR(__value)?__inst_arm(__value)
#define?BUG()?_BUG(__FILE__,?__LINE__,?BUG_INSTR_VALUE)
#define?_BUG(file,?line,?value)?__BUG(file,?line,?value)
#define?__BUG(__file,?__line,?__value)????
do?{????????
?asm?volatile(BUG_INSTR(__value)?"n");???
?unreachable();??????
}?while?(0)

BUG() 流程分析

BUG()到系統(tǒng)重啟的總流程圖:

調(diào)用BUG()會向CPU下發(fā)一條未定義指令而觸發(fā)ARM發(fā)起未定義指令異常，隨后進入kernel異常處理流程歷經(jīng) Oops，die()，__die()等流程輸出用于調(diào)試分析的關(guān)鍵線索，最后進入panic()結(jié)束自己再獲得重生的過程,這個就是整個過程的基本流程，下面先來看die()具體做了什么呢？

die() 流程

源碼：

void?die(const?char?*str,?struct?pt_regs?*regs,?int?err)
{
?enum?bug_trap_type?bug_type?=?BUG_TRAP_TYPE_NONE;
?unsigned?long?flags?=?oops_begin();
?int?sig?=?SIGSEGV;
?
?if?(!user_mode(regs))
??bug_type?=?report_bug(regs->ARM_pc,?regs);
?if?(bug_type?!=?BUG_TRAP_TYPE_NONE)
??str?=?"Oops?-?BUG";
?if?(__die(str,?err,?regs))
??sig?=?0;
?oops_end(flags,?regs,?sig);
}

總流程大致如下：

通常來說，代碼分析過程結(jié)合kernel log一起看會理解來得更加深刻，如果是BUG()/BUG_ON(1)導(dǎo)致的異常，那么走到report_bug 就可以看到下面標志性 log：

enum?bug_trap_type?report_bug(unsigned?long?bugaddr,?struct?pt_regs?*regs)?
{
...
?if?(!is_valid_bugaddr(bugaddr))
??return?BUG_TRAP_TYPE_NONE;
...
?printk(KERN_DEFAULT?"------------[?cut?here?]------------n");
?if?(file)
??pr_crit("kernel?BUG?at?%s:%u!n",?file,?line);
?else
??pr_crit("Kernel?BUG?at?%p?[verbose?debug?info?unavailable]n",
???(void?*)bugaddr);
?
===>
[????2.052157]?<2>-(2)[1:swapper/0]------------[?cut?here?]------------
[????2.052163]?<2>-(2)[1:swapper/0]Kernel?BUG?at?c04289dc?[verbose?debug?info?unavailable]
[????2.052169]?<2>-(2)[1:swapper/0]Internal?error:?Oops?-?BUG:?0?[#1]?PREEMPT?SMP?ARM

所以如果在log中看到了這個 “[ cut here ]” 的信息就推斷是軟件發(fā)生致命fault而主動call了BUG()所致的系統(tǒng)重啟了，就可以根據(jù)相關(guān)信息嘗試定位分析修復(fù)異常了.這里要注意的是還有另外一種__WARN()的情況也會打印出 “[ cut here ]” 的標志性log但是內(nèi)核并不會掛掉，容易造成誤導(dǎo)：

#define?__WARN()????warn_slowpath_null(__FILE__,?__LINE__)
#define?__WARN_printf(arg...)?warn_slowpath_fmt(__FILE__,?__LINE__,?arg)
void?warn_slowpath_fmt(const?char?*file,?int?line,?const?char?*fmt,?...)
{
...
?warn_slowpath_common(file,?line,?__builtin_return_address(0),
????????TAINT_WARN,?&args);
static?void?warn_slowpath_common(const?char?*file,?int?line,?void?*caller,
?????unsigned?taint,?struct?slowpath_args?*args)
{
...
?pr_warn("------------[?cut?here?]------------n");
?pr_warn("WARNING:?CPU:?%d?PID:?%d?at?%s:%d?%pS()n",
??raw_smp_processor_id(),?current->pid,?file,?line,?caller);
?
===>
[????1.106219]?<2>-(2)[1:swapper/0]------------[?cut?here?]------------
[????1.107018]?<2>-(2)[1:swapper/0]WARNING:?CPU:?2?PID:?1?at?/home/android/work/prj/n-6580/kernel-3.18/kernel/irq/manage.c:454?__enable_irq+0x50/0x8c()

所以其實從顯現(xiàn)上很好區(qū)分兩種情況，如果是BUG()/BUG_ON(1)那么內(nèi)核一定會掛掉重啟，而__WARN()只會dump_stack()而不會死機, 從源碼跟log信息也可以容易區(qū)分兩種情況，如果是BUG()/BUG_ON(1)的話一定有類似下面的log輸出，只要搜索關(guān)鍵字：“Internal error: Oops” 即可。

[????2.052163]?<2>-(2)[1:swapper/0]Kernel?BUG?at?c04289dc?[verbose?debug?info?unavailable]
[????2.052169]?<2>-(2)[1:swapper/0]Internal?error:?Oops?-?BUG:?0?[#1]?PREEMPT?SMP?ARM

__die() 流程分析

從上面輸出的log信息還不足以定位具體出問題的代碼位置，包括定位異常所需要的最關(guān)鍵的 PC指針、調(diào)用棧等這些對于調(diào)試來說至關(guān)重要的線索信息都是在__die()中輸出。

流程圖：

打印出標志性log信息：

static?int?__die(const?char?*str,?int?err,?struct?pt_regs?*regs)
{
...
?printk(KERN_EMERG?"Internal?error:?%s:?%x?[#%d]"?S_PREEMPT?S_SMP
????????S_ISA?"n",?str,?err,?++die_counter);
===>
[????2.052169]?<2>-(2)[1:swapper/0]Internal?error:?Oops?-?BUG:?0?[#1]?PREEMPT?SMP?ARM

log 顯示異常str是Oops - BUG，error-code 為0，die計數(shù)器次數(shù)：1

Oops 的本意為 “哎呀” 的一個俚語，這里意形象的意指kernel出現(xiàn)了一件意外而不知道該如何處理的事件。

notify_die() 會通知對Oops感興趣的模塊執(zhí)行相關(guān)回調(diào)，比如mtk的aee異常引擎模塊就是通過注冊到die_chain通知鏈上的。

int?notrace?notify_die(enum?die_val?val,?const?char?*str,
????????struct?pt_regs?*regs,?long?err,?int?trap,?int?sig)
{
?struct?die_args?args?=?{
??.regs?=?regs,
??.str?=?str,
??.err?=?err,
??.trapnr?=?trap,
??.signr?=?sig,
?};
?return?atomic_notifier_call_chain(&die_chain,?val,?&args);
}

mtk的aee異常引擎在kernel初始化的時候會去注冊到die_chain通知鏈，而且我們可以看到其實還注冊了panic通知鏈。

int?__init?aee_ipanic_init(void)
{
?spin_lock_init(&ipanic_lock);
?mrdump_init();
?atomic_notifier_chain_register(&panic_notifier_list,?&panic_blk);
?register_die_notifier(&die_blk);
?register_ipanic_ops(&ipanic_oops_ops);
?ipanic_log_temp_init();
?ipanic_msdc_init();
?LOGI("ipanic:?startup,?partition?assgined?%sn",?AEE_IPANIC_PLABEL);
?return?0;
}

而對我們調(diào)試追蹤有用的關(guān)鍵信息是在 __show_regs() 里面打印的：

void?__show_regs(struct?pt_regs?*regs)
{
?unsigned?long?flags;
?char?buf[64];
?
?show_regs_print_info(KERN_DEFAULT);
?print_symbol("PC?is?at?%sn",?instruction_pointer(regs));
?print_symbol("LR?is?at?%sn",?regs->ARM_lr);
?printk("pc?:?[<%08lx>]????lr?:?[<%08lx>]????psr:?%08lxn"
????????"sp?:?%08lx??ip?:?%08lx??fp?:?%08lxn",
??regs->ARM_pc,?regs->ARM_lr,?regs->ARM_cpsr,
??regs->ARM_sp,?regs->ARM_ip,?regs->ARM_fp);
?printk("r10:?%08lx??r9?:?%08lx??r8?:?%08lxn",
??regs->ARM_r10,?regs->ARM_r9,
??regs->ARM_r8);
?printk("r7?:?%08lx??r6?:?%08lx??r5?:?%08lx??r4?:?%08lxn",
??regs->ARM_r7,?regs->ARM_r6,
??regs->ARM_r5,?regs->ARM_r4);
?printk("r3?:?%08lx??r2?:?%08lx??r1?:?%08lx??r0?:?%08lxn",
??regs->ARM_r3,?regs->ARM_r2,
??regs->ARM_r1,?regs->ARM_r0);
?flags?=?regs->ARM_cpsr;
?buf[0]?=?flags?&?PSR_N_BIT???'N'?:?'n';
?buf[1]?=?flags?&?PSR_Z_BIT???'Z'?:?'z';
?buf[2]?=?flags?&?PSR_C_BIT???'C'?:?'c';
?buf[3]?=?flags?&?PSR_V_BIT???'V'?:?'v';
?buf[4]?=?'';
?printk("Flags:?%s??IRQs?o%s??FIQs?o%s??Mode?%s??ISA?%s??Segment?%sn",
??buf,?interrupts_enabled(regs)???"n"?:?"ff",
??fast_interrupts_enabled(regs)???"n"?:?"ff",
??processor_modes[processor_mode(regs)],
??isa_modes[isa_mode(regs)],
??get_fs()?==?get_ds()???"kernel"?:?"user");
?show_extra_register_data(regs,?128);
}
void?dump_stack_print_info(const?char?*log_lvl)
{
?printk("%sCPU:?%d?PID:?%d?Comm:?%.20s?%s?%s?%.*sn",
????????log_lvl,?raw_smp_processor_id(),?current->pid,?current->comm,
????????print_tainted(),?init_utsname()->release,
????????(int)strcspn(init_utsname()->version,?"?"),
????????init_utsname()->version);
...

這里打印出了重要的pc停下的位置、相關(guān)寄存器信息，發(fā)生的是user還是kernel的異常、發(fā)生異常的cpu、進程pid等信息。

接下來 dump_mem() 用于dump出當(dāng)前線程的內(nèi)存信息：

dump_mem(KERN_EMERG,?"Stack:?",?regs->ARM_sp,
?THREAD_SIZE?+?(unsigned?long)task_stack_page(tsk));

使用 dump_backtrace(regs, tsk) 打印出調(diào)試最直觀的調(diào)用棧信息：

[????3.056363]?<2>-(2)[1:swapper/0]Backtrace:?-(2)[1:swapper/0]
[?3.056386]?<2>-(2)[1:swapper/0][<c010badc>]?(dump_backtrace)?from?[<c010bc7c>]?(show_stack+0x18/0x1c)?[?3.056393]?<2>-(2)[1:swapper/0]?r6:c103d790-(2)[1:swapper/0]?r5:ffffffff-(2)[1:swapper/0]?r4:00000000-(2)[1:swapper/0]?r3:00000000-(2)[1:swapper/0]?[?3.056426]?<2>-(2)[1:swapper/0][<c010bc64>]?(show_stack)?from?[<c0a91e64>]?(dump_stack+0x90/0xa4)?[?3.056439]?<2>-(2)[1:swapper/0][<c0a91dd4>]?(dump_stack)?from?[<c072d264>]?(ipan6503]?<2>-(2)[1:swapper/0][<c013e6bc>]?(notifier_call_chain)?from?[<c013eb84>]?(atomic_notifier_call_chain+0x3c/0x50)?[?3.056509]?<2>-(2)[1:swapper/0]?r10:c10efec4-(2)[1:swapper/0]?r9:df060000-(2)[1:swapper/0]?r8:df04a020-(2)[1:swapper/0]?r7:c0caaaf0-(2)[1:swapper/0]?r6:c10f0c88-(2)[1:swapper/0]?r5:00000001?[?3.056539]?<2>-(2)[1:swapper/0]?r4:df04bb74-(2)[1:swapper/0]?[?3.056554]?<2>-(2)[1:swapper/0][<c013eb48>]?(atomic_notifier_call_chain)?from?[<c013f244>]?(notify_die+0x44/0x4c)?[?3.056560]?<2>-(2)[1:swapper/0]?r6:df04bce8-(2)[1:swapper/0]?r5:00000000-(2)[1:swapper/0]?r4:00000001-(2)[1:swapper/0]?[?3.056585]?<2>-(2)[1:swapper/0][<c013f200>]?(notify_die)?from?[<c010bd94>]?(die+0x114/0x41c)?[?3.056590]?<2>-(2)[1:swapper/0]?r4:c102826c-(2)[1:swapper/0]?[?3.056607]?<2>-(2)[1:swapper/0][<c010bc80>]?(die)?from?[<c010c0c0>]?(arm_notify_die+0x24/0x5c)?[?3.056612]?<2>-(2)[1:swapper/0]?r10:df04a000-(2)[1:swapper/0]?r9:00000000-(2)[1:swapper/0]?r8:df04bce8-(2)[1:swapper/0]?r7:e7f001f2-(2)[1:swapper/0]?r6:df04a000-(2)[1:swapper/0]?r5:c04289dc?[?3.056642]?<2>-(2)[1:swapper/0]?r4:00000004-(2)[1:swapper/0]?[?3.056658]?<2>-(2)[1:swapper/0][<c010c09c>]?(arm_notify_die)?from?[<c01001cc>]?(do_undefinstr+0x1a4/0x1ec)?[?3.056670]?<2>-(2)[1:swapper/0][<c0100028>]?(do_undefinstr)?from?[<c010c98c>]?(__und_svc_finish+0x0/0x34)?[?3.056676]?<2>-(2)[1:swapper/0]Exception?stack(0xdf04bce8?to?0xdf04bd30)?[?3.056687]?<2>-(2)[1:swapper/0]bce0:?de366a00?00000000?00000000?c115ef4c?c0b53358?dea1bc20?[?3.056698]?<2>-(2)[1:swapper/0]bd00:?dea1bc04?dea1bc00?c0428948?de348fc0?00000003?df04bd4c?00000000?df04bd30?[?3.056706]?<2>-(2)[1:swapper/0]bd20:?00000000?c04289dc?a0000113?ffffffff?[?3.056711]?<2>-(2)[1:swapper/0]?r9:c010c98c-(2)[1:swapper/0]?r8:e7100000-(2)[1:swapper/0]?r7:00000000-(2)[1:swapper/0]?r6:c010cd98-(2)[1:swapper/0]?r5:00000000-(2)[1:swapper/0]?r4:c04289e0?[?3.056750]?<2>-(2)[1:swapper/0][<c0428948>]?(ltr553_i2c_probe)?from?[<c07d88d8>]?(i2c_device_probe+0xd0/0x12c)?[?3.056756]?<2>-(2)[1:swapper/0]?r5:dea1bc20-(2)[1:swapper/0]?r4:c0b53358-(2)[1:swapper/0]?[?3.056778]?<2>-(2)[1:swapper/0][<c07d8808>]?(i2c_device_probe)?from?[<c03c298c>]?(driver_probe_device+0x160/0x43c)

通過上面的調(diào)用棧信息結(jié)合GUN Tools（add2Line）基本就可以定位發(fā)生異常的具體代碼位置了。

最后會通過dump_instr(KERN_EMERG, regs) 打印出pc指針和前4條指令：

static?void?dump_instr(const?char?*lvl,?struct?pt_regs?*regs)
{
...
?for?(i?=?-4;?i?<?1?+?!!thumb;?i++)?{
??unsigned?int?val,?bad;
??if?(thumb)
???bad?=?__get_user(val,?&((u16?*)addr)[i]);
??else
???bad?=?__get_user(val,?&((u32?*)addr)[i]);
??if?(!bad)
???p?+=?sprintf(p,?i?==?0???"(%0*x)?"?:?"%0*x?",?width,?val);
??else?{
???p?+=?sprintf(p,?"bad?PC?value");
???break;
??}
?}
?printk("%sCode:?%sn",?lvl,?str);
..
===>
[????3.226706]?<2>-(2)[1:swapper/0][<c0a8ae74>]?(/0]Code:?e89da830?e30e3f4c?e34c3115?e5830000?(e7f001f2)

看到這個 e7f001f2 了吧，是不是很眼熟？這個就是BUG()中埋入的未定義指令！

到這一步，大部分關(guān)鍵信息都已經(jīng)輸出了，可以通過add2Line工具定位出具體死在的代碼行號，大致看看發(fā)生了什么，如果是BUG()導(dǎo)致的異常，那么就可以考慮分析和修復(fù)異常了，因為BUG()屬于主動匯報異常，一般來說debug難度會相對其它的被動上報方式容易得多.

例如：

從上面log知PC死在的地址，通過add2Line工具結(jié)合內(nèi)核符號映射表 vmlinux 就可以定位出具體代碼所在文件行號：

arm-linux-androideabi-addr2line?-e?out/target/product/$project/obj/KERNEL_OBJ/vmlinux?-f?-C?c04289dc
ltr553_i2c_probe
/aosp/kernel-3.18/drivers/misc/mediatek/alsps/ltr553/ltr553.c:3278

定位到了具體代碼行號就可以進一步分析代碼log找出問題原因修復(fù)異常了(一般來說BUG()導(dǎo)致的異常比較好解，其它的情況難度就是天差地別了..)。 那么接下來kernel要干什么呢？重要信息都輸出完了接下來就直接走 kernel panic 流程了.

panic 流程

panic 本意是“恐慌”的意思，這里意旨kernel發(fā)生了致命錯誤導(dǎo)致無法繼續(xù)運行下去的情況。

流程圖：

最后附上總時序圖：