syzbot


possible deadlock in lookup_one_len_unlocked

Status: auto-closed as invalid on 2020/12/08 06:01
Reported-by: syzbot+30f40d3828334201f27f@syzkaller.appspotmail.com
First crash: 1353d, last: 1353d
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in lookup_one_len_unlocked fs 6 1542d 1546d 0/26 auto-closed as invalid on 2020/06/01 21:33
linux-4.19 possible deadlock in lookup_one_len_unlocked (2) 2 965d 986d 0/1 auto-closed as invalid on 2021/12/30 20:51
linux-4.19 possible deadlock in lookup_one_len_unlocked (3) 5 581d 808d 0/1 auto-obsoleted due to no activity on 2023/01/19 13:28

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
4.19.138-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.2/23449 is trying to acquire lock:
0000000050927443 (&ovl_i_mutex_dir_key[depth]#2){++++}, at: inode_lock_shared include/linux/fs.h:758 [inline]
0000000050927443 (&ovl_i_mutex_dir_key[depth]#2){++++}, at: lookup_slow fs/namei.c:1688 [inline]
0000000050927443 (&ovl_i_mutex_dir_key[depth]#2){++++}, at: lookup_one_len_unlocked+0x111/0x140 fs/namei.c:2573

but task is already holding lock:
000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: inode_lock_shared include/linux/fs.h:758 [inline]
000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: do_last fs/namei.c:3326 [inline]
000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: path_openat+0x17ec/0x2df0 fs/namei.c:3537

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #4 (&ovl_i_mutex_dir_key[depth]#3){.+.+}:
       inode_lock_shared include/linux/fs.h:758 [inline]
       do_last fs/namei.c:3326 [inline]
       path_openat+0x17ec/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_open_execat+0x11d/0x5b0 fs/exec.c:853
       __do_execve_file+0x1a8b/0x2360 fs/exec.c:1757
       do_execveat_common fs/exec.c:1866 [inline]
       do_execve+0x35/0x50 fs/exec.c:1883
       __do_sys_execve fs/exec.c:1964 [inline]
       __se_sys_execve fs/exec.c:1959 [inline]
       __x64_sys_execve+0x7c/0xa0 fs/exec.c:1959
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #3 (&sig->cred_guard_mutex){+.+.}:
       lock_trace fs/proc/base.c:402 [inline]
       proc_pid_personality+0x4a/0x170 fs/proc/base.c:2926
       proc_single_show+0xeb/0x170 fs/proc/base.c:755
       seq_read+0x4be/0x1160 fs/seq_file.c:229
       do_loop_readv_writev fs/read_write.c:701 [inline]
       do_loop_readv_writev fs/read_write.c:688 [inline]
       do_iter_read+0x471/0x630 fs/read_write.c:925
       vfs_readv+0xe5/0x150 fs/read_write.c:987
       do_preadv fs/read_write.c:1071 [inline]
       __do_sys_preadv fs/read_write.c:1121 [inline]
       __se_sys_preadv fs/read_write.c:1116 [inline]
       __x64_sys_preadv+0x22b/0x310 fs/read_write.c:1116
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #2 (&p->lock){+.+.}:
       seq_read+0x6b/0x1160 fs/seq_file.c:161
       proc_reg_read+0x1bd/0x2d0 fs/proc/inode.c:231
       do_loop_readv_writev fs/read_write.c:701 [inline]
       do_loop_readv_writev fs/read_write.c:688 [inline]
       do_iter_read+0x471/0x630 fs/read_write.c:925
       vfs_readv+0xe5/0x150 fs/read_write.c:987
       kernel_readv fs/splice.c:362 [inline]
       default_file_splice_read+0x457/0xa00 fs/splice.c:417
       do_splice_to+0x10e/0x160 fs/splice.c:881
       splice_direct_to_actor+0x2b9/0x8d0 fs/splice.c:959
       do_splice_direct+0x1a7/0x270 fs/splice.c:1068
       do_sendfile+0x550/0xc30 fs/read_write.c:1447
       __do_sys_sendfile64 fs/read_write.c:1508 [inline]
       __se_sys_sendfile64+0x147/0x160 fs/read_write.c:1494
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (sb_writers#3){.+.+}:
       sb_start_write include/linux/fs.h:1579 [inline]
       mnt_want_write+0x3a/0xb0 fs/namespace.c:360
       ovl_do_remove+0xf0/0xdb0 fs/overlayfs/dir.c:843
       vfs_rmdir.part.0+0x10f/0x3d0 fs/namei.c:3882
       vfs_rmdir fs/namei.c:3868 [inline]
       do_rmdir+0x3fd/0x490 fs/namei.c:3943
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (&ovl_i_mutex_dir_key[depth]#2){++++}:
       down_read+0x36/0x80 kernel/locking/rwsem.c:24
       inode_lock_shared include/linux/fs.h:758 [inline]
       lookup_slow fs/namei.c:1688 [inline]
       lookup_one_len_unlocked+0x111/0x140 fs/namei.c:2573
       ovl_lookup_single+0x60/0x920 fs/overlayfs/namei.c:206
       ovl_lookup_layer+0x3bd/0x440 fs/overlayfs/namei.c:292
       ovl_lookup+0x729/0x1a00 fs/overlayfs/namei.c:903
       lookup_open+0x698/0x1a20 fs/namei.c:3214
       do_last fs/namei.c:3327 [inline]
       path_openat+0x1804/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_open_execat+0x11d/0x5b0 fs/exec.c:853
       __do_execve_file+0x1a8b/0x2360 fs/exec.c:1757
       do_execveat_common fs/exec.c:1866 [inline]
       do_execve+0x35/0x50 fs/exec.c:1883
       __do_sys_execve fs/exec.c:1964 [inline]
       __se_sys_execve fs/exec.c:1959 [inline]
       __x64_sys_execve+0x7c/0xa0 fs/exec.c:1959
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  &ovl_i_mutex_dir_key[depth]#2 --> &sig->cred_guard_mutex --> &ovl_i_mutex_dir_key[depth]#3

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&ovl_i_mutex_dir_key[depth]#3);
                               lock(&sig->cred_guard_mutex);
                               lock(&ovl_i_mutex_dir_key[depth]#3);
  lock(&ovl_i_mutex_dir_key[depth]#2);

 *** DEADLOCK ***

2 locks held by syz-executor.2/23449:
 #0: 00000000e2c018b7 (&sig->cred_guard_mutex){+.+.}, at: prepare_bprm_creds fs/exec.c:1406 [inline]
 #0: 00000000e2c018b7 (&sig->cred_guard_mutex){+.+.}, at: __do_execve_file+0x38c/0x2360 fs/exec.c:1749
 #1: 000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: inode_lock_shared include/linux/fs.h:758 [inline]
 #1: 000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: do_last fs/namei.c:3326 [inline]
 #1: 000000006ca40356 (&ovl_i_mutex_dir_key[depth]#3){.+.+}, at: path_openat+0x17ec/0x2df0 fs/namei.c:3537

stack backtrace:
CPU: 0 PID: 23449 Comm: syz-executor.2 Not tainted 4.19.138-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1221
 check_prev_add kernel/locking/lockdep.c:1865 [inline]
 check_prevs_add kernel/locking/lockdep.c:1978 [inline]
 validate_chain kernel/locking/lockdep.c:2419 [inline]
 __lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3415
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
 down_read+0x36/0x80 kernel/locking/rwsem.c:24
 inode_lock_shared include/linux/fs.h:758 [inline]
 lookup_slow fs/namei.c:1688 [inline]
 lookup_one_len_unlocked+0x111/0x140 fs/namei.c:2573
 ovl_lookup_single+0x60/0x920 fs/overlayfs/namei.c:206
 ovl_lookup_layer+0x3bd/0x440 fs/overlayfs/namei.c:292
 ovl_lookup+0x729/0x1a00 fs/overlayfs/namei.c:903
 lookup_open+0x698/0x1a20 fs/namei.c:3214
 do_last fs/namei.c:3327 [inline]
 path_openat+0x1804/0x2df0 fs/namei.c:3537
 do_filp_open+0x18c/0x3f0 fs/namei.c:3567
 do_open_execat+0x11d/0x5b0 fs/exec.c:853
 __do_execve_file+0x1a8b/0x2360 fs/exec.c:1757
 do_execveat_common fs/exec.c:1866 [inline]
 do_execve+0x35/0x50 fs/exec.c:1883
 __do_sys_execve fs/exec.c:1964 [inline]
 __se_sys_execve fs/exec.c:1959 [inline]
 __x64_sys_execve+0x7c/0xa0 fs/exec.c:1959
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45ce69
Code: 2d b6 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 fb b5 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fcdfd836c78 EFLAGS: 00000246 ORIG_RAX: 000000000000003b
RAX: ffffffffffffffda RBX: 0000000000002c80 RCX: 000000000045ce69
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000500
RBP: 000000000118bf60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007fff001bd41f R14: 00007fcdfd8379c0 R15: 000000000118bf2c
audit: type=1800 audit(1597039227.982:508): pid=23456 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18739 res=0
device bond525 entered promiscuous mode
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1800 audit(1597039228.442:509): pid=23538 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18399 res=0
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
(unnamed net_device) (uninitialized): Device ip_vti0 is not bonding slave
(unnamed net_device) (uninitialized): option active_slave: invalid value (ip_vti0)
audit: type=1800 audit(1597039229.192:510): pid=23668 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.2" name="bus" dev="sda1" ino=18723 res=0
(unnamed net_device) (uninitialized): Device ip_vti0 is not bonding slave
(unnamed net_device) (uninitialized): option active_slave: invalid value (ip_vti0)
audit: type=1800 audit(1597039229.652:511): pid=23740 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18821 res=0
(unnamed net_device) (uninitialized): Device ip_vti0 is not bonding slave
audit: type=1800 audit(1597039230.242:512): pid=23805 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.2" name="bus" dev="sda1" ino=18106 res=0
(unnamed net_device) (uninitialized): option active_slave: invalid value (ip_vti0)
audit: type=1800 audit(1597039230.782:513): pid=23836 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18383 res=0
audit: type=1800 audit(1597039231.322:514): pid=23881 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.2" name="bus" dev="sda1" ino=18897 res=0
(unnamed net_device) (uninitialized): Device ip_vti0 is not bonding slave
(unnamed net_device) (uninitialized): option active_slave: invalid value (ip_vti0)
(unnamed net_device) (uninitialized): Device ip_vti0 is not bonding slave
(unnamed net_device) (uninitialized): option active_slave: invalid value (ip_vti0)
audit: type=1800 audit(1597039231.912:515): pid=23934 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18773 res=0
audit: type=1800 audit(1597039232.492:516): pid=23989 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.2" name="bus" dev="sda1" ino=18853 res=0
audit: type=1800 audit(1597039233.002:517): pid=24073 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18932 res=0
audit: type=1800 audit(1597039233.592:518): pid=24153 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.2" name="bus" dev="sda1" ino=18980 res=0
device bond532 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): bond532: link is not ready
8021q: adding VLAN 0 to HW filter on device bond532
audit: type=1800 audit(1597039234.162:519): pid=24189 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18415 res=0
audit: type=1800 audit(1597039235.282:520): pid=24314 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=19009 res=0
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.
audit: type=1800 audit(1597039236.472:521): pid=24469 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.3" name="bus" dev="sda1" ino=18446 res=0
IPv6: ADDRCONF(NETDEV_UP): bond535: link is not ready
8021q: adding VLAN 0 to HW filter on device bond535
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.5'.

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/08/10 06:00 linux-4.19.y 961f830af065 70301872 .config console log report ci2-linux-4-19
* Struck through repros no longer work on HEAD.