問題現象:在ARM服務器上,構造oops異常,本應該產生panic,進入dump流程,並且系統重啟,但是系統並未重啟,而是出現了卡死,在串口會隔一段時間就循環打印調用棧信息。如下所示
linux-fATqUY login: [ME] Fault detect start!
[ME] Fault detect start!
[ 254.202183] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000000
[ 254.211111] Mem abort info:
[ 254.213939] ESR = 0x96000044
[ 254.217042] Exception class = DABT (current EL), IL = 32 bits
[ 254.223054] SET = 0, FnV = 0
[ 254.226154] EA = 0, S1PTW = 0
[ 254.229335] Data abort info:
[ 254.232261] ISV = 0, ISS = 0x00000044
[ 254.236155] CM = 0, WnR = 1
[ 254.239167] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000509fb5ee
[ 254.245883] [0000000000000000] pgd=0000000000000000
[ 254.250838] Internal error: Oops: 96000044 [#1] SMP
[ 254.255785] CPU: 0 PID: 58147 Comm: gen_seri_oops/0 Kdump: loaded Tainted:
[ 254.273985] pstate: 60000005 (nZCv daif -PAN -UAO)
[ 254.278851] pc : gen_seri_oops+0x28/0x38 [kpgen_kbox]
[ 254.283971] lr : gen_seri_oops+0x1c/0x38 [kpgen_kbox]
[ 254.289089] sp : ffff000033ea3e50
[ 254.292443] x29: ffff000033ea3e50 x28: 0000000000000000
[ 254.297831] x27: ffff000035fdbb08 x26: ffff803f713412b8
[ 254.303218] x25: ffff000000fb2370 x24: 0000000000000000
[ 254.308605] x23: ffff0000091bcb10 x22: ffff80df64dc2e80
[ 254.380350] Process gen_seri_oops/0 (pid: 58147, stack limit = 0x0000000088aed8c0)
[ 254.391639] Call trace:
[ 254.397760] gen_seri_oops+0x28/0x38 [kpgen_kbox]
[ 254.406069] kthread+0x108/0x138
[ 254.412721] ret_from_fork+0x10/0x18
[ 254.419733] Code: 95c66ac7 d2800001 52800c22 52800000 (39000022)
[ 254.429390] die event detected
[ 254.436533] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000008
[ 254.448966] Mem abort info:
[ 254.455502] ESR = 0x96000004
[ 254.462278] Exception class = DABT (current EL), IL = 32 bits
[ 254.472023] SET = 0, FnV = 0
[ 254.478845] EA = 0, S1PTW = 0
[ 254.485645] Data abort info:
[ 254.492130] ISV = 0, ISS = 0x00000004
[ 254.499576] CM = 0, WnR = 0
[ 254.505933] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000509fb5ee
[ 254.515960] [0000000000000008] pgd=0000000000000000
360.462046] watchdog: BUG: soft lockup - CPU#35 stuck for 22s! [docker-containe:29506] [ 360.473208] Modules linked in: pt_MASQUERADE(E) iptable_nat(E) …… [ 360.565132] CPU: 35 PID: 29506 Comm: docker-containe Kdump: loaded Tainted: G OEL 4.19.5-1.1.29.aarch64 #1[ 360.595535] pstate: 80000005 (Nzcv daif -PAN -UAO) [ 360.604905] pc : smp_call_function_many+0x308/0x370 [ 360.614105] lr : smp_call_function_many+0x2c4/0x370 [ 360.623278] sp : ffff00002f4739e0 [ 360.630878] x29: ffff00002f4739e0 x28: ffff000009592184 [ 360.640673] x27: ffff80bffbeb2f08 x26: 0000000000000000 [ 360.650447] x25: ffff00000818a790 x24: 0000000000000001 [ 360.660310] x23: 0000000000001000 x22: ffff000009592184 [ 360.670118] x21: ffff000009589000 x20: ffff80bffbeb2d08 [ 360.680004] x19: ffff80bffbeb2d00 x18: 000000000bf5d62e [ 360.689922] x17: 000000bf5d62e000 x16: 000000bf5d62f000 [ 360.699700] x15: 0000000000000008 x14: 0000000000000000 [ 360.709468] x13: 0000000000000001 x12: ffff803f72c8b530 [ 360.719251] x11: 0000000000000000 x10: 0000000000000b80 [ 360.728983] x9 : 0000000000000000 x8 : ffff80bffbeb3108 [ 360.738859] x7 : 0000000000000000 x6 : 000000000000003f [ 360.748533] x5 : 0000000000000000 x4 : fffffff7ffffffff [ 360.758230] x3 : 0000000000000000 x2 : ffff803ffbe69638 [ 360.767909] x1 : 0000000000000003 x0 : 0000000000000000 [ 360.777504] Call trace: [ 360.784282] smp_call_function_many+0x308/0x370 [ 360.793075] kick_all_cpus_sync+0x30/0x38 [ 360.801443] sync_icache_aliases+0x74/0x98 [ 360.809852] __sync_icache_dcache+0x94/0xc8 [ 360.818371] alloc_set_pte+0x460/0x570 [ 360.826435] filemap_map_pages+0x3e0/0x400 [ 360.834510] __handle_mm_fault+0xb78/0x10f0 [ 360.842743] handle_mm_fault+0xf4/0x1c0 [ 360.850561] do_page_fault+0x230/0x488 [ 360.858095] do_translation_fault+0x74/0x84 [ 360.865948] do_mem_abort+0x6c/0x130 [ 360.873255] do_el0_ia_bp_hardening+0x64/0xa8 [ 360.881020] el0_ia+0x18/0x1c [ 364.514043] watchdog: BUG: soft lockup - CPU#51 stuck for 22s! [vm_io_monitor.p:10065] 下面的內容同上
[ 464.446045] watchdog: BUG: soft lockup - CPU#30 stuck for 22s! [kill:2031]
[ 516.538048] watchdog: BUG: soft lockup - CPU#58 stuck for 23s! [libvirtd:29334]
[ 576.358044] watchdog: BUG: soft lockup - CPU#2 stuck for 22s! [logrotate:2045]
問題原因:在進入dump流程中,dump相關的組件如kernel box出現了空指針訪問,出現了oops嵌套。每次在出現oops后,進入內核異常處理流程,執行die函數,該函數中會獲取鎖,raw_spin_lock_irqsave($die_lock,flags),然后又會在通知鏈中調用kernel box的注冊回調函數,在回調過程中,由於這個回調函數內部又存在空指針訪問,又出現oops,又走入了異常處理流程,進入die函數,那么這是想要獲取鎖,就獲取不到,一直在等鎖。
問題來了:
1、為何每個cpu打印調用棧都是stuck 20s左右呢?
2、如果一個cpu出現了死鎖,其他cpu為何會softlockup呢?
3、為啥每個cpu的調用棧都在smp_call_function_many
現在我們來看第一個問題,20s的時間剛好是softlockup的時間,那么什么是softlockup呢,其實說白了,就是搶占被長時間關閉,導致進程無法調度。系統為每個cpu core注冊了一個一般的kernel線程,這個線程會定期的調用watchdog函數,這個函數在時鍾中斷更新時,kernel線程才會被得到運行。當kernel線程里的watchdog函數中的一個watchdog_touch_ts變量在最近20s沒有被更新,那就意味這個這個線程在20s內沒有被調度,很有可能就是在某個cpu core上搶占被關閉了。所以調度器沒法進行調度。那么與之對應的就是hardlockup,是中斷被長時間關閉導致的更嚴重的問題。
那么,為什么一個cpu上出現了死鎖,其他的cpu也會出現softlockup呢,讓我們來分析一下softlockup的調用棧,在不清楚這些calltrace函數都是干什么的時候,分析為啥其他cpu上也會出現softlockup是一件難事。經過我多次搜索,差不多理清了思路。調用棧中的兩個關鍵函數是kick_all_cpus_sync, sync_icache_aliases,從函數名稱大概能看出這些函數是用來做cpu之間的cache同步的。我們服務器上大概有64個cpu,為了保證cache的一致性,應該會有一種機制來對所有cpu進行同步 。那么如何進行同步,從一篇patch文章中搜到https://patchwork.kernel.org/patch/10325093/,可以查到一些相關信息,如下內容:
kick_all_cpus_sync() forces all CPUs to sync caches by sending broadcast IPI. If CPU is in extended quiescent state (idle task or nohz_full userspace), this work may be done at the exit of this state.
也就是說通過廣播IPI中斷,來強制讓所有cpu來同步cache。具體的IPI中斷的相關介紹可以參考http://www.voidcn.com/article/p-auwhbhgz-oh.html。IPI中斷,是核間通信同步的一種方式。
這篇博客https://segmentfault.com/a/1190000017238912,其實與我遇到的問題很像,摘錄這里的一段總結:
一方面,為了避免產生競爭,線程在刷新本地tlb的時候,會停掉搶占。這就導致一個結果:其他的線程,當然包括watchdog線程,沒有辦法被調度執行(soft lockup)。另外一方面,為了要求其他cpu同步地刷新tlb,當前線程會使用ipi和其他cpu同步進展,直到其他cpu也完成刷新為止。其他cpu如果遲遲不配合,那么當前線程就會死等。
我們來看一下 smp_call_function_many這個函數的最后面就是在等待。
void smp_call_function_many(const struct cpumask *mask, smp_call_func_t func, void *info, bool wait) { …… if (wait) { for_each_cpu(cpu, cfd->cpumask) { struct call_single_data *csd; csd = per_cpu_ptr(cfd->csd, cpu); csd_lock_wait(csd); } } }
那么當cpu 0上出現了oops后,后面又出現了死鎖,在剛進入oops時,做的第一件事情就是禁用中斷。這個非常好理解,oops邏輯要做的事情是保存現場,它當然不希望,中斷在這個時候破壞問題現場。
分析到這里,這個問題就清晰了,當其他cpu例行公事的發過來IPI中斷,CPU0 出現了死鎖無法響應,於是其他cpu就在死等,進而導致其他cpu上都產生了softlockup。
附錄:
do_mem_abort是在arm體系架構中,當出現缺頁異常,或者訪問空指針后arm的中斷異常處理。__handle_mm_fault這個函數是在處理大頁缺頁時的處理函數。具體可以參考http://www.leviathan.vip/2019/03/03/Linux%E5%86%85%E6%A0%B8%E6%BA%90%E7%A0%81%E5%88%86%E6%9E%90-%E5%86%85%E5%AD%98%E8%AF%B7%E9%A1%B5%E6%9C%BA%E5%88%B6/
內核訪問空指針之后的處理流程 https://blog.csdn.net/rikeyone/article/details/80021720,https://blog.csdn.net/zangdongming/article/details/38543059