INFO: task hung in rfcomm_process

Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
upstream	INFO: task hung in rfcomm_process_sessions (2) bluetooth	C	error	done	14	485d	759d	22/26	fixed on 2023/06/08 14:41

INFO: task krfcommd:2875 blocked for more than 143 seconds. Not tainted 5.15.0-rc1-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. task:krfcommd state:D stack:28296 pid: 2875 ppid: 2 flags:0x00004000 Call Trace: context_switch kernel/sched/core.c:4940 [inline] __schedule+0xc8d/0x1270 kernel/sched/core.c:6287 schedule+0x14b/0x210 kernel/sched/core.c:6366 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6425 __mutex_lock_common+0xdff/0x2550 kernel/locking/mutex.c:669 __mutex_lock kernel/locking/mutex.c:729 [inline] mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:743 rfcomm_process_sessions+0x21/0x3f0 net/bluetooth/rfcomm/core.c:1979 rfcomm_run+0x195/0x2c0 net/bluetooth/rfcomm/core.c:2086 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 INFO: task syz-executor.5:30772 blocked for more than 143 seconds. Not tainted 5.15.0-rc1-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. task:syz-executor.5 state:D stack:25496 pid:30772 ppid: 27366 flags:0x00004006 Call Trace: context_switch kernel/sched/core.c:4940 [inline] __schedule+0xc8d/0x1270 kernel/sched/core.c:6287 schedule+0x14b/0x210 kernel/sched/core.c:6366 __lock_sock+0x1cf/0x330 net/core/sock.c:2644 lock_sock_nested+0x7b/0x110 net/core/sock.c:3185 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_dlc_close+0x10d/0x1c0 net/bluetooth/rfcomm/core.c:520 __rfcomm_sock_close+0x101/0x220 net/bluetooth/rfcomm/sock.c:220 rfcomm_sock_shutdown+0xa5/0x220 net/bluetooth/rfcomm/sock.c:931 rfcomm_sock_release+0x55/0x120 net/bluetooth/rfcomm/sock.c:951 __sock_release net/socket.c:649 [inline] sock_close+0xd8/0x260 net/socket.c:1314 __fput+0x3fe/0x870 fs/file_table.c:280 task_work_run+0x146/0x1c0 kernel/task_work.c:164 get_signal+0x2014/0x20c0 kernel/signal.c:2641 arch_do_signal_or_restart+0x9c/0x730 arch/x86/kernel/signal.c:865 handle_signal_work kernel/entry/common.c:148 [inline] exit_to_user_mode_loop kernel/entry/common.c:172 [inline] exit_to_user_mode_prepare+0x191/0x220 kernel/entry/common.c:209 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline] syscall_exit_to_user_mode+0x2e/0x70 kernel/entry/common.c:302 do_syscall_64+0x53/0xd0 arch/x86/entry/common.c:86 entry_SYSCALL_64_after_hwframe+0x44/0xae RIP: 0033:0x7f8f6481b739 RSP: 002b:00007f8f61d92188 EFLAGS: 00000246 ORIG_RAX: 000000000000002a RAX: fffffffffffffffc RBX: 00007f8f6491ff80 RCX: 00007f8f6481b739 RDX: 0000000000000080 RSI: 0000000020000000 RDI: 0000000000000005 RBP: 00007f8f64875cc4 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 00007f8f6491ff80 R13: 00007fffb89ecf1f R14: 00007f8f61d92300 R15: 0000000000022000 Showing all locks held in the system: 1 lock held by khungtaskd/26: #0: ffffffff8c91c180 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30 1 lock held by krfcommd/2875: #0: ffffffff8dac67c8 (rfcomm_mutex){+.+.}-{3:3}, at: rfcomm_process_sessions+0x21/0x3f0 net/bluetooth/rfcomm/core.c:1979 1 lock held by in:imklog/6203: #0: ffff888023e8d9f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x24e/0x2f0 fs/file.c:990 4 locks held by kworker/u4:7/9399: 3 locks held by kworker/0:1/23110: #0: ffff888011064d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x7ca/0x1140 #1: ffffc9000448fd20 (deferred_process_work){+.+.}-{0:0}, at: process_one_work+0x808/0x1140 kernel/workqueue.c:2272 #2: ffffffff8d95b448 (rtnl_mutex){+.+.}-{3:3}, at: switchdev_deferred_process_work+0xa/0x20 net/switchdev/switchdev.c:74 3 locks held by kworker/0:6/26608: #0: ffff888011064d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x7ca/0x1140 #1: ffffc90002dbfd20 ((linkwatch_work).work){+.+.}-{0:0}, at: process_one_work+0x808/0x1140 kernel/workqueue.c:2272 #2: ffffffff8d95b448 (rtnl_mutex){+.+.}-{3:3}, at: linkwatch_event+0xa/0x50 net/core/link_watch.c:251 4 locks held by syz-executor.5/30772: #0: ffff888039876e10 (&sb->s_type->i_mutex_key#13){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:786 [inline] #0: ffff888039876e10 (&sb->s_type->i_mutex_key#13){+.+.}-{3:3}, at: __sock_release net/socket.c:648 [inline] #0: ffff888039876e10 (&sb->s_type->i_mutex_key#13){+.+.}-{3:3}, at: sock_close+0x94/0x260 net/socket.c:1314 #1: ffff8880801ba120 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}, at: lock_sock include/net/sock.h:1612 [inline] #1: ffff8880801ba120 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}, at: rfcomm_sock_shutdown+0x51/0x220 net/bluetooth/rfcomm/sock.c:928 #2: ffffffff8dac67c8 (rfcomm_mutex){+.+.}-{3:3}, at: rfcomm_dlc_close+0x32/0x1c0 net/bluetooth/rfcomm/core.c:507 #3: ffff88803b0a2128 (&d->lock){+.+.}-{3:3}, at: __rfcomm_dlc_close+0x281/0x480 net/bluetooth/rfcomm/core.c:487 ============================================= NMI backtrace for cpu 0 CPU: 0 PID: 26 Comm: khungtaskd Not tainted 5.15.0-rc1-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 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:105 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline] check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline] watchdog+0xc54/0xca0 kernel/hung_task.c:295 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 Sending NMI from CPU 0 to CPUs 1: NMI backtrace for cpu 1 CPU: 1 PID: 29856 Comm: kworker/1:11 Not tainted 5.15.0-rc1-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: events_power_efficient wg_ratelimiter_gc_entries RIP: 0010:kasan_check_range+0x224/0x2f0 mm/kasan/generic.c:189 Code: 89 cf 49 8d 5e 07 4d 85 f6 49 0f 49 de 48 83 e3 f8 49 29 de 74 11 45 0f b6 1f 45 84 db 75 64 49 ff c7 49 ff ce 75 ef 5b 41 5c <41> 5d 41 5e 41 5f c3 45 84 db 75 50 45 8a 59 01 45 84 db 0f 85 8a RSP: 0018:ffffc900033cf6e0 EFLAGS: 00000056 RAX: 0000000000000001 RBX: 00000000000006e6 RCX: ffffffff81648361 RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff8fd17ed8 RBP: ffffc900033cf8f0 R08: dffffc0000000000 R09: fffffbfff1fa2fdc R10: fffffbfff1fa2fdc R11: 0000000000000000 R12: 1ffff92000679eec R13: dffffc0000000001 R14: 0000000000000001 R15: dffffc0000000000 FS: 0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 000000c021e1a4e0 CR3: 000000000c68e000 CR4: 00000000001506e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: instrument_atomic_read include/linux/instrumented.h:71 [inline] test_bit include/asm-generic/bitops/instrumented-non-atomic.h:134 [inline] hlock_class kernel/locking/lockdep.c:199 [inline] mark_lock+0x191/0x1e00 kernel/locking/lockdep.c:4571 mark_usage kernel/locking/lockdep.c:4502 [inline] __lock_acquire+0xccf/0x2b00 kernel/locking/lockdep.c:4969 lock_acquire+0x19f/0x4d0 kernel/locking/lockdep.c:5625 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline] _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:154 spin_lock include/linux/spinlock.h:363 [inline] wg_ratelimiter_gc_entries+0x5c/0x4a0 drivers/net/wireguard/ratelimiter.c:63 process_one_work+0x853/0x1140 kernel/workqueue.c:2297 worker_thread+0xac1/0x1320 kernel/workqueue.c:2444 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 ---------------- Code disassembly (best guess): 0: 89 cf mov %ecx,%edi 2: 49 8d 5e 07 lea 0x7(%r14),%rbx 6: 4d 85 f6 test %r14,%r14 9: 49 0f 49 de cmovns %r14,%rbx d: 48 83 e3 f8 and $0xfffffffffffffff8,%rbx 11: 49 29 de sub %rbx,%r14 14: 74 11 je 0x27 16: 45 0f b6 1f movzbl (%r15),%r11d 1a: 45 84 db test %r11b,%r11b 1d: 75 64 jne 0x83 1f: 49 ff c7 inc %r15 22: 49 ff ce dec %r14 25: 75 ef jne 0x16 27: 5b pop %rbx 28: 41 5c pop %r12 * 2a: 41 5d pop %r13 <-- trapping instruction 2c: 41 5e pop %r14 2e: 41 5f pop %r15 30: c3 retq 31: 45 84 db test %r11b,%r11b 34: 75 50 jne 0x86 36: 45 8a 59 01 mov 0x1(%r9),%r11b 3a: 45 84 db test %r11b,%r11b 3d: 0f .byte 0xf 3e: 85 .byte 0x85 3f: 8a .byte 0x8a