audit: type=1804 audit(1612260088.820:206): pid=26345 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/295/bus" dev="sda1" ino=16273 res=1 device bridge0 entered promiscuous mode netlink: 14 bytes leftover after parsing attributes in process `syz-executor.3'. ====================================================== WARNING: possible circular locking dependency detected 4.14.218-syzkaller #0 Not tainted ------------------------------------------------------ syz-executor.0/26350 is trying to acquire lock: ("%s"hdev->name#2){+.+.}, at: [] start_flush_work kernel/workqueue.c:2860 [inline] ("%s"hdev->name#2){+.+.}, at: [] flush_work+0x387/0x770 kernel/workqueue.c:2892 but task is already holding lock: (&hdev->lock){+.+.}, at: [] hci_dev_do_close+0x21c/0xca0 net/bluetooth/hci_core.c:1607 which lock already depends on the new lock. bridge0: port 2(bridge_slave_1) entered blocking state the existing dependency chain (in reverse order) is: -> #2 (&hdev->lock){+.+.}: __mutex_lock_common kernel/locking/mutex.c:756 [inline] __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893 hci_cc_write_scan_enable net/bluetooth/hci_event.c:375 [inline] hci_cmd_complete_evt+0x4d34/0xb490 net/bluetooth/hci_event.c:2831 hci_event_packet+0x21ce/0x7510 net/bluetooth/hci_event.c:5330 hci_rx_work+0x427/0xb40 net/bluetooth/hci_core.c:4244 process_one_work+0x793/0x14a0 kernel/workqueue.c:2116 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250 kthread+0x30d/0x420 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 -> #1 ((&hdev->rx_work)){+.+.}: process_one_work+0x736/0x14a0 kernel/workqueue.c:2092 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250 kthread+0x30d/0x420 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 -> #0 ("%s"hdev->name#2){+.+.}: lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 start_flush_work kernel/workqueue.c:2861 [inline] flush_work+0x3ac/0x770 kernel/workqueue.c:2892 __cancel_work_timer+0x321/0x460 kernel/workqueue.c:2964 bridge0: port 2(bridge_slave_1) entered forwarding state hci_conn_del+0x52/0x6f0 net/bluetooth/hci_conn.c:575 hci_conn_hash_flush+0x19c/0x260 net/bluetooth/hci_conn.c:1394 hci_dev_do_close+0x535/0xca0 net/bluetooth/hci_core.c:1620 hci_rfkill_set_block+0xaf/0x120 net/bluetooth/hci_core.c:2050 rfkill_set_block+0x1b2/0x4a0 net/rfkill/core.c:337 bridge0: port 1(bridge_slave_0) entered blocking state rfkill_fop_write+0x1b6/0x3c0 net/rfkill/core.c:1233 __vfs_write+0xe4/0x630 fs/read_write.c:480 vfs_write+0x17f/0x4d0 fs/read_write.c:544 SYSC_write fs/read_write.c:590 [inline] SyS_write+0xf2/0x210 fs/read_write.c:582 bridge0: port 1(bridge_slave_0) entered forwarding state do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x46/0xbb other info that might help us debug this: device bridge0 left promiscuous mode Chain exists of: "%s"hdev->name#2 --> (&hdev->rx_work) --> &hdev->lock Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock(&hdev->lock); lock((&hdev->rx_work)); lock(&hdev->lock); lock("%s"hdev->name#2); *** DEADLOCK *** 3 locks held by syz-executor.0/26350: #0: (rfkill_global_mutex){+.+.}, at: [] rfkill_fop_write+0xbf/0x3c0 net/rfkill/core.c:1225 #1: (&hdev->req_lock){+.+.} IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready , at: [] hci_dev_do_close+0x109/0xca0 net/bluetooth/hci_core.c:1576 #2: (&hdev->lock){+.+.}, at: [] hci_dev_do_close+0x21c/0xca0 net/bluetooth/hci_core.c:1607 stack backtrace: CPU: 0 PID: 26350 Comm: syz-executor.0 Not tainted 4.14.218-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_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1258 check_prev_add kernel/locking/lockdep.c:1905 [inline] check_prevs_add kernel/locking/lockdep.c:2022 [inline] validate_chain kernel/locking/lockdep.c:2464 [inline] __lock_acquire+0x2e0e/0x3f20 kernel/locking/lockdep.c:3491 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 start_flush_work kernel/workqueue.c:2861 [inline] flush_work+0x3ac/0x770 kernel/workqueue.c:2892 __cancel_work_timer+0x321/0x460 kernel/workqueue.c:2964 hci_conn_del+0x52/0x6f0 net/bluetooth/hci_conn.c:575 hci_conn_hash_flush+0x19c/0x260 net/bluetooth/hci_conn.c:1394 hci_dev_do_close+0x535/0xca0 net/bluetooth/hci_core.c:1620 hci_rfkill_set_block+0xaf/0x120 net/bluetooth/hci_core.c:2050 rfkill_set_block+0x1b2/0x4a0 net/rfkill/core.c:337 rfkill_fop_write+0x1b6/0x3c0 net/rfkill/core.c:1233 __vfs_write+0xe4/0x630 fs/read_write.c:480 vfs_write+0x17f/0x4d0 fs/read_write.c:544 SYSC_write fs/read_write.c:590 [inline] SyS_write+0xf2/0x210 fs/read_write.c:582 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x46/0xbb RIP: 0033:0x465b09 RSP: 002b:00007fa495d46188 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000056c0b0 RCX: 0000000000465b09 RDX: 0000000000000008 RSI: 0000000020000000 RDI: 0000000000000005 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056c0b0 R13: 00007fffcd7ca0df R14: 00007fa495d46300 R15: 0000000000022000 audit: type=1804 audit(1612260088.820:207): pid=26345 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/295/bus" dev="sda1" ino=16273 res=1 audit: type=1804 audit(1612260088.830:208): pid=26347 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/295/bus" dev="sda1" ino=16273 res=1 audit: type=1804 audit(1612260088.830:209): pid=26345 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/295/bus" dev="sda1" ino=16273 res=1 audit: type=1804 audit(1612260089.080:210): pid=26361 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/296/bus" dev="sda1" ino=15930 res=1 audit: type=1804 audit(1612260089.170:211): pid=26363 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="bus" dev="sda1" ino=16328 res=1 IPv6: ADDRCONF(NETDEV_CHANGE): bridge0: link becomes ready kauditd_printk_skb: 20 callbacks suppressed audit: type=1804 audit(1612260093.240:232): pid=26480 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/299/bus" dev="sda1" ino=16994 res=1 audit: type=1804 audit(1612260093.350:233): pid=26483 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="bus" dev="sda1" ino=17010 res=1 audit: type=1804 audit(1612260093.360:234): pid=26484 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir530328961/syzkaller.R0S6TB/299/bus" dev="sda1" ino=16994 res=1 audit: type=1804 audit(1612260093.370:235): pid=26483 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.2" name="bus" dev="sda1" ino=17010 res=1 audit: type=1804 audit(1612260093.540:236): pid=26491 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir407900396/syzkaller.uBaVIl/231/bus" dev="sda1" ino=16900 res=1 audit: type=1804 audit(1612260093.570:237): pid=26493 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir349976260/syzkaller.r1NR5g/503/bus" dev="sda1" ino=16434 res=1 audit: type=1804 audit(1612260093.620:238): pid=26494 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir407900396/syzkaller.uBaVIl/231/bus" dev="sda1" ino=16900 res=1 audit: type=1804 audit(1612260093.640:239): pid=26495 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir349976260/syzkaller.r1NR5g/503/bus" dev="sda1" ino=16434 res=1 audit: type=1804 audit(1612260094.500:240): pid=26460 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir342778518/syzkaller.IFjQVq/516/file0" dev="sda1" ino=16932 res=1 TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. audit: type=1804 audit(1612260094.890:241): pid=26523 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir407900396/syzkaller.uBaVIl/232/bus" dev="sda1" ino=16772 res=1 TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. kauditd_printk_skb: 7 callbacks suppressed audit: type=1326 audit(1612260098.500:249): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=26626 comm="syz-executor.5" exe="/root/syz-executor.5" sig=9 arch=c000003e syscall=231 compat=0 ip=0x465b09 code=0x0