From 1349a252eb45cc1b8244ab3c882edb2539eb1049 Mon Sep 17 00:00:00 2001 From: Kari Suvanto Date: Tue, 19 Aug 2014 14:25:28 +0300 Subject: [PATCH 1/2] usb: dwc: fix lockdep false positive Os wrapper function for spinlock init causes lockdep to show this false positive splat during boot: [ 3.789851] ============================================= [ 3.796603] [ INFO: possible recursive locking detected ] [ 3.803320] 3.16.1+ #5 Not tainted [ 3.808015] --------------------------------------------- [ 3.814730] khubd/18 is trying to acquire lock: [ 3.820537] (&(sl)->rlock){-.-...}, at: [] DWC_SPINLOCK_IRQSAVE+0xc/0x14 [ 3.830932] [ 3.830932] but task is already holding lock: [ 3.839274] (&(sl)->rlock){-.-...}, at: [] DWC_SPINLOCK_IRQSAVE+0xc/0x14 [ 3.849704] [ 3.849704] other info that might help us debug this: [ 3.858826] Possible unsafe locking scenario: [ 3.858826] [ 3.867334] CPU0 [ 3.871052] ---- [ 3.874721] lock(&(sl)->rlock); [ 3.879302] lock(&(sl)->rlock); [ 3.883815] [ 3.883815] *** DEADLOCK *** [ 3.883815] [ 3.892869] May be due to missing lock nesting notation [ 3.892869] [ 3.901736] 4 locks held by khubd/18: [ 3.906438] #0: (&dev->mutex){......}, at: [] hub_thread+0x98/0x1000 [ 3.916026] #1: (&port_dev->status_lock){+.+.+.}, at: [] hub_thread+0x63c/0x1000 [ 3.926847] #2: (&bus->usb_address0_mutex){+.+.+.}, at: [] hub_port_init+0x5c/0xb24 [ 3.938015] #3: (&(sl)->rlock){-.-...}, at: [] DWC_SPINLOCK_IRQSAVE+0xc/0x14 [ 3.948730] [ 3.948730] stack backtrace: [ 3.955457] CPU: 0 PID: 18 Comm: khubd Not tainted 3.16.1+ #5 [ 3.962541] [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [ 3.972998] [] (show_stack) from [] (__lock_acquire+0x1420/0x1ae0) [ 3.983910] [] (__lock_acquire) from [] (lock_acquire+0x6c/0x8c) [ 3.994908] [] (lock_acquire) from [] (_raw_spin_lock_irqsave+0x50/0x64) [ 4.006756] [] (_raw_spin_lock_irqsave) from [] (DWC_SPINLOCK_IRQSAVE+0xc/0x14) [ 4.019382] [] (DWC_SPINLOCK_IRQSAVE) from [] (dwc_otg_hcd_select_transactions+0x20c/0x368) [ 4.033064] [] (dwc_otg_hcd_select_transactions) from [] (dwc_otg_hcd_urb_enqueue+0x158/0x1ec) [ 4.047017] [] (dwc_otg_hcd_urb_enqueue) from [] (dwc_otg_urb_enqueue+0x1a8/0x2e0) [ 4.059889] [] (dwc_otg_urb_enqueue) from [] (usb_hcd_submit_urb+0xb8/0x870) [ 4.072316] [] (usb_hcd_submit_urb) from [] (usb_start_wait_urb+0x44/0xbc) [ 4.084786] [] (usb_start_wait_urb) from [] (usb_control_msg+0xb4/0xec) [ 4.097045] [] (usb_control_msg) from [] (hub_port_init+0x420/0xb24) [ 4.109018] [] (hub_port_init) from [] (hub_thread+0x650/0x1000) [ 4.120667] [] (hub_thread) from [] (kthread+0xc8/0xe4) [ 4.129668] [] (kthread) from [] (ret_from_fork+0x14/0x2c) This is false positive because the lockdep uses the lock variable name to keep track of locks. To fix this, the spin_lock_init function can't be in a wrapper function for spinlock name to recorder correctly. I noticed similar fix was already made for mutex debugging so used similar approach and added extra macro to be used to spinlock allocation when spinlock debugging is on. Signed-off-by: Kari Suvanto --- .../usb/host/dwc_common_port/dwc_common_linux.c | 8 ++++++++ drivers/usb/host/dwc_common_port/dwc_os.h | 16 +++++++++++++++- drivers/usb/host/dwc_otg/dwc_otg_hcd.c | 5 +++++ drivers/usb/host/dwc_otg/dwc_otg_pcd.c | 4 ++++ 4 files changed, 32 insertions(+), 1 deletion(-) diff --git a/drivers/usb/host/dwc_common_port/dwc_common_linux.c b/drivers/usb/host/dwc_common_port/dwc_common_linux.c index 6d01261785716..5c50a8b828989 100644 --- a/drivers/usb/host/dwc_common_port/dwc_common_linux.c +++ b/drivers/usb/host/dwc_common_port/dwc_common_linux.c @@ -766,7 +766,11 @@ dwc_timer_t *DWC_TIMER_ALLOC(char *name, dwc_timer_callback_t cb, void *data) goto no_name; } +#if (defined(DWC_LINUX) && defined(CONFIG_DEBUG_SPINLOCK)) + DWC_SPINLOCK_ALLOC_LINUX_DEBUG(t->lock); +#else t->lock = DWC_SPINLOCK_ALLOC(); +#endif if (!t->lock) { DWC_ERROR("Cannot allocate memory for lock"); goto no_lock; @@ -1083,7 +1087,11 @@ dwc_workq_t *DWC_WORKQ_ALLOC(char *name) wq->pending = 0; +#if (defined(DWC_LINUX) && defined(CONFIG_DEBUG_SPINLOCK)) + DWC_SPINLOCK_ALLOC_LINUX_DEBUG(wq->lock); +#else wq->lock = DWC_SPINLOCK_ALLOC(); +#endif if (!wq->lock) { goto no_lock; } diff --git a/drivers/usb/host/dwc_common_port/dwc_os.h b/drivers/usb/host/dwc_common_port/dwc_os.h index 09ed244b1414a..a2bbe232ffc3b 100644 --- a/drivers/usb/host/dwc_common_port/dwc_os.h +++ b/drivers/usb/host/dwc_common_port/dwc_os.h @@ -59,6 +59,7 @@ extern "C" { # ifdef CONFIG_DEBUG_MUTEXES # include # endif +# include # include # include #endif @@ -1039,9 +1040,22 @@ typedef unsigned long dwc_irqflags_t; /** Returns an initialized lock variable. This function should allocate and * initialize the OS-specific data structure used for locking. This data * structure is to be used for the DWC_LOCK and DWC_UNLOCK functions and should - * be freed by the DWC_FREE_LOCK when it is no longer used. */ + * be freed by the DWC_FREE_LOCK when it is no longer used. + * + * For Linux Spinlock Debugging make it macro because the debugging routines use + * the symbol name to determine recursive locking. Using a wrapper function + * makes it falsely think recursive locking occurs. */ +#if defined(DWC_LINUX) && defined(CONFIG_DEBUG_SPINLOCK) +#define DWC_SPINLOCK_ALLOC_LINUX_DEBUG(lock) ({ \ + lock = DWC_ALLOC(sizeof(spinlock_t)); \ + if (lock) { \ + spin_lock_init((spinlock_t *)lock); \ + } \ +}) +#else extern dwc_spinlock_t *DWC_SPINLOCK_ALLOC(void); #define dwc_spinlock_alloc(_ctx_) DWC_SPINLOCK_ALLOC() +#endif /** Frees an initialized lock variable. */ extern void DWC_SPINLOCK_FREE(dwc_spinlock_t *lock); diff --git a/drivers/usb/host/dwc_otg/dwc_otg_hcd.c b/drivers/usb/host/dwc_otg/dwc_otg_hcd.c index 35721e55f95fe..c39ef317af267 100644 --- a/drivers/usb/host/dwc_otg/dwc_otg_hcd.c +++ b/drivers/usb/host/dwc_otg/dwc_otg_hcd.c @@ -951,8 +951,13 @@ int dwc_otg_hcd_init(dwc_otg_hcd_t * hcd, dwc_otg_core_if_t * core_if) int i; dwc_hc_t *channel; +#if (defined(DWC_LINUX) && defined(CONFIG_DEBUG_SPINLOCK)) + DWC_SPINLOCK_ALLOC_LINUX_DEBUG(hcd->lock); + DWC_SPINLOCK_ALLOC_LINUX_DEBUG(hcd->channel_lock); +#else hcd->lock = DWC_SPINLOCK_ALLOC(); hcd->channel_lock = DWC_SPINLOCK_ALLOC(); +#endif DWC_DEBUGPL(DBG_HCDV, "init of HCD %p given core_if %p\n", hcd, core_if); if (!hcd->lock) { diff --git a/drivers/usb/host/dwc_otg/dwc_otg_pcd.c b/drivers/usb/host/dwc_otg/dwc_otg_pcd.c index 40fb25c798184..ae0c72d02d007 100644 --- a/drivers/usb/host/dwc_otg/dwc_otg_pcd.c +++ b/drivers/usb/host/dwc_otg/dwc_otg_pcd.c @@ -1120,7 +1120,11 @@ dwc_otg_pcd_t *dwc_otg_pcd_init(dwc_otg_core_if_t * core_if) return NULL; } +#if (defined(DWC_LINUX) && defined(CONFIG_DEBUG_SPINLOCK)) + DWC_SPINLOCK_ALLOC_LINUX_DEBUG(pcd->lock); +#else pcd->lock = DWC_SPINLOCK_ALLOC(); +#endif DWC_DEBUGPL(DBG_HCDV, "Init of PCD %p given core_if %p\n", pcd, core_if);//GRAYG if (!pcd->lock) { From 51dd458f1097d92f4731fd497a54954fd8bcc0e5 Mon Sep 17 00:00:00 2001 From: Kari Suvanto Date: Tue, 19 Aug 2014 14:38:24 +0300 Subject: [PATCH 2/2] usb: dwc: fix inconsistent lock state Lockdep gives this splat during boot: [ 4.136748] ================================= [ 4.145487] [ INFO: inconsistent lock state ] [ 4.154157] 3.16.1+ #12 Not tainted [ 4.161852] --------------------------------- [ 4.170459] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. [ 4.180776] khubd/18 [HC0[0]:SC0[0]:HE1:SE1] takes: [ 4.189971] (&((spinlock_t *)hcd->lock)->rlock){?.-...}, at: [] dwc_otg_hcd_qh_free+0x18/0xcc [ 4.204074] {IN-HARDIRQ-W} state was registered at: [ 4.213359] [] _raw_spin_lock+0x40/0x50 [ 4.222743] [] dwc_otg_handle_common_intr+0x44/0xd90 [ 4.233133] [] dwc_otg_common_irq+0xc/0x18 [ 4.242739] [] handle_irq_event_percpu+0x34/0x150 [ 4.252955] [] handle_irq_event+0x3c/0x5c [ 4.262395] [] handle_level_irq+0x8c/0x130 [ 4.271972] [] generic_handle_irq+0x28/0x40 [ 4.281489] [] handle_IRQ+0x30/0x84 [ 4.290442] [] __irq_svc+0x38/0xd0 [ 4.299164] [] DWC_MODIFY_REG32+0x64/0x84 [ 4.308613] [] dwc_otg_driver_probe+0x720/0x7a8 [ 4.318523] [] platform_drv_probe+0x18/0x48 [ 4.328141] [] really_probe+0x68/0x200 [ 4.337334] [] __driver_attach+0xa0/0xa4 [ 4.346592] [] bus_for_each_dev+0x60/0x94 [ 4.355998] [] bus_add_driver+0x140/0x1ec [ 4.365262] [] driver_register+0x78/0xf8 [ 4.374561] [] dwc_otg_driver_init+0x58/0x114 [ 4.384271] [] do_one_initcall+0x80/0x1cc [ 4.393661] [] kernel_init_freeable+0xf0/0x1b0 [ 4.403501] [] kernel_init+0x8/0xec [ 4.412308] [] ret_from_fork+0x14/0x2c [ 4.421444] irq event stamp: 2351 [ 4.428928] hardirqs last enabled at (2351): [] _raw_spin_unlock_irqrestore+0x7c/0x94 [ 4.442100] hardirqs last disabled at (2350): [] _raw_spin_lock_irqsave+0x1c/0x64 [ 4.454802] softirqs last enabled at (2320): [] __do_softirq+0x1ac/0x26c [ 4.466739] softirqs last disabled at (2297): [] irq_exit+0xac/0x100 [ 4.478260] [ 4.478260] other info that might help us debug this: [ 4.493215] Possible unsafe locking scenario: [ 4.493215] [ 4.507451] CPU0 [ 4.513932] ---- [ 4.520505] lock(&((spinlock_t *)hcd->lock)->rlock); [ 4.529767] [ 4.536515] lock(&((spinlock_t *)hcd->lock)->rlock); [ 4.545951] [ 4.545951] *** DEADLOCK *** [ 4.545951] [ 4.564132] 3 locks held by khubd/18: [ 4.571884] #0: (&dev->mutex){......}, at: [] hub_thread+0x98/0x1000 [ 4.583536] #1: (&port_dev->status_lock){+.+.+.}, at: [] hub_thread+0x63c/0x1000 [ 4.596241] #2: (&bus->usb_address0_mutex){+.+.+.}, at: [] hub_port_init+0x5c/0xb24 [ 4.609307] [ 4.609307] stack backtrace: [ 4.621705] CPU: 0 PID: 18 Comm: khubd Not tainted 3.16.1+ #12 [ 4.631643] [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [ 4.643580] [] (show_stack) from [] (print_usage_bug+0x240/0x2b0) [ 4.655608] [] (print_usage_bug) from [] (mark_lock+0x1d0/0x67c) [ 4.667527] [] (mark_lock) from [] (__lock_acquire+0x5d4/0x1ae0) [ 4.679551] [] (__lock_acquire) from [] (lock_acquire+0x6c/0x8c) [ 4.691610] [] (lock_acquire) from [] (_raw_spin_lock+0x40/0x50) [ 4.703584] [] (_raw_spin_lock) from [] (dwc_otg_hcd_qh_free+0x18/0xcc) [ 4.716305] [] (dwc_otg_hcd_qh_free) from [] (dwc_otg_hcd_endpoint_disable+0x9c/0xb0) [ 4.730246] [] (dwc_otg_hcd_endpoint_disable) from [] (endpoint_disable+0x18/0x24) [ 4.743919] [] (endpoint_disable) from [] (usb_ep0_reinit+0x14/0x38) [ 4.756379] [] (usb_ep0_reinit) from [] (hub_port_init+0x2a4/0xb24) [ 4.768652] [] (hub_port_init) from [] (hub_thread+0x650/0x1000) [ 4.780824] [] (hub_thread) from [] (kthread+0xc8/0xe4) [ 4.792231] [] (kthread) from [] (ret_from_fork+0x14/0x2c) This splat shows that the hcd spinlock is used from hard irq context and also from process context with irqs on. To fix this, use spinlock_irqsave instead of spinlock in dwc_otg_hcd_qh_free. Signed-off-by: Kari Suvanto --- drivers/usb/host/dwc_otg/dwc_otg_hcd_queue.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/drivers/usb/host/dwc_otg/dwc_otg_hcd_queue.c b/drivers/usb/host/dwc_otg/dwc_otg_hcd_queue.c index 8706a5ce60e46..17d30300df3f0 100644 --- a/drivers/usb/host/dwc_otg/dwc_otg_hcd_queue.c +++ b/drivers/usb/host/dwc_otg/dwc_otg_hcd_queue.c @@ -55,9 +55,10 @@ extern bool microframe_schedule; void dwc_otg_hcd_qh_free(dwc_otg_hcd_t * hcd, dwc_otg_qh_t * qh) { dwc_otg_qtd_t *qtd, *qtd_tmp; + dwc_irqflags_t flags; /* Free each QTD in the QTD list */ - DWC_SPINLOCK(hcd->lock); + DWC_SPINLOCK_IRQSAVE(hcd->lock, &flags); DWC_CIRCLEQ_FOREACH_SAFE(qtd, qtd_tmp, &qh->qtd_list, qtd_list_entry) { DWC_CIRCLEQ_REMOVE(&qh->qtd_list, qtd, qtd_list_entry); dwc_otg_hcd_qtd_free(qtd); @@ -76,7 +77,7 @@ void dwc_otg_hcd_qh_free(dwc_otg_hcd_t * hcd, dwc_otg_qh_t * qh) } DWC_FREE(qh); - DWC_SPINUNLOCK(hcd->lock); + DWC_SPINUNLOCK_IRQRESTORE(hcd->lock, flags); return; }