中断上下文使用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:[<ffffffff815f7087>]  [<ffffffff815f7087>] _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]  <IRQ> 
[16698.442500]  [<ffffffff813dceae>] Timeout_callback+0xce/0x220
[16698.442504]  [<ffffffff813dcde0>] ? init_dom_starttime+0x250/0x250
[16698.442510]  [<ffffffff8106d9d6>] call_timer_fn+0x36/0x110
[16698.442514]  [<ffffffff813dcde0>] ? init_dom_starttime+0x250/0x250
[16698.442519]  [<ffffffff8106fabf>] run_timer_softirq+0x21f/0x320
[16698.442525]  [<ffffffff81067497>] __do_softirq+0xf7/0x290
[16698.442530]  [<ffffffff81601b1c>] call_softirq+0x1c/0x30
[16698.442537]  [<ffffffff81014d35>] do_softirq+0x55/0xa0
[16698.442541]  [<ffffffff81067abd>] irq_exit+0x25d/0x270
[16698.442545]  [<ffffffff816024f5>] smp_apic_timer_interrupt+0x45/0x60
[16698.442550]  [<ffffffff81600e5d>] apic_timer_interrupt+0x6d/0x80
[16698.485272]  <EOI>  [<ffffffff81224847>] ? proc_pid_status+0x2b7/0x6d0
[16698.486741]  [<ffffffff81224827>] ? proc_pid_status+0x297/0x6d0
[16698.488205]  [<ffffffff8122049d>] proc_single_show+0x4d/0x80
[16698.489621]  [<ffffffff811d9ece>] seq_read+0x16e/0x3b0
[16698.491041]  [<ffffffff811b5aec>] vfs_read+0x9c/0x170
[16698.492419]  [<ffffffff811b6618>] SyS_read+0x58/0xb0
[16698.493764]  [<ffffffff816001d9>] 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]  <EOI>  [<ffffffff81224847>] ? proc_pid_status+0x2b7/0x6d0
[16698.486741]  [<ffffffff81224827>] ? proc_pid_status+0x297/0x6d0
[16698.488205]  [<ffffffff8122049d>] proc_single_show+0x4d/0x80
[16698.489621]  [<ffffffff811d9ece>] seq_read+0x16e/0x3b0
[16698.491041]  [<ffffffff811b5aec>] vfs_read+0x9c/0x170
[16698.492419]  [<ffffffff811b6618>] SyS_read+0x58/0xb0
[16698.493764]  [<ffffffff816001d9>] 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 <proc_pid_status+655>: mov %r14,%rdi
0xffffffff81224822 <proc_pid_status+658>: 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 <proc_pid_status+663>: mov 0x758(%r12),%rax
0xffffffff8122482f <proc_pid_status+671>: test %rax,%rax
0xffffffff81224832 <proc_pid_status+674>: je 0xffffffff81224c28 <proc_pid_status+1688>
/usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 208
0xffffffff81224838 <proc_pid_status+680>: 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 <proc_pid_status+684>: test %rax,%rax
0xffffffff8122483f <proc_pid_status+687>: je 0xffffffff81224c28 <proc_pid_status+1688>
0xffffffff81224845 <proc_pid_status+693>: mov (%rax),%edx
0xffffffff81224847 <proc_pid_status+695>: mov $0xffffffff818214bb,%rsi      //这里是被中断的IP

所以问题就来了，由于在 proc_pid_status中使用了task_lock()，而发生中断后，在中断上下文中再次使用了task_lock()获取同一把锁，从而导致了死锁。
所以，该问题是spin_lock()锁的使用问题，spin_lock(task_lock)由于没有关中断，就不能用在中断上下文中，否则重入可能导致死锁.

三、结论及思考
本问题是个简单的内核编程问题(spin_lock的用法问题)：spin_lock(task_lock)不能直接在中断上下文中使用，因为这样的锁没有关中断，他可能被中断打断，然后中断上下文中如果再次获取该锁就导致死锁了，除非能确认该锁不会在其它地方使用。
问题很简单，但却很有警示意义。可能有人认为内核代码随便就能写，模仿模仿就行，但实际上，内核编程水很深、坑很多，稍不留神(对相关用法和原理了解不够)就可能会掉坑里，立马掉进去还好，最怕就是给自己埋雷，不知道哪一天会踩到，到时后果就很严重了，所以，对内核的任何改动或新增代码，都需要千万谨慎，多修炼吧！