inconsistent lock state in sco_sock_timeout

Status: upstream: reported C repro on 2020/08/08 22:36
Reported-by: syzbot+0aaddce8deb6b82ba8f4@syzkaller.appspotmail.com
First crash: 2194d, last: 1269d
▶ ▼ Similar bugs (2)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream inconsistent lock state in sco_sock_timeout bluetooth 4 syz, C done 16 1840d 2185d 20/29 fixed on 2021/11/10 00:50
linux-4.19 inconsistent lock state in sco_sock_timeout 4 syz, C done 19 1794d 2185d 1/1 fixed on 2021/10/12 13:38
▶ ▼ Fix bisection attempts (25)
Created Duration User Patch Repo Result
2023/02/19 15:04 37m bisect fix linux-4.14.y OK (0) job log log
2023/01/20 05:12 32m bisect fix linux-4.14.y OK (0) job log log
2022/10/27 13:44 34m bisect fix linux-4.14.y OK (0) job log log
2022/09/19 13:08 36m bisect fix linux-4.14.y OK (0) job log log
2022/08/20 10:41 31m bisect fix linux-4.14.y OK (0) job log log
2022/07/21 10:07 34m bisect fix linux-4.14.y OK (0) job log log
2022/06/21 09:29 38m bisect fix linux-4.14.y OK (0) job log log
2022/05/22 08:57 31m bisect fix linux-4.14.y OK (0) job log log
2022/04/22 04:43 30m bisect fix linux-4.14.y OK (0) job log log
2022/03/23 03:57 35m bisect fix linux-4.14.y OK (0) job log log
2022/02/20 12:08 39m bisect fix linux-4.14.y OK (0) job log log
2022/01/21 11:31 36m bisect fix linux-4.14.y OK (0) job log log
2021/12/22 10:57 34m bisect fix linux-4.14.y OK (0) job log log
2021/11/22 09:23 32m bisect fix linux-4.14.y OK (0) job log log
2021/10/23 08:41 30m bisect fix linux-4.14.y OK (0) job log log
2021/09/22 16:24 34m bisect fix linux-4.14.y OK (0) job log log
2021/08/23 14:11 39m bisect fix linux-4.14.y OK (0) job log log
2021/07/24 13:22 34m bisect fix linux-4.14.y OK (0) job log log
2021/06/24 12:48 28m bisect fix linux-4.14.y OK (0) job log log
2021/05/25 09:34 32m bisect fix linux-4.14.y OK (0) job log log
2021/02/19 18:45 36m bisect fix linux-4.14.y OK (0) job log log
2021/02/17 13:52 18m bisect fix linux-4.14.y error job log
2021/01/31 00:23 1m bisect fix linux-4.14.y error job log
2020/12/21 19:09 38m bisect fix linux-4.14.y OK (0) job log log
2020/10/06 10:26 31m bisect fix linux-4.14.y OK (0) job log log

Sample crash report:
================================
WARNING: inconsistent lock state
4.14.203-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor347/31903 [HC0[0]:SC1[1]:HE1:SE0] takes:
 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: [<ffffffff86895c89>] spin_lock include/linux/spinlock.h:317 [inline]
 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: [<ffffffff86895c89>] sco_sock_timeout+0x29/0x1c0 net/bluetooth/sco.c:82
{SOFTIRQ-ON-W} state was registered at:
  lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
  __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
  _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152
  spin_lock include/linux/spinlock.h:317 [inline]
  sco_conn_del+0xbf/0x290 net/bluetooth/sco.c:175
  sco_disconn_cfm+0x65/0xa0 net/bluetooth/sco.c:1134
  hci_disconn_cfm include/net/bluetooth/hci_core.h:1226 [inline]
  hci_conn_hash_flush+0x127/0x260 net/bluetooth/hci_conn.c:1393
  hci_dev_do_close+0x535/0xca0 net/bluetooth/hci_core.c:1620
  hci_unregister_dev+0x17f/0x8c0 net/bluetooth/hci_core.c:3191
  vhci_release+0x70/0xe0 drivers/bluetooth/hci_vhci.c:354
  __fput+0x25f/0x7a0 fs/file_table.c:210
  task_work_run+0x11f/0x190 kernel/task_work.c:113
  exit_task_work include/linux/task_work.h:22 [inline]
  do_exit+0xa08/0x27f0 kernel/exit.c:865
  do_group_exit+0x100/0x2e0 kernel/exit.c:962
  get_signal+0x38d/0x1ca0 kernel/signal.c:2423
  do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:814
  exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
  prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
  syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
  do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
  entry_SYSCALL_64_after_hwframe+0x46/0xbb
