内核中的死锁问题--当UHCI遇上OHCI

上次我上网查资料,突然弹出来一个网页,很黄很暴力,和张殊凡小朋友一样,我赶紧给关了.不过,从此……我天天上网查资料.今天我就给大家介绍一下我的成果.

比如有一个网站叫做 bugzilla.kernel.org, 这是一个 Linux hacker 云集的网站 .

这个网站用于汇报 Linux 内核的那些 bug, 每当看到这些 bug,Linux 黑客们就采用各种手段去解决它 , 包括暴力手段 .

在 2007 年的那个枫叶飘零的晚秋 , 一个瑞典人描述了他所遇到的一个 bug. 这个 bug 编号为 9335, 关于它的更多细节可以在下面这个 link 中看到 .

http://bugzilla.kernel.org/show_bug.cgi?id=9335

当时他是这样描述的 :

Most recent kernel where this bug did not occur: 2.6.23

Distribution: Debian

Hardware Environment: Thinkpad R60, Intel Core 2 Duo

Software Environment: x86_64 kernel, XFS, X.org, KDE.

Problem Description:

 

When using the system for some time, usually at most a few hours, it suddenly hangs completely, the screen goes black, and it can only be reset with the power switch. The fan is still spinning however and the system seems to generate heat as if it were doing something CPU-intensive.

 

This happens consistently but at seemingly random times. It's a desktop system, used for some browsing and e-mail mostly.

他说他的系统用着用着就会挂起 . 后来经高人指点 , 他开启了 NMI watchdog. 于是这次能够在发生异常的时候打印出 oops 信息来 . 下面我们就来从这个 oops 信息找出问题的根源 .

netconsole: network logging started

NMI Watchdog detected LOCKUP on CPU 0

CPU 0

Modules linked in: netconsole configfs i915 drm rfcomm l2cap xfrm_user xfrm4_tunnel af_key xfrm4_mode_tunnel nfsd exportfs autofs4 cpufreq_conservative cpufreq_userspace cpufreq_stats cpufreq_powersave rpcsec_gss_krb5 auth_rpcgss tunnel4 ipcomp nfs esp4 lockd ah4 nfs_acl sunrpc deflate zlib_deflate twofish_x86_64 twofish_common camellia serpent blowfish des_generic xcbc sha1_generic crypto_null hmac crypto_hash ppp_async crc_ccitt fuse ipv6 ppp_generic nls_utf8 slhc ntfs xfs pl2303 option usbserial kqemu coretemp cpufreq_ondemand acpi_cpufreq freq_table snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq snd_seq_device arc4 ecb ohci_hcd snd_hda_intel snd_pcm_oss snd_mixer_oss iwl3945 snd_pcm pcmcia snd_timer firmware_class snd thinkpad_acpi mousedev mac80211 hci_usb soundcore hwmon serio_raw snd_page_alloc bluetooth video backlight output yenta_socket rsrc_nonstatic pcmcia_core button i2c_i801 cfg80211 pcspkr iTCO_wdt nvram rtc psmouse evdev ext3 jbd mbcache sha256_generic aes_x86_64 aes_generic cbc blkcipher dm_crypt dm_mirror dm_snapshot dm_mod firewire_ohci firewire_core crc_itu_t uhci_hcd ehci_hcd usbcore tg3 sr_mod cdrom sd_mod thermal processor fan

Pid: 0, comm: swapper Not tainted 2.6.24-rc2-melech #3

RIP: 0010:[<ffffffff804876c9>] [<ffffffff804876c9>] _spin_lock+0x59/0x70

RSP: 0018:ffffffff805ecc18 EFLAGS: 00000002

RAX: 0000000000000001 RBX: ffffffff8807afd0 RCX: ffff81000113c8b8

RDX: 0000000000020004 RSI: ffff810004af0028 RDI: 0000000000000001

RBP: ffff81000427cd48 R08: ffff810005a713e0 R09: 00000000ffffff8d

R10: 0000000000000000 R11: ffff810003add80c R12: ffff8100042e2780

R13: ffff810004af0028 R14: ffff81000427cc00 R15: ffff8100042e27b0

FS: 0000000000000000(0000) GS:ffffffff80591000(0000) knlGS:0000000000000000

CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b

CR2: 00002ae0240a2a08 CR3: 000000000b81a000 CR4: 00000000000006e0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000

DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400

Process swapper (pid: 0, threadinfo ffffffff805a2000, task ffffffff8055b340)

