Chinaunix首页 | 论坛 | 博客
  • 博客访问: 1213126
  • 博文数量: 122
  • 博客积分: 0
  • 博客等级: 民兵
  • 技术积分: 4002
  • 用 户 组: 普通用户
  • 注册时间: 2014-02-20 08:27
文章分类
文章存档

2016年(1)

2015年(21)

2014年(100)

分类: LINUX

2015-07-29 18:47:00

本文讲述一个简单的死锁案例,由于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()的简单封装:

点击(此处)折叠或打开

  1. static inline void task_lock(struct task_struct *p)
  2. {
  3.     spin_lock(&p->alloc_lock);
  4. }

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的地方:

点击(此处)折叠或打开

  1. /usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/include/linux/spinlock.h: 293
  2. 0xffffffff8122481f <proc_pid_status+655>: mov %r14,%rdi
  3. 0xffffffff81224822 <proc_pid_status+658>: callq 0xffffffff815f7050 <_raw_spin_lock>   //这里就是task_lock锁
  4. /usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 207
  5. 0xffffffff81224827 <proc_pid_status+663>: mov 0x758(%r12),%rax
  6. 0xffffffff8122482f <proc_pid_status+671>: test %rax,%rax
  7. 0xffffffff81224832 <proc_pid_status+674>: je 0xffffffff81224c28 <proc_pid_status+1688>
  8. /usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 208
  9. 0xffffffff81224838 <proc_pid_status+680>: mov 0x8(%rax),%rax
  10. /usr/src/debug/kernel-3.10.0-123.el7/linux-3.10.0-123.el7.x86_64/fs/proc/array.c: 209
  11. 0xffffffff8122483c <proc_pid_status+684>: test %rax,%rax
  12. 0xffffffff8122483f <proc_pid_status+687>: je 0xffffffff81224c28 <proc_pid_status+1688>
  13. 0xffffffff81224845 <proc_pid_status+693>: mov (%rax),%edx
  14. 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)不能直接在中断上下文中使用,因为这样的锁没有关中断,他可能被中断打断,然后中断上下文中如果再次获取该锁就导致死锁了,除非能确认该锁不会在其它地方使用。
问题很简单,但却很有警示意义。可能有人认为内核代码随便就能写,模仿模仿就行,但实际上,内核编程水很深、坑很多,稍不留神(对相关用法和原理了解不够)就可能会掉坑里,立马掉进去还好,最怕就是给自己埋雷,不知道哪一天会踩到,到时后果就很严重了,所以,对内核的任何改动或新增代码,都需要千万谨慎,多修炼吧!
阅读(9622) | 评论(0) | 转发(0) |
给主人留下些什么吧!~~