linux关机报softlock,中断上下文使用spin_lock使导致死锁案例分析

本文讲述一个简单的死锁案例，由于spin_lock的使用不当导致，旨在提示spin_lock使用时需要关注的一个简单而重要的问题。

另一方面，也说明内核开发中，坑很多，这只是一个小坑，要写内核代码，还需多修炼。

一、问题

环境中出现了softlockup，触发了panic，堆栈如下：

[16698.440604] BUG: soft lockup - CPU#0 stuck for 22s! [ps:6851]

[16698.442430] CPU: 0 PID: 6851 Comm: ps Tainted: GF          O--------------   3.10.0-123.el7.x86_64 #1

[16698.442436] task: ffff882027ed8000 ti: ffff881fab9fa000 task.ti: ffff881fab9fa000

[16698.442438] RIP: 0010:[]  [] _raw_spin_lock+0x37/0x50

[16698.442447] RSP: 0018:ffff88103fc03de0  EFLAGS: 00000206

[16698.442449] RAX: 00000000000075bb RBX: ffff88103fc03e10 RCX: 0000000000006e9a

[16698.442451] RDX: 0000000000006e9c RSI: 0000000000006e9c RDI: ffff881e394c79c0

[16698.442453] RBP: ffff88103fc03de0 R08: 1000000000000000 R09: 0000000000000000

[16698.442455] R10: 8840000000000000 R11: 0001f9b93d719108 R12: ffff88103fc03d58

[16698.442457] R13: ffffffff81600e5d R14: ffff88103fc03de0 R15: ffff881e394c71c0

[16698.442460] FS:  00007f09afb34740(0000) GS:ffff88103fc00000(0000) knlGS:0000000000000000

[16698.442462] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033

[16698.442464] CR2: 00007fff5a1aaf98 CR3: 00000009f220b000 CR4: 00000000000427f0

[16698.442466] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000

[16698.442469] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400

[16698.442470] Stack:

[16698.442472]  ffff88103fc03e20 ffffffff813dceae ffff88101a114c00 ffffffff81cb14c0

[16698.442479]  ffffffff81e233a0 0000000000000100 ffffffff813dcde0 ffffffff81e233f0

[16698.442484]  ffff88103fc03e58 ffffffff8106d9d6 ffffffff81cb14c0 00000000000000ff

[16698.442489] Call Trace:

[16698.442492]  

[16698.442500]  [] Timeout_callback+0xce/0x220

[16698.442504]  [] ? init_dom_starttime+0x250/0x250

[16698.442510]  [] call_timer_fn+0x36/0x110

[16698.442514]  [] ? init_dom_starttime+0x250/0x250

[16698.442519]  [] run_timer_softirq+0x21f/0x320

[16698.442525]  [] __do_softirq+0xf7/0x290

[16698.442530]  [] call_softirq+0x1c/0x30

[16698.442537]  [] do_softirq+0x55/0xa0

[16698.442541]  [] irq_exit+0x25d/0x270

[16698.442545]  [] smp_apic_timer_interrupt+0x45/0x60

[16698.442550]  [] apic_timer_interrupt+0x6d/0x80

[16698.485272]    [] ? proc_pid_status+0x2b7/0x6d0

[16698.486741]  [] ? proc_pid_status+0x297/0x6d0

[16698.488205]  [] proc_single_show+0x4d/0x80

[16698.489621]  [] seq_read+0x16e/0x3b0

[16698.491041]  [] vfs_read+0x9c/0x170

[16698.492419]  [] SyS_read+0x58/0xb0

[16698.493764]  [] system_call_fastpath+0x16/0x1b

二、分析

1、直接原因

从堆栈可以看出，最终是在spinlock上发生了阻塞。流程是位于定时器的软中断处理中。其中Timeout_callback是用户自己编写的定时器handler。

根据其代码分析，是因为在其中使用了task_lock()，而x86环境中task_lock()就是spin_lock()的简单封装：

点击(此处)折叠或打开

static inline void task_lock(struct task_struct *p)

{

spin_lock(&p->alloc_lock);

}

2、根本原因

再看看内核栈中的内容：

[16698.485272]    [] ? proc_pid_status+0x2b7/0x6d0

[16698.486741]  [] ? proc_pid_status+0x297/0x6d0

[16698.488205]  [] proc_single_show+0x4d/0x80

[16698.489621]  [] seq_read+0x16e/0x3b0

[16698.491041]  [] vfs_read+0x9c/0x170

[16698.492419]  [] SyS_read+0x58/0xb0

[16698.493764]  [] system_call_fastpath+0x16/0x1b

可以看出是在读取/proc接口中的进程相关信息，最终在 proc_pid_status函数中发生了时钟中断，从而进入了上述的定时器软中断流程。而 proc_pid_status函数中有很多使用task_lock的地方：

点击(此处)折叠或打开

/usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/include/linux/spinlock.h: 293

0xffffffff8122481f : mov %r14,%rdi

0xffffffff81224822:callq 0xffffffff815f7050<_raw_spin_lock>   //这里就是task_lock锁

/usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 207

0xffffffff81224827 : mov 0x758(%r12),%rax

0xffffffff8122482f : test %rax,%rax

0xffffffff81224832 : je 0xffffffff81224c28

/usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 208

0xffffffff81224838 : mov 0x8(%rax),%rax

/usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 209

0xffffffff8122483c : test %rax,%rax

0xffffffff8122483f : je 0xffffffff81224c28

0xffffffff81224845 : mov (%rax),%edx

0xffffffff81224847: mov$0xffffffff818214bb,%rsi      //这里是被中断的IP

所以问题就来了，由于在 proc_pid_status中使用了task_lock()，而发生中断后，在中断上下文中再次使用了task_lock()获取同一把锁，从而导致了死锁。

所以，该问题是spin_lock()锁的使用问题，spin_lock(task_lock)由于没有关中断，就不能用在中断上下文中，否则重入可能导致死锁.

三、结论及思考

本问题是个简单的内核编程问题(spin_lock的用法问题)：spin_lock(task_lock)不能直接在中断上下文中使用，因为这样的锁没有关中断，他可能被中断打断，然后中断上下文中如果再次获取该锁就导致死锁了，除非能确认该锁不会在其它地方使用。

问题很简单，但却很有警示意义。可能有人认为内核代码随便就能写，模仿模仿就行，但实际上，内核编程水很深、坑很多，稍不留神(对相关用法和原理了解不够)就可能会掉坑里，立马掉进去还好，最怕就是给自己埋雷，不知道哪一天会踩到，到时后果就很严重了，所以，对内核的任何改动或新增代码，都需要千万谨慎，多修炼吧！