1、前言
1.1 目的
能夠結合知識背景，藉助相關除錯工具，使用一般分析手段分析、定位解決專案過程中遇到的宕機類系統穩定性問題，提升工作效率
持續積累，拓寬知識深度和廣度
1.2 宕機？
指系統發生致命性異常導致主動或者被動進入系統完全不可用的狀態，導致系統宕機的問題原因有很多，排除硬體問題，還有這些大模組：Android、Linux kenrel、modem、TZ 等等，各個子系統都有可能導致系統宕機重啟，我們這裡主要介紹最常見的Linux kernel panic的一般除錯分析手法。
1.3 除錯策略
。穩定復現的問題，可以藉助飛線抓uart log的方式來獲取異常現場，kernel在發生panic之前會把很多重要暫存器資訊、以及重要的call stack（呼叫棧）資訊打印出來（可參考http://blog.csdn.net/forever_2015/article/details/53235716），通常可以藉助相關GNU工具（addr2Line) 解析出異常地址所在的檔案、函式、行號來定位問題。這是最常用的分析手法，對於很多簡單的宕機問題通常可以比較清晰的定位解決。
。概率性復現的問題，上面飛線抓uart log的方式就顯得有些無力了，由於出現異常的時機存在不確定性，所以必須要一直連著串列埠線操作才可以，還有些問題幾天或者更長時間才出現一次，此種情況下，普通的抓uart log的方式就顯得很蒼白無力了。這個時候就需要藉助另外的分析手段抓ramdump分析了。ramdump是什麼？其實就是指記憶體轉儲，簡單來說就是整個DRAM的執行時內容資料，當系統發生崩潰性異常時候，通過一種機制實現將DRAM中的資料儲存起來的一種方式，保留了異常現場，待離線分析用。ramdump中保留了所以異常時候的DRAM中的資訊，包括各種全域性變數、區域性變數、程序狀態等待供除錯的資訊，通過Crash、gdb、Trace32等工具就可以完成這些資訊的提前，非常有助於複雜問題的分析。
2、案例描述
2.1 問題現象：
高通8940平臺系統滅屏下，快速重複用錯誤指紋觸控指紋模組（或亮屏在指紋列表目錄下），系統宕機，持續測試30min出現2-4次，概率很高。
2.2 初步判斷
我們知道Android層（使用者空間程序）如果主執行緒（tid == 0）被堵塞了會觸發Watchdog time out導致system_server程序被殺 =》zygote被殺 =》開機動畫響起，出現Android crash的情況：

    services/core/java/com/android/server/Watchdog.java :533
    Slog.w(TAG, "*** GOODBYE!");
    Process.killProcess(Process.myPid());
    System.exit(10);

通常這種情況出現異常後不會馬上宕機重啟，會有一個觸發WDT的等待時間（各種元件前臺後臺程序觸發時間設定策略不同），此種類型異常給使用者的感覺就是：指紋失效了，然後等個10s左右手機自動重啟。
而目前的情況不同，與測試mm溝通確認發現，出問題後手機沒有任何等待，直接黑屏宕機，沒有重啟，直接進入了ramdump模式，所以可以初步判斷為底層發現異常，而跟指紋相關的最大可能就是發生了kernel panic（TA crash異常最終會以Android wdt方式表現出來）。
3、ramdump的抓取
高通平臺首先保證機器是已使能ramdump抓取機制的，預設設定開關：

    kernel/drivers/power/reset/msm-poweroff.c
    static int download_mode = 1;

如果開啟了secboot 支援的專案還需要更改BOOT：

    BOOT.BF.3.3/boot_images/core/securemsm/secdbgplcy/oem/oem_debug_policy.c
    -//#define SKIP_SERIAL_NUMBER_CHECK 1
    +#define SKIP_SERIAL_NUMBER_CHECK 1

高通平臺可以使用PC端的QPST工具抓取全部的dump資訊，步驟如下：
安裝QPST工具（需要安裝QBUK驅動），開啟程式主介面，選址Ports分頁：

插入usb，自動識別抓取ramdump，完全傻瓜式操作：

大概5min左右完成，選擇 Help =》Open Log File Directory ，拿到抓取的ramdump資料：

PS: 若僅僅是為了測試除錯，可以這樣主動觸發ramdump
adb root
adb shell
echo c > /proc/sysrq-trigger
其本質就是讓核心訪問空指標記憶體，被MMU攔截而觸發data abort異常.
4、 ramdump解析
4.1 高通QCAP網站
https://cap.qti.qualcomm.com/default.aspx
登入高通賬戶後進入如下介面：（此處建議使用google瀏覽器，個別瀏覽器有不支援的情況）

點選 START NEW ANALYSIS

將對應模組（KERNEL/TZ/RPM/MODEM/ADSP等）的符號檔案（elf、vmlinux）路徑加到對應的選項裡面選擇開始即可，解析完成後會產生一個報告檔案：QCAPReport.html ，裡面會有各個模組的相關異常資訊描述，包括dmesg等等。QCAP的優點是使用簡單，工具安裝簡單，缺點是解析出來的資訊很有限，跟抓log差不多的意思，無法分析定位複雜問題。（QCAP的使用可以參考高通文件：80-nr964-54_j_qcap start-up guide.pdf）
4.2 ramdump-parse
（此指令碼只能解析kernel的異常，不同子系統需要配合不同的解析腳步）
ramdump-parse指令碼配置：http://blog.csdn.net/forever_2015/article/details/70185313
解析前需要確保vimlinux跟ramdump的一致性，可以按下面的方法確認：

    $ strings vmlinux |grep "Linux version"
    Linux version 3.18.31 (and[email protected]) (gcc version 4.9 20150123 (prerelease) (GCC) ) #1 SMP PREEMPT Wed Aug 9 23:23:27 CST 2017
     
    $ strings DDRCS0.BIN |grep "Linux version"
    Linux version 3.18.31 ([email protected]) (gcc version 4.9 20150123 (prerelease) (GCC) ) #1 SMP PREEMPT Wed Aug 9 23:23:27 CST 2017

