============================================ WARNING: possible recursive locking detected 4.15.0-rc8+ #269 Not tainted -------------------------------------------- syz-executor4/6895 is trying to acquire lock: (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 but task is already holding lock: (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] 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-executor4/6895: #0: (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_dev_lock_vqs drivers/vhost/vhost.c:907 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_process_iotlb_msg drivers/vhost/vhost.c:997 [inline] #0: (&vq->mutex){+.+.}, at: [<0000000050f93ee8>] vhost_chr_write_iter+0x278/0x1580 drivers/vhost/vhost.c:1046 stack backtrace: CPU: 1 PID: 6895 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 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:00007f16e0644c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452ee9 RDX: 0000000000000068 RSI: 00000000201c4000 RDI: 0000000000000013 RBP: 000000000000042c R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f54c0 R13: 00000000ffffffff R14: 00007f16e06456d4 R15: 0000000000000000 kvm_pmu: event creation failed -2 kvm [7078]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0x187 data 0xffffffffffffffff QAT: Invalid ioctl QAT: Invalid ioctl binder: 7247:7250 ioctl 893f 20dadfb0 returned -22 binder_alloc: binder_alloc_mmap_handler: 7247 20000000-20002000 already mapped failed -16 binder: BINDER_SET_CONTEXT_MGR already set binder_alloc: 7247: binder_alloc_buf, no vma binder: 7247:7250 ioctl 40046207 0 returned -16 binder: 7247:7263 transaction failed 29189/-3, size 40-8 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: release 7247:7250 transaction 21 out, still active binder: unexpected work type, 4, not freed binder: undelivered TRANSACTION_COMPLETE binder: send failed reply for transaction 21, target dead netlink: 3 bytes leftover after parsing attributes in process `syz-executor6'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor6'. kauditd_printk_skb: 107 callbacks suppressed audit: type=1326 audit(1516425895.695:265): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 netlink: 12 bytes leftover after parsing attributes in process `syz-executor2'. netlink: 12 bytes leftover after parsing attributes in process `syz-executor2'. audit: type=1326 audit(1516425895.740:266): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=130 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.740:267): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.740:268): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.743:269): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=55 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.743:270): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.743:271): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.744:272): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=54 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.744:273): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 comm="syz-executor4" exe="/root/syz-executor4" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425895.744:274): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=7622 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 capability: warning: `syz-executor0' uses deprecated v2 capabilities in a way that may be insecure sock: sock_set_timeout: `syz-executor7' (pid 7861) tries to set negative timeout sock: sock_set_timeout: `syz-executor7' (pid 7875) tries to set negative timeout SELinux: policydb version 127508616 does not match my version range 15-31 SELinux: failed to load policy openvswitch: netlink: Key 13 has unexpected len 0 expected 24 netlink: 'syz-executor4': attribute type 1 has an invalid length. openvswitch: netlink: Key 13 has unexpected len 0 expected 24 binder: 8055 RLIMIT_NICE not set netlink: 'syz-executor4': attribute type 1 has an invalid length. binder_alloc: 8054: binder_alloc_buf, no vma binder: 8054:8068 transaction failed 29189/-3, size 0-0 line 2903 binder: BINDER_SET_CONTEXT_MGR already set binder: 8054:8075 ioctl 40046207 0 returned -16 binder_alloc: 8054: binder_alloc_buf, no vma binder: 8054:8076 transaction failed 29189/-3, size 0-0 line 2903 binder: undelivered TRANSACTION_ERROR: 29189 binder: undelivered TRANSACTION_ERROR: 29189 syz-executor3 uses obsolete (PF_INET,SOCK_PACKET) sock: sock_set_timeout: `syz-executor5' (pid 8153) tries to set negative timeout sock: sock_set_timeout: `syz-executor5' (pid 8153) tries to set negative timeout cgroup: cgroup2: unknown option "" cgroup: cgroup2: unknown option "" rfkill: input handler disabled rfkill: input handler enabled rfkill: input handler disabled rfkill: input handler enabled netlink: 8 bytes leftover after parsing attributes in process `syz-executor2'. dccp_close: ABORT with 4294967275 bytes unread kauditd_printk_skb: 204 callbacks suppressed audit: type=1400 audit(1516425900.756:479): avc: denied { getrlimit } for pid=8838 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=process permissive=1 audit: type=1326 audit(1516425900.861:480): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:481): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:482): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=114 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:483): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:484): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:485): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=257 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:486): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:487): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=202 compat=0 ip=0x452ee9 code=0x7ffc0000 audit: type=1326 audit(1516425900.862:488): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=8876 comm="syz-executor1" exe="/root/syz-executor1" sig=0 arch=c000003e syscall=321 compat=0 ip=0x452ee9 code=0x7ffc0000 dccp_close: ABORT with 1 bytes unread binder: 9156 RLIMIT_NICE not set binder: 9156 RLIMIT_NICE not set binder: BINDER_SET_CONTEXT_MGR already set binder: 9149:9173 ioctl 40046207 0 returned -16 binder_alloc: 9149: binder_alloc_buf, no vma binder: 9149:9186 transaction failed 29189/-3, size 0-0 line 2903 binder: 9149:9192 BC_FREE_BUFFER u000000002000c000 no match binder: undelivered TRANSACTION_ERROR: 29189 binder: undelivered TRANSACTION_COMPLETE binder: 9237 RLIMIT_NICE not set binder: 9237 RLIMIT_NICE not set binder: undelivered TRANSACTION_COMPLETE binder: 9272 RLIMIT_NICE not set binder: 9272 RLIMIT_NICE not set binder: undelivered TRANSACTION_COMPLETE