possible deadlock in rfcomm_sk_state

possible deadlock in rfcomm_sk_state_change
Status: upstream: reported C repro on 2021/09/13 05:15
Reported-by: syzbot+d7ce59b06b3eb14fd218@syzkaller.appspotmail.com
First crash: 36d, last: 1h02m

Cause bisection: introduced by (bisect log) :
commit 1804fdf6e494e5e2938c65d8391690b59bcff897
Author: Tedd Ho-Jeong An <tedd.an@intel.com>
Date: Thu Aug 5 00:32:19 2021 +0000

Bluetooth: btintel: Combine setting up MSFT extension

Crash: BUG: sleeping function called from invalid context in stack_depot_save (log)
Repro: C syz .config

Patch testing requests:
Created	Duration	User	Patch	Repo	Result
2021/10/10 13:34	11m	phind.uet@gmail.com		linux-next	report log
2021/10/10 13:32	11m	phind.uet@gmail.com		linux-next	report log

Sample crash report:

======================================================
WARNING: possible circular locking dependency detected
5.14.0-syzkaller #0 Not tainted
------------------------------------------------------
krfcommd/2875 is trying to acquire lock:
ffff888012b9d120 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}, at: lock_sock include/net/sock.h:1612 [inline]
ffff888012b9d120 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}, at: rfcomm_sk_state_change+0x63/0x300 net/bluetooth/rfcomm/sock.c:73

but task is already holding lock:
ffff88807cf12528 (&d->lock){+.+.}-{3:3}, at: __rfcomm_dlc_close+0x281/0x480 net/bluetooth/rfcomm/core.c:487

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&d->lock){+.+.}-{3:3}:
       lock_acquire+0x19f/0x4d0 kernel/locking/lockdep.c:5625
       __mutex_lock_common+0x1df/0x2550 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:743
       __rfcomm_dlc_close+0x281/0x480 net/bluetooth/rfcomm/core.c:487
       rfcomm_process_dlcs+0x92/0x620 net/bluetooth/rfcomm/core.c:1844
       rfcomm_process_sessions+0x2f6/0x3f0 net/bluetooth/rfcomm/core.c:2003
       rfcomm_run+0x195/0x2c0 net/bluetooth/rfcomm/core.c:2086
       kthread+0x453/0x480 kernel/kthread.c:319
       ret_from_fork+0x1f/0x30

-> #1 (rfcomm_mutex){+.+.}-{3:3}:
       lock_acquire+0x19f/0x4d0 kernel/locking/lockdep.c:5625
       __mutex_lock_common+0x1df/0x2550 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:743
       rfcomm_dlc_open+0x25/0x50 net/bluetooth/rfcomm/core.c:425
       rfcomm_sock_connect+0x285/0x470 net/bluetooth/rfcomm/sock.c:413
       __sys_connect_file net/socket.c:1896 [inline]
       __sys_connect+0x38a/0x410 net/socket.c:1913
       __do_sys_connect net/socket.c:1923 [inline]
       __se_sys_connect net/socket.c:1920 [inline]
       __x64_sys_connect+0x76/0x80 net/socket.c:1920
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x44/0xae

-> #0 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3051 [inline]
       check_prevs_add kernel/locking/lockdep.c:3174 [inline]
       validate_chain+0x1dfb/0x8240 kernel/locking/lockdep.c:3789
       __lock_acquire+0x1382/0x2b00 kernel/locking/lockdep.c:5015
       lock_acquire+0x19f/0x4d0 kernel/locking/lockdep.c:5625
       lock_sock_nested+0xc6/0x110 net/core/sock.c:3191
       lock_sock include/net/sock.h:1612 [inline]
       rfcomm_sk_state_change+0x63/0x300 net/bluetooth/rfcomm/sock.c:73
       __rfcomm_dlc_close+0x2cc/0x480 net/bluetooth/rfcomm/core.c:489
       rfcomm_process_dlcs+0x92/0x620 net/bluetooth/rfcomm/core.c:1844
       rfcomm_process_sessions+0x2f6/0x3f0 net/bluetooth/rfcomm/core.c:2003
       rfcomm_run+0x195/0x2c0 net/bluetooth/rfcomm/core.c:2086
       kthread+0x453/0x480 kernel/kthread.c:319
       ret_from_fork+0x1f/0x30

other info that might help us debug this:

Chain exists of:
  sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM --> rfcomm_mutex --> &d->lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&d->lock);
                               lock(rfcomm_mutex);
                               lock(&d->lock);
  lock(sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM);

 *** DEADLOCK ***