irq event stamp: 450
hardirqs last  enabled at (450): [<ffffffff872067d4>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last  enabled at (450): [<ffffffff872067d4>] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:200
hardirqs last disabled at (449): [<ffffffff87206465>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (449): [<ffffffff87206465>] _raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:168
softirqs last  enabled at (350): [<ffffffff86346914>] raw_hash_sk+0x1c4/0x250 net/ipv4/raw.c:107
softirqs last disabled at (443): [<ffffffff813303e3>] invoke_softirq kernel/softirq.c:368 [inline]
softirqs last disabled at (443): [<ffffffff813303e3>] irq_exit+0x193/0x240 kernel/softirq.c:409

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(slock-AF_BLUETOOTH-BTPROTO_SCO);
  <Interrupt>
    lock(slock-AF_BLUETOOTH-BTPROTO_SCO);

 *** DEADLOCK ***

1 lock held by syz-executor347/31903:
 #0:  (((&sk->sk_timer))){+.-.}, at: [<ffffffff814a4548>] lockdep_copy_map include/linux/lockdep.h:174 [inline]
 #0:  (((&sk->sk_timer))){+.-.}, at: [<ffffffff814a4548>] call_timer_fn+0xb8/0x650 kernel/time/timer.c:1270

stack backtrace:
CPU: 1 PID: 31903 Comm: syz-executor347 Not tainted 4.14.203-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x1b2/0x283 lib/dump_stack.c:58
 print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2589
 valid_state kernel/locking/lockdep.c:2602 [inline]
 mark_lock_irq kernel/locking/lockdep.c:2796 [inline]
 mark_lock+0xb4d/0x1050 kernel/locking/lockdep.c:3194
 mark_irqflags kernel/locking/lockdep.c:3072 [inline]
 __lock_acquire+0xc81/0x3f20 kernel/locking/lockdep.c:3448
 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152
 spin_lock include/linux/spinlock.h:317 [inline]
 sco_sock_timeout+0x29/0x1c0 net/bluetooth/sco.c:82
 call_timer_fn+0x14a/0x650 kernel/time/timer.c:1280
 expire_timers+0x232/0x4d0 kernel/time/timer.c:1319
 __run_timers kernel/time/timer.c:1644 [inline]
 run_timer_softirq+0x1d5/0x5a0 kernel/time/timer.c:1657
 __do_softirq+0x254/0xa1d kernel/softirq.c:288
 invoke_softirq kernel/softirq.c:368 [inline]
 irq_exit+0x193/0x240 kernel/softirq.c:409
 exiting_irq arch/x86/include/asm/apic.h:648 [inline]
 smp_apic_timer_interrupt+0x141/0x5e0 arch/x86/kernel/apic/apic.c:1102
 apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
 </IRQ>
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x50/0x80 kernel/locking/spinlock.c:200
RSP: 0018:ffff88820e87f948 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff11e1233 RBX: ffff88820e88e440 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff88820e88ecc4
RBP: ffff8880ba52a2c0 R08: ffffffff8b9ada48 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880ba52a2c0
R13: ffff8880954a8440 R14: 0000000000000000 R15: ffff8880ba52ac10
 finish_lock_switch kernel/sched/sched.h:1352 [inline]
 finish_task_switch+0x178/0x610 kernel/sched/core.c:2675
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x893/0x1de0 kernel/sched/core.c:3384
 preempt_schedule_common+0x45/0xc0 kernel/sched/core.c:3508
 ___preempt_schedule+0x16/0x18
 __raw_write_unlock_irq include/linux/rwlock_api_smp.h:268 [inline]
 _raw_write_unlock_irq+0x6c/0x80 kernel/locking/spinlock.c:344
 exit_notify kernel/exit.c:736 [inline]
 do_exit+0x11ef/0x27f0 kernel/exit.c:885
 do_group_exit+0x100/0x2e0 kernel/exit.c:962
 get_signal+0x38d/0x1ca0 kernel/signal.c:2423
 do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:814
 exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
 prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
 do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x4472c9
RSP: 002b:00007f994d16cd88 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 00000000006dcc28 RCX: 00000000004472c9
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 00000000006dcc28
RBP: 00000000006dcc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dcc2c
R13: 0000000000000004 R14: 0000000000000003 R15: 00007f994d16d6d0

Crashes (14):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/11/04 00:36 linux-4.14.y 2b7915014161 cba33199 .config console log report syz C ci2-linux-4-14
2020/11/02 05:43 linux-4.14.y 2b7915014161 8bc4594f .config console log report syz C ci2-linux-4-14
2020/09/06 08:57 linux-4.14.y 2f166cdcf8a9 abf9ba4f .config console log report syz C ci2-linux-4-14
2020/09/05 20:47 linux-4.14.y 2f166cdcf8a9 abf9ba4f .config console log report syz C ci2-linux-4-14
2020/08/17 11:01 linux-4.14.y 14b58326976d 5ce13532 .config console log report syz C ci2-linux-4-14
2021/04/25 09:34 linux-4.14.y cf256fbcbe34 36c88236 .config console log report info ci2-linux-4-14 inconsistent lock state in sco_sock_timeout
2021/04/13 10:11 linux-4.14.y 958e517f4e16 6a81331a .config console log report info ci2-linux-4-14 inconsistent lock state in sco_sock_timeout
2021/03/30 16:35 linux-4.14.y bd634aa64163 6a81331a .config console log report info ci2-linux-4-14 inconsistent lock state in sco_sock_timeout
2021/03/19 08:11 linux-4.14.y cb83ddcd5332 380dcc3e .config console log report info ci2-linux-4-14 inconsistent lock state in sco_sock_timeout
2021/03/09 07:50 linux-4.14.y 1d177c0872ab 09fbf400 .config console log report info ci2-linux-4-14 inconsistent lock state in sco_sock_timeout
2020/12/31 23:41 linux-4.14.y 1752938529c6 79264ae3 .config console log report info ci2-linux-4-14
2020/11/21 19:09 linux-4.14.y 8961076ed318 c7ec2d19 .config console log report info ci2-linux-4-14
2020/10/23 15:06 linux-4.14.y 5b7a52cd2eef 4e740c00 .config console log report info ci2-linux-4-14
2020/08/08 22:35 linux-4.14.y 14b58326976d 01975a06 .config console log report ci2-linux-4-14
* Struck through repros no longer work on HEAD.