Ran into this deadlock in the btwilink coupled with the omap-serial
driver.Kernel is only tainted with a custom dts and small kim dts
enablement patch, nothing which would cause this error.
Please CC as I'm not on list.
[ 1144.307220]
[ 1144.308837] ======================================================
[ 1144.310821] [ INFO: possible circular locking dependency detected ]
[ 1144.321960] 4.2.0-rc4-00001-gaa22fe1-dirty #1 Not tainted
[ 1144.321960] -------------------------------------------------------
[ 1144.334259] connmand/322 is trying to acquire lock:
[ 1144.334259] (&(&st_gdata->lock)->rlock){-.....}, at: [<c040f0b8>]
st_tx_wakeup+0x48/0xf4
[ 1144.340820]
[ 1144.340820] but task is already holding lock:
[ 1144.354248] (&port_lock_key){-.-...}, at: [<c03e64a8>]
serial_omap_irq+0x14/0x3ec
[ 1144.362304]
[ 1144.362304] which lock already depends on the new lock.
[ 1144.362304]
[ 1144.370819]
[ 1144.370819] the existing dependency chain (in reverse order) is:
[ 1144.370941]
-> #1 (&port_lock_key){-.-...}:
[ 1144.383453] [<c03dc41c>] uart_write+0x34/0xdc
[ 1144.383453] [<c040f0dc>] st_tx_wakeup+0x6c/0xf4
[ 1144.390777] [<c040f57c>] st_write+0xa0/0x100
[ 1144.390777] [<bf44b0f0>] ti_st_send_frame+0x3c/0xdc [btwilink]
[ 1144.406127] [<bf3c441c>] hci_send_frame+0x6c/0xbc [bluetooth]
[ 1144.413116] [<bf3c44e8>] hci_cmd_work+0x7c/0xe0 [bluetooth]
[ 1144.415313] [<c0058f9c>] process_one_work+0x1b4/0x4b4
[ 1144.420776] [<c00592d8>] worker_thread+0x3c/0x4a4
[ 1144.430786] [<c005ef24>] kthread+0xd4/0xf0
[ 1144.431396] [<c000f618>] ret_from_fork+0x14/0x3c
[ 1144.440673]
-> #0 (&(&st_gdata->lock)->rlock){-.....}:
[ 1144.447540] [<c0602090>] _raw_spin_lock_irqsave+0x40/0x54
[ 1144.450805] [<c040f0b8>] st_tx_wakeup+0x48/0xf4
[ 1144.459350] [<c03be994>] tty_wakeup+0x50/0x5c
[ 1144.464630] [<c03e67e0>] serial_omap_irq+0x34c/0x3ec
[ 1144.464630] [<c009c338>] handle_irq_event_percpu+0x40/0x1e8
[ 1144.470794] [<c009c520>] handle_irq_event+0x40/0x64
[ 1144.480773] [<c009f5dc>] handle_fasteoi_irq+0xcc/0x1c4
[ 1144.480773] [<c009b9d4>] generic_handle_irq+0x28/0x3c
[ 1144.494689] [<c009bcbc>] __handle_domain_irq+0x64/0xe0
[ 1144.500915] [<c00094dc>] gic_handle_irq+0x20/0x60
[ 1144.500915] [<c0602cc8>] __irq_usr+0x48/0x60
[ 1144.511596] [<b6d9b094>] 0xb6d9b094
[ 1144.515319]
[ 1144.515319] other info that might help us debug this:
[ 1144.515319]
[ 1144.524261] Possible unsafe locking scenario:
[ 1144.524261]
[ 1144.530456] CPU0 CPU1
[ 1144.530670] ---- ----
[ 1144.538269] lock(&port_lock_key);
[ 1144.540832] lock(&(&st_gdata->lock)->rlock);
[ 1144.550872] lock(&port_lock_key);
[ 1144.551422] lock(&(&st_gdata->lock)->rlock);
[ 1144.551422]
[ 1144.551422] *** DEADLOCK ***
[ 1144.551422]
[ 1144.565277] 2 locks held by connmand/322:
[ 1144.569366] #0: (&port_lock_key){-.-...}, at: [<c03e64a8>]
serial_omap_irq+0x14/0x3ec
[ 1144.569366] #1: (&tty->ldisc_sem){++++++}, at: [<c03c7c80>]
tty_ldisc_ref+0x14/0x48
[ 1144.588378]
[ 1144.588378] stack backtrace:
[ 1144.593383] CPU: 0 PID: 322 Comm: connmand Not tainted
4.2.0-rc4-00001-gaa22fe1-dirty #1
[ 1144.601837] Hardware name: Generic OMAP4 (Flattened Device Tree)
[ 1144.608123] [<c0016e8c>] (unwind_backtrace) from [<c001335c>]
(show_stack+0x10/0x14)
[ 1144.616241] [<c001335c>] (show_stack) from [<c05fb570>]
(dump_stack+0x84/0x9c)
[ 1144.622070] [<c05fb570>] (dump_stack) from [<c008cf1c>]
(print_circular_bug+0x1c8/0x30c)
[ 1144.631408] [<c008cf1c>] (print_circular_bug) from [<c00908b4>]
(__lock_acquire+0x1ba0/0x1eb0)
[ 1144.641296] [<c00908b4>] (__lock_acquire) from [<c00914a0>]
(lock_acquire+0xa8/0x120)
[ 1144.649475] [<c00914a0>] (lock_acquire) from [<c0602090>]
(_raw_spin_lock_irqsave+0x40/0x54)
[ 1144.658325] [<c0602090>] (_raw_spin_lock_irqsave) from [<c040f0b8>]
(st_tx_wakeup+0x48/0xf4)
[ 1144.666839] [<c040f0b8>] (st_tx_wakeup) from [<c03be994>]
(tty_wakeup+0x50/0x5c)
[ 1144.674468] [<c03be994>] (tty_wakeup) from [<c03e67e0>]
(serial_omap_irq+0x34c/0x3ec)
[ 1144.681823] [<c03e67e0>] (serial_omap_irq) from [<c009c338>]
(handle_irq_event_percpu+0x40/0x1e8)
[ 1144.692382] [<c009c338>] (handle_irq_event_percpu) from [<c009c520>]
(handle_irq_event+0x40/0x64)
[ 1144.700897] [<c009c520>] (handle_irq_event) from [<c009f5dc>]
(handle_fasteoi_irq+0xcc/0x1c4)
[ 1144.708312] [<c009f5dc>] (handle_fasteoi_irq) from [<c009b9d4>]
(generic_handle_irq+0x28/0x3c)
[ 1144.710998] [<c009b9d4>] (generic_handle_irq) from [<c009bcbc>]
(__handle_domain_irq+0x64/0xe0)
[ 1144.722015] [<c009bcbc>] (__handle_domain_irq) from [<c00094dc>]
(gic_handle_irq+0x20/0x60)
[ 1144.731201] [<c00094dc>] (gic_handle_irq) from [<c0602cc8>]
(__irq_usr+0x48/0x60)
[ 1144.745239] Exception stack(0xdcda5fb0 to 0xdcda5ff8)
[ 1144.750457] 5fa0: 000d30c8 000d1bc4 00000000 00000000
[ 1144.754516] 5fc0: 000d30c8 000000e4 000000e4 bedd2ae4 bedd2aec
bedd2ae8 00000000 b6e4e85c
[ 1144.767639] 5fe0: 00000000 bedd2ad8 b6d9b958 b6d9b094 20070110 ffffffff
[ 1165.444732] BUG: spinlock lockup suspected on CPU#0, connmand/322
[ 1165.453247] lock: 0xddbf2410, .magic: dead4ead, .owner:
connmand/322, .owner_cpu: 0
[ 1165.460327] CPU: 0 PID: 322 Comm: connmand Not tainted
4.2.0-rc4-00001-gaa22fe1-dirty #1
[ 1165.461822] Hardware name: Generic OMAP4 (Flattened Device Tree)
[ 1165.475250] [<c0016e8c>] (unwind_backtrace) from [<c001335c>]
(show_stack+0x10/0x14)
[ 1165.483093] [<c001335c>] (show_stack) from [<c05fb570>]
(dump_stack+0x84/0x9c)
[ 1165.491729] [<c05fb570>] (dump_stack) from [<c00944a4>]
(do_raw_spin_lock+0xec/0x1b0)
[ 1165.499908] [<c00944a4>] (do_raw_spin_lock) from [<c0602098>]
(_raw_spin_lock_irqsave+0x48/0x54)
[ 1165.508636] [<c0602098>] (_raw_spin_lock_irqsave) from [<c03dc41c>]
(uart_write+0x34/0xdc)
[ 1165.515411] [<c03dc41c>] (uart_write) from [<c040f0dc>]
(st_tx_wakeup+0x6c/0xf4)
[ 1165.525482] [<c040f0dc>] (st_tx_wakeup) from [<c03be994>]
(tty_wakeup+0x50/0x5c)
[ 1165.530853] [<c03be994>] (tty_wakeup) from [<c03e67e0>]
(serial_omap_irq+0x34c/0x3ec)
[ 1165.541412] [<c03e67e0>] (serial_omap_irq) from [<c009c338>]
(handle_irq_event_percpu+0x40/0x1e8)
[ 1165.550689] [<c009c338>] (handle_irq_event_percpu) from [<c009c520>]
(handle_irq_event+0x40/0x64)
[ 1165.559967] [<c009c520>] (handle_irq_event) from [<c009f5dc>]
(handle_fasteoi_irq+0xcc/0x1c4)
[ 1165.568878] [<c009f5dc>] (handle_fasteoi_irq) from [<c009b9d4>]
(generic_handle_irq+0x28/0x3c)
[ 1165.576568] [<c009b9d4>] (generic_handle_irq) from [<c009bcbc>]
(__handle_domain_irq+0x64/0xe0)
[ 1165.581909] [<c009bcbc>] (__handle_domain_irq) from [<c00094dc>]
(gic_handle_irq+0x20/0x60)
[ 1165.593353] [<c00094dc>] (gic_handle_irq) from [<c0602cc8>]
(__irq_usr+0x48/0x60)
[ 1165.593353] Exception stack(0xdcda5fb0 to 0xdcda5ff8)
[ 1165.604461] 5fa0: 000d30c8 000d1bc4 00000000 00000000
[ 1165.617401] 5fc0: 000d30c8 000000e4 000000e4 bedd2ae4 bedd2aec
bedd2ae8 00000000 b6e4e85c
[ 1165.620697] 5fe0: 00000000 bedd2ad8 b6d9b958 b6d9b094 20070110 ffffffff
[ 1170.528594] INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1170.534362] 0: (1 GPs behind) idle=7f7/140000000000001/0
softirq=2274/2274 fqs=19
[ 1170.534362] (detected by 1, t=2622 jiffies, g=707, c=706, q=5)
[ 1170.534362] Task dump for CPU 0:
[ 1170.534362] connmand R running 0 322 1 0x00000002
[ 1170.558593] [<c05fcd6c>] (__schedule) from [<c03639e0>]
(vsnprintf+0x2e4/0x3c8)
[ 1170.558593] [<c03639e0>] (vsnprintf) from [<c0364074>]
(sprintf+0x24/0x34)
[ 1170.566253] [<c0364074>] (sprintf) from [<c00c9e68>]
(__sprint_symbol+0xa0/0xc8)
[ 1170.566253] [<c00c9e68>] (__sprint_symbol) from [<00000000>] ( (null))
[ 1170.581176] rcu_sched kthread starved for 2603 jiffies! g707 c706 f0x0
Hi Jack,
On 07/27/2015 09:01 AM, Jack Mitchell wrote:
> Ran into this deadlock in the btwilink coupled with the omap-serial driver.Kernel is only tainted with a custom dts and small kim dts enablement patch, nothing which would cause this error.
Lock inversion in st_tx_wakeup(). This is a common bug in line disciplines.
The typical fix is to schedule the actual work to perform in a kworker.
Regards,
Peter Hurley
> Please CC as I'm not on list.
>
> [ 1144.307220]
> [ 1144.308837] ======================================================
> [ 1144.310821] [ INFO: possible circular locking dependency detected ]
> [ 1144.321960] 4.2.0-rc4-00001-gaa22fe1-dirty #1 Not tainted
> [ 1144.321960] -------------------------------------------------------
> [ 1144.334259] connmand/322 is trying to acquire lock:
> [ 1144.334259] (&(&st_gdata->lock)->rlock){-.....}, at: [<c040f0b8>] st_tx_wakeup+0x48/0xf4
> [ 1144.340820]
> [ 1144.340820] but task is already holding lock:
> [ 1144.354248] (&port_lock_key){-.-...}, at: [<c03e64a8>] serial_omap_irq+0x14/0x3ec
> [ 1144.362304]
> [ 1144.362304] which lock already depends on the new lock.
> [ 1144.362304]
> [ 1144.370819]
> [ 1144.370819] the existing dependency chain (in reverse order) is:
> [ 1144.370941]
> -> #1 (&port_lock_key){-.-...}:
> [ 1144.383453] [<c03dc41c>] uart_write+0x34/0xdc
> [ 1144.383453] [<c040f0dc>] st_tx_wakeup+0x6c/0xf4
> [ 1144.390777] [<c040f57c>] st_write+0xa0/0x100
> [ 1144.390777] [<bf44b0f0>] ti_st_send_frame+0x3c/0xdc [btwilink]
> [ 1144.406127] [<bf3c441c>] hci_send_frame+0x6c/0xbc [bluetooth]
> [ 1144.413116] [<bf3c44e8>] hci_cmd_work+0x7c/0xe0 [bluetooth]
> [ 1144.415313] [<c0058f9c>] process_one_work+0x1b4/0x4b4
> [ 1144.420776] [<c00592d8>] worker_thread+0x3c/0x4a4
> [ 1144.430786] [<c005ef24>] kthread+0xd4/0xf0
> [ 1144.431396] [<c000f618>] ret_from_fork+0x14/0x3c
> [ 1144.440673]
> -> #0 (&(&st_gdata->lock)->rlock){-.....}:
> [ 1144.447540] [<c0602090>] _raw_spin_lock_irqsave+0x40/0x54
> [ 1144.450805] [<c040f0b8>] st_tx_wakeup+0x48/0xf4
> [ 1144.459350] [<c03be994>] tty_wakeup+0x50/0x5c
> [ 1144.464630] [<c03e67e0>] serial_omap_irq+0x34c/0x3ec
> [ 1144.464630] [<c009c338>] handle_irq_event_percpu+0x40/0x1e8
> [ 1144.470794] [<c009c520>] handle_irq_event+0x40/0x64
> [ 1144.480773] [<c009f5dc>] handle_fasteoi_irq+0xcc/0x1c4
> [ 1144.480773] [<c009b9d4>] generic_handle_irq+0x28/0x3c
> [ 1144.494689] [<c009bcbc>] __handle_domain_irq+0x64/0xe0
> [ 1144.500915] [<c00094dc>] gic_handle_irq+0x20/0x60
> [ 1144.500915] [<c0602cc8>] __irq_usr+0x48/0x60
> [ 1144.511596] [<b6d9b094>] 0xb6d9b094
> [ 1144.515319]
> [ 1144.515319] other info that might help us debug this:
> [ 1144.515319]
> [ 1144.524261] Possible unsafe locking scenario:
> [ 1144.524261]
> [ 1144.530456] CPU0 CPU1
> [ 1144.530670] ---- ----
> [ 1144.538269] lock(&port_lock_key);
> [ 1144.540832] lock(&(&st_gdata->lock)->rlock);
> [ 1144.550872] lock(&port_lock_key);
> [ 1144.551422] lock(&(&st_gdata->lock)->rlock);
> [ 1144.551422]
> [ 1144.551422] *** DEADLOCK ***
> [ 1144.551422]
> [ 1144.565277] 2 locks held by connmand/322:
> [ 1144.569366] #0: (&port_lock_key){-.-...}, at: [<c03e64a8>] serial_omap_irq+0x14/0x3ec
> [ 1144.569366] #1: (&tty->ldisc_sem){++++++}, at: [<c03c7c80>] tty_ldisc_ref+0x14/0x48
> [ 1144.588378]
> [ 1144.588378] stack backtrace:
> [ 1144.593383] CPU: 0 PID: 322 Comm: connmand Not tainted 4.2.0-rc4-00001-gaa22fe1-dirty #1
> [ 1144.601837] Hardware name: Generic OMAP4 (Flattened Device Tree)
> [ 1144.608123] [<c0016e8c>] (unwind_backtrace) from [<c001335c>] (show_stack+0x10/0x14)
> [ 1144.616241] [<c001335c>] (show_stack) from [<c05fb570>] (dump_stack+0x84/0x9c)
> [ 1144.622070] [<c05fb570>] (dump_stack) from [<c008cf1c>] (print_circular_bug+0x1c8/0x30c)
> [ 1144.631408] [<c008cf1c>] (print_circular_bug) from [<c00908b4>] (__lock_acquire+0x1ba0/0x1eb0)
> [ 1144.641296] [<c00908b4>] (__lock_acquire) from [<c00914a0>] (lock_acquire+0xa8/0x120)
> [ 1144.649475] [<c00914a0>] (lock_acquire) from [<c0602090>] (_raw_spin_lock_irqsave+0x40/0x54)
> [ 1144.658325] [<c0602090>] (_raw_spin_lock_irqsave) from [<c040f0b8>] (st_tx_wakeup+0x48/0xf4)
> [ 1144.666839] [<c040f0b8>] (st_tx_wakeup) from [<c03be994>] (tty_wakeup+0x50/0x5c)
> [ 1144.674468] [<c03be994>] (tty_wakeup) from [<c03e67e0>] (serial_omap_irq+0x34c/0x3ec)
> [ 1144.681823] [<c03e67e0>] (serial_omap_irq) from [<c009c338>] (handle_irq_event_percpu+0x40/0x1e8)
> [ 1144.692382] [<c009c338>] (handle_irq_event_percpu) from [<c009c520>] (handle_irq_event+0x40/0x64)
> [ 1144.700897] [<c009c520>] (handle_irq_event) from [<c009f5dc>] (handle_fasteoi_irq+0xcc/0x1c4)
> [ 1144.708312] [<c009f5dc>] (handle_fasteoi_irq) from [<c009b9d4>] (generic_handle_irq+0x28/0x3c)
> [ 1144.710998] [<c009b9d4>] (generic_handle_irq) from [<c009bcbc>] (__handle_domain_irq+0x64/0xe0)
> [ 1144.722015] [<c009bcbc>] (__handle_domain_irq) from [<c00094dc>] (gic_handle_irq+0x20/0x60)
> [ 1144.731201] [<c00094dc>] (gic_handle_irq) from [<c0602cc8>] (__irq_usr+0x48/0x60)
> [ 1144.745239] Exception stack(0xdcda5fb0 to 0xdcda5ff8)
> [ 1144.750457] 5fa0: 000d30c8 000d1bc4 00000000 00000000
> [ 1144.754516] 5fc0: 000d30c8 000000e4 000000e4 bedd2ae4 bedd2aec bedd2ae8 00000000 b6e4e85c
> [ 1144.767639] 5fe0: 00000000 bedd2ad8 b6d9b958 b6d9b094 20070110 ffffffff
> [ 1165.444732] BUG: spinlock lockup suspected on CPU#0, connmand/322
> [ 1165.453247] lock: 0xddbf2410, .magic: dead4ead, .owner: connmand/322, .owner_cpu: 0
> [ 1165.460327] CPU: 0 PID: 322 Comm: connmand Not tainted 4.2.0-rc4-00001-gaa22fe1-dirty #1
> [ 1165.461822] Hardware name: Generic OMAP4 (Flattened Device Tree)
> [ 1165.475250] [<c0016e8c>] (unwind_backtrace) from [<c001335c>] (show_stack+0x10/0x14)
> [ 1165.483093] [<c001335c>] (show_stack) from [<c05fb570>] (dump_stack+0x84/0x9c)
> [ 1165.491729] [<c05fb570>] (dump_stack) from [<c00944a4>] (do_raw_spin_lock+0xec/0x1b0)
> [ 1165.499908] [<c00944a4>] (do_raw_spin_lock) from [<c0602098>] (_raw_spin_lock_irqsave+0x48/0x54)
> [ 1165.508636] [<c0602098>] (_raw_spin_lock_irqsave) from [<c03dc41c>] (uart_write+0x34/0xdc)
> [ 1165.515411] [<c03dc41c>] (uart_write) from [<c040f0dc>] (st_tx_wakeup+0x6c/0xf4)
> [ 1165.525482] [<c040f0dc>] (st_tx_wakeup) from [<c03be994>] (tty_wakeup+0x50/0x5c)
> [ 1165.530853] [<c03be994>] (tty_wakeup) from [<c03e67e0>] (serial_omap_irq+0x34c/0x3ec)
> [ 1165.541412] [<c03e67e0>] (serial_omap_irq) from [<c009c338>] (handle_irq_event_percpu+0x40/0x1e8)
> [ 1165.550689] [<c009c338>] (handle_irq_event_percpu) from [<c009c520>] (handle_irq_event+0x40/0x64)
> [ 1165.559967] [<c009c520>] (handle_irq_event) from [<c009f5dc>] (handle_fasteoi_irq+0xcc/0x1c4)
> [ 1165.568878] [<c009f5dc>] (handle_fasteoi_irq) from [<c009b9d4>] (generic_handle_irq+0x28/0x3c)
> [ 1165.576568] [<c009b9d4>] (generic_handle_irq) from [<c009bcbc>] (__handle_domain_irq+0x64/0xe0)
> [ 1165.581909] [<c009bcbc>] (__handle_domain_irq) from [<c00094dc>] (gic_handle_irq+0x20/0x60)
> [ 1165.593353] [<c00094dc>] (gic_handle_irq) from [<c0602cc8>] (__irq_usr+0x48/0x60)
> [ 1165.593353] Exception stack(0xdcda5fb0 to 0xdcda5ff8)
> [ 1165.604461] 5fa0: 000d30c8 000d1bc4 00000000 00000000
> [ 1165.617401] 5fc0: 000d30c8 000000e4 000000e4 bedd2ae4 bedd2aec bedd2ae8 00000000 b6e4e85c
> [ 1165.620697] 5fe0: 00000000 bedd2ad8 b6d9b958 b6d9b094 20070110 ffffffff
> [ 1170.528594] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1170.534362] 0: (1 GPs behind) idle=7f7/140000000000001/0 softirq=2274/2274 fqs=19
> [ 1170.534362] (detected by 1, t=2622 jiffies, g=707, c=706, q=5)
> [ 1170.534362] Task dump for CPU 0:
> [ 1170.534362] connmand R running 0 322 1 0x00000002
> [ 1170.558593] [<c05fcd6c>] (__schedule) from [<c03639e0>] (vsnprintf+0x2e4/0x3c8)
> [ 1170.558593] [<c03639e0>] (vsnprintf) from [<c0364074>] (sprintf+0x24/0x34)
> [ 1170.566253] [<c0364074>] (sprintf) from [<c00c9e68>] (__sprint_symbol+0xa0/0xc8)
> [ 1170.566253] [<c00c9e68>] (__sprint_symbol) from [<00000000>] ( (null))
> [ 1170.581176] rcu_sched kthread starved for 2603 jiffies! g707 c706 f0x0