2 locks held by krfcommd/2875:
 #0: ffffffff8dac7488 (rfcomm_mutex){+.+.}-{3:3}, at: rfcomm_process_sessions+0x21/0x3f0 net/bluetooth/rfcomm/core.c:1979
 #1: ffff88807cf12528 (&d->lock){+.+.}-{3:3}, at: __rfcomm_dlc_close+0x281/0x480 net/bluetooth/rfcomm/core.c:487

stack backtrace:
CPU: 1 PID: 2875 Comm: krfcommd Not tainted 5.14.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1dc/0x2d8 lib/dump_stack.c:106
 check_noncircular+0x2f9/0x3b0 kernel/locking/lockdep.c:2131
 check_prev_add kernel/locking/lockdep.c:3051 [inline]
 check_prevs_add kernel/locking/lockdep.c:3174 [inline]
 validate_chain+0x1dfb/0x8240 kernel/locking/lockdep.c:3789
 __lock_acquire+0x1382/0x2b00 kernel/locking/lockdep.c:5015
 lock_acquire+0x19f/0x4d0 kernel/locking/lockdep.c:5625
 lock_sock_nested+0xc6/0x110 net/core/sock.c:3191
 lock_sock include/net/sock.h:1612 [inline]
 rfcomm_sk_state_change+0x63/0x300 net/bluetooth/rfcomm/sock.c:73
 __rfcomm_dlc_close+0x2cc/0x480 net/bluetooth/rfcomm/core.c:489
 rfcomm_process_dlcs+0x92/0x620 net/bluetooth/rfcomm/core.c:1844
 rfcomm_process_sessions+0x2f6/0x3f0 net/bluetooth/rfcomm/core.c:2003
 rfcomm_run+0x195/0x2c0 net/bluetooth/rfcomm/core.c:2086
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30

Crashes (1001):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-kasan-gce-smack-root	2021/09/09 20:55	upstream	a3fa7a101dcf	e2776ee4	.config	log	report	syz	C		possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/15 16:26	upstream	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/15 15:00	upstream	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/15 11:43	upstream	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/15 09:43	upstream	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/15 07:38	upstream	ec681c53f8d2	aab7690b	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/15 07:06	upstream	ec681c53f8d2	aab7690b	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/15 03:50	upstream	26d657410983	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/14 22:18	upstream	26d657410983	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/14 21:22	upstream	26d657410983	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 20:11	upstream	26d657410983	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 20:00	upstream	26d657410983	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/14 17:13	upstream	26d657410983	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/14 15:52	upstream	26d657410983	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/14 14:59	upstream	26d657410983	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 13:47	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/14 12:38	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 07:35	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/14 06:13	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 05:07	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/14 03:13	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-selinux-root	2021/10/14 02:10	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/13 22:19	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/13 20:59	upstream	348949d9a444	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/12 15:44	upstream	fa5878760579	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/10/12 11:09	upstream	fa5878760579	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/12 07:17	upstream	fa5878760579	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-smack-root	2021/10/12 06:06	upstream	fa5878760579	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-kasan-gce-root	2021/09/09 05:05	upstream	730bf31b8fc8	e2776ee4	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-qemu-upstream-386	2021/10/15 12:40	upstream	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/15 20:22	net	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/15 10:41	net	ec681c53f8d2	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/15 02:29	net	1fcd794518b7	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/14 10:15	net	e599ee234ad4	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/13 23:21	net	e599ee234ad4	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/12 04:45	net	732b74d64704	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-this-kasan-gce	2021/10/12 00:55	net	732b74d64704	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-kasan-gce	2021/10/15 18:32	net-next	40088915f547	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-kasan-gce	2021/10/15 05:00	net-next	201f1a2d77f6	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-kasan-gce	2021/10/14 10:56	net-next	9974cb5c8790	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-kasan-gce	2021/10/13 22:01	net-next	13b5ffa0e282	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-net-kasan-gce	2021/10/12 02:25	net-next	ce8bd03c47fc	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/15 13:46	linux-next	7c832d2f9b95	0c5d9412	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/15 08:39	linux-next	8006b911c90a	aab7690b	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/15 00:13	linux-next	8006b911c90a	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/14 18:57	linux-next	8006b911c90a	7aa5fe41	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/14 00:57	linux-next	8006b911c90a	5462d470	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/12 17:19	linux-next	6d3d22efa090	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/12 08:38	linux-next	d3134eb5de85	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change
ci-upstream-linux-next-kasan-gce-root	2021/10/12 00:47	linux-next	d3134eb5de85	838e7e2c	.config	log	report			info	possible deadlock in rfcomm_sk_state_change