Hi,
On Thu, Jul 09, 2015, Johan Hedberg wrote:
> On Thu, Jul 09, 2015, Marcel Holtmann wrote:
> > > Dean Jenkins (8):
> > > Bluetooth: L2CAP ERTM shutdown protect sk and chan
> > > Bluetooth: Make __l2cap_wait_ack more efficient
> > > Bluetooth: Unwind l2cap_sock_shutdown()
> > > Bluetooth: l2cap_sock_shutdown() remove mutex_lock calls
> > > Bluetooth: l2cap_sock_shutdown() reduce scope of chan locking
> > > Bluetooth: Add BT_DBG to l2cap_sock_shutdown()
> > > Bluetooth: __l2cap_wait_ack() use msecs_to_jiffies()
> > > Bluetooth: __l2cap_wait_ack() add defensive timeout
> > >
> > > include/net/bluetooth/l2cap.h | 2 ++
> > > net/bluetooth/l2cap_sock.c | 74 +++++++++++++++++++++++++++----------------
> > > 2 files changed, 49 insertions(+), 27 deletions(-)
> >
> > all 8 patches have been applied to bluetooth-next tree.
>
> I'm getting the following now when running our l2cap-tester tool:
>
> [Jul 9 12:34] ======================================================
> [ +0.000298] [ INFO: possible circular locking dependency detected ]
> [ +0.000298] 4.1.0-rc4+ #1356 Not tainted
> [ +0.000165] -------------------------------------------------------
> [ +0.000288] l2cap-tester/10613 is trying to acquire lock:
> [ +0.000000] (sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+...}, at: [<f942807e>] lock_sock+0xa/0xc [bluetooth]
> [ +0.000336]
> but task is already holding lock:
> [ +0.000000] (&chan->lock/1){+.+...}, at: [<f94283b6>] l2cap_chan_lock+0x13/0x15 [bluetooth]
> [ +0.000000]
> which lock already depends on the new lock.
>
> [ +0.000000]
> the existing dependency chain (in reverse order) is:
> [ +0.000000]
> -> #1 (&chan->lock/1){+.+...}:
> [ +0.000000] [<c1064917>] lock_acquire+0xdd/0x14f
> [ +0.000000] [<c13ff419>] mutex_lock_nested+0x54/0x393
> [ +0.000000] [<f94283b6>] l2cap_chan_lock+0x13/0x15 [bluetooth]
> [ +0.000000] [<f9428ec1>] l2cap_sock_shutdown+0x28c/0x327 [bluetooth]
> [ +0.000000] [<f942937a>] l2cap_sock_release+0x57/0xa5 [bluetooth]
> [ +0.000000] [<c1318032>] sock_release+0x19/0x6b
> [ +0.000000] [<c1318094>] sock_close+0x10/0x14
> [ +0.000000] [<c10e808a>] __fput+0xd6/0x162
> [ +0.000000] [<c10e8146>] ____fput+0xd/0xf
> [ +0.000000] [<c1049bc8>] task_work_run+0x7e/0xa4
> [ +0.000000] [<c1001d1e>] do_notify_resume+0x3c/0x3f
> [ +0.000000] [<c1402730>] work_notifysig+0x29/0x31
> [ +0.000000]
> -> #0 (sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+...}:
> [ +0.000000] [<c1064396>] __lock_acquire+0x98c/0xbfb
> [ +0.000000] [<c1064917>] lock_acquire+0xdd/0x14f
> [ +0.000000] [<c131cb86>] lock_sock_nested+0x63/0x7d
> [ +0.000000] [<f942807e>] lock_sock+0xa/0xc [bluetooth]
> [ +0.000000] [<f9428ed9>] l2cap_sock_shutdown+0x2a4/0x327 [bluetooth]
> [ +0.000000] [<f942937a>] l2cap_sock_release+0x57/0xa5 [bluetooth]
> [ +0.000000] [<c1318032>] sock_release+0x19/0x6b
> [ +0.000000] [<c1318094>] sock_close+0x10/0x14
> [ +0.000000] [<c10e808a>] __fput+0xd6/0x162
> [ +0.000000] [<c10e8146>] ____fput+0xd/0xf
> [ +0.000000] [<c1049bc8>] task_work_run+0x7e/0xa4
> [ +0.000000] [<c1001d1e>] do_notify_resume+0x3c/0x3f
> [ +0.000000] [<c1402730>] work_notifysig+0x29/0x31
> [ +0.000000]
> other info that might help us debug this:
>
> [ +0.000000] Possible unsafe locking scenario:
>
> [ +0.000000] CPU0 CPU1
> [ +0.000000] ---- ----
> [ +0.000000] lock(&chan->lock/1);
> [ +0.000000] lock(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP);
> [ +0.000000] lock(&chan->lock/1);
> [ +0.000000] lock(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP);
> [ +0.000000]
> *** DEADLOCK ***
>
> [ +0.000000] 1 lock held by l2cap-tester/10613:
> [ +0.000000] #0: (&chan->lock/1){+.+...}, at: [<f94283b6>] l2cap_chan_lock+0x13/0x15 [bluetooth]
> [ +0.000000]
> stack backtrace:
> [ +0.000000] CPU: 1 PID: 10613 Comm: l2cap-tester Not tainted 4.1.0-rc4+ #1356
> [ +0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.8.1-20150318_183358- 04/01/2014
> [ +0.000000] 00000000 00000000 f1acbde4 c13fd7f8 c1c2d760 f1acbe14 c1062c61 c15f5534
> [ +0.000000] c15f5427 c15f53ef c15f5410 c15f53ef f1acbe48 f537f380 f537f7fc f537f380
> [ +0.000000] f537f814 f1acbe78 c1064396 f537f7fc 00000000 00000000 c1c2ffc0 00000000
> [ +0.000000] Call Trace:
> [ +0.000000] [<c13fd7f8>] dump_stack+0x49/0x73
> [ +0.000000] [<c1062c61>] print_circular_bug+0x190/0x19d
> [ +0.000000] [<c1064396>] __lock_acquire+0x98c/0xbfb
> [ +0.000000] [<c1064917>] lock_acquire+0xdd/0x14f
> [ +0.000000] [<f942807e>] ? lock_sock+0xa/0xc [bluetooth]
> [ +0.000000] [<c131cb86>] lock_sock_nested+0x63/0x7d
> [ +0.000000] [<f942807e>] ? lock_sock+0xa/0xc [bluetooth]
> [ +0.000000] [<f942807e>] lock_sock+0xa/0xc [bluetooth]
> [ +0.000000] [<f9428ed9>] l2cap_sock_shutdown+0x2a4/0x327 [bluetooth]
> [ +0.000000] [<f9401112>] ? bt_sock_unlink+0x16/0x54 [bluetooth]
> [ +0.000000] [<c1402276>] ? _raw_write_unlock+0x2c/0x3e
> [ +0.000000] [<f942937a>] l2cap_sock_release+0x57/0xa5 [bluetooth]
> [ +0.000000] [<f942937a>] ? l2cap_sock_release+0x57/0xa5 [bluetooth]
> [ +0.000000] [<c1318032>] sock_release+0x19/0x6b
> [ +0.000000] [<c1318032>] ? sock_release+0x19/0x6b
> [ +0.000000] [<c1318094>] sock_close+0x10/0x14
> [ +0.000000] [<c10e808a>] __fput+0xd6/0x162
> [ +0.000000] [<c10e8146>] ____fput+0xd/0xf
> [ +0.000000] [<c1049bc8>] task_work_run+0x7e/0xa4
> [ +0.000000] [<c1001d1e>] do_notify_resume+0x3c/0x3f
> [ +0.000000] [<c1402730>] work_notifysig+0x29/0x31
I wanted to follow up that it's the very first test case that just does
a socket() + close() that triggers this. It may well be that there are
other lockdep issues hidden, but since the kernel suppresses them after
the first one we'll only see once this one is fixed.
Johan
--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
