inconsistent lock state in sco_sock_timeout

From: syzbot
Date: Mon Aug 17 2020 - 15:32:42 EST

Next message: Kees Cook: "Re: [PATCH 00/10] mmc: convert tasklets to use new tasklet_setup()"
Previous message: Greg Kroah-Hartman: "[PATCH 5.8 254/464] drm/imx: tve: fix regulator_disable error path"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hello,

syzbot found the following issue on:

HEAD commit: 2cc3c4b3 Merge tag 'io_uring-5.9-2020-08-15' of git://git...
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=10cf6aa6900000
kernel config: https://syzkaller.appspot.com/x/.config?x=19f02fc5c511a391
dashboard link: https://syzkaller.appspot.com/bug?extid=2f6d7c28bb4bf7e82060
compiler: clang version 10.0.0 (https://github.com/llvm/llvm-project/ c2443155a0fb245c8f17f2c1c72b6ea391e86e81)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13071491900000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11ec5be2900000

The issue was bisected to:

commit 331c56ac73846fa267c04ee6aa9a00bb5fed9440
Author: Heiner Kallweit <hkallweit1@xxxxxxxxx>
Date: Mon Aug 12 21:51:27 2019 +0000

net: phy: add phy_speed_down_core and phy_resolve_min_speed

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=1623bea6900000
final oops: https://syzkaller.appspot.com/x/report.txt?x=1523bea6900000
console output: https://syzkaller.appspot.com/x/log.txt?x=1123bea6900000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+2f6d7c28bb4bf7e82060@xxxxxxxxxxxxxxxxxxxxxxxxx
Fixes: 331c56ac7384 ("net: phy: add phy_speed_down_core and phy_resolve_min_speed")

================================
WARNING: inconsistent lock state
5.8.0-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/1/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
ffff888088b810a0 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}-{2:2}, at: spin_lock include/linux/spinlock.h:354 [inline]
ffff888088b810a0 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}-{2:2}, at: sco_sock_timeout+0x2b/0x280 net/bluetooth/sco.c:83
{SOFTIRQ-ON-W} state was registered at:
lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:354 [inline]
sco_conn_del+0x100/0x710 net/bluetooth/sco.c:176
hci_disconn_cfm include/net/bluetooth/hci_core.h:1438 [inline]
hci_conn_hash_flush+0x127/0x200 net/bluetooth/hci_conn.c:1557
hci_dev_do_close+0xb7b/0x1040 net/bluetooth/hci_core.c:1770
hci_unregister_dev+0x185/0x1590 net/bluetooth/hci_core.c:3790
vhci_release+0x73/0xc0 drivers/bluetooth/hci_vhci.c:340
__fput+0x34f/0x7b0 fs/file_table.c:281
task_work_run+0x137/0x1c0 kernel/task_work.c:141
exit_task_work include/linux/task_work.h:25 [inline]
do_exit+0x5f3/0x1f20 kernel/exit.c:806
do_group_exit+0x161/0x2d0 kernel/exit.c:903
get_signal+0x13bb/0x1d50 kernel/signal.c:2757
arch_do_signal+0x33/0x610 arch/x86/kernel/signal.c:811
exit_to_user_mode_loop kernel/entry/common.c:135 [inline]
exit_to_user_mode_prepare+0x8d/0x1b0 kernel/entry/common.c:166
syscall_exit_to_user_mode+0x5e/0x1a0 kernel/entry/common.c:241
entry_SYSCALL_64_after_hwframe+0x44/0xa9
irq event stamp: 1760434
hardirqs last enabled at (1760434): [<ffffffff882bbc5f>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (1760434): [<ffffffff882bbc5f>] _raw_spin_unlock_irq+0x1f/0x80 kernel/locking/spinlock.c:199
hardirqs last disabled at (1760433): [<ffffffff882bbab1>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (1760433): [<ffffffff882bbab1>] _raw_spin_lock_irq+0x41/0x80 kernel/locking/spinlock.c:167
softirqs last enabled at (1760422): [<ffffffff88292264>] sysvec_apic_timer_interrupt+0x14/0xf0 arch/x86/kernel/apic/apic.c:1091
softirqs last disabled at (1760423): [<ffffffff88400f2f>] asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706

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 swapper/1/0:
#0: ffffc90000da8dc0 ((&sk->sk_timer)){+.-.}-{0:0}, at: lockdep_copy_map include/linux/lockdep.h:45 [inline]
#0: ffffc90000da8dc0 ((&sk->sk_timer)){+.-.}-{0:0}, at: call_timer_fn+0x57/0x160 kernel/time/timer.c:1403

stack backtrace:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.8.0-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:77 [inline]
dump_stack+0x1f0/0x31e lib/dump_stack.c:118
print_usage_bug+0x1117/0x11d0 kernel/locking/lockdep.c:3350
mark_lock_irq arch/x86/include/asm/paravirt.h:661 [inline]
mark_lock+0x10e2/0x1b00 kernel/locking/lockdep.c:4006
mark_usage kernel/locking/lockdep.c:3905 [inline]
__lock_acquire+0xa99/0x2ab0 kernel/locking/lockdep.c:4380
lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:354 [inline]
sco_sock_timeout+0x2b/0x280 net/bluetooth/sco.c:83
call_timer_fn+0x91/0x160 kernel/time/timer.c:1413
expire_timers kernel/time/timer.c:1458 [inline]
__run_timers+0x65e/0x830 kernel/time/timer.c:1755
run_timer_softirq+0x46/0x80 kernel/time/timer.c:1768
__do_softirq+0x236/0x66c kernel/softirq.c:298
asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
</IRQ>
__run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
do_softirq_own_stack+0x91/0xe0 arch/x86/kernel/irq_64.c:77
invoke_softirq kernel/softirq.c:393 [inline]
__irq_exit_rcu+0x1e1/0x1f0 kernel/softirq.c:423
irq_exit_rcu+0x5/0x10 kernel/softirq.c:435
sysvec_apic_timer_interrupt+0xd5/0xf0 arch/x86/kernel/apic/apic.c:1091
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
RIP: 0010:tick_nohz_idle_exit+0x2f2/0x3a0 kernel/time/tick-sched.c:1213
Code: 30 00 74 0c 48 c7 c7 08 15 4d 89 e8 f8 0b 4c 00 48 83 3d 48 52 e4 07 00 0f 84 a6 00 00 00 e8 95 37 0c 00 fb 66 0f 1f 44 00 00 <48> 83 c4 20 5b 41 5c 41 5d 41 5e 41 5f 5d c3 e8 7a 37 0c 00 0f 0b
RSP: 0018:ffffc90000d3fe68 EFLAGS: 00000293
RAX: ffffffff8168c2cb RBX: ffff8880ae927f80 RCX: ffff8880a9a3e340
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff8168c29a
RBP: 000000b26607d004 R08: ffffffff817abce0 R09: ffffed1015d26c6c
R10: ffffed1015d26c6c R11: 0000000000000000 R12: 0000000000000000
R13: ffff8880ae927f54 R14: dffffc0000000000 R15: 1ffff11015d24fea
do_idle+0x5fe/0x650 kernel/sched/idle.c:289
cpu_startup_entry+0x15/0x20 kernel/sched/idle.c:372
secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243

---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@xxxxxxxxxxxxxxxx.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches

Next message: Kees Cook: "Re: [PATCH 00/10] mmc: convert tasklets to use new tasklet_setup()"
Previous message: Greg Kroah-Hartman: "[PATCH 5.8 254/464] drm/imx: tve: fix regulator_disable error path"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]