====================================================== WARNING: possible circular locking dependency detected 4.14.0-rc4-next-20171009+ #33 Not tainted ------------------------------------------------------ loop0/9841 is trying to acquire lock: (&sb->s_type->i_mutex_key#9){++++}, at: [] inode_lock include/linux/fs.h:712 [inline] (&sb->s_type->i_mutex_key#9){++++}, at: [] generic_file_write_iter+0xdc/0x7a0 mm/filemap.c:3175 but now in release context of a crosslock acquired at the following: ((complete)&ret.event){+.+.}, at: [] submit_bio_wait+0x15e/0x200 block/bio.c:953 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #4 ((complete)&ret.event){+.+.}: lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 complete_acquire include/linux/completion.h:39 [inline] __wait_for_common kernel/sched/completion.c:108 [inline] wait_for_common_io kernel/sched/completion.c:128 [inline] wait_for_completion_io+0xcb/0x7b0 kernel/sched/completion.c:176 submit_bio_wait+0x15e/0x200 block/bio.c:953 blkdev_issue_zeroout+0x13c/0x1d0 block/blk-lib.c:370 sb_issue_zeroout include/linux/blkdev.h:1363 [inline] ext4_init_inode_table+0x4fd/0xdb1 fs/ext4/ialloc.c:1447 ext4_run_li_request fs/ext4/super.c:2868 [inline] ext4_lazyinit_thread+0x808/0xd30 fs/ext4/super.c:2962 kthread+0x3c9/0x4b0 kernel/kthread.c:242 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 -> #3 (&meta_group_info[i]->alloc_sem){++++}: lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 down_read+0x96/0x150 kernel/locking/rwsem.c:23 __ext4_new_inode+0x26dc/0x4f00 fs/ext4/ialloc.c:1056 ext4_symlink+0x2d9/0xae0 fs/ext4/namei.c:3118 vfs_symlink+0x323/0x560 fs/namei.c:4115 SYSC_symlinkat fs/namei.c:4142 [inline] SyS_symlinkat fs/namei.c:4122 [inline] SYSC_symlink fs/namei.c:4155 [inline] SyS_symlink+0x134/0x200 fs/namei.c:4153 entry_SYSCALL_64_fastpath+0x1f/0xbe -> #2 (jbd2_handle){++++}: lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 start_this_handle+0x4b8/0x1080 fs/jbd2/transaction.c:390 jbd2__journal_start+0x389/0x9f0 fs/jbd2/transaction.c:444 __ext4_journal_start_sb+0x15f/0x550 fs/ext4/ext4_jbd2.c:80 __ext4_journal_start fs/ext4/ext4_jbd2.h:314 [inline] ext4_dirty_inode+0x56/0xa0 fs/ext4/inode.c:5897 __mark_inode_dirty+0x912/0x1170 fs/fs-writeback.c:2129 generic_update_time+0x1b2/0x270 fs/inode.c:1649 update_time fs/inode.c:1665 [inline] touch_atime+0x26d/0x2f0 fs/inode.c:1737 file_accessed include/linux/fs.h:2061 [inline] ext4_file_mmap+0x161/0x1b0 fs/ext4/file.c:353 call_mmap include/linux/fs.h:1775 [inline] mmap_region+0xa99/0x15a0 mm/mmap.c:1690 do_mmap+0x6a1/0xd50 mm/mmap.c:1468 do_mmap_pgoff include/linux/mm.h:2180 [inline] vm_mmap_pgoff+0x1de/0x280 mm/util.c:333 SYSC_mmap_pgoff mm/mmap.c:1518 [inline] SyS_mmap_pgoff+0x462/0x5f0 mm/mmap.c:1476 SYSC_mmap arch/x86/kernel/sys_x86_64.c:99 [inline] SyS_mmap+0x16/0x20 arch/x86/kernel/sys_x86_64.c:90 entry_SYSCALL_64_fastpath+0x1f/0xbe -> #1 (&mm->mmap_sem){++++}: lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 __might_fault+0x13a/0x1d0 mm/memory.c:4541 _copy_to_user+0x2c/0xc0 lib/usercopy.c:24 copy_to_user include/linux/uaccess.h:154 [inline] filldir+0x1a7/0x320 fs/readdir.c:196 dir_emit_dot include/linux/fs.h:3341 [inline] dir_emit_dots include/linux/fs.h:3352 [inline] dcache_readdir+0x12d/0x5e0 fs/libfs.c:193 iterate_dir+0x4b2/0x5d0 fs/readdir.c:51 SYSC_getdents fs/readdir.c:231 [inline] SyS_getdents+0x225/0x450 fs/readdir.c:212 entry_SYSCALL_64_fastpath+0x1f/0xbe -> #0 (&sb->s_type->i_mutex_key#9){++++}: inode_lock include/linux/fs.h:712 [inline] generic_file_write_iter+0xdc/0x7a0 mm/filemap.c:3175 call_write_iter include/linux/fs.h:1770 [inline] do_iter_readv_writev+0x531/0x7f0 fs/read_write.c:673 do_iter_write+0x15a/0x540 fs/read_write.c:952 vfs_iter_write+0x77/0xb0 fs/read_write.c:965 lo_write_bvec+0x12b/0x3b0 drivers/block/loop.c:272 other info that might help us debug this: Chain exists of: &sb->s_type->i_mutex_key#9 --> &meta_group_info[i]->alloc_sem --> (complete)&ret.event Possible unsafe locking scenario by crosslock: CPU0 CPU1 ---- ---- lock(&meta_group_info[i]->alloc_sem); lock((complete)&ret.event); lock(&sb->s_type->i_mutex_key#9); unlock((complete)&ret.event); *** DEADLOCK *** 1 lock held by loop0/9841: #0: (&x->wait#14){..-.}, at: [] complete+0x18/0x80 kernel/sched/completion.c:34 stack backtrace: CPU: 0 PID: 9841 Comm: loop0 Not tainted 4.14.0-rc4-next-20171009+ #33 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:16 [inline] dump_stack+0x194/0x257 lib/dump_stack.c:52 print_circular_bug+0x503/0x710 kernel/locking/lockdep.c:1259 check_prev_add+0x865/0x1520 kernel/locking/lockdep.c:1894 commit_xhlock kernel/locking/lockdep.c:5015 [inline] commit_xhlocks kernel/locking/lockdep.c:5059 [inline] lock_commit_crosslock+0xe59/0x1d00 kernel/locking/lockdep.c:5098 complete_release_commit include/linux/completion.h:49 [inline] complete+0x24/0x80 kernel/sched/completion.c:39 submit_bio_wait_endio+0x9c/0xd0 block/bio.c:930 bio_endio+0x2f8/0x8d0 block/bio.c:1843 req_bio_endio block/blk-core.c:204 [inline] blk_update_request+0x2a6/0xe20 block/blk-core.c:2784 blk_mq_end_request+0x54/0x120 block/blk-mq.c:512 lo_complete_rq+0xbe/0x1f0 drivers/block/loop.c:463 __blk_mq_complete_request+0x38f/0x6c0 block/blk-mq.c:553 blk_mq_complete_request+0x4f/0x60 block/blk-mq.c:573 loop_handle_cmd drivers/block/loop.c:1723 [inline] loop_queue_work+0x26b/0x3900 drivers/block/loop.c:1732 kthread_worker_fn+0x32b/0x980 kernel/kthread.c:646 loop_kthread_worker_fn+0x51/0x60 drivers/block/loop.c:841 kthread+0x3c9/0x4b0 kernel/kthread.c:242 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 nla_parse: 6 callbacks suppressed netlink: 5 bytes leftover after parsing attributes in process `syz-executor0'. SELinux: unrecognized netlink message: protocol=0 nlmsg_type=129 sclass=netlink_route_socket pig=9860 comm=syz-executor4 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=129 sclass=netlink_route_socket pig=9860 comm=syz-executor4 netlink: 3 bytes leftover after parsing attributes in process `syz-executor2'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor2'. netlink: 5 bytes leftover after parsing attributes in process `syz-executor6'. netlink: 5 bytes leftover after parsing attributes in process `syz-executor0'. program syz-executor1 is using a deprecated SCSI ioctl, please convert it to SG_IO sd 0:0:1:0: ioctl_internal_command: ILLEGAL REQUEST asc=0x20 ascq=0x0 APIC base relocation is unsupported by KVM program syz-executor1 is using a deprecated SCSI ioctl, please convert it to SG_IO sd 0:0:1:0: ioctl_internal_command: ILLEGAL REQUEST asc=0x20 ascq=0x0 device syz6 entered promiscuous mode device syz6 left promiscuous mode device syz6 entered promiscuous mode device syz6 left promiscuous mode 9pnet_virtio: no channels available for device ./file0 9pnet_virtio: no channels available for device ./file0 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=21706 sclass=netlink_route_socket pig=9977 comm=syz-executor1 QAT: Invalid ioctl QAT: Invalid ioctl SELinux: unrecognized netlink message: protocol=0 nlmsg_type=21706 sclass=netlink_route_socket pig=9977 comm=syz-executor1 QAT: Invalid ioctl QAT: Invalid ioctl netlink: 2 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 2 bytes leftover after parsing attributes in process `syz-executor4'. kvm [10072]: vcpu1, guest rIP: 0xfff0 Hyper-V uhandled wrmsr: 0x40000020 data 0xd5 device lo entered promiscuous mode RDS: rds_bind could not find a transport for 0.0.0.5, load rds_tcp or rds_rdma? device lo left promiscuous mode kvm [10072]: vcpu1, guest rIP: 0xfff0 Hyper-V uhandled wrmsr: 0x40000020 data 0xd5 RDS: rds_bind could not find a transport for 0.0.0.5, load rds_tcp or rds_rdma? audit: type=1326 audit(1508021072.554:37): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.554:38): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.554:39): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.554:40): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.555:41): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.555:42): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.555:43): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.555:44): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 audit: type=1326 audit(1508021072.555:45): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 netlink: 4 bytes leftover after parsing attributes in process `syz-executor5'. audit: type=1326 audit(1508021072.555:46): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=10164 comm=2F6587762F716175747464665F6361 exe="/root/syz-executor7" sig=0 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x50000 netlink: 4 bytes leftover after parsing attributes in process `syz-executor5'. netlink: 7 bytes leftover after parsing attributes in process `syz-executor4'. PF_BRIDGE: br_mdb_parse() with unknown ifindex PF_BRIDGE: br_mdb_parse() with unknown ifindex dccp_invalid_packet: pskb_may_pull failed dccp_invalid_packet: P.Data Offset(0) too small dccp_invalid_packet: pskb_may_pull failed dccp_invalid_packet: P.Data Offset(0) too small device syz4 entered promiscuous mode sg_write: data in/out 167162/1 bytes for SCSI command 0x67-- guessing data in; program syz-executor1 not setting count and/or reply_len properly sg_write: data in/out 167162/1 bytes for SCSI command 0x67-- guessing data in; program syz-executor1 not setting count and/or reply_len properly QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl nla_parse: 9 callbacks suppressed netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. SELinux: unrecognized netlink message: protocol=6 nlmsg_type=3131 sclass=netlink_xfrm_socket pig=11104 comm=syz-executor2 SELinux: unrecognized netlink message: protocol=6 nlmsg_type=3131 sclass=netlink_xfrm_socket pig=11104 comm=syz-executor2 QAT: Invalid ioctl netlink: 13 bytes leftover after parsing attributes in process `syz-executor7'. !: renamed from syz7 netlink: 13 bytes leftover after parsing attributes in process `syz-executor7'. device syz6 entered promiscuous mode device syz6 left promiscuous mode device syz6 entered promiscuous mode 9pnet_virtio: no channels available for device ./file0 9pnet_virtio: no channels available for device ./file0 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=35 sclass=netlink_route_socket pig=11406 comm=syz-executor1 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=35 sclass=netlink_route_socket pig=11429 comm=syz-executor1 netlink: 5 bytes leftover after parsing attributes in process `syz-executor5'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor4'. netlink: 5 bytes leftover after parsing attributes in process `syz-executor5'. QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl kvm [11629]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0x186 data 0x8 QAT: Invalid ioctl print_req_error: I/O error, dev loop4, sector 0 Buffer I/O error on dev loop4, logical block 0, lost async page write device gre0 entered promiscuous mode QAT: Invalid ioctl QAT: Invalid ioctl SELinux: unrecognized netlink message: protocol=4 nlmsg_type=0 sclass=netlink_tcpdiag_socket pig=11866 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=4 sclass=netlink_route_socket pig=11900 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=11900 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=4 nlmsg_type=0 sclass=netlink_tcpdiag_socket pig=11919 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=5 sclass=netlink_route_socket pig=11866 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=4 sclass=netlink_route_socket pig=11866 comm=syz-executor3 SELinux: unrecognized netlink message: protocol=6 nlmsg_type=324 sclass=netlink_xfrm_socket pig=11968 comm=syz-executor0 SELinux: unrecognized netlink message: protocol=6 nlmsg_type=324 sclass=netlink_xfrm_socket pig=11968 comm=syz-executor0 loop_reread_partitions: partition scan of loop0 (-\t@r9hxGQ:[il L*@R-Tr-x) failed (rc=-13) Trying to set illegal importance in message Trying to set illegal importance in message