Stack: ffff810004af0028 ffffffff88058d60 ffff81000427cdd0 ffffffff8808cbea

 00000000042a9940 00000000030007ff ffff8100042e2780 ffff8100042a9ac0

 ffff810004af0028 ffff810005a713e8 ffff81000427cd48 ffffffff8808d15a

Call Trace:

 <IRQ> [<ffffffff88058d60>] :usbcore:usb_hcd_unlink_urb_from_ep+0x10/0x40

 [<ffffffff8808cbea>] :uhci_hcd:uhci_giveback_urb+0x9a/0x220

 [<ffffffff8808d15a>] :uhci_hcd:uhci_scan_schedule+0x29a/0x990

 [<ffffffff8808f77e>] :uhci_hcd:uhci_irq+0xbe/0x1a0

 [<ffffffff880591ed>] :usbcore:usb_hcd_irq+0x2d/0x60

 [<ffffffff802752b4>] handle_IRQ_event+0x34/0x70

 [<ffffffff80276add>] handle_fasteoi_irq+0x8d/0x110

 [<ffffffff8020f9db>] do_IRQ+0x7b/0x100

 [<ffffffff8020c921>] ret_from_intr+0x0/0xa

 [<ffffffff8048768e>] _spin_lock+0x1e/0x70

 [<ffffffff88058d60>] :usbcore:usb_hcd_unlink_urb_from_ep+0x10/0x40

 [<ffffffff882d363b>] :ohci_hcd:finish_urb+0x5b/0xe0

 [<ffffffff882d37ae>] :ohci_hcd:takeback_td+0xee/0x110

 [<ffffffff882d38ac>] :ohci_hcd:dl_done_list+0xdc/0x170

 [<ffffffff882d6452>] :ohci_hcd:ohci_irq+0x1e2/0x370

 [<ffffffff880591ed>] :usbcore:usb_hcd_irq+0x2d/0x60

 [<ffffffff802752b4>] handle_IRQ_event+0x34/0x70

 [<ffffffff80276add>] handle_fasteoi_irq+0x8d/0x110

 [<ffffffff8020f9db>] do_IRQ+0x7b/0x100

 [<ffffffff8020c921>] ret_from_intr+0x0/0xa

 <EOI> [<ffffffff880052c0>] :processor:acpi_processor_idle+0x2e0/0x4c0

 [<ffffffff880052bc>] :processor:acpi_processor_idle+0x2dc/0x4c0

 [<ffffffff88004fe0>] :processor:acpi_processor_idle+0x0/0x4c0

 [<ffffffff8020af50>] default_idle+0x0/0x40

 [<ffffffff8020aff7>] cpu_idle+0x67/0xd0

 [<ffffffff805aabba>] start_kernel+0x2aa/0x330

 [<ffffffff805aa117>] _sinittext+0x117/0x120

 

 

Code: 8b 03 85 c0 7e f1 eb a3 e8 ba e4 ff ff eb d4 0f 1f 84 00 00

Kernel panic - not syncing: Aiee, killing interrupt handler!

看到 RIP 的位置在 _spin_lock, 一个敏感的男人的第一反应就是死锁 . 没错 , 这就是个死锁问题 .

我们看到这其中牵涉到的模块有 usbcore,ohci_hcd, 以及 uhci_hcd. 我们注意到函数调用栈里面有两个 usb_hcd_unlink_urb_from_ep, 这个函数来自 drivers/usb/core/hcd.c:

   1096 /**

   1097 * usb_hcd_unlink_urb_from_ep - remove an URB from its endpoint queue

   1098 * @hcd: host controller to which @urb was submitted

   1099 * @urb: URB being unlinked

   1100 *

   1101 * Host controller drivers should call this routine before calling

   1102 * usb_hcd_giveback_urb(). The HCD's private spinlock must be held and

   1103 * interrupts must be disabled. The actions carried out here are required

   1104 * for URB completion.

   1105 */

   1106 void usb_hcd_unlink_urb_from_ep(struct usb_hcd *hcd, struct urb *urb)

   1107 {

   1108         /* clear all state linking urb to this dev (and hcd) */

   1109         spin_lock(&hcd_urb_list_lock);

   1110         list_del_init(&urb->urb_list);

   1111         spin_unlock(&hcd_urb_list_lock);

   1112 }

这里的确用到了 spin_lock, 而这把锁就是 hcd_urb_list_lock. 那么是否说明这个问题就已经归结为关于 hcd_urb_list_lock 的 deadlock 呢 ? 还有待进一步考证 .

