============================================ WARNING: possible recursive locking detected 4.15.0-rc8+ #269 Not tainted -------------------------------------------- syz-executor7/6001 is trying to acquire lock: (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 but task is already holding lock: (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<00000000481017ef>] 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-executor7/6001: #0: (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] #0: (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] #0: (&vq->mutex){+.+.}, at: [<00000000481017ef>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 stack backtrace: CPU: 1 PID: 6001 Comm: syz-executor7 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:00007fc61a033c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000068 RSI: 0000000020977f98 RDI: 0000000000000013 RBP: 00000000000003d6 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f4cb0 R13: 00000000ffffffff R14: 00007fc61a0346d4 R15: 0000000000000000 kauditd_printk_skb: 67 callbacks suppressed audit: type=1400 audit(1516426215.658:105): avc: denied { ipc_lock } for pid=6084 comm="syz-executor6" 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(1516426215.817:106): avc: denied { create } for pid=6095 comm="syz-executor7" 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 syz-executor6: vmalloc: allocation failure: 0 bytes, mode:0x14000c0(GFP_KERNEL), nodemask=(null) audit: type=1400 audit(1516426216.519:107): avc: denied { set_context_mgr } for pid=6321 comm="syz-executor0" 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 audit: type=1400 audit(1516426216.521:108): avc: denied { getopt } for pid=6321 comm="syz-executor0" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1 binder: 6323 RLIMIT_NICE not set binder: 6323 RLIMIT_NICE not set sctp: [Deprecated]: syz-executor5 (pid 6333) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead sctp: [Deprecated]: syz-executor5 (pid 6337) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead binder: 6321:6342 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0 binder: 6321:6323 BC_CLEAR_DEATH_NOTIFICATION invalid ref 0 binder: 6323 RLIMIT_NICE not set binder: 6321:6342 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0 binder: 6323 RLIMIT_NICE not set binder: 6321:6342 BC_DEAD_BINDER_DONE 0000000000000003 not found binder: undelivered death notification, 0000000000000000 syz-executor6 cpuset=/ mems_allowed=0 CPU: 0 PID: 6320 Comm: syz-executor6 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 mm/vmalloc.c:1818 [inline] vmalloc+0x45/0x50 mm/vmalloc.c:1840 sel_write_load+0x1f5/0x1910 security/selinux/selinuxfs.c:495 __vfs_write+0xef/0x970 fs/read_write.c:480 vfs_write+0x189/0x510 fs/read_write.c:544 SYSC_pwrite64 fs/read_write.c:631 [inline] SyS_pwrite64+0x15b/0x190 fs/read_write.c:618 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f3321e64c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000000 RSI: 000000002037d000 RDI: 0000000000000013 RBP: 0000000000000648 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f8760 R13: 00000000ffffffff R14: 00007f3321e656d4 R15: 0000000000000000 Mem-Info: active_anon:75753 inactive_anon:63 isolated_anon:0 active_file:3498 inactive_file:7918 isolated_file:0 unevictable:0 dirty:5914 writeback:0 unstable:0 slab_reclaimable:6906 slab_unreclaimable:92524 mapped:23673 shmem:70 pagetables:668 bounce:0 free:1417699 free_pcp:534 free_cma:0 Node 0 active_anon:303012kB inactive_anon:252kB active_file:13992kB inactive_file:31672kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:94692kB dirty:23656kB writeback:0kB shmem:280kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 135168kB 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:624kB free_cma:0kB lowmem_reserve[]: 0 0 3510 3510 Node 0 Normal free:2713400kB min:37084kB low:46352kB high:55620kB active_anon:303012kB inactive_anon:252kB active_file:13992kB inactive_file:31672kB unevictable:0kB writepending:23668kB present:4718592kB managed:3594628kB mlocked:0kB kernel_stack:3744kB pagetables:2672kB bounce:0kB free_pcp:1336kB local_pcp:624kB 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: 856*4kB (UM) 89*8kB (UME) 781*16kB (UME) 577*32kB (UME) 97*64kB (UME) 32*128kB (UME) 16*256kB (UME) 5*512kB (M) 3*1024kB (M) 6*2048kB (UME) 646*4096kB (M) = 2713432kB Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 11491 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-executor6: vmalloc: allocation failure: 0 bytes, mode:0x14000c0(GFP_KERNEL), nodemask=(null) syz-executor6 cpuset=/ mems_allowed=0 CPU: 1 PID: 6335 Comm: syz-executor6 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 mm/vmalloc.c:1818 [inline] vmalloc+0x45/0x50 mm/vmalloc.c:1840 sel_write_load+0x1f5/0x1910 security/selinux/selinuxfs.c:495 __vfs_write+0xef/0x970 fs/read_write.c:480 vfs_write+0x189/0x510 fs/read_write.c:544 SYSC_pwrite64 fs/read_write.c:631 [inline] SyS_pwrite64+0x15b/0x190 fs/read_write.c:618 entry_SYSCALL_64_fastpath+0x29/0xa0 RIP: 0033:0x452ee9 RSP: 002b:00007f3321e43c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 000000000071bf58 RCX: 0000000000452ee9 RDX: 0000000000000000 RSI: 000000002037d000 RDI: 0000000000000017 RBP: 00000000000003d6 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f4cb0 R13: 00000000ffffffff R14: 00007f3321e446d4 R15: 0000000000000006 audit: type=1326 audit(1516426217.475:109): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426217.475:110): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426217.475:111): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=72 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426217.475:112): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426217.475:113): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426217.475:114): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=6357 comm="syz-executor2" exe="/root/syz-executor2" sig=0 arch=c000003e syscall=43 compat=0 ip=0x452ee9 code=0x7ffc0000 TCP: request_sock_TCP: Possible SYN flooding on port 20009. Sending cookies. Check SNMP counters. PPPIOCDETACH file->f_count=2 binder: BINDER_SET_CONTEXT_MGR already set binder: 6910:6936 ioctl 40046207 0 returned -16 binder: 6910:6918 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0 binder: 6910:6936 Release 1 refcount change on invalid ref 0 ret -22 SELinux: unknown mount option SELinux: unknown mount option QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl TCP: request_sock_TCPv6: Possible SYN flooding on port 20030. Sending cookies. Check SNMP counters. ptrace attach of "/root/syz-executor3"[4443] was attempted by "/root/syz-executor3"[7384] ptrace attach of "/root/syz-executor3"[4443] was attempted by "/root/syz-executor3"[7400] QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl SELinux: policydb string length 327 does not match expected length 8 SELinux: failed to load policy QAT: Invalid ioctl QAT: Invalid ioctl binder: 7603 RLIMIT_NICE not set kauditd_printk_skb: 71 callbacks suppressed audit: type=1326 audit(1516426221.390:186): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.390:187): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=266 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.390:188): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.390:189): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=9 compat=0 ip=0x452ee9 code=0x7ffc0000 binder: 7586:7651 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0 binder: 7648 RLIMIT_NICE not set binder: 7586:7648 BC_DEAD_BINDER_DONE 0000000000000000 not found audit: type=1326 audit(1516426221.396:190): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.396:191): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=257 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.396:192): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.396:193): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.396:194): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=257 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426221.396:195): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7634 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 QAT: Invalid ioctl QAT: Invalid ioctl kvm [7659]: vcpu0, guest rIP: 0xfff0 Hyper-V unhandled rdmsr: 0x40000085 QAT: Invalid ioctl QAT: Invalid ioctl kvm [7659]: vcpu0, guest rIP: 0xfff0 Hyper-V unhandled rdmsr: 0x40000085 binder: 7736:7744 ioctl c0306201 204edfd0 returned -14 kvm: vcpu 3: requested 10176 ns lapic timer period limited to 500000 ns kvm: vcpu 3: requested 10176 ns lapic timer period limited to 500000 ns netlink: 40 bytes leftover after parsing attributes in process `syz-executor0'. netlink: 40 bytes leftover after parsing attributes in process `syz-executor0'.