====================================================== WARNING: possible circular locking dependency detected 4.14.0-rc2-next-20170929+ #32 Not tainted ------------------------------------------------------ loop0/8954 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: [] shmem_fallocate+0x161/0x1160 mm/shmem.c:2841 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){+.+.}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498 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:1368 [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){++++}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498 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){++++}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498 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:5859 __mark_inode_dirty+0x912/0x1170 fs/fs-writeback.c:2096 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:352 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:2150 [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){++++}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x328f/0x4620 kernel/locking/lockdep.c:3498 lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 __might_fault+0x13a/0x1d0 mm/memory.c:4522 _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){++++}: down_write+0x87/0x120 kernel/locking/rwsem.c:53 inode_lock include/linux/fs.h:712 [inline] shmem_fallocate+0x161/0x1160 mm/shmem.c:2841 lo_discard drivers/block/loop.c:434 [inline] do_req_filebacked drivers/block/loop.c:575 [inline] loop_handle_cmd drivers/block/loop.c:1718 [inline] loop_queue_work+0x46f/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 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/8954: #0: (&x->wait#14){..-.}, at: [] complete+0x18/0x80 kernel/sched/completion.c:34 stack backtrace: CPU: 1 PID: 8954 Comm: loop0 Not tainted 4.14.0-rc2-next-20170929+ #32 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:2746 blk_mq_end_request+0x54/0x120 block/blk-mq.c:509 lo_complete_rq+0xbe/0x1f0 drivers/block/loop.c:463 __blk_mq_complete_request+0x38f/0x6c0 block/blk-mq.c:550 blk_mq_complete_request+0x4f/0x60 block/blk-mq.c:570 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 device lo entered promiscuous mode 9pnet_virtio: no channels available for device ./file0 9pnet_virtio: no channels available for device ./file0 QAT: Invalid ioctl QAT: Invalid ioctl netlink: 11 bytes leftover after parsing attributes in process `syz-executor3'. netlink: 11 bytes leftover after parsing attributes in process `syz-executor3'. 9pnet_virtio: no channels available for device ./bus QAT: Invalid ioctl QAT: Invalid ioctl 9pnet_virtio: no channels available for device ./bus Subscription rejected, illegal request Subscription rejected, illegal request netlink: 13 bytes leftover after parsing attributes in process `syz-executor0'. netlink: 2 bytes leftover after parsing attributes in process `syz-executor2'. netlink: 13 bytes leftover after parsing attributes in process `syz-executor0'. sctp: [Deprecated]: syz-executor4 (pid 28106) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead sctp: [Deprecated]: syz-executor4 (pid 28115) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead dccp_invalid_packet: invalid packet type QAT: Invalid ioctl dccp_invalid_packet: invalid packet type QAT: Invalid ioctl device lo entered promiscuous mode IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready device lo left promiscuous mode audit: type=1326 audit(1507319150.515:1019): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=28303 comm="syz-executor5" exe="/root/syz-executor5" sig=31 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0xffff0000 QAT: Invalid ioctl device lo entered promiscuous mode IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready device lo left promiscuous mode QAT: Invalid ioctl audit: type=1326 audit(1507319150.599:1020): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=28303 comm="syz-executor5" exe="/root/syz-executor5" sig=31 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0xffff0000 nla_parse: 5 callbacks suppressed netlink: 4 bytes leftover after parsing attributes in process `syz-executor2'. Bearer <÷ÿ> rejected, not supported in standalone mode netlink: 4 bytes leftover after parsing attributes in process `syz-executor2'. Bearer <÷ÿ> rejected, not supported in standalone mode netlink: 3 bytes leftover after parsing attributes in process `syz-executor3'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor3'. print_req_error: 727 callbacks suppressed print_req_error: I/O error, dev loop4, sector 0 netlink: 3 bytes leftover after parsing attributes in process `syz-executor3'. print_req_error: I/O error, dev loop4, sector 0 netlink: 3 bytes leftover after parsing attributes in process `syz-executor3'. RDS: rds_bind could not find a transport for 172.20.6.187, load rds_tcp or rds_rdma? QAT: Invalid ioctl RDS: rds_bind could not find a transport for 172.20.6.187, load rds_tcp or rds_rdma? QAT: Invalid ioctl netlink: 9 bytes leftover after parsing attributes in process `syz-executor2'. IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready netlink: 9 bytes leftover after parsing attributes in process `syz-executor2'. IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready skbuff: bad partial csum: csum=53081/14726 len=2273 audit: type=1326 audit(1507319152.437:1021): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=28791 comm="syz-executor3" exe="/root/syz-executor3" sig=9 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x0 audit: type=1326 audit(1507319152.517:1022): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=28791 comm="syz-executor3" exe="/root/syz-executor3" sig=9 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x0 netlink: 5 bytes leftover after parsing attributes in process `syz-executor6'. netlink: 5 bytes leftover after parsing attributes in process `syz-executor6'. kvm [28895]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0x186 data 0x8 kvm: apic: phys broadcast and lowest prio device lo entered promiscuous mode IPv6: ADDRCONF(NETDEV_CHANGE): lo: link becomes ready kvm [28895]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0x186 data 0x8 IPv6: NLM_F_REPLACE set, but no existing node found! IPv6: NLM_F_REPLACE set, but no existing node found! SELinux: unrecognized netlink message: protocol=0 nlmsg_type=2 sclass=netlink_route_socket pig=29020 comm=syz-executor1 QAT: Invalid ioctl QAT: Invalid ioctl kvm [29011]: vcpu1, guest rIP: 0xfff0 Hyper-V uhandled wrmsr: 0x40000074 data 0x800ff SELinux: unrecognized netlink message: protocol=0 nlmsg_type=2 sclass=netlink_route_socket pig=29060 comm=syz-executor1 kvm [29011]: vcpu1, guest rIP: 0xfff0 Hyper-V uhandled wrmsr: 0x40000074 data 0x800ff print_req_error: I/O error, dev loop4, sector 0 buffer_io_error: 727 callbacks suppressed Buffer I/O error on dev loop4, logical block 0, lost async page write IPv6: Can't replace route, no match found audit: type=1326 audit(1507319153.823:1023): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=29096 comm="syz-executor3" exe="/root/syz-executor3" sig=31 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x0 IPv6: Can't replace route, no match found audit: type=1326 audit(1507319153.915:1024): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=29096 comm="syz-executor3" exe="/root/syz-executor3" sig=31 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0x0 TCP: request_sock_TCP: Possible SYN flooding on port 20010. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20030. Sending cookies. Check SNMP counters. device lo entered promiscuous mode device lo left promiscuous mode device lo entered promiscuous mode device lo left promiscuous mode PF_BRIDGE: RTM_NEWNEIGH with unknown ifindex PF_BRIDGE: RTM_NEWNEIGH with unknown ifindex IPv6: NLM_F_REPLACE set, but no existing node found! lo: Invalid MTU -1431698681 requested, hw min 0 IPv6: NLM_F_REPLACE set, but no existing node found! audit: type=1326 audit(1507319155.570:1025): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=29511 comm="syz-executor0" exe="/root/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x4520a9 code=0xffff0000 dccp_invalid_packet: P.Data Offset(4) too small dccp_invalid_packet: P.Data Offset(4) too small device syz4 entered promiscuous mode device syz4 left promiscuous mode device syz4 entered promiscuous mode device syz4 left promiscuous mode device lo entered promiscuous mode