Hello,
Every time I boot a particular development server the complaint shown
below appears in the system log. I don't know when this behavior has
been introduced. But I noticed that I can reproduce this with older
kernel versions, e.g. 4.4.63. Does anyone know what is going on or how
to fix this?
Thanks,
Bart.
usb 1-8: new low-speed USB device number 2 using xhci_hcd
usb 3-1: new high-speed USB device number 2 using ehci-pci
=========================================================
[ INFO: possible irq lock inversion dependency detected ]
4.11.0-rc8-dbg+ #1 Not tainted
---------------------------------------------------------
swapper/7/0 just changed the state of lock:
(&(&ehci->lock)->rlock){-.-...}, at: [<ffffffffa0130a69>] ehci_hrtimer_func+0x29/0xc0 [ehci_hcd]
but this lock took another, HARDIRQ-unsafe lock in the past:
(hcd_urb_list_lock){+.....}
and interrupts could create inverse lock ordering between them.
other info that might help us debug this:
Possible interrupt unsafe locking scenario:
CPU0 CPU1
---- ----
lock(hcd_urb_list_lock);
local_irq_disable();
lock(&(&ehci->lock)->rlock);
lock(hcd_urb_list_lock);
<Interrupt>
lock(&(&ehci->lock)->rlock);
*** DEADLOCK ***
no locks held by swapper/7/0.
the shortest dependencies between 2nd lock and 1st lock:
-> (hcd_urb_list_lock){+.....} ops: 252 {
HARDIRQ-ON-W at:
__lock_acquire+0x602/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock+0x2f/0x40
usb_hcd_unlink_urb_from_ep+0x1b/0x60 [usbcore]
xhci_giveback_urb_in_irq.isra.45+0x70/0x1b0 [xhci_hcd]
finish_td.constprop.60+0x1d8/0x2e0 [xhci_hcd]
xhci_irq+0xdd6/0x1fa0 [xhci_hcd]
usb_hcd_irq+0x26/0x40 [usbcore]
irq_forced_thread_fn+0x2f/0x70
irq_thread+0x149/0x1d0
kthread+0x113/0x150
ret_from_fork+0x2e/0x40
INITIAL USE at:
__lock_acquire+0x343/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock+0x2f/0x40
usb_hcd_link_urb_to_ep+0x2e/0xd0 [usbcore]
usb_hcd_submit_urb+0x117/0xb40 [usbcore]
usb_submit_urb+0x2f4/0x560 [usbcore]
usb_start_wait_urb+0x5f/0x150 [usbcore]
usb_control_msg+0xc1/0xf0 [usbcore]
usb_get_descriptor+0x79/0xc0 [usbcore]
usb_get_device_descriptor+0x57/0x100 [usbcore]
usb_add_hcd+0x329/0x8a0 [usbcore]
usb_hcd_pci_probe+0x1af/0x450 [usbcore]
xhci_pci_probe+0x1c/0x180 [xhci_pci]
local_pci_probe+0x24/0x60
pci_device_probe+0xd8/0x130
driver_probe_device+0x26a/0x410
__driver_attach+0xe3/0xf0
bus_for_each_dev+0x62/0xa0
driver_attach+0x1e/0x20
bus_add_driver+0x173/0x270
driver_register+0x60/0xe0
__pci_register_driver+0x5d/0x60
0xffffffffa0147031
do_one_initcall+0x43/0x170
do_init_module+0x5f/0x1fa
load_module+0x24ab/0x2c00
SYSC_finit_module+0xbc/0xf0
SyS_finit_module+0xe/0x10
do_syscall_64+0x5c/0x140
return_from_SYSCALL_64+0x0/0x7a
}
... key at: [<ffffffffa008bf18>] hcd_urb_list_lock+0x18/0xffffffffffff7100 [usbcore]
... acquired at:
lock_acquire+0xd5/0x1c0
_raw_spin_lock+0x2f/0x40
usb_hcd_link_urb_to_ep+0x2e/0xd0 [usbcore]
ehci_urb_enqueue+0xab/0x107f [ehci_hcd]
usb_hcd_submit_urb+0x8f/0xb40 [usbcore]
usb_submit_urb+0x2f4/0x560 [usbcore]
usb_start_wait_urb+0x5f/0x150 [usbcore]
usb_control_msg+0xc1/0xf0 [usbcore]
hub_port_init+0x305/0xb90 [usbcore]
hub_event+0x690/0x1250 [usbcore]
process_one_work+0x20b/0x6a0
worker_thread+0x4e/0x4a0
kthread+0x113/0x150
ret_from_fork+0x2e/0x40
-> (&(&ehci->lock)->rlock){-.-...} ops: 38 {
IN-HARDIRQ-W at:
__lock_acquire+0x67d/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock_irqsave+0x3a/0x50
ehci_hrtimer_func+0x29/0xc0 [ehci_hcd]
__hrtimer_run_queues+0xde/0x4c0
hrtimer_interrupt+0xaa/0x200
local_apic_timer_interrupt+0x38/0x60
smp_apic_timer_interrupt+0x38/0x50
apic_timer_interrupt+0x90/0xa0
cpuidle_enter_state+0x135/0x380
cpuidle_enter+0x17/0x20
call_cpuidle+0x23/0x40
do_idle+0xe8/0x1c0
cpu_startup_entry+0x1d/0x20
start_secondary+0x103/0x130
verify_cpu+0x0/0xfc
IN-SOFTIRQ-W at:
__lock_acquire+0x560/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock_irqsave+0x3a/0x50
ehci_hub_status_data+0x6c/0x1a0 [ehci_hcd]
usb_hcd_poll_rh_status+0x49/0x140 [usbcore]
rh_timer_func+0xe/0x10 [usbcore]
call_timer_fn+0x90/0x330
run_timer_softirq+0x21a/0x5b0
__do_softirq+0xbf/0x4b7
run_ksoftirqd+0x1f/0x60
smpboot_thread_fn+0x128/0x1f0
kthread+0x113/0x150
ret_from_fork+0x2e/0x40
INITIAL USE at:
__lock_acquire+0x343/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock_irq+0x35/0x50
ehci_halt+0x1e/0xf0 [ehci_hcd]
ehci_setup+0x4de/0x810 [ehci_hcd]
ehci_pci_setup+0xb7/0x576 [ehci_pci]
usb_add_hcd+0x22e/0x8a0 [usbcore]
usb_hcd_pci_probe+0x36d/0x450 [usbcore]
ehci_pci_probe+0x36/0x40 [ehci_pci]
local_pci_probe+0x24/0x60
pci_device_probe+0xd8/0x130
driver_probe_device+0x26a/0x410
__driver_attach+0xe3/0xf0
bus_for_each_dev+0x62/0xa0
driver_attach+0x1e/0x20
bus_add_driver+0x173/0x270
driver_register+0x60/0xe0
__pci_register_driver+0x5d/0x60
0xffffffffa015006a
do_one_initcall+0x43/0x170
do_init_module+0x5f/0x1fa
load_module+0x24ab/0x2c00
SYSC_finit_module+0xbc/0xf0
SyS_finit_module+0xe/0x10
do_syscall_64+0x5c/0x140
return_from_SYSCALL_64+0x0/0x7a
}
... key at: [<ffffffffa013d390>] __key.38270+0x0/0xffffffffffffcc70 [ehci_hcd]
... acquired at:
check_usage_forwards+0x120/0x130
mark_lock+0x3bf/0x5c0
__lock_acquire+0x67d/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock_irqsave+0x3a/0x50
ehci_hrtimer_func+0x29/0xc0 [ehci_hcd]
__hrtimer_run_queues+0xde/0x4c0
hrtimer_interrupt+0xaa/0x200
local_apic_timer_interrupt+0x38/0x60
smp_apic_timer_interrupt+0x38/0x50
apic_timer_interrupt+0x90/0xa0
cpuidle_enter_state+0x135/0x380
cpuidle_enter+0x17/0x20
call_cpuidle+0x23/0x40
do_idle+0xe8/0x1c0
cpu_startup_entry+0x1d/0x20
start_secondary+0x103/0x130
verify_cpu+0x0/0xfc
stack backtrace:
CPU: 7 PID: 0 Comm: swapper/7 Not tainted 4.11.0-rc8-dbg+ #1
Hardware name: Dell Inc. PowerEdge R430/03XKDV, BIOS 1.0.2 11/17/2014
Call Trace:
<IRQ>
dump_stack+0x68/0x93
print_irq_inversion_bug.part.37+0x1a5/0x1b1
check_usage_forwards+0x120/0x130
mark_lock+0x3bf/0x5c0
__lock_acquire+0x67d/0x1280
lock_acquire+0xd5/0x1c0
_raw_spin_lock_irqsave+0x3a/0x50
ehci_hrtimer_func+0x29/0xc0 [ehci_hcd]
__hrtimer_run_queues+0xde/0x4c0
hrtimer_interrupt+0xaa/0x200
local_apic_timer_interrupt+0x38/0x60
smp_apic_timer_interrupt+0x38/0x50
apic_timer_interrupt+0x90/0xa0
</IRQ>
cpuidle_enter+0x17/0x20
call_cpuidle+0x23/0x40
do_idle+0xe8/0x1c0
cpu_startup_entry+0x1d/0x20
start_secondary+0x103/0x130
start_cpu+0x14/0x14--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