如果不匹配，無法繼續分析，若確認匹配後就可以執行解析：

    $ ramdump-parser.sh
    Start ramdump parser..
    cd /home/android/tools/ramdump/tools/linux-ramdump-parser-v2
    python ramparse.py -v /home/android/share/fp-quick-wakeup/crash/Port_COM112-6901-die/vmlinux -g /home/android/tools/gnu-tools/aarch64-linux-android-4.9/bin/aarch64-linux-android-gdb  -n /home/android/tools/gnu-tools/aarch64-linux-android-4.9/bin/aarch64-linux-android-nm  -j /home/android/tools/gnu-tools/aarch64-linux-android-4.9/bin/aarch64-linux-android-objdump -a /home/android/share/fp-quick-wakeup/crash/Port_COM112-6901-die/ -o /home/android/share/fp-quick-wakeup/crash/Port_COM112-6901-die/out -x
     
        [1/32] --clock-dump ... 0.848617s
        [2/32] --cpr3-info ... 0.157973s
        [3/32] --cpr-info ... 1.026817s
        [4/32] --cpu-state ... 0.104325s
        [5/32] --ddr-compare ... 5.864537s
        [6/32] --check-for-watchdog ... 0.011254s
        [7/32] --parse-debug-image ... 10.632866s
        [8/32] --dmesg ... 0.519516s
    ...
    out: /home/android/share/fp-quick-wakeup/crash/Port_COM112-6901-die/out
    ls out/
    ClockDumps.txt  DDRCacheCompare.txt              MSM_DUMP_DATA_L1_DATA_CACHE_0x2  roareadiff.txt               t32_startup_script.cmm  thermal_info.txt
    core0_regs.cmm  dmesg_TZ.txt                     MSM_DUMP_DATA_L1_DATA_CACHE_0x3  secure_world_core0_regs.cmm  tasks_sched_stats0.txt  timerlist.txt
    core1_regs.cmm  kconfig.txt                      MSM_DUMP_DATA_L1_DATA_CACHE_0x6  secure_world_core1_regs.cmm  tasks_sched_stats1.txt  tmc-etf.bin
    core2_regs.cmm  launch_t32.sh                    MSM_DUMP_DATA_L1_DATA_CACHE_0x7  secure_world_core2_regs.cmm  tasks_sched_stats2.txt  tmc-etr.bin
    core3_regs.cmm  lpm.txt                          msm_iommu_domain_00.txt          secure_world_core3_regs.cmm  tasks_sched_stats3.txt  tmc_etr.txt
    core4_regs.cmm  mdpinfo_out.txt                  msm_iommu_domain_01.txt          secure_world_core4_regs.cmm  tasks_sched_stats4.txt  vmalloc.txt
    core6_regs.cmm  memory.txt                       msm_iommu_domain_02.txt          secure_world_core6_regs.cmm  tasks_sched_stats5.txt
    core7_regs.cmm  mem_stat.txt                     msm_iommu_domain_03.txt          secure_world_core7_regs.cmm  tasks_sched_stats6.txt
    cpr3_info.txt   MSM_DUMP_DATA_L1_DATA_CACHE_0x0  New Folder                       spm.txt                      tasks_sched_stats7.txt
    cprinfo.txt     MSM_DUMP_DATA_L1_DATA_CACHE_0x1  page_tables.txt                  t32_config.t32               tasks.txt

