From 614b35af53468f13a41192ffb4ea34f264035b91 Mon Sep 17 00:00:00 2001 From: Don Zickus Date: Thu, 20 Oct 2011 23:52:14 -0400 Subject: usb, xhci: fix lockdep warning on endpoint timeout commit f43d623164022dcbf6750ef220b7a1133a1183eb upstream. While debugging a usb3 problem, I stumbled upon this lockdep warning. Oct 18 21:41:17 dhcp47-74 kernel: ================================= Oct 18 21:41:17 dhcp47-74 kernel: [ INFO: inconsistent lock state ] Oct 18 21:41:17 dhcp47-74 kernel: 3.1.0-rc4nmi+ #456 Oct 18 21:41:17 dhcp47-74 kernel: --------------------------------- Oct 18 21:41:17 dhcp47-74 kernel: inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. Oct 18 21:41:17 dhcp47-74 kernel: swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes: Oct 18 21:41:17 dhcp47-74 kernel: (&(&xhci->lock)->rlock){?.-...}, at: [] xhci_stop_endpoint_command_watchdog+0x30/0x340 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: {IN-HARDIRQ-W} state was registered at: Oct 18 21:41:17 dhcp47-74 kernel: [] __lock_acquire+0x781/0x1660 Oct 18 21:41:17 dhcp47-74 kernel: [] lock_acquire+0x97/0x170 Oct 18 21:41:17 dhcp47-74 kernel: [] _raw_spin_lock+0x46/0x80 Oct 18 21:41:17 dhcp47-74 kernel: [] xhci_irq+0x3a/0x1960 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] xhci_msi_irq+0x31/0x40 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] handle_irq_event_percpu+0x85/0x320 Oct 18 21:41:17 dhcp47-74 kernel: [] handle_irq_event+0x48/0x70 Oct 18 21:41:17 dhcp47-74 kernel: [] handle_edge_irq+0x6d/0x130 Oct 18 21:41:17 dhcp47-74 kernel: [] handle_irq+0x49/0xa0 Oct 18 21:41:17 dhcp47-74 kernel: [] do_IRQ+0x5d/0xe0 Oct 18 21:41:17 dhcp47-74 kernel: [] ret_from_intr+0x0/0x13 Oct 18 21:41:17 dhcp47-74 kernel: [] usb_set_device_state+0x8a/0x180 Oct 18 21:41:17 dhcp47-74 kernel: [] usb_add_hcd+0x2b8/0x730 Oct 18 21:41:17 dhcp47-74 kernel: [] xhci_pci_probe+0x9e/0xd4 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] local_pci_probe+0x5f/0xd0 Oct 18 21:41:17 dhcp47-74 kernel: [] pci_device_probe+0x119/0x120 Oct 18 21:41:17 dhcp47-74 kernel: [] driver_probe_device+0xa3/0x2c0 Oct 18 21:41:17 dhcp47-74 kernel: [] __driver_attach+0xab/0xb0 Oct 18 21:41:17 dhcp47-74 kernel: [] bus_for_each_dev+0x6c/0xa0 Oct 18 21:41:17 dhcp47-74 kernel: [] driver_attach+0x1e/0x20 Oct 18 21:41:17 dhcp47-74 kernel: [] bus_add_driver+0x1f8/0x2b0 Oct 18 21:41:17 dhcp47-74 kernel: [] driver_register+0x76/0x140 Oct 18 21:41:17 dhcp47-74 kernel: [] __pci_register_driver+0x66/0xe0 Oct 18 21:41:17 dhcp47-74 kernel: [] snd_timer_find+0x4a/0x70 [snd_timer] Oct 18 21:41:17 dhcp47-74 kernel: [] snd_timer_find+0xe/0x70 [snd_timer] Oct 18 21:41:17 dhcp47-74 kernel: [] do_one_initcall+0x43/0x180 Oct 18 21:41:17 dhcp47-74 kernel: [] sys_init_module+0x92/0x1f0 Oct 18 21:41:17 dhcp47-74 kernel: [] system_call_fastpath+0x16/0x1b Oct 18 21:41:17 dhcp47-74 kernel: irq event stamp: 631984 Oct 18 21:41:17 dhcp47-74 kernel: hardirqs last enabled at (631984): [] _raw_spin_unlock_irq+0x30/0x50 Oct 18 21:41:17 dhcp47-74 kernel: hardirqs last disabled at (631983): [] _raw_spin_lock_irq+0x19/0x90 Oct 18 21:41:17 dhcp47-74 kernel: softirqs last enabled at (631980): [] _local_bh_enable+0x13/0x20 Oct 18 21:41:17 dhcp47-74 kernel: softirqs last disabled at (631981): [] call_softirq+0x1c/0x30 Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: other info that might help us debug this: Oct 18 21:41:17 dhcp47-74 kernel: Possible unsafe locking scenario: Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: CPU0 Oct 18 21:41:17 dhcp47-74 kernel: ---- Oct 18 21:41:17 dhcp47-74 kernel: lock(&(&xhci->lock)->rlock); Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: lock(&(&xhci->lock)->rlock); Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: *** DEADLOCK *** Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: 1 lock held by swapper/0: Oct 18 21:41:17 dhcp47-74 kernel: #0: (&ep->stop_cmd_timer){+.-...}, at: [] run_timer_softirq+0x162/0x570 Oct 18 21:41:17 dhcp47-74 kernel: Oct 18 21:41:17 dhcp47-74 kernel: stack backtrace: Oct 18 21:41:17 dhcp47-74 kernel: Pid: 0, comm: swapper Tainted: G W 3.1.0-rc4nmi+ #456 Oct 18 21:41:17 dhcp47-74 kernel: Call Trace: Oct 18 21:41:17 dhcp47-74 kernel: [] print_usage_bug+0x227/0x270 Oct 18 21:41:17 dhcp47-74 kernel: [] mark_lock+0x346/0x410 Oct 18 21:41:17 dhcp47-74 kernel: [] __lock_acquire+0x61e/0x1660 Oct 18 21:41:17 dhcp47-74 kernel: [] ? mark_lock+0x213/0x410 Oct 18 21:41:17 dhcp47-74 kernel: [] lock_acquire+0x97/0x170 Oct 18 21:41:17 dhcp47-74 kernel: [] ? xhci_stop_endpoint_command_watchdog+0x30/0x340 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] _raw_spin_lock+0x46/0x80 Oct 18 21:41:17 dhcp47-74 kernel: [] ? xhci_stop_endpoint_command_watchdog+0x30/0x340 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] xhci_stop_endpoint_command_watchdog+0x30/0x340 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] ? run_timer_softirq+0x162/0x570 Oct 18 21:41:17 dhcp47-74 kernel: [] run_timer_softirq+0x20d/0x570 Oct 18 21:41:17 dhcp47-74 kernel: [] ? run_timer_softirq+0x162/0x570 Oct 18 21:41:17 dhcp47-74 kernel: [] ? xhci_queue_isoc_tx_prepare+0x8e0/0x8e0 [xhci_hcd] Oct 18 21:41:17 dhcp47-74 kernel: [] __do_softirq+0xf2/0x3f0 Oct 18 21:41:17 dhcp47-74 kernel: [] ? lapic_next_event+0x1d/0x30 Oct 18 21:41:17 dhcp47-74 kernel: [] ? clockevents_program_event+0x5e/0x90 Oct 18 21:41:17 dhcp47-74 kernel: [] call_softirq+0x1c/0x30 Oct 18 21:41:17 dhcp47-74 kernel: [] do_softirq+0x8d/0xc0 Oct 18 21:41:17 dhcp47-74 kernel: [] irq_exit+0xe5/0x100 Oct 18 21:41:17 dhcp47-74 kernel: [] smp_apic_timer_interrupt+0x6e/0x99 Oct 18 21:41:17 dhcp47-74 kernel: [] apic_timer_interrupt+0x70/0x80 Oct 18 21:41:17 dhcp47-74 kernel: [] ? trace_hardirqs_off+0xd/0x10 Oct 18 21:41:17 dhcp47-74 kernel: [] ? acpi_idle_enter_bm+0x227/0x25b Oct 18 21:41:17 dhcp47-74 kernel: [] ? acpi_idle_enter_bm+0x222/0x25b Oct 18 21:41:17 dhcp47-74 kernel: [] cpuidle_idle_call+0x103/0x290 Oct 18 21:41:17 dhcp47-74 kernel: [] cpu_idle+0xe5/0x160 Oct 18 21:41:17 dhcp47-74 kernel: [] rest_init+0xe0/0xf0 Oct 18 21:41:17 dhcp47-74 kernel: [] ? csum_partial_copy_generic+0x170/0x170 Oct 18 21:41:17 dhcp47-74 kernel: [] start_kernel+0x3fc/0x407 Oct 18 21:41:17 dhcp47-74 kernel: [] x86_64_start_reservations+0x131/0x135 Oct 18 21:41:17 dhcp47-74 kernel: [] x86_64_start_kernel+0xed/0xf4 Oct 18 21:41:17 dhcp47-74 kernel: xhci_hcd 0000:00:14.0: xHCI host not responding to stop endpoint command. Oct 18 21:41:17 dhcp47-74 kernel: xhci_hcd 0000:00:14.0: Assuming host is dying, halting host. Oct 18 21:41:17 dhcp47-74 kernel: xhci_hcd 0000:00:14.0: HC died; cleaning up Oct 18 21:41:17 dhcp47-74 kernel: usb 3-4: device descriptor read/8, error -110 Oct 18 21:41:17 dhcp47-74 kernel: usb 3-4: device descriptor read/8, error -22 Oct 18 21:41:17 dhcp47-74 kernel: hub 3-0:1.0: cannot disable port 4 (err = -19) Basically what is happening is in xhci_stop_endpoint_command_watchdog() the xhci->lock is grabbed with just spin_lock. What lockdep deduces is that if an interrupt occurred while in this function it would deadlock with xhci_irq because that function also grabs the xhci->lock. Fixing it is trivial by using spin_lock_irqsave instead. This should be queued to stable kernels as far back as 2.6.33. Signed-off-by: Don Zickus Signed-off-by: Sarah Sharp Signed-off-by: Greg Kroah-Hartman --- drivers/usb/host/xhci-ring.c | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) (limited to 'drivers/usb/host/xhci-ring.c') diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index b20d2f7..b4b0691 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -819,23 +819,24 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) struct xhci_ring *ring; struct xhci_td *cur_td; int ret, i, j; + unsigned long flags; ep = (struct xhci_virt_ep *) arg; xhci = ep->xhci; - spin_lock(&xhci->lock); + spin_lock_irqsave(&xhci->lock, flags); ep->stop_cmds_pending--; if (xhci->xhc_state & XHCI_STATE_DYING) { xhci_dbg(xhci, "Stop EP timer ran, but another timer marked " "xHCI as DYING, exiting.\n"); - spin_unlock(&xhci->lock); + spin_unlock_irqrestore(&xhci->lock, flags); return; } if (!(ep->stop_cmds_pending == 0 && (ep->ep_state & EP_HALT_PENDING))) { xhci_dbg(xhci, "Stop EP timer ran, but no command pending, " "exiting.\n"); - spin_unlock(&xhci->lock); + spin_unlock_irqrestore(&xhci->lock, flags); return; } @@ -847,11 +848,11 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) xhci->xhc_state |= XHCI_STATE_DYING; /* Disable interrupts from the host controller and start halting it */ xhci_quiesce(xhci); - spin_unlock(&xhci->lock); + spin_unlock_irqrestore(&xhci->lock, flags); ret = xhci_halt(xhci); - spin_lock(&xhci->lock); + spin_lock_irqsave(&xhci->lock, flags); if (ret < 0) { /* This is bad; the host is not responding to commands and it's * not allowing itself to be halted. At least interrupts are @@ -899,7 +900,7 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) } } } - spin_unlock(&xhci->lock); + spin_unlock_irqrestore(&xhci->lock, flags); xhci_dbg(xhci, "Calling usb_hc_died()\n"); usb_hc_died(xhci_to_hcd(xhci)->primary_hcd); xhci_dbg(xhci, "xHCI host controller is dead.\n"); -- cgit v1.1