此时我们还注意到 , 函数堆栈里还有两个很特别的函数 ,uhci_irq 和 ohci_irq. 即使是十三岁的张殊凡小朋友都能从这两个函数的名字判断得出 , 这两个函数分别是 uhci 主机控制器的中断服务函数和 ohci 主机控制器的中断服务函数 . 而仔细看这个堆栈 , 我们不难得出这样的结论 , 首先 ohci 产生了中断 ,ohci_irq 被调用 , 但当它正在执行的时候 ,uhci 的中断发生了 , 于是 uhci 将 cpu 抢了过去 , 于是 uhci_irq 也被调用 .

然而问题在于甭管 ohci_irq 还是 uhci_irq, 最后都会调用 u sb_hcd_unlink_urb_from_ep, 而这个函数又会调用 spin_lock 去获取 hcd_urb_list_lock. 巧的是当 uhci 抢 cpu 的时候 ,ohci 已经获得了这把锁 , 并且还没来得及释放 . 以前我说信号量像北京户口 , 你占了一个名额我就少了一个机会 , 而这里不是信号量 , 是自旋锁 , 如果要把自旋锁打个比方 , 那么我把它比作刘涛 , 很多人 YY 刘涛 , 可是她嫁给了 200 亿身价的王柯 , 做一个最极端的假设 , 假设你有 100 亿 , 而且你也幻想得到刘涛 , 那么从法律上来讲 , 除非刘涛就是下一个李湘 , 即除非王柯把她甩了 .

而法律应用到这个案例上来 , 就是说 , 除非 ohci_irq 这边甩了 hcd_urb_list_lock, 否则 uhci_irq 那边就甭想得到 . 而自旋锁更绝的地方在于 , 如果获得不了锁 ,cpu 就不停的自旋 , 它也不睡眠也不干别的 , 就好比高衙内得不到林冲的老婆 , 亦酷似西门大官人得不到潘金莲 , 这时他们仿佛丢了魂魄 , 完全陷入其中 , 似乎就不能活了一样 , 除非违反法律 , 除非做掉林冲 , 除非做掉武大郎 . 所以 , 这就是一个彻底的死锁问题 , 要破除这个很 ” 黄 ” 的死锁 , 只能用很暴力的方法 .

这个充满暴力的方法就是把中断彻底关掉 , 把 spin_lock() 换成 spin_lock_irqsave(), 同时把 spin_unlock() 换成 spin_unlock_irqrestore() 就可以 .spin_lock_irqsave() 是 spin_lock() 的加强版 , 它就是在获得 spinlock 之前 , 先关掉本处理器的中断 . 用 LDD3 中的话说就是 :

spin_lock_irqsave disables interrupts (on the local processor only) before taking the spinlock.

这样就使得当我 ohci_irq() 调用到了 usb_hcd_unlink_urb_from_ep() 并且进一步 , 获取了 hcd_urb_list_lock 之后 , 在我没有释放它之前 , 根本就不会允许本 cpu 再接受别的中断 , 任你 uhci 如何呐喊 , 如何愤怒 ,cpu 就是不理你 , 摆出一幅九阳真经中描述的姿态来 : 他狂由他狂 , 清风拂山岗 . 他横任他横 , 明月照大江 .

等到 cpu 愿意响应 uhci 的 irq, 已然是在 spin_unlock_irqrestore() 之后 .ohci 这边已经把锁释放了 , 它挥一挥衣袖 , 不带走一片云彩 . 在这种情况下 ,uhci 要获得就让他去获得 , 天要下雨 , 娘要嫁人 , 随它去吧 .

以上就是对这个 bug 的分析以及解决方案 . 以上 bug 存在于 2.6.24-rc2 和之前的内核中 . 一个月之后 ,Alan Stern 大侠提交了一个 patch 以解决这个问题 , 不过他的解决方法和以上说的略有不同 , 他不仅仅是让 usb_hcd_unlink_urb_from_ep() 内部关中断 , 他在注册中断服务函数的时候使用了 IRQF_DISABLED 这个 flag, 使得 ohci_irq/uhci_irq/ehci_irq 这些中断服务函数函数执行的整个过程中都是关中断的 . 这样做当然会引发一些争议 , 有人说它很好很强大 , 有人说它很黄很暴力 , 不过它是否对系统性能有比较大的影响目前还很难说 , 让我们骑驴看唱本 — 走着瞧 .