============================================ WARNING: possible recursive locking detected 4.15.0-rc8+ #269 Not tainted -------------------------------------------- syz-executor2/20287 is trying to acquire lock: (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 but task is already holding lock: (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<00000000c4784259>] 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-executor2/20287: #0: (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] #0: (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] #0: (&vq->mutex){+.+.}, at: [<00000000c4784259>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 stack backtrace: CPU: 0 PID: 20287 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 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:00007f56a7187c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bec8 RCX: 0000000000452ee9 RDX: 0000000000000068 RSI: 00000000208baf98 RDI: 0000000000000015 RBP: 000000000071bec8 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000 R13: 0000000000a2f7cf R14: 00007f56a71889c0 R15: 0000000000000000 binder: 20259:20302 ERROR: BC_REGISTER_LOOPER called without request sit: non-ECT from 172.20.7.0 with TOS=0x3 openvswitch: netlink: Key type 256 is out of range max 29 sit: non-ECT from 172.20.7.0 with TOS=0x3 binder: 20259:20280 ioctl 40046207 0 returned -16 binder_alloc: 20259: binder_alloc_buf, no vma binder: 20259:20265 transaction failed 29189/-3, size 0-0 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: send failed reply for transaction 109 to 20259:20265 binder: undelivered TRANSACTION_COMPLETE binder: undelivered TRANSACTION_ERROR: 29189 SELinux: policydb string SE Linux does not match my string SE Linux SELinux: failed to load policy SELinux: policydb string SE Linux does not match my string SE Linux SELinux: failed to load policy binder: 20653:20658 ioctl c0306201 20009fd0 returned -14 binder: 20653:20672 ioctl c0306201 20009fd0 returned -14 binder: 20735:20739 ERROR: BC_REGISTER_LOOPER called without request binder: release 20735:20739 transaction 112 out, still active binder: undelivered TRANSACTION_COMPLETE binder: 20735:20756 got reply transaction with no transaction stack binder: 20735:20756 transaction failed 29201/-71, size 0-0 line 2703 binder_alloc: binder_alloc_mmap_handler: 20735 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 20735:20768 ERROR: BC_REGISTER_LOOPER called without request binder: 20768 RLIMIT_NICE not set binder: 20735:20770 got reply transaction with no transaction stack binder: 20735:20770 transaction failed 29201/-71, size 0-0 line 2703 binder: 20735:20739 ioctl 40046207 0 returned -16 binder_alloc: 20735: binder_alloc_buf, no vma binder: 20735:20756 transaction failed 29189/-3, size 0-0 line 2903 binder: undelivered TRANSACTION_ERROR: 29201 binder: undelivered TRANSACTION_ERROR: 29201 binder: send failed reply for transaction 112, target dead binder: undelivered TRANSACTION_ERROR: 29189 QAT: Invalid ioctl QAT: Invalid ioctl syz-executor6: vmalloc: allocation failure: 0 bytes, mode:0x14000c0(GFP_KERNEL), nodemask=(null) syz-executor6 cpuset=/ mems_allowed=0 CPU: 1 PID: 21026 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:00007f3fea0d4c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000000 RSI: 0000000020cf4000 RDI: 0000000000000014 RBP: 000000000000041c R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f5340 R13: 00000000ffffffff R14: 00007f3fea0d56d4 R15: 0000000000000000 Mem-Info: active_anon:85598 inactive_anon:60 isolated_anon:0 active_file:3600 inactive_file:8224 isolated_file:0 unevictable:0 dirty:104 writeback:0 unstable:0 slab_reclaimable:11280 slab_unreclaimable:93994 mapped:23791 shmem:69 pagetables:749 bounce:0 free:1399164 free_pcp:408 free_cma:0 Node 0 active_anon:334032kB inactive_anon:240kB active_file:14400kB inactive_file:32896kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:95164kB dirty:416kB writeback:0kB shmem:276kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 139264kB 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:148kB free_cma:0kB lowmem_reserve[]: 0 0 3510 3510 Node 0 Normal free:2654052kB min:37084kB low:46352kB high:55620kB active_anon:329752kB inactive_anon:240kB active_file:14400kB inactive_file:32896kB unevictable:0kB writepending:416kB present:4718592kB managed:3594628kB mlocked:0kB kernel_stack:4000kB pagetables:2848kB bounce:0kB free_pcp:1332kB local_pcp:680kB 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: 4*4kB (UM) 2*8kB (U) 5*16kB (UM) 2*32kB (UM) 3*64kB (M) 4*128kB (M) 5*256kB (UM) 3*512kB (UM) 3*1024kB (UM) 3*2048kB (UM) 715*4096kB (M) = 2941552kB Node 0 Normal: 683*4kB (UME) 423*8kB (UME) 440*16kB (UME) 916*32kB (UM) 370*64kB (UM) 63*128kB (UME) 30*256kB (UME) 10*512kB (UME) 9*1024kB (UME) 3*2048kB (ME) 623*4096kB (M) = 2654180kB Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 11892 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: 21050 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:00007f3fea0b3c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 00007f3fea0b4700 RCX: 0000000000452ee9 RDX: 0000000000000000 RSI: 0000000020cf4000 RDI: 0000000000000014 RBP: 0000000000a2f850 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000 R13: 0000000000a2f7cf R14: 00007f3fea0b49c0 R15: 0000000000000000 binder: 21068:21072 ioctl c0306201 204edfd0 returned -14 binder: 21068:21083 ioctl c0306201 204edfd0 returned -14 sctp: [Deprecated]: syz-executor7 (pid 21101) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead sctp: [Deprecated]: syz-executor7 (pid 21101) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead rfkill: input handler disabled rfkill: input handler enabled rfkill: input handler disabled rfkill: input handler enabled PPPIOCDETACH file->f_count=2 PPPIOCDETACH file->f_count=2 binder: 21191:21195 ioctl c0046209 20001000 returned -22 kauditd_printk_skb: 139 callbacks suppressed audit: type=1400 audit(1516426148.585:3435): avc: denied { map_read map_write } for pid=21216 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=bpf permissive=1 binder: BINDER_SET_CONTEXT_MGR already set binder: 21222:21223 ioctl 40046207 0 returned -16 audit: type=1326 audit(1516426148.916:3436): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21301 comm="syz-executor3" exe="/root/syz-executor3" sig=31 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x0 audit: type=1326 audit(1516426149.408:3437): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3438): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3439): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=148 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3440): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3441): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3442): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=292 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3443): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516426149.408:3444): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=21435 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 binder: 21641:21648 unknown command 1074291675 binder: 21641:21648 ioctl c0306201 20041fd0 returned -22 binder: 21641:21666 unknown command 1074291675 binder: 21641:21666 ioctl c0306201 20041fd0 returned -22 tmpfs: No value for mount option '«' tmpfs: No value for mount option '«' binder: 21796:21798 ERROR: BC_REGISTER_LOOPER called without request binder: 21798 RLIMIT_NICE not set binder: 21798 RLIMIT_NICE not set binder: 21796:21813 got reply transaction with bad transaction stack, transaction 120 has target 21796:21798 binder: 21796:21813 transaction failed 29201/-71, size 24-8 line 2718 binder: release 21796:21798 transaction 120 in, still active binder: send failed reply for transaction 120 to 21796:21813 binder: undelivered TRANSACTION_COMPLETE binder: 21796:21813 ERROR: BC_REGISTER_LOOPER called without request binder: 21813 RLIMIT_NICE not set binder: 21796:21798 unknown command 76 binder: 21796:21798 ioctl c0306201 2000a000 returned -22 binder: 21796:21813 got reply transaction with no transaction stack binder: 21796:21813 transaction failed 29201/-71, size 24-8 line 2703 binder: undelivered TRANSACTION_ERROR: 29201 binder: undelivered TRANSACTION_ERROR: 29189 binder: undelivered TRANSACTION_ERROR: 29201 binder: 21903:21915 tried to acquire reference to desc 0, got 1 instead binder: tried to use weak ref as strong ref binder: 21903:21925 Acquire 1 refcount change on invalid ref 1 ret -22 binder: BINDER_SET_CONTEXT_MGR already set binder: 21903:21925 ioctl 40046207 0 returned -16 binder: BINDER_SET_CONTEXT_MGR already set binder: 21903:21925 ioctl 40046207 0 returned -16 sctp: [Deprecated]: syz-executor5 (pid 22111) Use of int in maxseg socket option. Use struct sctp_assoc_value instead sctp: [Deprecated]: syz-executor5 (pid 22111) Use of int in maxseg socket option. Use struct sctp_assoc_value instead binder: 22134 RLIMIT_NICE not set binder: 22134 RLIMIT_NICE not set binder: 22120:22134 BC_DEAD_BINDER_DONE 0000000000000003 not found binder: 22120:22149 tried to acquire reference to desc 0, got 1 instead binder: 22120:22134 BC_CLEAR_DEATH_NOTIFICATION invalid ref 0 binder: 22134 RLIMIT_NICE not set binder: 22120:22149 unknown command 536907575 binder: 22120:22149 ioctl c0306201 20008fd0 returned -22 binder: 22120:22149 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0 binder: 22120:22159 BC_DEAD_BINDER_DONE 0000000000000003 not found binder: undelivered death notification, 0000000000000000 kauditd_printk_skb: 120 callbacks suppressed audit: type=1400 audit(1516426153.706:3565): avc: denied { map } for pid=22434 comm="sh" path="/bin/dash" dev="sda1" ino=1473 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready