ARM架构4.1.52内核NMI watchdog触发CPU soft lockup故障求助

故障基本信息 #

• 内核版本：4.1.52
• 架构：arm
• 关联进程：用户态自研程序testd
• 故障现象：CPU触发软死锁，内核panic

根因分析 #

从崩溃栈可以明确故障发生在内核态的UBIFS文件系统模块，和用户态testd程序无直接关联，testd仅为故障触发入口：

当testd异常触发coredump时，内核需要将core文件写入UBIFS分区，在UBIFS申请写入预算的逻辑ubifs_budget_space中出现自旋锁死锁/死循环，导致CPU1卡住超过22秒，被NMI看门狗检测到后触发panic。

额外需要注意你的内核标记了Tainted: P，说明加载过第三方专有内核模块，也可排查第三方模块是否对UBIFS逻辑有侵入性修改。

修复建议 #

• 临时规避：关闭coredump写入UBIFS分区，执行命令echo "|/bin/false" > /proc/sys/kernel/core_pattern直接禁用coredump，或修改core_pattern路径指向tmpfs分区
• 补丁修复：针对4.1版本内核合入上游UBIFS的相关修复补丁，重点合入ubifs_budget_space自旋锁边界释放、低空间场景预算申请死循环的修复逻辑
• 长期方案：升级内核到4.19及以上LTS版本，该版本段UBIFS模块已经经过大量稳定性修复，此类死锁问题已被解决

完整崩溃日志 #

NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [testd:6556]
[685228.664372] CPU: 1 PID: 6556 Comm: testd Tainted: P                4.1.52 #1
[685228.664373] Hardware name: XXXXXXX (XX)
[685228.664375] task: ffffffc00c4a4ac0 ti: ffffffc00988c000 task.ti: ffffffc00988c000
[685228.664387] PC is at _raw_spin_unlock+0x20/0x40
[685228.664394] LR is at ubifs_budget_space+0x4f4/0x5d0
[685228.664396] pc : [<ffffffc0005d5730>] lr : [<ffffffc00026d3d4>] pstate: 00000145
[685228.664397] sp : ffffffc00988f640
[685228.664400] x29: ffffffc00988f640 x28: ffffffc01dd87000 
[685228.664403] x27: ffffffc00988f718 x26: 00000000ffffffe4 
[685228.664405] x25: 0000000000001ff8 x24: ffffffc0009f1f90 
[685228.664408] x23: ffffffc000603000 x22: ffffffc01dd87920 
[685228.664410] x21: 0000000000000000 x20: 0000000000000000 
[685228.664413] x19: 00000000000000a0 x18: 0000000000000000 
[685228.664415] x17: 0000000000000000 x16: ffffffc0000f8ce8 
[685228.664418] x15: 0000000000000000 x14: 00000000f5ac9920 
[685228.664420] x13: 0000000000000002 x12: 0000000000000000 
[685228.664422] x11: 0000000000000001 x10: 0000000000000000 
[685228.664425] x9 : ffffffc00988f590 x8 : ffffffc00c4a5030 
[685228.664427] x7 : ffffffc01eb26000 x6 : 000000007ffff000 
[685228.664430] x5 : ffffffffffffffff x4 : 0000000000000001 
[685228.664432] x3 : 0000000000000000 x2 : 0000000000000000 
[685228.664434] x1 : ffffffc00988c000 x0 : 0000000000000001 
[685228.664435] 
[685228.664437] Kernel panic - not syncing: softlockup: hung tasks
[685228.664440] CPU: 1 PID: 6556 Comm: testd Tainted: P             L  4.1.52 #1
[685228.664441] Hardware name: XXXXXXX (XX)
[685228.664443] Call trace:
[685228.664450] [<ffffffc0000871c0>] dump_backtrace+0x0/0x150
[685228.664454] [<ffffffc000087324>] show_stack+0x14/0x20
[685228.664457] [<ffffffc0005d096c>] dump_stack+0x90/0xb0
[685228.664462] [<ffffffc0005ce0a4>] panic+0xd8/0x220
[685228.664468] [<ffffffc0001088d8>] watchdog+0x0/0x48
[685228.664473] [<ffffffc0000e04c0>] hrtimer_run_queues+0xa8/0x1e0
[685228.664476] [<ffffffc0000dfb84>] update_process_times+0x2c/0x70
[685228.664482] [<ffffffc0000ed330>] tick_nohz_handler+0x80/0x108
[685228.664488] [<ffffffc0003f2638>] arch_timer_handler_phys+0x30/0x40
[685228.664493] [<ffffffc0000d5998>] handle_percpu_devid_irq+0x78/0xa0
[685228.664496] [<ffffffc0000d14b4>] generic_handle_irq+0x34/0x50
[685228.664498] [<ffffffc0000d17c4>] __handle_domain_irq+0x5c/0xb8
[685228.664501] [<ffffffc000080c18>] gic_handle_irq+0x38/0x90
[685228.664504] Exception stack(0xffffffc00988f4f0 to 0xffffffc00988f620)
[685228.664507] f4e0:                                     000000a0 00000000 00000000 00000080
[685228.664511] f500: 0988f640 ffffffc0 005d5730 ffffffc0 00000001 00000000 0988c000 ffffffc0
[685228.664515] f520: 00000000 00000000 00000000 00000000 00000001 00000000 ffffffff ffffffff
[685228.664519] f540: 7ffff000 00000000 1eb26000 ffffffc0 0c4a5030 ffffffc0 0988f590 ffffffc0
[685228.664522] f560: 00000000 00000000 00000001 00000000 00000000 00000000 00000002 00000000
[685228.664526] f580: f5ac9920 00000000 00000000 00000000 000f8ce8 ffffffc0 00000000 00000000
[685228.664529] f5a0: 00000000 00000000 000000a0 00000000 00000000 00000000 00000000 00000000
[685228.664533] f5c0: 1dd87920 ffffffc0 00603000 ffffffc0 009f1f90 ffffffc0 00001ff8 00000000
[685228.664537] f5e0: ffffffe4 00000000 0988f718 ffffffc0 1dd87000 ffffffc0 0988f640 ffffffc0
[685228.664541] f600: 0026d3d4 ffffffc0 0988f640 ffffffc0 005d5730 ffffffc0 00000145 00000000
[685228.664544] [<ffffffc000083f00>] el1_irq+0x80/0xf8
[685228.664548] [<ffffffc00026d3d4>] ubifs_budget_space+0x4f4/0x5d0
[685228.664553] [<ffffffc0002573a8>] ubifs_write_iter+0x88/0x180
[685228.664558] [<ffffffc000159e70>] __vfs_write+0xa8/0x108
[685228.664560] [<ffffffc000159f14>] __kernel_write+0x44/0x110
[685228.664564] [<ffffffc000402154>] crashdump_write+0x44/0x88
[685228.664567] [<ffffffc000402b60>] crashdump_sync_buf+0x160/0x218
[685228.664570] [<ffffffc000402e4c>] crash_zdump_write+0x14/0x28
[685228.664576] [<ffffffc0001aa3d8>] dump_emit+0x130/0x160
[685228.664580] [<ffffffc0001a7074>] elf_core_dump+0xfa4/0x10e8
[685228.664583] [<ffffffc0001aaba8>] do_coredump+0x620/0x1108
[685228.664589] [<ffffffc0000a0560>] get_signal+0x2a8/0x530
[685228.664592] [<ffffffc00008697c>] do_signal+0x194/0x4f8
[685228.664595] [<ffffffc000086ed4>] do_notify_resume+0x64/0x70

内容的提问来源于stack exchange，提问作者Franc