5、解題手段
5.1 分析dmesg
上面是解析完成後的檔案，有我們需要的kernel log，也就是檔案 dmesg_TZ.txt，開啟 dmesg_TZ.txt 看下大致發生了什麼事情？
搜尋關鍵字發現發生了kernel panic！
...

    [  423.400073] Unable to handle kernel NULL pointer dereference at virtual address 00000008
    [  423.400075] [silead finger_interrupt_handler 505]:S IRQ 19 , GPIO 12 state is 0
    [  423.400083] [silead finger_interrupt_handler 506]:state is 0
    [  423.400096] pgd = ffffffc0017eb000
    [  423.400103] [00000008] *pgd=000000008ea0a003, *pud=000000008ea0a003, *pmd=000000008ea0b003, *pte=006000000b000707
    [  423.400124] Internal error: Oops: 96000046 [#1] PREEMPT SMP
    [  423.400132] Modules linked in: wlan(O)
    [  423.400148] CPU: 4 PID: 0 Comm: swapper/4 Tainted: G        W  O   3.18.31-perf #1
    [  423.400155] Hardware name: Qualcomm Technologies, Inc. MSM8940-PMI8950 MTP (DT)
    [  423.400164] task: ffffffc04eae4980 ti: ffffffc0b28bc000 task.ti: ffffffc0b28bc000
    [  423.400182] PC is at run_timer_softirq+0x4ac/0x5ec
    [  423.400192] LR is at run_timer_softirq+0x324/0x5ec
    [  423.400199] pc : [<ffffffc0000feb98>] lr : [<ffffffc0000fea10>] pstate: 600001c5
    [  423.400204] sp : ffffffc0b28bfb60
    ...
    [  423.401490] Process swapper/4 (pid: 0, stack limit = 0xffffffc0b28bc058)
    [  423.401496] Call trace:
    [  423.401510] [<ffffffc0000feb98>] run_timer_softirq+0x4ac/0x5ec
    [  423.401523] [<ffffffc0000a6864>] __do_softirq+0x178/0x350
    [  423.401532] [<ffffffc0000a6c8c>] irq_exit+0x74/0xb0
    [  423.401543] [<ffffffc0000edf18>] __handle_domain_irq+0xb4/0xec
    [  423.401553] [<ffffffc00008254c>] gic_handle_irq+0x54/0x84
    [  423.401560] Exception stack(0xffffffc0b28bfd40 to 0xffffffc0b28bfe60)
    ...
    [  423.401671] [<ffffffc000085da8>] el1_irq+0x68/0xd4
    [  423.401685] [<ffffffc000851480>] cpuidle_enter_state+0xd0/0x224
    [  423.401695] [<ffffffc0008516ac>] cpuidle_enter+0x18/0x20
    [  423.401706] [<ffffffc0000e1cc0>] cpu_startup_entry+0x288/0x384
    [  423.401717] [<ffffffc000091d5c>] secondary_start_kernel+0x108/0x114
    [  423.401728] Code: b90052a0 34000840 f9400321 f9400720 (f9000420)
    [  423.401736] ---[ end trace d0daa1892c14378b ]---
    [  423.401753] Kernel panic - not syncing: Fatal exception in interrupt
    [  423.401774] CPU7: stopping

...
看到異常呼叫棧，一眼看不出問題所在，那麼我們需要搞清楚CPU發生了什麼事情？CPU停下的原因是什麼？
先來看當前64位CPU的狀態暫存器組PSTATE：《ARMv8-A Architecture reference manual-DDI0487A_g_armv8_arm.pdf》

pstate:600001c5
0x600001c5 ==》1610613189 ==》1100000000000000000000111000101
解析後代表的意思就是禁止debug異常，禁止IRQ，切換異常等級到EL1（Exception Level 1）,使用SP_EL1為堆疊指標，EL1說明異常確實是發生在kernel層，禁止IRQ是為了不讓被中斷干擾現場.
繼續看Oops：
[423.400124] Internal error: Oops:96000046[#1] PREEMPT SMP
這裡Oops後面接的96000046是ARM發生異常後上報的錯誤碼，分析kernel panic流程程式碼（可參考：http://blog.csdn.net/forever_2015/article/details/53235716）可知，這個錯誤碼就是ESR（異常綜合暫存器）暫存器的值，
根據上面PSTATE的解析，ESR暫存器也將是使用ESR_EL1，ESR_EL1暫存器的描述如下：
An ESR_ELx holds the syndrome information for an exception that is taken to AArch64 state

所以，ESR暫存器中的EC值保持了異常的型別等資訊，我們可以解析這個值：
0x96000046 ==》2516582470 ==》10010110000000000000000001000110
EC ==》100101
對應如下：

表面kernel層發生資料終止異常，並且沒有改變Exception level，也就是沒有路由到EL3或者sec-EL1.
==》宕機的原因就是因為CPU發生了 Data abort異常！那麼什麼時候會發生Data abort異常呢？簡單來說就是訪問了不可訪問的虛擬記憶體地址，被記憶體管理單元（MMU）攔截到的異常，比如最常見的空指標異常，核心執行緒訪問非核心虛擬地址空間等（核心虛擬地址空間：
0xFFFF_0000_0000_0000 =>0xFFFF_FFFF_FFFF_FFFF ）
現在宕機的原因是知道了，那麼接下來我們最想知道的就是導致宕機的程式碼是在哪裡，我們可以藉助add2Line工具解析出呼叫棧所在函式，檔案行號：

    $ aarch64-linux-android-addr2line -e vmlinux -f -C ffffffc0000feb98
    __list_del
    /home/android/project/6901-7.1/LA.UM.5.6/LINUX/android/kernel/msm-3.18/include/linux/list.h:89
     
     
    $ aarch64-linux-android-addr2line -e vmlinux -f -C ffffffc0000a6864
    static_key_count
    /home/android/project/6901-7.1/LA.UM.5.6/LINUX/android/kernel/msm-3.18/include/linux/jump_label.h:88
     
    $ aarch64-linux-android-addr2line -e vmlinux -f -C ffffffc0000a6c8c
    tick_irq_exit
    /home/android/project/6901-7.1/LA.UM.5.6/LINUX/android/kernel/msm-3.18/kernel/softirq.c:363

如此便可以還原呼叫棧的程式碼，最終是下面的程式碼導致的異常：

     87 static inline void __list_del(struct list_head * prev, struct list_head * next)
     88 {
     89     next->prev = prev;   ==》猜想那會不會是next->prev指標為NULL所致麼？
     90     prev->next = next;
     91 }

要確認是不是NULL指標所致，我們需要來看下對應的彙編指令，開啟Trace32，切到彙編原始碼混合顯示（也可以通過objdump -S vmlinux > vmlinux.S 檢視）：

為方便檢視，複製貼出來：

     static inline void __list_del(struct list_head * prev, struct list_head * next)
                           |{
                         89|        next->prev = prev;
       NSX:FFFFFFC0000FE958|F9000420 str x0,[x1,#0x8]; x0,[x1,#8]
                         90|        prev->next = next;
       NSX:FFFFFFC0000FE95C|F9000001            str     x1,[x0]
                        769|        entry->prev = LIST_POISON2;
       NSX:FFFFFFC0000FE960|D2804000            mov     x0,#0x200        ; x0,#512
       NSX:FFFFFFC0000FE964|F2FBD5A0            movk    x0,#0xDEAD,lsl #0x30   ; x0,#57005,lsl #48
       NSX:FFFFFFC0000FE968|F9000760            str     x0,[x27,#0x8]    ; x0,[x27,#8]
                           |...

簡單解釋下，
FFFFFFC0000FE968 ==》當前彙編指令的虛擬地址
F9000760 ===》彙編機器碼，ARM/ARM64的指令機器碼都是32位固定長度
str x0,[x27,#0x8]==》 彙編指令，；後的是註釋
根據AAPCS（ARM二進位制過程呼叫標準）引數傳遞規則，ARM64的 v0 - v7 引數直接由 x0 - x7 傳遞，其他引數由壓棧傳遞，子程式返回結果儲存到x0，
那麼這裡可推導如下：
x0 == prev
x1 == next
指令：strx0,[x1,#0x8]
x1+0x8 其實就是next+8個位元組的偏移，看下struct list_head 的結構：

    struct list_head {
        struct list_head *next, *prev;
    };

ARM體系結構中，ARM64一個指標佔8個位元組記憶體，也就是: [x1+0x8] == prev
所以這個str指令就是對應上面的next->prev = prev ，那麼我們來看下具體的暫存器x0，x1值是多少？
從dmesg log中找到當前發生異常的呼叫棧（注意，一定要找對應的異常棧的暫存器值），如下：

    [  423.400182] PC is at run_timer_softirq+0x4ac/0x5ec
    [  423.400192] LR is at run_timer_softirq+0x324/0x5ec
    [  423.400199] pc : [<ffffffc0000feb98>] lr : [<ffffffc0000fea10>] pstate: 600001c5
    [  423.400204] sp : ffffffc0b28bfb60
    [  423.400210] x29: ffffffc0b28bfb60 x28: ffffffc0b2619038
    [  423.400219] x27: ffffffc000c9a000 x26: 0000000000000000
    [  423.400228] x25: ffffffc001741120 x24: ffffffc0006e277c
    [  423.400237] x23: ffffffc0b2619000 x22: ffffffc0b28bfbf8
    [  423.400246] x21: ffffffc0b28bc000 x20: ffffffc0013d2000
    [  423.400254] x19: ffffffc0b2618000 x18: 0000007f9588e080
    [  423.400263] x17: 0000007f9a36d4b4 x16: ffffffc0001e4f6c
    [  423.400272] x15: 003b9aca00000000 x14: 0000000000000001
    [  423.400280] x13: 0000000000000000 x12: 0000000000000001
    [  423.400289] x11: 000000000000000f x10: ffffffc000c9c3f4
    [  423.400297] x9 : 0000000000000000 x8 : 0000000000000005
    [  423.400305] x7 : 0000000000000000 x6 : 000000000001451c
    [  423.400314] x5 : ffffffc0b2ae8000 x4 : 00135f1aa15bb200
    [  423.400323] x3 : 0000000000000018 x2 : 0000000000000000
    [  423.400331] x1 : 0000000000000000 x0 : ffffffc0b28bfbf8

上面可以看到，x1+0x8 ==0x0000000000000000+0x8==0x0000000000000008
上面我們有講過，ARM64核心的虛擬地址空間範圍是0xFFFF_0000_0000_0000 =>0xFFFF_FFFF_FFFF_FFFF
很明顯這個值0x0000000000000008不在範圍內，它屬於使用者空間的虛擬地址空間，肯定會被MMU攔截掉上報data abort異常,所以此題的真正原因是程式跑飛訪問非法地址所致.
CPU發生異常的原因已經明確了，但仔細一看，好像也看不出來具體是哪裡原始碼導致的宕機，而且這些都是核心本身的程式碼，沒人改動過的，為什麼會報異常呢？
目前看來從kernel log上的資訊無法直接分析出導致問題的具體原始碼，從dmesg的這些資訊我們已經知道出問題的是這個prev指標，但是比較難直接抓到導致異常的真凶原始碼位置。
5.2 Trace32分析
安裝：http://blog.csdn.net/forever_2015/article/details/70185527
5.2.1 啟動模擬器
前面使用ramdump-parse指令碼解析完成後，out下有生成這幾隻檔案：
launch_t32.sh t32_config.t32 t32_startup_script.cmm
但是需要做一些簡單修改才可以使用trace32工具載入（參考http://blog.csdn.net/forever_2015/article/details/70185638）
./launch_t32.sh

輸入v.f 調出 當前的呼叫棧關係

為便於分析傳參分析，需要將Locals的框框打鉤：

可以看到，異常時候的各種引數都顯示出來了，這樣就非常有利於我們debug了，這也是單純從dmesg無法得到的重要資訊！注意inline型別的函式會被編譯器預設優化掉，所以inline型別的函式的引數不可見，需要通過讀彙編程式碼，分析暫存器傳參推導。
輸入d.list 檢視PC停止的位置，如下高亮:

5.2.2 分析Call Stack：
為方便檢視，把呼叫棧資訊複製出來，如下：

     1. ...
    -007|die(
        |  ?,
        |    regs = 0xFFFFFFC0B28BFA40 -> (
        |      user_regs = (regs = (0xFFFFFFC0B28BFBF8, 0x0, 0x0, 0x18, 0x00135F1AA15BB200, 0xFFFFFFC0B2AE800
        |      regs = (0xFFFFFFC0B28BFBF8, 0x0, 0x0, 0x18, 0x00135F1AA15BB200, 0xFFFFFFC0B2AE8000, 0x0001451C
        |      sp = 0xFFFFFFC0B28BFB60,
        |      pc = 0xFFFFFFC0000FEB98,
        |      pstate = 0x600001C5,
        |      orig_x0 = 0xFFFFFFC0B2618000,
        |      syscallno = 0xFFFFFFC0000FE7D0),
        |    err = 0x96000046)
        |  flags = 0x01C0
        |  ret = 0x1
        |  tsk = 0xFFFFFFC04EAE4980
        |  die_counter = 0x1
    -008|__do_kernel_fault.part.5(
        |    mm = 0x0,
        |    addr = 0x8,
        |    esr = 0x96000046,
        |    regs = 0xFFFFFFC0B28BFA40)
    -009|do_page_fault(
        |    addr = 0x8,
        |    esr = 0x96000046,
        |    regs = 0xFFFFFFC0B28BFA40)
        |  tsk = 0xFFFFFFC04EAE4980
        |  mm = 0x0
        |  vm_flags = 0xFFFFFFC000C9A000
        |  vma = 0xFFFFFFC0B28BFA40
    -010|do_translation_fault(
        |    addr = 0x0A44,
        |    esr = 0x0124F800,
        |  ?)
    -011|do_mem_abort(
        |    addr = 0x8,
        |    esr = 0x96000046,
        |    regs = 0xFFFFFFC0B28BFA40)
        |  inf = 0xFFFFFFC0013DC790 -> (
        |    fn = 0xFFFFFFC000099A74,
        |    sig = 0x0B,
        |    code = 0x00030001,
        |    name = 0xFFFFFFC0010DF250 -> 0x6C)
        |  info = (
        |    si_signo = 0x0032D110,
        |    si_errno = 0xFFFFFFC0,
        |    si_code = 0x01C0,
        |    _sifields = (_pad = (0x7, 0x0, 0xB28BF9E0, 0xFFFFFFC0, 0x000A6D78, 0xFFFFFFC0, 0xB28BF9F0, 0xFFF
    -012|el1_da(asm)
     -->|exception
    -013|__list_del(inline)
    -013|detach_timer(inline)
    -013|detach_expired_timer(inline)
    -013|__run_timers(inline)
    -013|run_timer_softirq(
        |  ?)
        |  base = 0xFFFFFFC0B2618000 -> (
        |    lock = (rlock = (raw_lock = (owner = 0x6FCD, next = 0x6FCE))),
        |    running_timer = 0xFFFFFFC001741120 -> (
        |      entry = (next = 0xFFFFFFC0B27BC9B8, prev = 0xFFFFFFC0B27BC9B8),
        |      expires = 0x0000000100003098,
        |      base = 0xFFFFFFC0B27BC000,
        |      function = 0xFFFFFFC0006E277C -> ,
        |      data = 0x0,
        |      slack = 0xFFFFFFFF,
        |      start_pid = 0xFFFFFFFF,
        |      start_site = 0x0,
        |      start_comm = (0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0))
        |    timer_jiffies = 0x0000000100003035,
        |    next_timer = 0x0000000100003034,
        |    active_timers = 0x7,
        |    all_timers = 0x7,
        |    cpu_=_0x4,
        |    tv1 = (vec = ((next = 0xFFFFFFC0B2618038, prev = 0xFFFFFFC0B2618038), (next = 0xFFFFFFC0B2618048
        |    tv2 = (vec = ((next = 0xFFFFFFC0B2619038, prev = 0xFFFFFFC0B2619038), (next = 0xFFFFFFC0B2619048
        |    tv3 = (vec = ((next = 0xFFFFFFC0B2619438, prev = 0xFFFFFFC0B2619438), (next = 0xFFFFFFC0B2619448
        |    tv4 = (vec = ((next = 0xFFFFFFC0B2619838, prev = 0xFFFFFFC0B2619838), (next = 0xFFFFFFC0B2619848
        |    tv5 = (vec = ((next = 0xFFFFFFC0B2619C38, prev = 0xFFFFFFC0B2619C38), (next = 0xFFFFFFC0B2619C48
        |  fn = 0xFFFFFFC0006E277C ->
        |  data = 0x0
        |  it_func_ptr = 0x0
    ...

看到這裡，我們可以猜想是不是run_timer_softirq的引數出現了問題導致後面發生的一系列異常？可以從這個方向開始思考，我們先來看下這個函式的實現：

    static void run_timer_softirq(struct softirq_action *h)
    {
        struct tvec_base *base = __this_cpu_read(tvec_bases);
        hrtimer_run_pending();
        __run_deferrable_timers();
        if (time_after_eq(jiffies, base->timer_jiffies))
            __run_timers(base);
    }

我們看到這個函式最重要的引數變數就是這個base，傳入的*h沒有使用，繼續來看下*base的結構tvec_base ：

    struct tvec_base {
        spinlock_t lock;
        struct timer_list *running_timer;
        unsigned long timer_jiffies;
        unsigned long next_timer;
        unsigned long active_timers;
        unsigned long all_timers;
        int cpu;  // 跟蹤所在的CPU是哪個核，這裡是CPU 4
        struct tvec_root tv1;
        struct tvec tv2;
        struct tvec tv3;
        struct tvec tv4;
        struct tvec tv5;
    } ____cacheline_aligned;

這裡就看到，*base的結構裡面有個 struct timer_list * 的結構，我們繼續看它的結構是怎麼樣的：

    struct timer_list {
        /*
         * All fields that change during normal runtime grouped to the
         * same cacheline
         */
        struct list_head entry;
        unsigned long expires;
        struct tvec_base *base;
        void (*function)(unsigned long);
        unsigned long data;
        int slack;
    ...

這個就是核心裡面實現定時器標準的資料結構了，其中function這個指標就是time out後執行的callback，而且異常發生在CPU 4，
瞭解這些資料結構背景後就可以藉助T32工具來分析了，既然這個定時器發生了異常，那麼我們最想知道的是這是哪一個定時器？
它在原始碼中的定義是在哪個檔案哪個行號？這些都可以藉助Trace32工具來獲取.
首先我們檢視*running_timer的資料內容：
工具欄 調出：view -> Watch，輸入：(struct timer_list *)0xffffffc001741120

複製出來就是這樣：

    (struct timer_list *)0xffffffc001741120 = 0xFFFFFFC001741120 -> (
        entry = (next = 0xFFFFFFC0B27BC9B8, prev = 0xFFFFFFC0B27BC9B8),
        expires = 4294979736,
        base = 0xFFFFFFC0B27BC000,
        function = 0xFFFFFFC0006E277C,
        data = 0,
        slack = -1,
        start_pid = -1,
        start_site = 0x0,
        start_comm = (0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0))

這個就是發生異常的那個timer的資料結構例項，我們最希望的就是希望可以通過這裡的資料資訊找到它在原始碼的位置，然後進一步分析它，使用Trace32的dump分析功能就可以做到這點。
選單欄調出：view -》dump

輸入地址 0xffffffc001741120 然後點OK

右擊高亮，選擇view info：

同理，還可以看function的位置（0xFFFFFFC0006E277C）：

上面所示，出異常的timer例項就是：fp_drv/m_timer, callback = timer_out_handle，
原始碼位置也給出來了，那麼就可以著手修復問題了。
6、 同源不同表現
6.1 dmesg分析
導致Kernel panic的原始碼改動是同一處，但是宕機後的表現卻可能大不一樣，像這個問題當時出現的時候有抓到兩份ramdump，解開後卻發現表現不一樣（很可能每次出現宕機都在不一樣的地方），逆向推導過程總是需要耐心細心分析，加上一定的運氣成分，那麼就可以比較順利定位問題點，簡單介紹下：
解析ramdump後檢視的dmesg是這樣的：

    [  256.595276] list_add corruption. prev->next should be next (ffffffc0ab1d4178), but was ffffffc0aba4c628. (prev=ffffffc001b77da8).
    [  256.595282] Modules linked in: wlan(O)
    [  256.595299] CPU: 5 PID: 6210 Comm: mdss_fb0 Tainted: G        W  O   3.18.31 #1
    [  256.595305] Hardware name: Qualcomm Technologies, Inc. MSM8940-PMI8950 MTP (DT)
    [  256.595311] Call trace:
    [  256.595324] [<ffffffc000089b14>] dump_backtrace+0x0/0x270
    [  256.595334] [<ffffffc000089d98>] show_stack+0x14/0x1c
    [  256.595345] [<ffffffc000dbd254>] dump_stack+0x80/0xa4
    [  256.595356] [<ffffffc0000a3240>] warn_slowpath_common+0x8c/0xb0
    [  256.595366] [<ffffffc0000a32c4>] warn_slowpath_fmt+0x60/0x80
    [  256.595374] [<ffffffc000345dd4>] __list_add+0x74/0xf0
    [  256.595384] [<ffffffc00010356c>] __internal_add_timer+0xb4/0xbc
    [  256.595392] [<ffffffc000103b30>] internal_add_timer+0x34/0x90
    [  256.595404] [<ffffffc000dca78c>] schedule_timeout+0x1f0/0x278
    [  256.595414] [<ffffffc0003e95f0>] mdss_mdp_cmd_wait4pingpong+0x12c/0x534
    [  256.595424] [<ffffffc0003c1494>] mdss_mdp_display_wait4pingpong+0xd8/0x404
    [  256.595432] [<ffffffc0003c2110>] mdss_mdp_display_commit+0x890/0x1128
    [  256.595443] [<ffffffc0003f8c30>] mdss_mdp_overlay_kickoff+0x9ec/0x15f4
    [  256.595453] [<ffffffc00043e098>] __mdss_fb_display_thread+0x278/0x4c4
    [  256.595462] [<ffffffc0000beccc>] kthread+0xf0/0xf8
    [  256.595468] ---[ end trace 02fd337171f1bd82 ]---
    [  256.595498] ------------[ cut here ]------------
    [  256.595506] kernel BUG at /home/android/work/prj/6901-7.1/LA.UM.5.6/LINUX/android/kernel/msm-3.18/lib/list_debug.c:40!
    [  256.595513] Internal error: Oops - BUG: 0 [#1] PREEMPT SMP
    [  256.595519] Modules linked in: wlan(O)
    [  256.595533] CPU: 5 PID: 6210 Comm: mdss_fb0 Tainted: G        W  O   3.18.31 #1
    [  256.595538] Hardware name: Qualcomm Technologies, Inc. MSM8940-PMI8950 MTP (DT)
    [  256.595545] task: ffffffc02f5e6e00 ti: ffffffc002bdc000 task.ti: ffffffc002bdc000
    [  256.595553] PC is at __list_add+0xcc/0xf0
    [  256.595560] LR is at __list_add+0x74/0xf0
    [  256.595567] pc : [<ffffffc000345e2c>] lr : [<ffffffc000345dd4>] pstate: 200001c5

看到紅色部分的kernel BUG 我們就知道，這個屬於核心主動上報異常的行為，我們看看list_debug.c:40 這裡有什麼？
如下雙鏈表add實現的紅色部分程式碼，明顯就是觸發了BUG_ON(x)的條件導致！

    void __list_add(struct list_head *new, struct list_head *prev, struct list_head *next)
    {
        WARN(next->prev != prev,
            "list_add corruption. next->prev should be "
            "prev (%p), but was %p. (next=%p).\n",
            prev, next->prev, next);
        WARN(prev->next != next,
            "list_add corruption. prev->next should be "
            "next (%p), but was %p. (prev=%p).\n",
            next, prev->next, prev);
        WARN(new == prev || new == next,
             "list_add double add: new=%p, prev=%p, next=%p.\n",
             new, prev, next);
     
        BUG_ON((prev->next != next || next->prev != prev ||
             new == prev || new == next) && PANIC_CORRUPTION);
     
        next->prev = new;
        new->next = next;
        new->prev = prev;
        prev->next = new;
    }

這個核心雙鏈表標準的插入實現,這個BUG_ON條件滿足被觸發了Panic所致，表示引數傳的有錯誤。繼續看log發現：

[  256.595299] CPU: 5 PID: 6210 Comm: mdss_fb0 Tainted: G        W  O   3.18.31 #1

異常發生在CPU5這個核，程序是mdss_fb0,這個是屬於顯示相關的程序，一般我們是動不到的，初步判斷是別的地方改動埋的雷導致mdss_fb0整個程序在執行的時候炸了的過程。
那麼我們要做的就是如何從這個爆炸現場到推出埋雷的地方。
6.2 Trace32分析
開啟Trace32，輸入 v.f 回車，將call frame內容貼出來：

    -000|ipi_cpu_stop(inline)
    -000|handle_IPI(ipinr = 3, regs = 0xFFFFFFC0A3BF36E0)
    -001|gic_handle_irq(regs = 0xFFFFFFC0A3BF36E0)
    -002|el1_irq(asm)
     -->|exception
    -003|debug_check_no_obj_freed(address = 0xFFFFFFC028805C00, size = 128)
    -004|current_thread_info(inline)
    -004|preempt_count(inline)
    -004|should_resched(inline)
    -004|slab_free(inline)
    -004|kfree(x = 0xFFFFFFC028805C00)
    -005|ext4_ext_map_blocks(handle = 0x0, inode = 0xFFFFFFC0A3FA8D50, map = 0xFFFFFFC0A3BF3A80, ?)
    -006|ext4_map_blocks(handle = 0x0, inode = 0x80, map = 0xFFFFFFC0A3BF3A80, flags = 12)
    -007|ext4_get_block(inode = 0xFFFFFFC0A3FA8D50, ?, bh = 0xFFFFFFC0A3BF3AD0, flags = 0)
    -008|ext4_get_block(?, ?, ?, ?)
    -009|generic_block_bmap(?, ?, ?)
    -010|ext4_bmap(mapping = 0xFFFFFFC0A3FA8ED0, block = 12712)
    -011|bmap(?, block = 128)
    -012|jbd2_journal_bmap(journal = 0xFFFFFFC0A41F3900, ?, retp = 0xFFFFFFC0A3BF3CC0)
    -013|jbd2_journal_next_log_block(journal = 0xFFFFFFC0A41F3900, retp = 0xFFFFFFC0A3BF3CC0)
    -014|jbd2_journal_commit_transaction(journal = 0xFFFFFFC0A41F3900)
    -015|kjournald2(arg = 0xFFFFFFC0A41F3900)
    -016|kthread(_create = 0xFFFFFFC0A41E4400)
    -017|ret_from_fork(asm)
     ---|end of frame

這個call frame看上去還挺正常的，屬於正常的系統異常切換操作？怎麼發現跟dmesg裡面看到的call statck不對？？？
我們來看下載入指令碼：t32_startup_script.cmm

    title "/home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/out"
    sys.cpu CORTEXA53
    sys.up
    data.load.binary /home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/OCIMEM.BIN 0x8600000
    data.load.binary /home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/DDRCS0.BIN 0x40000000
    data.load.binary /home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/DDRCS1.BIN 0x80000000
    Register.Set NS 1
    Data.Set SPR:0x30201 %Quad 0x41c22000
    Data.Set SPR:0x30202 %Quad 0x00000032B5193519
    Data.Set SPR:0x30A20 %Quad 0x000000FF440C0400
    Data.Set SPR:0x30A30 %Quad 0x0000000000000000
    Data.Set SPR:0x30100 %Quad 0x0000000004C5D93D
    Register.Set CPSR 0x3C5
    MMU.Delete
    MMU.SCAN PT 0xFFFFFF8000000000--0xFFFFFFFFFFFFFFFF
    mmu.on
    mmu.pt.list 0xffffff8000000000
    data.load.elf /home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/vmlinux /nocode
    task.config /opt/t32/demo/arm64/kernel/linux/linux-3.x/linux3.t32
    menu.reprogram /opt/t32/demo/arm64/kernel/linux/linux-3.x/linux.men
    task.dtask
    v.v  %ASCII %STRING linux_banner
    do /home/android/share/fp-quick-wakeup/crash/Port_COM29-0813/out/core0_regs.cmm

上面可以看到腳本里面配置trace32預設載入的是CPU 0的上下文，而我們從dmesg看到的panic異常是發生在CPU 5，需要手動切換到CPU 5的上下文：
執行：do core1_regs.cmm
（這裡有必要需要說明一下，按一般理解應該執行do core5_xx, 但是我發現這樣還不對，只能一個個試驗了，發現剛好是core1的這個，暫時不知道具體原因）

    -000|arch_counter_get_cntvct_cp15()
    -001|arch_counter_get_cntvct()
    -002|__delay(cycles = 19200)
    -003|__const_udelay(?)
    -004|msm_trigger_wdog_bite()
    -005|do_msm_restart(?, cmd = 0x0)
    -006|machine_restart(?)
    -007|emergency_restart()
    -008|panic(?)
    -009|oops_end(inline)
    -009|die(?, regs = 0xFFFFFFC002BDF870, err = 0)
    -010|arm64_notify_die(?, ?, ?, ?)
    -011|do_undefinstr(regs = 0xFFFFFFC002BDF870)  --- 發生未定義指令異常 BUG()
    -012|__list_add(new = 0xFFFFFFC002BDF990, prev = 0xFFFFFFC001B77DA8, next = 0xFFFFFFC0AB1D4178)
    -013|__internal_add_timer(?, ?)
    -014|tbase_get_deferrable(inline)
    -014|internal_add_timer(base = 0xFFFFFFC0AB1D4000, timer = 0x0124F800)
    -015|spin_unlock_irqrestore(inline)
    -015|__mod_timer(inline)
    -015|schedule_timeout(?)
    -016|mdss_mdp_cmd_wait4pingpong(ctl = 0xFFFFFFC0A791A318, ?)
    -017|mdss_mdp_display_wait4pingpong(ctl = 0xFFFFFFC0A791A318, use_lock = FALSE)
    -018|mdss_mdp_display_commit(ctl = 0xFFFFFFC0A791A318, ?, commit_cb = 0xFFFFFFC002BDFD38)
    -019|mdss_mdp_overlay_kickoff(mfd = 0xFFFFFFC0A7B08360, ?)
    -020|__mdss_fb_perform_commit(inline)
    -020|__mdss_fb_display_thread(data = 0xFFFFFFC0A7B08360)
    -021|kthread(_create = 0xFFFFFFC05ABCE200)
    -022|ret_from_fork(asm)
     ---|end of frame

勾選Local、Caller 分析：

雙鏈表的結構有前驅next指標和後繼prev指標，所以prev->next == next && next->prev == prev,這個條件是必現要成立的，我們來看這裡的情況：

    -012|__list_add(
        |    new = 0xFFFFFFC002BDF990 -> (
        |      next = 0xFFFFFFC002BDF9C0,
        |      prev = 0xFFFFFFC00010356C),
        |    prev = 0xFFFFFFC001B77DA8 -> (
        |      next = 0xFFFFFFC0ABA4C628,
        |      prev = 0xFFFFFFC0ABA4C628),
        |    next = 0xFFFFFFC0AB1D4178 -> (
        |      next = 0xFFFFFFC001B77DA8,
        |      prev = 0xFFFFFFC001B77DA8))

很顯然，prev == next->prev, 但是 prev->netxt != next, 所以導致了上面的BUG_ON(1)異常！.
所以出問題的就是這個prev，我們來看看這個prev具體是什麼內容？
前面看過timer的結構知道，這個prev其實就是指向一個struct timer_list *的指標，我們看下這個結構的內容是什麼，
調出 view -> Watch 視窗：

    (struct timer_list *)0xFFFFFFC001B77DA8 = 0xFFFFFFC001B77DA8 -> (
        entry = (next = 0xFFFFFFC0ABA4C628, prev = 0xFFFFFFC0ABA4C628),
        expires = 4294963038,
        base = 0xFFFFFFC0ABA4C000,
        function_=_0xFFFFFFC00077D4A8,
        data = 0,
        slack = -1,
        start_pid = -1,
        start_site = 0x0,
        start_comm = (0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0))

同上：view -> dump ：0xFFFFFFC00077D4A8

    address
       NSD:FFFFFFC00077D4A8
    address_info
    attr: AARCH64
    frame:RET:X30 CFA:SP+0x0
    line
    \\vmlinux\fp_drv     \277--278     /home/android/work/prj/6901-7.1/LA.UM.5.6/LINUX/android/vendor/ti
    ----------------------------------------------------------------------------------------------------
         P:FFFFFFC00077D4A8--FFFFFFC00077D4AB
    function
    \\vmlinux\fp_drv\timer_out_handle
    ...

如此，很清晰的顯示了出問題的原始碼位置，到這裡，異常定位分析就已經基本完成了，完成了“追根溯源”，
剩下的就是去分析程式碼出解決方案了。
---------------------  
作者：你必須十分努力，才能看起來毫不費力  
來源：CSDN  
原文：https://blog.csdn.net/forever_2015/article/details/77434580  
版權宣告：本文為博主原創文章，轉載請附上博文連結！