====================================================== WARNING: possible circular locking dependency detected 4.14.222-syzkaller #0 Not tainted ------------------------------------------------------ kworker/1:1/23 is trying to acquire lock: (&sb->s_type->i_mutex_key#10){++++}, at: [] inode_lock include/linux/fs.h:719 [inline] (&sb->s_type->i_mutex_key#10){++++}, at: [] __generic_file_fsync+0x9e/0x190 fs/libfs.c:989 but task is already holding lock: ((&dio->complete_work)){+.+.}, at: [] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #2 ((&dio->complete_work)){+.+.}: process_one_work+0x736/0x14a0 kernel/workqueue.c:2092 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250 kthread+0x30d/0x420 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 -> #1 ("dio/%s"sb->s_id){+.+.}: flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2624 drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2789 destroy_workqueue+0x71/0x710 kernel/workqueue.c:4109 __alloc_workqueue_key+0xd50/0x1080 kernel/workqueue.c:4086 sb_init_dio_done_wq+0x34/0x80 fs/direct-io.c:624 do_blockdev_direct_IO fs/direct-io.c:1286 [inline] __blockdev_direct_IO+0x3dea/0xdc60 fs/direct-io.c:1422 ext4_direct_IO_write fs/ext4/inode.c:3725 [inline] ext4_direct_IO+0x888/0x1b80 fs/ext4/inode.c:3866 generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958 __generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137 ext4_file_write_iter+0x7c5/0xd20 fs/ext4/file.c:270 call_write_iter include/linux/fs.h:1778 [inline] aio_write+0x2ed/0x560 fs/aio.c:1553 io_submit_one fs/aio.c:1641 [inline] do_io_submit+0x847/0x1570 fs/aio.c:1709 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x46/0xbb -> #0 (&sb->s_type->i_mutex_key#10){++++}: lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 down_write+0x34/0x90 kernel/locking/rwsem.c:54 inode_lock include/linux/fs.h:719 [inline] __generic_file_fsync+0x9e/0x190 fs/libfs.c:989 ext4_sync_file+0x8ed/0x12c0 fs/ext4/fsync.c:118 vfs_fsync_range+0x103/0x260 fs/sync.c:196 generic_write_sync include/linux/fs.h:2682 [inline] dio_complete+0x561/0x8d0 fs/direct-io.c:330 process_one_work+0x793/0x14a0 kernel/workqueue.c:2116 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250 kthread+0x30d/0x420 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 other info that might help us debug this: Chain exists of: &sb->s_type->i_mutex_key#10 --> "dio/%s"sb->s_id --> (&dio->complete_work) Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock((&dio->complete_work)); lock("dio/%s"sb->s_id); lock((&dio->complete_work)); lock(&sb->s_type->i_mutex_key#10); *** DEADLOCK *** 2 locks held by kworker/1:1/23: #0: ("dio/%s"sb->s_id){+.+.}, at: [] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087 #1: ((&dio->complete_work)){+.+.}, at: [] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091 stack backtrace: CPU: 1 PID: 23 Comm: kworker/1:1 Not tainted 4.14.222-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: dio/sda1 dio_aio_complete_work Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0x1b2/0x281 lib/dump_stack.c:58 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1258 check_prev_add kernel/locking/lockdep.c:1905 [inline] check_prevs_add kernel/locking/lockdep.c:2022 [inline] validate_chain kernel/locking/lockdep.c:2464 [inline] __lock_acquire+0x2e0e/0x3f20 kernel/locking/lockdep.c:3491 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 down_write+0x34/0x90 kernel/locking/rwsem.c:54 inode_lock include/linux/fs.h:719 [inline] __generic_file_fsync+0x9e/0x190 fs/libfs.c:989 ext4_sync_file+0x8ed/0x12c0 fs/ext4/fsync.c:118 vfs_fsync_range+0x103/0x260 fs/sync.c:196 generic_write_sync include/linux/fs.h:2682 [inline] dio_complete+0x561/0x8d0 fs/direct-io.c:330 process_one_work+0x793/0x14a0 kernel/workqueue.c:2116 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250 kthread+0x30d/0x420 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'. audit: type=1804 audit(1614336497.901:145): pid=26327 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir041920117/syzkaller.WOY6dG/380/bus" dev="sda1" ino=16865 res=1 audit: type=1804 audit(1614336498.231:146): pid=26355 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir041920117/syzkaller.WOY6dG/380/bus" dev="sda1" ino=16865 res=1 program syz-executor.4 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 netlink: 156 bytes leftover after parsing attributes in process `syz-executor.0'. program syz-executor.4 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 program syz-executor.4 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 audit: type=1804 audit(1614336498.411:147): pid=26368 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir041920117/syzkaller.WOY6dG/381/bus" dev="sda1" ino=16946 res=1 program syz-executor.4 is using a deprecated SCSI ioctl, please convert it to SG_IO netlink: 156 bytes leftover after parsing attributes in process `syz-executor.0'. sd 0:0:1:0: ioctl_internal_command: ILLEGAL REQUEST asc=0x20 ascq=0x0 program syz-executor.4 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 netlink: 156 bytes leftover after parsing attributes in process `syz-executor.2'. audit: type=1804 audit(1614336498.881:148): pid=26404 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir928327279/syzkaller.bMW4tU/390/bus" dev="sda1" ino=17058 res=1 netlink: 156 bytes leftover after parsing attributes in process `syz-executor.0'. audit: type=1804 audit(1614336498.911:149): pid=26407 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir782647388/syzkaller.B83z06/394/bus" dev="sda1" ino=17412 res=1 audit: type=1804 audit(1614336498.951:150): pid=26409 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir041920117/syzkaller.WOY6dG/382/bus" dev="sda1" ino=17413 res=1 netlink: 156 bytes leftover after parsing attributes in process `syz-executor.2'. audit: type=1804 audit(1614336499.311:151): pid=26425 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir709998062/syzkaller.5Sz592/411/bus" dev="sda1" ino=16865 res=1 xt_nfacct: accounting object with name `syz0' does not exists can: request_module (can-proto-0) failed. xt_nfacct: accounting object with name `syz0' does not exists can: request_module (can-proto-0) failed. audit: type=1804 audit(1614336499.911:152): pid=26439 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir928327279/syzkaller.bMW4tU/391/bus" dev="sda1" ino=17185 res=1 xt_nfacct: accounting object with name `syz0' does not exists audit: type=1804 audit(1614336499.981:153): pid=26440 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir782647388/syzkaller.B83z06/395/bus" dev="sda1" ino=17412 res=1 team0: Device geneve0 is up. Set it down before adding it as a team port xt_nfacct: accounting object with name `syz0' does not exists xt_nfacct: accounting object with name `syz0' does not exists team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port audit: type=1804 audit(1614336500.811:154): pid=26478 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir928327279/syzkaller.bMW4tU/392/bus" dev="sda1" ino=17413 res=1 team0: Device geneve0 is up. Set it down before adding it as a team port audit: type=1804 audit(1614336500.851:155): pid=26473 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir782647388/syzkaller.B83z06/396/bus" dev="sda1" ino=17412 res=1 team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port xt_nfacct: accounting object with name `syz0' does not exists team0: Device geneve0 is up. Set it down before adding it as a team port team0: Device geneve0 is up. Set it down before adding it as a team port xt_nfacct: accounting object with name `syz0' does not exists team0: Device geneve0 is up. Set it down before adding it as a team port xt_nfacct: accounting object with name `syz0' does not exists nla_parse: 2 callbacks suppressed netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'.