============================================ WARNING: possible recursive locking detected 4.15.0-rc8+ #269 Not tainted -------------------------------------------- syz-executor1/4798 is trying to acquire lock: (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 but task is already holding lock: (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&vq->mutex); lock(&vq->mutex); *** DEADLOCK *** May be due to missing lock nesting notation 1 lock held by syz-executor1/4798: #0: (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000017f94012>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 stack backtrace: CPU: 0 PID: 4798 Comm: syz-executor1 Not tainted 4.15.0-rc8+ #269 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+0x194/0x257 lib/dump_stack.c:53 print_deadlock_bug kernel/locking/lockdep.c:1756 [inline] check_deadlock kernel/locking/lockdep.c:1800 [inline] validate_chain kernel/locking/lockdep.c:2396 [inline] __lock_acquire+0xe8f/0x3e00 kernel/locking/lockdep.c:3426 lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3914 __mutex_lock_common kernel/locking/mutex.c:756 [inline] __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 vhost_net_chr_write_iter+0x59/0x70 drivers/vhost/net.c:1353 call_write_iter include/linux/fs.h:1772 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x684/0x970 fs/read_write.c:482 vfs_write+0x189/0x510 fs/read_write.c:544 SYSC_write fs/read_write.c:589 [inline] SyS_write+0xef/0x220 fs/read_write.c:581 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007fed9063bc58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000068 RSI: 00000000201c4000 RDI: 0000000000000016 RBP: 0000000000000624 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f8400 R13: 00000000ffffffff R14: 00007fed9063c6d4 R15: 0000000000000000 handle_userfault: 3 callbacks suppressed FAULT_FLAG_ALLOW_RETRY missing 30 CPU: 0 PID: 4811 Comm: syz-executor2 Not tainted 4.15.0-rc8+ #269 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+0x194/0x257 lib/dump_stack.c:53 handle_userfault+0x12fa/0x24c0 fs/userfaultfd.c:427 do_anonymous_page mm/memory.c:3127 [inline] handle_pte_fault mm/memory.c:3941 [inline] __handle_mm_fault+0x32a3/0x3ce0 mm/memory.c:4067 handle_mm_fault+0x334/0x8d0 mm/memory.c:4104 __do_page_fault+0x5c9/0xc90 arch/x86/mm/fault.c:1430 do_page_fault+0xee/0x720 arch/x86/mm/fault.c:1505 page_fault+0x2c/0x60 arch/x86/entry/entry_64.S:1260 RIP: 0010:fault_in_pages_readable include/linux/pagemap.h:601 [inline] RIP: 0010:iov_iter_fault_in_readable+0x1a7/0x410 lib/iov_iter.c:421 RSP: 0018:ffff8801c386f928 EFLAGS: 00010246 RAX: 0000000000010000 RBX: 0000000020011fd2 RCX: ffffffff82587fc1 RDX: 00000000000000ff RSI: ffffc900029dc000 RDI: ffff8801c386fd28 RBP: ffff8801c386fa08 R08: 0000000000000000 R09: 1ffff1003870dee7 R10: ffff8801c386f858 R11: ffff8801c07951a0 R12: 1ffff1003870df28 R13: ffff8801c386f9e0 R14: 0000000000000000 R15: ffff8801c386fd20 generic_perform_write+0x200/0x600 mm/filemap.c:3129 __generic_file_write_iter+0x366/0x5b0 mm/filemap.c:3264 generic_file_write_iter+0x399/0x790 mm/filemap.c:3292 call_write_iter include/linux/fs.h:1772 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x684/0x970 fs/read_write.c:482 vfs_write+0x189/0x510 fs/read_write.c:544 SYSC_write fs/read_write.c:589 [inline] SyS_write+0xef/0x220 fs/read_write.c:581 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f39da97ac58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000030 RSI: 0000000020011fd2 RDI: 0000000000000014 RBP: 0000000000000069 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006efa78 R13: 00000000ffffffff R14: 00007f39da97b6d4 R15: 0000000000000000 netlink: 8 bytes leftover after parsing attributes in process `syz-executor5'. pit: kvm: requested 5866 ns i8254 timer period limited to 500000 ns netlink: 8 bytes leftover after parsing attributes in process `syz-executor5'. audit: type=1400 audit(1516426059.449:22): avc: denied { ipc_lock } for pid=4894 comm="syz-executor3" capability=14 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1 audit: type=1400 audit(1516426059.575:23): avc: denied { create } for pid=4942 comm="syz-executor1" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:unlabeled_t:s0 tclass=key permissive=1 audit: type=1400 audit(1516426059.785:24): avc: denied { map } for pid=5018 comm="syz-executor1" path=2F616E6F6E5F6875676570616765202864656C6574656429 dev="hugetlbfs" ino=13130 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:hugetlbfs_t:s0 tclass=file permissive=1 TCP: request_sock_TCP: Possible SYN flooding on port 20026. Sending cookies. Check SNMP counters. audit: type=1326 audit(1516426059.932:25): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=5036 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426059.932:26): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=5036 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426059.959:27): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=5036 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=317 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426059.959:28): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=5036 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426059.959:29): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=5036 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1400 audit(1516426060.131:30): avc: denied { create } for pid=5120 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1 mmap: syz-executor4 (5144) uses deprecated remap_file_pages() syscall. See Documentation/vm/remap_file_pages.txt. encrypted_key: master key parameter '»ù"8õå$Üæ' is invalid encrypted_key: master key parameter '»ù"8õå$Üæ' is invalid SELinux: unrecognized netlink message: protocol=0 nlmsg_type=45163 sclass=netlink_route_socket pig=5512 comm=syz-executor0 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=45163 sclass=netlink_route_socket pig=5525 comm=syz-executor0 netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. dccp_close: ABORT with 2 bytes unread binder: 5728:5731 BC_ACQUIRE_DONE u0000000000000000 node 1 cookie mismatch 0000000000000003 != 0000000000000000 binder: 5728:5731 BC_CLEAR_DEATH_NOTIFICATION invalid ref -2147483648 binder: 5728:5731 BC_REQUEST_DEATH_NOTIFICATION invalid ref 2 binder: 5728:5731 DecRefs 0 refcount change on invalid ref 2 ret -22 binder: 5728:5731 got transaction to invalid handle binder: 5728:5731 transaction failed 29201/-22, size 56-40 line 2788 binder: BINDER_SET_CONTEXT_MGR already set binder: 5728:5757 ioctl 40046207 0 returned -16 binder: 5728:5757 BC_ACQUIRE_DONE u0000000000000000 no match binder: 5728:5731 BC_CLEAR_DEATH_NOTIFICATION invalid ref -2147483648 binder: 5728:5757 BC_REQUEST_DEATH_NOTIFICATION invalid ref 2 binder: 5728:5757 DecRefs 0 refcount change on invalid ref 2 ret -22 binder: 5728:5757 got transaction to invalid handle binder: 5728:5757 transaction failed 29201/-22, size 56-40 line 2788 netlink: 'syz-executor5': attribute type 1 has an invalid length. netlink: 'syz-executor5': attribute type 1 has an invalid length. TCP: request_sock_TCP: Possible SYN flooding on port 20030. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20030. Sending cookies. Check SNMP counters. QAT: Invalid ioctl kauditd_printk_skb: 157 callbacks suppressed audit: type=1400 audit(1516426063.727:188): avc: denied { call } for pid=6044 comm="syz-executor4" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=binder permissive=1 binder: 6044:6049 got transaction with invalid handle, 0 binder: 6044:6049 transaction failed 29201/-22, size 24-8 line 2995 binder_alloc: binder_alloc_mmap_handler: 6044 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 6044:6049 ioctl 40046207 0 returned -16 binder_alloc: 6044: binder_alloc_buf, no vma binder: 6044:6049 transaction failed 29189/-3, size 24-8 line 2903 capability: warning: `syz-executor5' uses deprecated v2 capabilities in a way that may be insecure FAULT_FLAG_ALLOW_RETRY missing 30 CPU: 0 PID: 6150 Comm: syz-executor5 Not tainted 4.15.0-rc8+ #269 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+0x194/0x257 lib/dump_stack.c:53 handle_userfault+0x12fa/0x24c0 fs/userfaultfd.c:427 do_anonymous_page mm/memory.c:3127 [inline] handle_pte_fault mm/memory.c:3941 [inline] __handle_mm_fault+0x32a3/0x3ce0 mm/memory.c:4067 handle_mm_fault+0x334/0x8d0 mm/memory.c:4104 __do_page_fault+0x5c9/0xc90 arch/x86/mm/fault.c:1430 do_page_fault+0xee/0x720 arch/x86/mm/fault.c:1505 page_fault+0x2c/0x60 arch/x86/entry/entry_64.S:1260 RIP: 0010:fault_in_pages_readable include/linux/pagemap.h:601 [inline] RIP: 0010:iov_iter_fault_in_readable+0x1a7/0x410 lib/iov_iter.c:421 RSP: 0018:ffff8801d1f77928 EFLAGS: 00010246 RAX: 0000000000010000 RBX: 0000000020011fd2 RCX: ffffffff82587fc1 RDX: 00000000000000c3 RSI: ffffc90003f06000 RDI: ffff8801d1f77d28 RBP: ffff8801d1f77a08 R08: 1ffff100381ab42a R09: 1ffff1003a3eef22 R10: ffff8801d1f77858 R11: ffffffff87f08fc8 R12: 1ffff1003a3eef28 R13: ffff8801d1f779e0 R14: 0000000000000000 R15: ffff8801d1f77d20 generic_perform_write+0x200/0x600 mm/filemap.c:3129 __generic_file_write_iter+0x366/0x5b0 mm/filemap.c:3264 generic_file_write_iter+0x399/0x790 mm/filemap.c:3292 call_write_iter include/linux/fs.h:1772 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x684/0x970 fs/read_write.c:482 vfs_write+0x189/0x510 fs/read_write.c:544 SYSC_write fs/read_write.c:589 [inline] SyS_write+0xef/0x220 fs/read_write.c:581 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f07477b8c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000030 RSI: 0000000020011fd2 RDI: 0000000000000016 RBP: 0000000000000167 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f1248 R13: 00000000ffffffff R14: 00007f07477b96d4 R15: 0000000000000000 audit: type=1326 audit(1516426064.678:189): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6169 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1400 audit(1516426064.718:190): avc: denied { map } for pid=6193 comm="syz-executor0" path="/dev/sg0" dev="devtmpfs" ino=106 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:scsi_generic_device_t:s0 tclass=chr_file permissive=1 audit: type=1326 audit(1516426064.815:191): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6226 comm="syz-executor0" exe="/root/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7efc0000 dccp_invalid_packet: P.type (REQUEST) not Data || [Data]Ack, while P.X == 0 audit: type=1400 audit(1516426064.879:192): avc: denied { transfer } for pid=6239 comm="syz-executor6" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=binder permissive=1 binder: release 6239:6240 transaction 8 out, still active binder: unexpected work type, 4, not freed binder: undelivered TRANSACTION_COMPLETE binder: BINDER_SET_CONTEXT_MGR already set binder: 6239:6240 ioctl 40046207 0 returned -16 binder: invalid inc weak node for 9 binder: 6239:6240 IncRefs 0 refcount change on invalid ref 1 ret -22 binder_alloc: binder_alloc_mmap_handler: 6239 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 6239:6240 ioctl 40046207 0 returned -16 binder_alloc: 6239: binder_alloc_buf, no vma binder: 6239:6240 transaction failed 29189/-3, size 40-8 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: BINDER_SET_CONTEXT_MGR already set binder: 6239:6240 ioctl 40046207 0 returned -16 binder: 6239:6240 IncRefs 0 refcount change on invalid ref 1 ret -22 binder: send failed reply for transaction 8, target dead audit: type=1326 audit(1516426064.934:193): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6226 comm="syz-executor0" exe="/root/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7efc0000 audit: type=1326 audit(1516426065.799:194): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6398 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426065.800:195): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6398 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426065.804:196): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6398 comm="syz-executor7" exe="/root/syz-executor7" sig=0 arch=c000003e syscall=297 compat=0 ip=0x452ee9 code=0x7ffc0000 PPPIOCDETACH file->f_count=2 PPPIOCDETACH file->f_count=2 QAT: Invalid ioctl QAT: Invalid ioctl binder: 6740:6743 BC_ACQUIRE_DONE node 12 has no pending acquire request binder: 6740:6743 got reply transaction with bad transaction stack, transaction 13 has target 6740:0 binder: 6740:6743 transaction failed 29201/-71, size 0-0 line 2718 binder_alloc: binder_alloc_mmap_handler: 6740 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 6740:6743 ioctl 40046207 0 returned -16 binder_alloc: 6740: binder_alloc_buf, no vma binder: 6740:6760 transaction failed 29189/-3, size 40-8 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: release 6740:6743 transaction 13 out, still active binder: unexpected work type, 4, not freed binder: undelivered TRANSACTION_COMPLETE binder: undelivered TRANSACTION_ERROR: 29201 binder: send failed reply for transaction 13, target dead sctp: [Deprecated]: syz-executor0 (pid 6800) Use of int in maxseg socket option. Use struct sctp_assoc_value instead binder: 6810:6815 got new transaction with bad transaction stack, transaction 19 has target 6810:0 binder: 6810:6815 transaction failed 29201/-71, size 24-8 line 2815 binder_alloc: binder_alloc_mmap_handler: 6810 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 6810:6831 ioctl 40046207 0 returned -16 binder_alloc: 6810: binder_alloc_buf, no vma binder: 6810:6815 transaction failed 29189/-3, size 40-8 line 2903 binder_alloc: 6810: binder_alloc_buf, no vma binder: 6810:6845 transaction failed 29189/-3, size 24-8 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: release 6810:6815 transaction 19 out, still active binder: send failed reply for transaction 19, target dead QAT: Invalid ioctl syz-executor7 uses obsolete (PF_INET,SOCK_PACKET) QAT: Invalid ioctl