audit: type=1800 audit(1615276201.950:11008): pid=28121 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17464 res=0 Bearer rejected, not supported in standalone mode ================================ WARNING: inconsistent lock state 4.14.224-syzkaller #0 Not tainted -------------------------------- inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. syz-executor.4/28093 [HC0[0]:SC1[1]:HE1:SE0] takes: (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: [] spin_lock include/linux/spinlock.h:317 [inline] (slock-AF_BLUETOOTH-BTPROTO_SCO){+.?.}, at: [] 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:1622 hci_unregister_dev+0x17f/0x8c0 net/bluetooth/hci_core.c:3193 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+0xa44/0x2850 kernel/exit.c:868 do_group_exit+0x100/0x2e0 kernel/exit.c:965 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: 24080 hardirqs last enabled at (24080): [] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline] hardirqs last enabled at (24080): [] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:200 hardirqs last disabled at (24079): [] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline] hardirqs last disabled at (24079): [] _raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:168 softirqs last enabled at (23604): [] rcu_read_unlock_bh include/linux/rcupdate.h:721 [inline] softirqs last enabled at (23604): [] __dev_queue_xmit+0xc96/0x2480 net/core/dev.c:3548 softirqs last disabled at (23605): [] do_softirq_own_stack+0x2a/0x40 arch/x86/entry/entry_64.S:1016 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(slock-AF_BLUETOOTH-BTPROTO_SCO); lock(slock-AF_BLUETOOTH-BTPROTO_SCO); *** DEADLOCK *** 2 locks held by syz-executor.4/28093: #0: (rcu_read_lock){....}, at: [] netlink_deliver_tap+0x0/0x7d0 net/netlink/af_netlink.c:417 #1: (((&sk->sk_timer))#2){+.-.}, at: [] lockdep_copy_map include/linux/lockdep.h:174 [inline] #1: (((&sk->sk_timer))#2){+.-.}, at: [] call_timer_fn+0xb8/0x650 kernel/time/timer.c:1270 stack backtrace: CPU: 0 PID: 28093 Comm: syz-executor.4 Not tainted 4.14.224-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0x1b2/0x281 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:1637 [inline] run_timer_softirq+0x1d5/0x5a0 kernel/time/timer.c:1650 __do_softirq+0x24d/0x9ff kernel/softirq.c:288 do_softirq_own_stack+0x2a/0x40 arch/x86/entry/entry_64.S:1016 do_softirq.part.0+0x154/0x1b0 kernel/softirq.c:332 do_softirq kernel/softirq.c:324 [inline] __local_bh_enable_ip+0x12b/0x170 kernel/softirq.c:185 local_bh_enable include/linux/bottom_half.h:32 [inline] rcu_read_unlock_bh include/linux/rcupdate.h:725 [inline] __dev_queue_xmit+0xcc9/0x2480 net/core/dev.c:3548 __netlink_deliver_tap_skb net/netlink/af_netlink.c:273 [inline] __netlink_deliver_tap net/netlink/af_netlink.c:291 [inline] netlink_deliver_tap+0x60c/0x7d0 net/netlink/af_netlink.c:302 netlink_deliver_tap_kernel net/netlink/af_netlink.c:311 [inline] netlink_unicast_kernel net/netlink/af_netlink.c:1286 [inline] netlink_unicast+0x485/0x610 net/netlink/af_netlink.c:1313 netlink_sendmsg+0x62e/0xb80 net/netlink/af_netlink.c:1878 sock_sendmsg_nosec net/socket.c:646 [inline] sock_sendmsg+0xb5/0x100 net/socket.c:656 ___sys_sendmsg+0x326/0x800 net/socket.c:2062 netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'. __sys_sendmmsg+0x129/0x330 net/socket.c:2152 SYSC_sendmmsg net/socket.c:2183 [inline] SyS_sendmmsg+0x2f/0x50 net/socket.c:2178 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x46/0xbb RIP: 0033:0x465f69 RSP: 002b:00007fbb839d0188 EFLAGS: 00000246 ORIG_RAX: 0000000000000133 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465f69 RDX: 04924924924924cb RSI: 0000000020000000 RDI: 0000000000000005 RBP: 00000000004bfa67 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffd617491ff R14: 00007fbb839d0300 R15: 0000000000022000 netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'. EXT4-fs (loop2): Unrecognized mount option "nod%lalloc" or missing value print_req_error: 251 callbacks suppressed print_req_error: I/O error, dev loop2, sector 0 IPVS: ftp: loaded support on port[0] = 21 EXT4-fs (loop2): Unrecognized mount option "nod%lalloc" or missing value Bluetooth: hci0 command 0x0405 tx timeout IPVS: ftp: loaded support on port[0] = 21 IPVS: set_ctl: invalid protocol: 1 172.20.20.0:20001 IPVS: set_ctl: invalid protocol: 1 172.20.20.0:20001 IPVS: set_ctl: invalid protocol: 43 224.0.0.2:20000 IPVS: set_ctl: invalid protocol: 44 172.30.0.5:20002 IPVS: set_ctl: invalid protocol: 43 224.0.0.2:20000 Bluetooth: hci0 command 0x0405 tx timeout IPVS: set_ctl: invalid protocol: 44 172.30.0.5:20002 IPVS: ftp: loaded support on port[0] = 21 kauditd_printk_skb: 24 callbacks suppressed audit: type=1800 audit(1615276205.810:11033): pid=28481 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=17508 res=0 audit: type=1800 audit(1615276205.870:11034): pid=28479 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17508 res=0 audit: type=1800 audit(1615276205.900:11035): pid=28488 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=17509 res=0 IPVS: set_ctl: invalid protocol: 1 172.20.20.0:20001 audit: type=1800 audit(1615276205.970:11036): pid=28479 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17508 res=0 audit: type=1800 audit(1615276206.080:11037): pid=28499 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=17508 res=0 audit: type=1800 audit(1615276206.350:11038): pid=28515 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17502 res=0 audit: type=1800 audit(1615276206.370:11039): pid=28518 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=17507 res=0 audit: type=1800 audit(1615276206.400:11040): pid=28525 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17502 res=0 audit: type=1800 audit(1615276206.760:11041): pid=28543 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17483 res=0 audit: type=1800 audit(1615276206.790:11042): pid=28543 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17483 res=0 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: set_ctl: invalid protocol: 3 224.0.0.2:20001 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 kauditd_printk_skb: 11 callbacks suppressed audit: type=1800 audit(1615276210.950:11054): pid=28830 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17460 res=0 audit: type=1800 audit(1615276210.980:11055): pid=28830 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17460 res=0 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 audit: type=1800 audit(1615276211.620:11056): pid=28851 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17446 res=0 IPVS: ip_vs_svc_hash(): request for already hashed, called from do_ip_vs_set_ctl+0xa4e/0xc60 net/netfilter/ipvs/ip_vs_ctl.c:2487 audit: type=1800 audit(1615276211.640:11057): pid=28851 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17446 res=0 audit: type=1800 audit(1615276211.820:11058): pid=28876 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17446 res=0 audit: type=1800 audit(1615276211.840:11059): pid=28876 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=17446 res=0