inconsistent lock state in sco_conn_del

6 views
Skip to first unread message

syzbot

unread,
Sep 7, 2020, 3:17:17 PM9/7/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: c37da90e Linux 4.19.143
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=17080b95900000
kernel config: https://syzkaller.appspot.com/x/.config?x=d162ec57805c4e4d
dashboard link: https://syzkaller.appspot.com/bug?extid=e5b57fedc9f4dbcb6d14
compiler: gcc (GCC) 10.1.0-syz 20200507

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e5b57f...@syzkaller.appspotmail.com

================================
WARNING: inconsistent lock state
4.19.143-syzkaller #0 Not tainted
--------------------------------
inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
syz-executor.1/19033 [HC0[0]:SC0[0]:HE1:SE1] takes:
00000000c2f9e15b (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: spin_lock include/linux/spinlock.h:329 [inline]
00000000c2f9e15b (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: sco_conn_del+0xb0/0x220 net/bluetooth/sco.c:175
{IN-SOFTIRQ-W} state was registered at:
loop5: p1 p2 < > p3 p4 < p5 >
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_sock_timeout+0x22/0x190 net/bluetooth/sco.c:82
call_timer_fn+0x177/0x700 kernel/time/timer.c:1338
loop5: partition table partially beyond EOD, truncated
expire_timers+0x243/0x4e0 kernel/time/timer.c:1375
__run_timers kernel/time/timer.c:1703 [inline]
run_timer_softirq+0x21c/0x670 kernel/time/timer.c:1716
__do_softirq+0x26c/0x9a0 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
loop5: p1 size 11290111 extends beyond EOD, truncated
exiting_irq arch/x86/include/asm/apic.h:544 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1094
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
loop5: p3 start 4276224225 is beyond EOD, truncated
arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
_raw_spin_unlock_irqrestore+0xa3/0xe0 kernel/locking/spinlock.c:184
hrtimer_start_expires include/linux/hrtimer.h:412 [inline]
do_nanosleep+0x1fe/0x6c0 kernel/time/hrtimer.c:1688
hrtimer_nanosleep+0x24d/0x500 kernel/time/hrtimer.c:1745
__do_sys_nanosleep kernel/time/hrtimer.c:1779 [inline]
__se_sys_nanosleep kernel/time/hrtimer.c:1766 [inline]
__x64_sys_nanosleep+0x19d/0x220 kernel/time/hrtimer.c:1766
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
irq event stamp: 2765
loop5: p5 size 11290111 extends beyond EOD, truncated
hardirqs last enabled at (2765): [<ffffffff819fa520>] kfree+0x110/0x210 mm/slab.c:3823
hardirqs last disabled at (2764): [<ffffffff819fa47f>] kfree+0x6f/0x210 mm/slab.c:3816
softirqs last enabled at (2670): [<ffffffff8760069a>] __do_softirq+0x69a/0x9a0 kernel/softirq.c:318
softirqs last disabled at (2571): [<ffffffff813f36f5>] invoke_softirq kernel/softirq.c:372 [inline]
softirqs last disabled at (2571): [<ffffffff813f36f5>] irq_exit+0x215/0x260 kernel/softirq.c:412

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

CPU0
----
lock(slock-AF_BLUETOOTH-BTPROTO_SCO);
<Interrupt>
loop5: p1 p2 < > p3 p4 < p5 >
lock(slock-AF_BLUETOOTH-BTPROTO_SCO);

*** DEADLOCK ***

3 locks held by syz-executor.1/19033:
#0: 00000000be8e43a8 (&hdev->req_lock){+.+.}, at: hci_dev_do_close+0x177/0xe70 net/bluetooth/hci_core.c:1616
loop5: partition table partially beyond EOD, truncated
#1: 00000000a3581fe9 (&hdev->lock){+.+.}, at: hci_dev_do_close+0x2c1/0xe70 net/bluetooth/hci_core.c:1653
#2: 0000000008fead5e (hci_cb_list_lock){+.+.}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1258 [inline]
#2: 0000000008fead5e (hci_cb_list_lock){+.+.}, at: hci_conn_hash_flush+0xc7/0x220 net/bluetooth/hci_conn.c:1495

stack backtrace:
CPU: 0 PID: 19033 Comm: syz-executor.1 Not tainted 4.19.143-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
loop5: p1 size 11290111 extends beyond EOD, truncated
print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2544
valid_state kernel/locking/lockdep.c:2557 [inline]
mark_lock_irq kernel/locking/lockdep.c:2751 [inline]
mark_lock+0xc70/0x1160 kernel/locking/lockdep.c:3131
mark_irqflags kernel/locking/lockdep.c:3027 [inline]
__lock_acquire+0x6a8/0x3ff0 kernel/locking/lockdep.c:3372
lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
loop5: p3 start 4276224225 is beyond EOD, truncated
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_conn_del+0xb0/0x220 net/bluetooth/sco.c:175
sco_disconn_cfm net/bluetooth/sco.c:1133 [inline]
sco_disconn_cfm+0x62/0x80 net/bluetooth/sco.c:1126
hci_disconn_cfm include/net/bluetooth/hci_core.h:1261 [inline]
hci_conn_hash_flush+0x114/0x220 net/bluetooth/hci_conn.c:1495
loop5: p5 size 11290111 extends beyond EOD, truncated
hci_dev_do_close+0x624/0xe70 net/bluetooth/hci_core.c:1666
hci_unregister_dev+0x17c/0x7f0 net/bluetooth/hci_core.c:3271
vhci_release+0x70/0xe0 drivers/bluetooth/hci_vhci.c:354
__fput+0x2ce/0x890 fs/file_table.c:278
task_work_run+0x148/0x1c0 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xbb2/0x2b70 kernel/exit.c:887
do_group_exit+0x125/0x310 kernel/exit.c:990
get_signal+0x3f2/0x1f70 kernel/signal.c:2588
do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
loop5: p1 p2 < > p3 p4 < p5 >
exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
loop5: partition table partially beyond EOD, truncated
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45d5b9
Code: 5d b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 2b b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00
loop5: p1 size 11290111 extends beyond EOD, truncated
RSP: 002b:00007f0aae61fcf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 000000000118cf48 RCX: 000000000045d5b9
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000118cf48
RBP: 000000000118cf40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c
R13: 00007ffe14b3c8af R14: 00007f0aae6209c0 R15: 000000000118cf4c
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
batman_adv: batadv0: Interface deactivated: batadv_slave_0
batman_adv: batadv0: Removing interface: batadv_slave_0
batman_adv: batadv0: Interface deactivated: batadv_slave_1
batman_adv: batadv0: Removing interface: batadv_slave_1
device bridge_slave_1 left promiscuous mode
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_0 left promiscuous mode
bridge0: port 1(bridge_slave_0) entered disabled state
device veth0_macvtap left promiscuous mode
device veth1_vlan left promiscuous mode
device veth0_vlan left promiscuous mode
bond4 (unregistering): Releasing backup interface bridge1
device bridge1 left promiscuous mode
bond4 (unregistering): Released all slaves
bond3 (unregistering): Released all slaves
bond2 (unregistering): Released all slaves
bond1 (unregistering): Released all slaves
device hsr_slave_1 left promiscuous mode
device hsr_slave_0 left promiscuous mode
team0 (unregistering): Port device team_slave_1 removed
team0 (unregistering): Port device team_slave_0 removed
bond0 (unregistering): Releasing backup interface bond_slave_1
bond0 (unregistering): Releasing backup interface bond_slave_0
bond0 (unregistering): Released all slaves
IPVS: ftp: loaded support on port[0] = 21
chnl_net:caif_netlink_parms(): no params data found
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge_slave_0 entered promiscuous mode
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_1 entered promiscuous mode
bond0: Enslaving bond_slave_0 as an active interface with an up link
bond0: Enslaving bond_slave_1 as an active interface with an up link
IPv6: ADDRCONF(NETDEV_UP): team_slave_0: link is not ready
team0: Port device team_slave_0 added
IPv6: ADDRCONF(NETDEV_UP): team_slave_1: link is not ready
team0: Port device team_slave_1 added
batman_adv: batadv0: Adding interface: batadv_slave_0
batman_adv: batadv0: The MTU of interface batadv_slave_0 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1560 would solve the problem.
batman_adv: batadv0: Not using interface batadv_slave_0 (retrying later): interface not active
batman_adv: batadv0: Adding interface: batadv_slave_1
batman_adv: batadv0: The MTU of interface batadv_slave_1 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1560 would solve the problem.
batman_adv: batadv0: Not using interface batadv_slave_1 (retrying later): interface not active
IPv6: ADDRCONF(NETDEV_UP): bridge_slave_0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): bridge_slave_1: link is not ready
device hsr_slave_0 entered promiscuous mode
device hsr_slave_1 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr_slave_0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): hsr_slave_1: link is not ready
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered forwarding state
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
8021q: adding VLAN 0 to HW filter on device bond0
IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
bridge0: port 1(bridge_slave_0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
IPv6: ADDRCONF(NETDEV_UP): team0: link is not ready
8021q: adding VLAN 0 to HW filter on device team0
IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered forwarding state
IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
IPv6: ADDRCONF(NETDEV_UP): vxcan0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
8021q: adding VLAN 0 to HW filter on device batadv0
IPv6: ADDRCONF(NETDEV_UP): veth0_virt_wifi: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi: link becomes ready
IPv6: ADDRCONF(NETDEV_UP): veth0_vlan: link is not ready
IPv6: ADDRCONF(NETDEV_UP): vlan0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): vlan1: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready
device veth0_vlan entered promiscuous mode
device veth1_vlan entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): macvlan0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): macvlan1: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth0_macvtap: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap: link becomes ready
device veth0_macvtap entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): macvtap0: link is not ready
device veth1_macvtap entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth0_to_batadv: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth1_to_batadv: link is not ready
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: batadv0: Interface activated: batadv_slave_0
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link becomes ready
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
batman_adv: The newly added mac address (aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
batman_adv: It is strongly recommended to keep mac addresses unique to avoid problems!
IPv6: ADDRCONF(NETDEV_UP): batadv_slave_1: link is not ready
batman_adv: batadv0: Interface activated: batadv_slave_1
IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv: link becomes ready
audit: type=1400 audit(1599506212.835:151): avc: denied { block_suspend } for pid=19387 comm="syz-executor.1" capability=36 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:system_r:kernel_t:s0 tclass=capability2 permissive=1
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
Bluetooth: hci1: command 0x0409 tx timeout
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
Bluetooth: hci1: command 0x041b tx timeout
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
loop5: p1 p2 < > p3 p4 < p5 >
loop5: partition table partially beyond EOD, truncated
loop5: p1 size 11290111 extends beyond EOD, truncated
loop5: p3 start 4276224225 is beyond EOD, truncated
loop5: p5 size 11290111 extends beyond EOD, truncated
Bluetooth: hci1: command 0x040f tx timeout


---
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 syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Jan 14, 2021, 6:01:17 PM1/14/21
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 675cc038 Linux 4.19.167
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=121b7deb500000
kernel config: https://syzkaller.appspot.com/x/.config?x=25b512beb95e2b66
dashboard link: https://syzkaller.appspot.com/bug?extid=e5b57fedc9f4dbcb6d14
compiler: gcc (GCC) 10.1.0-syz 20200507
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13dddad0d00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e5b57f...@syzkaller.appspotmail.com

================================
WARNING: inconsistent lock state
4.19.167-syzkaller #0 Not tainted
--------------------------------
inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
syz-executor.3/30653 [HC0[0]:SC0[0]:HE1:SE1] takes:
000000003d690fd4 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: spin_lock include/linux/spinlock.h:329 [inline]
000000003d690fd4 (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: sco_conn_del+0xe2/0x240 net/bluetooth/sco.c:175
{IN-SOFTIRQ-W} state was registered at:
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_sock_timeout+0x31/0x210 net/bluetooth/sco.c:82
call_timer_fn+0x177/0x700 kernel/time/timer.c:1338
expire_timers+0x243/0x4e0 kernel/time/timer.c:1375
__run_timers kernel/time/timer.c:1696 [inline]
run_timer_softirq+0x21c/0x670 kernel/time/timer.c:1709
__do_softirq+0x26c/0x9a0 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:545 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1094
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
lock_acquire+0x1ec/0x3c0 kernel/locking/lockdep.c:3910
__might_fault mm/memory.c:4731 [inline]
__might_fault+0x152/0x1d0 mm/memory.c:4716
_copy_to_user+0x29/0x100 lib/usercopy.c:25
copy_to_user include/linux/uaccess.h:155 [inline]
put_timespec64+0xb2/0x120 kernel/time/time.c:886
__do_sys_clock_gettime kernel/time/posix-timers.c:1065 [inline]
__se_sys_clock_gettime+0x16b/0x1e0 kernel/time/posix-timers.c:1053
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
irq event stamp: 2229
hardirqs last enabled at (2229): [<ffffffff881607c4>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (2229): [<ffffffff881607c4>] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:192
hardirqs last disabled at (2228): [<ffffffff88160455>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (2228): [<ffffffff88160455>] _raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:160
softirqs last enabled at (0): [<ffffffff81380d99>] copy_process.part.0+0x15b9/0x8200 kernel/fork.c:1859
softirqs last disabled at (0): [<0000000000000000>] (null)

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 ***

3 locks held by syz-executor.3/30653:
#0: 000000004a99ddee (&hdev->req_lock){+.+.}, at: hci_dev_do_close+0x196/0xf10 net/bluetooth/hci_core.c:1616
#1: 0000000035fb3b7e (&hdev->lock){+.+.}, at: hci_dev_do_close+0x2e0/0xf10 net/bluetooth/hci_core.c:1653
#2: 00000000be34fd5e (hci_cb_list_lock){+.+.}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1258 [inline]
#2: 00000000be34fd5e (hci_cb_list_lock){+.+.}, at: hci_conn_hash_flush+0xda/0x260 net/bluetooth/hci_conn.c:1512

stack backtrace:
CPU: 0 PID: 30653 Comm: syz-executor.3 Not tainted 4.19.167-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2544
valid_state kernel/locking/lockdep.c:2557 [inline]
mark_lock_irq kernel/locking/lockdep.c:2751 [inline]
mark_lock+0xc70/0x1160 kernel/locking/lockdep.c:3131
mark_irqflags kernel/locking/lockdep.c:3027 [inline]
__lock_acquire+0x6a8/0x3ff0 kernel/locking/lockdep.c:3372
lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_conn_del+0xe2/0x240 net/bluetooth/sco.c:175
sco_disconn_cfm+0x74/0xb0 net/bluetooth/sco.c:1133
hci_disconn_cfm include/net/bluetooth/hci_core.h:1261 [inline]
hci_conn_hash_flush+0x127/0x260 net/bluetooth/hci_conn.c:1512
hci_dev_do_close+0x659/0xf10 net/bluetooth/hci_core.c:1666
hci_unregister_dev+0x18b/0x910 net/bluetooth/hci_core.c:3271
vhci_release+0x70/0xe0 drivers/bluetooth/hci_vhci.c:354
__fput+0x2ce/0x890 fs/file_table.c:278
task_work_run+0x148/0x1c0 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xbed/0x2be0 kernel/exit.c:890
do_group_exit+0x125/0x310 kernel/exit.c:993
get_signal+0x3f2/0x1f70 kernel/signal.c:2589
do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath+0x3f0/0x4a0 arch/x86/entry/common.c:271
ret_from_fork+0x15/0x30 arch/x86/entry/entry_64.S:407
RIP: 0033:0x45e219
Code: 0d b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db b3 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f6c408cbc68 EFLAGS: 00000246 ORIG_RAX: 0000000000000038
RAX: 0000000000000000 RBX: 0000000000000005 RCX: 000000000045e219
RDX: 9999999999999999 RSI: 0000000000000000 RDI: 00040000000007fc
RBP: 000000000119bfd0 R08: ffffffffffffffff R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000119bf8c
R13: 00007fff49251f5f R14: 00007f6c408cc9c0 R15: 000000000119bf8c
batman_adv: batadv0: Interface deactivated: batadv_slave_0
batman_adv: batadv0: Removing interface: batadv_slave_0
batman_adv: batadv0: Interface deactivated: batadv_slave_1
batman_adv: batadv0: Removing interface: batadv_slave_1
device bridge_slave_1 left promiscuous mode
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_0 left promiscuous mode
bridge0: port 1(bridge_slave_0) entered disabled state
device veth1_macvtap left promiscuous mode
device veth0_macvtap left promiscuous mode
device veth1_vlan left promiscuous mode
device veth0_vlan left promiscuous mode
Bluetooth: hci0: command 0x0409 tx timeout
8021q: adding VLAN 0 to HW filter on device bond0
IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
bridge0: port 1(bridge_slave_0) entered disabled state
bridge0: port 2(bridge_slave_1) entered disabled state
IPv6: ADDRCONF(NETDEV_UP): team0: link is not ready
8021q: adding VLAN 0 to HW filter on device team0
IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered forwarding state
IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready
hsr0: Slave A (hsr_slave_0) is not up; please bring it up to get a fully working HSR network
hsr0: Slave B (hsr_slave_1) is not up; please bring it up to get a fully working HSR network
ieee80211 phy20: Selected rate control algorithm 'minstrel_ht'
IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: Created IBSS using preconfigured BSSID 50:50:50:50:50:50
ieee80211 phy21: Selected rate control algorithm 'minstrel_ht'
wlan0: Creating new IBSS network, BSSID 50:50:50:50:50:50
IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
wlan1: Created IBSS using preconfigured BSSID 50:50:50:50:50:50
wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Bluetooth: hci0: command 0x041b tx timeout
Bluetooth: hci0: command 0x040f tx timeout

syzbot

unread,
Jan 16, 2021, 12:17:19 PM1/16/21
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 675cc038 Linux 4.19.167
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1623e1f7500000
kernel config: https://syzkaller.appspot.com/x/.config?x=25b512beb95e2b66
dashboard link: https://syzkaller.appspot.com/bug?extid=e5b57fedc9f4dbcb6d14
compiler: gcc (GCC) 10.1.0-syz 20200507
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=17e76a20d00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1686c220d00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e5b57f...@syzkaller.appspotmail.com

================================
WARNING: inconsistent lock state
4.19.167-syzkaller #0 Not tainted
--------------------------------
inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
syz-executor104/2297 [HC0[0]:SC0[0]:HE1:SE1] takes:
0000000080de040c (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: spin_lock include/linux/spinlock.h:329 [inline]
0000000080de040c (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: sco_conn_del+0xe2/0x240 net/bluetooth/sco.c:175
{IN-SOFTIRQ-W} state was registered at:
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_sock_timeout+0x31/0x210 net/bluetooth/sco.c:82
call_timer_fn+0x177/0x700 kernel/time/timer.c:1338
expire_timers+0x243/0x4e0 kernel/time/timer.c:1375
__run_timers kernel/time/timer.c:1696 [inline]
run_timer_softirq+0x21c/0x670 kernel/time/timer.c:1709
__do_softirq+0x26c/0x9a0 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:545 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1094
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
lock_release+0x429/0x8b0 kernel/locking/lockdep.c:3929
alloc_set_pte+0x927/0x1a00 mm/memory.c:3588
filemap_map_pages+0xd66/0x11c0 mm/filemap.c:2700
do_fault_around mm/memory.c:3735 [inline]
do_read_fault mm/memory.c:3769 [inline]
do_fault mm/memory.c:3903 [inline]
handle_pte_fault mm/memory.c:4134 [inline]
__handle_mm_fault+0x2a8e/0x41c0 mm/memory.c:4258
handle_mm_fault+0x436/0xb10 mm/memory.c:4295
__do_page_fault+0x68e/0xd60 arch/x86/mm/fault.c:1412
page_fault+0x1e/0x30 arch/x86/entry/entry_64.S:1205
irq event stamp: 1201
hardirqs last enabled at (1201): [<ffffffff881607c4>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (1201): [<ffffffff881607c4>] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:192
hardirqs last disabled at (1200): [<ffffffff88160455>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (1200): [<ffffffff88160455>] _raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:160
softirqs last enabled at (238): [<ffffffff876551d0>] sco_sock_connect+0x5b0/0xa90 net/bluetooth/sco.c:584
softirqs last disabled at (236): [<ffffffff868cce4b>] spin_lock_bh include/linux/spinlock.h:334 [inline]
softirqs last disabled at (236): [<ffffffff868cce4b>] release_sock+0x1b/0x1b0 net/core/sock.c:2879

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 ***

3 locks held by syz-executor104/2297:
#0: 00000000da46d8a2 (&hdev->req_lock){+.+.}, at: hci_dev_do_close+0x196/0xf10 net/bluetooth/hci_core.c:1616
#1: 00000000d9a3f969 (&hdev->lock){+.+.}, at: hci_dev_do_close+0x2e0/0xf10 net/bluetooth/hci_core.c:1653
#2: 00000000d345c75b (hci_cb_list_lock){+.+.}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1258 [inline]
#2: 00000000d345c75b (hci_cb_list_lock){+.+.}, at: hci_conn_hash_flush+0xda/0x260 net/bluetooth/hci_conn.c:1512

stack backtrace:
CPU: 0 PID: 2297 Comm: syz-executor104 Not tainted 4.19.167-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2544
valid_state kernel/locking/lockdep.c:2557 [inline]
mark_lock_irq kernel/locking/lockdep.c:2751 [inline]
mark_lock+0xc70/0x1160 kernel/locking/lockdep.c:3131
mark_irqflags kernel/locking/lockdep.c:3027 [inline]
__lock_acquire+0x6a8/0x3ff0 kernel/locking/lockdep.c:3372
lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
spin_lock include/linux/spinlock.h:329 [inline]
sco_conn_del+0xe2/0x240 net/bluetooth/sco.c:175
sco_disconn_cfm+0x74/0xb0 net/bluetooth/sco.c:1133
hci_disconn_cfm include/net/bluetooth/hci_core.h:1261 [inline]
hci_conn_hash_flush+0x127/0x260 net/bluetooth/hci_conn.c:1512
hci_dev_do_close+0x659/0xf10 net/bluetooth/hci_core.c:1666
hci_unregister_dev+0x18b/0x910 net/bluetooth/hci_core.c:3271
vhci_release+0x70/0xe0 drivers/bluetooth/hci_vhci.c:354
__fput+0x2ce/0x890 fs/file_table.c:278
task_work_run+0x148/0x1c0 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xbed/0x2be0 kernel/exit.c:890
do_group_exit+0x125/0x310 kernel/exit.c:993
get_signal+0x3f2/0x1f70 kernel/signal.c:2589
do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4474d9
Code: e8 4c e7 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 3b 07 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f2106e8ecf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 00000000006dcc28 RCX: 00000000004474d9
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 00000000006dcc28
RBP: 00000000006dcc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dcc2c
R13: 00007ffdccc5149f R14: 00007f2106e8f9c0 R15: 0000000000000064
Bluetooth: hci3: command 0x0405 tx timeout

Reply all
Reply to author
Forward
0 new messages