overlayfs: fs on 'file0' does not support file handles, falling back to index=off.
overlayfs: fs on './file0' does not support file handles, falling back to index=off.
======================================================
WARNING: possible circular locking dependency detected
4.14.307-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/13196 is trying to acquire lock:
 (&ovl_i_mutex_dir_key[depth]){++++}, at: [<ffffffff818b2877>] iterate_dir+0x387/0x5e0 fs/readdir.c:43

but task is already holding lock:
 (sb_writers#3){.+.+}, at: [<ffffffff818e203a>] sb_start_write include/linux/fs.h:1551 [inline]
 (sb_writers#3){.+.+}, at: [<ffffffff818e203a>] mnt_want_write+0x3a/0xb0 fs/namespace.c:386

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (sb_writers#3){.+.+}:
       percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36 [inline]
       percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
       __sb_start_write+0x64/0x260 fs/super.c:1342
       sb_start_write include/linux/fs.h:1551 [inline]
       mnt_want_write+0x3a/0xb0 fs/namespace.c:386
       ovl_create_object+0x75/0x1d0 fs/overlayfs/dir.c:538
       lookup_open+0x77a/0x1750 fs/namei.c:3241
       do_last fs/namei.c:3334 [inline]
       path_openat+0xe08/0x2970 fs/namei.c:3571
       do_filp_open+0x179/0x3c0 fs/namei.c:3605
       do_sys_open+0x296/0x410 fs/open.c:1081
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

-> #0 (&ovl_i_mutex_dir_key[depth]){++++}:
       lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
       down_write_killable+0x37/0xb0 kernel/locking/rwsem.c:68
       iterate_dir+0x387/0x5e0 fs/readdir.c:43
       ovl_dir_read fs/overlayfs/readdir.c:306 [inline]
       ovl_dir_read_merged+0x2c5/0x430 fs/overlayfs/readdir.c:365
       ovl_check_empty_dir+0x6e/0x200 fs/overlayfs/readdir.c:870
       ovl_check_empty_and_clear+0x72/0xe0 fs/overlayfs/dir.c:306
       ovl_rename+0x57d/0xe50 fs/overlayfs/dir.c:959
       vfs_rename+0x560/0x1820 fs/namei.c:4498
       SYSC_renameat2 fs/namei.c:4646 [inline]
       SyS_renameat2+0x95b/0xad0 fs/namei.c:4535
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

other info that might help us debug this:

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(sb_writers#3);
                               lock(&ovl_i_mutex_dir_key[depth]);
                               lock(sb_writers#3);
  lock(&ovl_i_mutex_dir_key[depth]);

 *** DEADLOCK ***

6 locks held by syz-executor.3/13196:
 #0:  (sb_writers#13){.+.+}, at: [<ffffffff818e203a>] sb_start_write include/linux/fs.h:1551 [inline]
 #0:  (sb_writers#13){.+.+}, at: [<ffffffff818e203a>] mnt_want_write+0x3a/0xb0 fs/namespace.c:386
 #1:  (&type->s_vfs_rename_key#2){+.+.}, at: [<ffffffff81893544>] lock_rename+0x54/0x280 fs/namei.c:2889
 #2:  (&ovl_i_mutex_dir_key[depth]#2/1){+.+.}, at: [<ffffffff81893622>] inode_lock_nested include/linux/fs.h:754 [inline]
 #2:  (&ovl_i_mutex_dir_key[depth]#2/1){+.+.}, at: [<ffffffff81893622>] lock_rename+0x132/0x280 fs/namei.c:2900
 #3:  (&ovl_i_mutex_dir_key[depth]#2/2){+.+.}, at: [<ffffffff81893656>] inode_lock_nested include/linux/fs.h:754 [inline]
 #3:  (&ovl_i_mutex_dir_key[depth]#2/2){+.+.}, at: [<ffffffff81893656>] lock_rename+0x166/0x280 fs/namei.c:2901
 #4:  (&ovl_i_mutex_dir_key[depth]#2){++++}, at: [<ffffffff818a71a8>] inode_lock include/linux/fs.h:719 [inline]
 #4:  (&ovl_i_mutex_dir_key[depth]#2){++++}, at: [<ffffffff818a71a8>] vfs_rename+0xbd8/0x1820 fs/namei.c:4472
 #5:  (sb_writers#3){.+.+}, at: [<ffffffff818e203a>] sb_start_write include/linux/fs.h:1551 [inline]
 #5:  (sb_writers#3){.+.+}, at: [<ffffffff818e203a>] mnt_want_write+0x3a/0xb0 fs/namespace.c:386

stack backtrace:
CPU: 1 PID: 13196 Comm: syz-executor.3 Not tainted 4.14.307-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/16/2023
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_killable+0x37/0xb0 kernel/locking/rwsem.c:68
 iterate_dir+0x387/0x5e0 fs/readdir.c:43
 ovl_dir_read fs/overlayfs/readdir.c:306 [inline]
 ovl_dir_read_merged+0x2c5/0x430 fs/overlayfs/readdir.c:365
 ovl_check_empty_dir+0x6e/0x200 fs/overlayfs/readdir.c:870
 ovl_check_empty_and_clear+0x72/0xe0 fs/overlayfs/dir.c:306
 ovl_rename+0x57d/0xe50 fs/overlayfs/dir.c:959
 vfs_rename+0x560/0x1820 fs/namei.c:4498
 SYSC_renameat2 fs/namei.c:4646 [inline]
 SyS_renameat2+0x95b/0xad0 fs/namei.c:4535
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7f0a43aa20f9
RSP: 002b:00007f0a42014168 EFLAGS: 00000246 ORIG_RAX: 0000000000000052
RAX: ffffffffffffffda RBX: 00007f0a43bc1f80 RCX: 00007f0a43aa20f9
RDX: 0000000000000000 RSI: 0000000020000440 RDI: 0000000020000100
RBP: 00007f0a43afdae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffefa19aa8f R14: 00007f0a42014300 R15: 0000000000022000
unregister_netdevice: waiting for ip6gre0 to become free. Usage count = -1
BTRFS info (device loop3): enabling inode map caching
BTRFS warning (device loop3): excessive commit interval 622039222
BTRFS info (device loop3): force zlib compression
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop3): enabling inode map caching
BTRFS warning (device loop3): excessive commit interval 622039222
BTRFS info (device loop3): force zlib compression
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
PM: Marking nosave pages: [mem 0x0009f000-0x000fffff]
PM: Marking nosave pages: [mem 0xbfffd000-0xffffffff]
PM: Basic memory bitmaps created
BTRFS info (device loop3): enabling inode map caching
BTRFS warning (device loop3): excessive commit interval 622039222
BTRFS info (device loop3): force zlib compression
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
PM: Basic memory bitmaps freed
PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
PM: Marking nosave pages: [mem 0x0009f000-0x000fffff]
audit: type=1326 audit(1677368869.869:58): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=13475 comm="syz-executor.0" exe="/root/syz-executor.0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7f221fb140f9 code=0x0
PM: Marking nosave pages: [mem 0xbfffd000-0xffffffff]
PM: Basic memory bitmaps created
print_req_error: 130 callbacks suppressed
print_req_error: I/O error, dev loop2, sector 0
print_req_error: I/O error, dev loop2, sector 0
buffer_io_error: 116 callbacks suppressed
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
BTRFS info (device loop3): enabling inode map caching
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
BTRFS warning (device loop3): excessive commit interval 622039222
print_req_error: I/O error, dev loop2, sector 0
BTRFS info (device loop3): force zlib compression
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
BTRFS info (device loop3): using free space tree
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
BTRFS info (device loop3): has skinny extents
Buffer I/O error on dev loop2p4, logical block 0, async page read
PM: Basic memory bitmaps freed
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
PM: Marking nosave pages: [mem 0x0009f000-0x000fffff]
PM: Marking nosave pages: [mem 0xbfffd000-0xffffffff]
PM: Basic memory bitmaps created
Buffer I/O error on dev loop2p4, logical block 0, async page read
PM: Basic memory bitmaps freed
PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
PM: Marking nosave pages: [mem 0x0009f000-0x000fffff]
PM: Marking nosave pages: [mem 0xbfffd000-0xffffffff]
PM: Basic memory bitmaps created
hid-generic 0000:0000:0000.0001: hidraw0: <UNKNOWN> HID v0.00 Device [syz0] on syz1
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
device veth3 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth3: link is not ready
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
PM: Basic memory bitmaps freed
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'.
device veth5 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth5: link is not ready
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
device veth5 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth5: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'.
device veth3 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth3: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'.
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
device veth7 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth7: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
device veth7 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth7: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'.
device veth5 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth5: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.4'.
device veth9 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth9: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
device veth9 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth9: link is not ready
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.1'.
device veth7 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth7: link is not ready
XFS (loop3): Mounting V4 Filesystem
XFS (loop3): Ending clean mount
XFS (loop3): Quotacheck needed: Please wait.
XFS (loop3): Quotacheck: Done.
audit: type=1804 audit(1677368874.729:59): pid=13831 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir4137342710/syzkaller.vAfFBY/118/file0/bus" dev="loop3" ino=42 res=1
audit: type=1804 audit(1677368874.839:60): pid=13875 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir4137342710/syzkaller.vAfFBY/118/file0/bus" dev="loop3" ino=42 res=1
XFS (loop3): Unmounting Filesystem
print_req_error: 60 callbacks suppressed
print_req_error: I/O error, dev loop2, sector 0
print_req_error: I/O error, dev loop2, sector 0
buffer_io_error: 53 callbacks suppressed
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2p4, logical block 0, async page read
XFS (loop1): Mounting V4 Filesystem
XFS (loop3): Mounting V4 Filesystem
XFS (loop1): Ending clean mount
XFS (loop3): Ending clean mount
XFS (loop1): Quotacheck needed: Please wait.
XFS (loop3): Quotacheck needed: Please wait.
XFS (loop1): Quotacheck: Done.
XFS (loop3): Quotacheck: Done.
vivid-002: kernel_thread() failed
audit: type=1804 audit(1677368876.359:61): pid=13900 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir843989350/syzkaller.Kx37PA/114/file0/bus" dev="loop1" ino=42 res=1
Buffer I/O error on dev loop2p4, logical block 0, async page read
audit: type=1804 audit(1677368876.719:62): pid=13947 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir843989350/syzkaller.Kx37PA/114/file0/bus" dev="loop1" ino=42 res=1