============================================ WARNING: possible recursive locking detected 4.15.0-rc8+ #269 Not tainted -------------------------------------------- syz-executor1/6034 is trying to acquire lock: (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 but task is already holding lock: (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] 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/6034: #0: (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000036fbd5ed>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 stack backtrace: CPU: 1 PID: 6034 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:00007fde5aa7dc58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 00007fde5aa7e700 RCX: 0000000000452ee9 RDX: 0000000000000068 RSI: 0000000020977f98 RDI: 0000000000000013 RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000 R13: 0000000000a2f7cf R14: 00007fde5aa7e9c0 R15: 0000000000000000 capability: warning: `syz-executor3' uses deprecated v2 capabilities in a way that may be insecure syz-executor4: vmalloc: allocation failure: 17146314752 bytes, mode:0x14080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null) binder: BINDER_SET_CONTEXT_MGR already set binder: 6106:6125 ioctl 40046207 0 returned -16 binder_alloc: 6106: binder_alloc_buf, no vma binder: 6106:6110 transaction failed 29189/-3, size 40-8 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: release 6106:6110 transaction 5 out, still active binder: unexpected work type, 4, not freed binder: undelivered TRANSACTION_COMPLETE binder: send failed reply for transaction 5, target dead syz-executor4: vmalloc: allocation failure: 17146314752 bytes, mode:0x14080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null) syz-executor4 cpuset=/ mems_allowed=0 CPU: 1 PID: 6133 Comm: syz-executor4 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 warn_alloc+0x19a/0x2b0 mm/page_alloc.c:3299 __vmalloc_node_range+0x4f0/0x650 mm/vmalloc.c:1775 __vmalloc_node mm/vmalloc.c:1804 [inline] __vmalloc_node_flags_caller+0x50/0x60 mm/vmalloc.c:1826 kvmalloc_node+0x82/0xd0 mm/util.c:406 kvmalloc include/linux/mm.h:541 [inline] kvzalloc include/linux/mm.h:549 [inline] kvm_arch_create_memslot+0xa7/0x470 arch/x86/kvm/x86.c:8356 __kvm_set_memory_region+0x1940/0x24d0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:994 kvm_set_memory_region+0x2e/0x50 arch/x86/kvm/../../../virt/kvm/kvm_main.c:1066 kvm_vm_ioctl_set_memory_region arch/x86/kvm/../../../virt/kvm/kvm_main.c:1078 [inline] kvm_vm_ioctl+0x1111/0x1c60 arch/x86/kvm/../../../virt/kvm/kvm_main.c:2981 vfs_ioctl fs/ioctl.c:46 [inline] do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:686 SYSC_ioctl fs/ioctl.c:701 [inline] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f92b749ec58 EFLAGS: 00000212 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000071c010 RCX: 0000000000452ee9 RDX: 0000000020005fe0 RSI: 000000004020ae46 RDI: 0000000000000016 RBP: 00000000000003d6 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f4cb0 R13: 00000000ffffffff R14: 00007f92b749f6d4 R15: 0000000000000002 Mem-Info: active_anon:75604 inactive_anon:83 isolated_anon:0 active_file:3519 inactive_file:7926 isolated_file:0 unevictable:0 dirty:13 writeback:0 unstable:0 slab_reclaimable:6646 slab_unreclaimable:92598 mapped:23769 shmem:90 pagetables:782 bounce:0 free:1414517 free_pcp:397 free_cma:0 Node 0 active_anon:302416kB inactive_anon:332kB active_file:14076kB inactive_file:31704kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:95076kB dirty:52kB writeback:0kB shmem:360kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 129024kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no Node 0 DMA free:15908kB min:164kB low:204kB high:244kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB lowmem_reserve[]: 0 2870 6381 6381 Node 0 DMA32 free:2941552kB min:30332kB low:37912kB high:45492kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:3129332kB managed:2942340kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:788kB local_pcp:612kB free_cma:0kB lowmem_reserve[]: 0 0 3510 3510 Node 0 Normal free:2700608kB min:37084kB low:46352kB high:55620kB active_anon:302416kB inactive_anon:332kB active_file:14076kB inactive_file:31704kB unevictable:0kB writepending:152kB present:4718592kB managed:3594628kB mlocked:0kB kernel_stack:4448kB pagetables:3128kB bounce:0kB free_pcp:800kB local_pcp:184kB free_cma:0kB lowmem_reserve[]: 0 0 0 0 Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15908kB Node 0 DMA32: 2*4kB (M) 1*8kB (U) 4*16kB (UM) 1*32kB (M) 4*64kB (UM) 4*128kB (M) 5*256kB (UM) 3*512kB (UM) 3*1024kB (UM) 3*2048kB (UM) 715*4096kB (M) = 2941552kB Node 0 Normal: 1138*4kB (UM) 168*8kB (UME) 1189*16kB (UME) 403*32kB (UME) 58*64kB (UME) 14*128kB (UME) 8*256kB (UME) 10*512kB (UME) 2*1024kB (M) 5*2048kB (UME) 644*4096kB (M) = 2700600kB Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 11534 total pagecache pages 0 pages in swap cache Swap cache stats: add 0, delete 0, find 0/0 Free swap = 0kB Total swap = 0kB 1965979 pages RAM 0 pages HighMem/MovableOnly 327760 pages reserved syz-executor4 cpuset=/ mems_allowed=0 CPU: 1 PID: 6112 Comm: syz-executor4 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 warn_alloc+0x19a/0x2b0 mm/page_alloc.c:3299 __vmalloc_node_range+0x4f0/0x650 mm/vmalloc.c:1775 __vmalloc_node mm/vmalloc.c:1804 [inline] __vmalloc_node_flags_caller+0x50/0x60 mm/vmalloc.c:1826 kvmalloc_node+0x82/0xd0 mm/util.c:406 kvmalloc include/linux/mm.h:541 [inline] kvzalloc include/linux/mm.h:549 [inline] kvm_arch_create_memslot+0xa7/0x470 arch/x86/kvm/x86.c:8356 __kvm_set_memory_region+0x1940/0x24d0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:994 kvm_set_memory_region+0x2e/0x50 arch/x86/kvm/../../../virt/kvm/kvm_main.c:1066 kvm_vm_ioctl_set_memory_region arch/x86/kvm/../../../virt/kvm/kvm_main.c:1078 [inline] kvm_vm_ioctl+0x1111/0x1c60 arch/x86/kvm/../../../virt/kvm/kvm_main.c:2981 vfs_ioctl fs/ioctl.c:46 [inline] do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:686 SYSC_ioctl fs/ioctl.c:701 [inline] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f92b74e0c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000020005fe0 RSI: 000000004020ae46 RDI: 0000000000000014 RBP: 0000000000000580 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f74a0 R13: 00000000ffffffff R14: 00007f92b74e16d4 R15: 0000000000000000 SELinux: unknown mount option SELinux: unknown mount option binder: 6261:6263 transaction failed 29189/-22, size 0-0 line 2788 binder: 6261:6268 transaction failed 29189/-22, size 0-0 line 2788 IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready kauditd_printk_skb: 38 callbacks suppressed audit: type=1400 audit(1516426265.589:285): avc: denied { map } for pid=6749 comm="syz-executor7" path=2F6D656D66643A24202864656C6574656429 dev="tmpfs" ino=16830 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:tmpfs_t:s0 tclass=file permissive=1 QAT: Invalid ioctl QAT: Invalid ioctl audit: type=1400 audit(1516426266.140:286): avc: denied { name_connect } for pid=6897 comm="syz-executor7" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:port_t:s0 tclass=dccp_socket permissive=1 binder: 6960:6964 got new transaction with bad transaction stack, transaction 12 has target 6960:0 binder: 6960:6964 transaction failed 29201/-71, size 24-8 line 2815 binder_alloc: binder_alloc_mmap_handler: 6960 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 6960:6964 ioctl 40046207 0 returned -16 binder_alloc: 6960: binder_alloc_buf, no vma binder: 6960:6982 transaction failed 29189/-3, size 40-8 line 2903 binder: release 6960:6964 transaction 12 out, still active binder: send failed reply for transaction 12, target dead audit: type=1400 audit(1516426266.600:287): avc: denied { setgid } for pid=7018 comm="syz-executor5" capability=6 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(1516426266.690:288): avc: denied { name_bind } for pid=7060 comm="syz-executor5" src=20020 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:port_t:s0 tclass=dccp_socket permissive=1 audit: type=1400 audit(1516426266.690:289): avc: denied { node_bind } for pid=7060 comm="syz-executor5" saddr=::1 src=20020 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:node_t:s0 tclass=dccp_socket permissive=1 dccp_close: ABORT with 13 bytes unread audit: type=1400 audit(1516426267.191:290): avc: denied { map } for pid=7221 comm="syz-executor0" path="/selinux/status" dev="selinuxfs" ino=19 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:security_t:s0 tclass=file permissive=1 audit: type=1400 audit(1516426267.383:291): avc: denied { map } for pid=7276 comm="syz-executor1" path="/dev/sg0" dev="devtmpfs" ino=1056 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(1516426267.690:292): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7374 comm="syz-executor0" exe="/root/syz-executor0" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426267.690:293): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7374 comm="syz-executor0" exe="/root/syz-executor0" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426267.690:294): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7374 comm="syz-executor0" exe="/root/syz-executor0" sig=0 arch=c000003e syscall=2 compat=0 ip=0x40d1e1 code=0x7ffc0000 sock: sock_set_timeout: `syz-executor3' (pid 7414) tries to set negative timeout netlink: 14 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 14 bytes leftover after parsing attributes in process `syz-executor1'. kauditd_printk_skb: 18 callbacks suppressed audit: type=1326 audit(1516426270.626:311): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.626:312): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.632:313): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=41 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.633:314): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.633:315): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.642:316): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=55 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.642:317): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.642:318): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.643:319): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=55 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426270.644:320): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7977 comm="syz-executor5" exe="/root/syz-executor5" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000