syzbot


possible deadlock in prepare_binprm

Status: auto-closed as invalid on 2020/11/21 16:10
Reported-by: syzbot+c76c418166f8aaa8c3c9@syzkaller.appspotmail.com
First crash: 1537d, last: 1343d

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
4.14.189-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.4/18743 is trying to acquire lock:
 (&ovl_i_mutex_key[depth]){+.+.}, at: [<ffffffff818e639a>] inode_lock include/linux/fs.h:719 [inline]
 (&ovl_i_mutex_key[depth]){+.+.}, at: [<ffffffff818e639a>] bprm_fill_uid fs/exec.c:1524 [inline]
 (&ovl_i_mutex_key[depth]){+.+.}, at: [<ffffffff818e639a>] prepare_binprm+0x31a/0x7e0 fs/exec.c:1559

but task is already holding lock:
 (&sig->cred_guard_mutex){+.+.}, at: [<ffffffff818eac69>] prepare_bprm_creds fs/exec.c:1391 [inline]
 (&sig->cred_guard_mutex){+.+.}, at: [<ffffffff818eac69>] do_execveat_common+0x319/0x1f30 fs/exec.c:1735

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&sig->cred_guard_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       lock_trace fs/proc/base.c:407 [inline]
       proc_pid_stack+0x13f/0x2f0 fs/proc/base.c:457
       proc_single_show+0xe7/0x150 fs/proc/base.c:761
       traverse+0x306/0x850 fs/seq_file.c:111
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
       seq_read+0x94b/0x1120 fs/seq_file.c:192
       do_loop_readv_writev fs/read_write.c:695 [inline]
       do_loop_readv_writev fs/read_write.c:682 [inline]
       do_iter_read+0x3eb/0x5b0 fs/read_write.c:919
       vfs_readv+0xc8/0x120 fs/read_write.c:981
       do_preadv fs/read_write.c:1065 [inline]
       SYSC_preadv fs/read_write.c:1115 [inline]
       SyS_preadv+0x15a/0x200 fs/read_write.c:1110
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #2 (&p->lock){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       seq_read+0xba/0x1120 fs/seq_file.c:165
       proc_reg_read+0xee/0x1a0 fs/proc/inode.c:217
       do_loop_readv_writev fs/read_write.c:695 [inline]
       do_loop_readv_writev fs/read_write.c:682 [inline]
       do_iter_read+0x3eb/0x5b0 fs/read_write.c:919
       vfs_readv+0xc8/0x120 fs/read_write.c:981
       kernel_readv fs/splice.c:361 [inline]
       default_file_splice_read+0x418/0x910 fs/splice.c:416
       do_splice_to+0xfb/0x140 fs/splice.c:880
       splice_direct_to_actor+0x207/0x730 fs/splice.c:952
       do_splice_direct+0x164/0x210 fs/splice.c:1061
       do_sendfile+0x47f/0xb30 fs/read_write.c:1441
       SYSC_sendfile64 fs/read_write.c:1502 [inline]
       SyS_sendfile64+0xff/0x110 fs/read_write.c:1488
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #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+0x19a/0x2e0 fs/super.c:1363
       sb_start_write include/linux/fs.h:1549 [inline]
       mnt_want_write+0x3a/0xb0 fs/namespace.c:386
       ovl_setattr+0x52/0x500 fs/overlayfs/inode.c:38
       notify_change+0x56b/0xd10 fs/attr.c:313
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
       do_truncate+0xff/0x1a0 fs/open.c:63
       handle_truncate fs/namei.c:3010 [inline]
       do_last fs/namei.c:3437 [inline]
       path_openat+0x1dcc/0x2970 fs/namei.c:3569
       do_filp_open+0x179/0x3c0 fs/namei.c:3603
       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+0x46/0xbb

-> #0 (&ovl_i_mutex_key[depth]){+.+.}:
       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]
       bprm_fill_uid fs/exec.c:1524 [inline]
       prepare_binprm+0x31a/0x7e0 fs/exec.c:1559
       do_execveat_common+0xd72/0x1f30 fs/exec.c:1785
       do_execve fs/exec.c:1847 [inline]
       SYSC_execve fs/exec.c:1928 [inline]
       SyS_execve+0x3b/0x50 fs/exec.c:1923
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x46/0xbb

other info that might help us debug this:

Chain exists of:
  &ovl_i_mutex_key[depth] --> &p->lock --> &sig->cred_guard_mutex

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&sig->cred_guard_mutex);
                               lock(&p->lock);
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
                               lock(&sig->cred_guard_mutex);
  lock(&ovl_i_mutex_key[depth]);

 *** DEADLOCK ***

1 lock held by syz-executor.4/18743:
 #0:  (&sig->cred_guard_mutex){+.+.}, at: [<ffffffff818eac69>] prepare_bprm_creds fs/exec.c:1391 [inline]
 #0:  (&sig->cred_guard_mutex){+.+.}, at: [<ffffffff818eac69>] do_execveat_common+0x319/0x1f30 fs/exec.c:1735

stack backtrace:
CPU: 0 PID: 18743 Comm: syz-executor.4 Not tainted 4.14.189-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x1b2/0x283 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]
 bprm_fill_uid fs/exec.c:1524 [inline]
 prepare_binprm+0x31a/0x7e0 fs/exec.c:1559
 do_execveat_common+0xd72/0x1f30 fs/exec.c:1785
 do_execve fs/exec.c:1847 [inline]
 SYSC_execve fs/exec.c:1928 [inline]
 SyS_execve+0x3b/0x50 fs/exec.c:1923
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45c1f9
RSP: 002b:00007ff23a97dc78 EFLAGS: 00000246 ORIG_RAX: 000000000000003b
RAX: ffffffffffffffda RBX: 0000000000002c00 RCX: 000000000045c1f9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000000
RBP: 000000000078bf40 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000078bf0c
R13: 00007ffc16253f4f R14: 00007ff23a97e9c0 R15: 000000000078bf0c
ptrace attach of "/root/syz-executor.4"[18787] was attempted by "/root/syz-executor.4"[18791]
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
audit: type=1804 audit(1595606986.261:148): pid=18857 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir591901974/syzkaller.QhSH9w/1877/bus" dev="sda1" ino=16183 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
audit: type=1804 audit(1595606987.061:149): pid=18915 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir591901974/syzkaller.QhSH9w/1877/bus" dev="sda1" ino=16183 res=1
audit: type=1804 audit(1595606987.121:150): pid=18917 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir591901974/syzkaller.QhSH9w/1877/bus" dev="sda1" ino=16183 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
audit: type=1804 audit(1595606989.301:151): pid=18921 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir591901974/syzkaller.QhSH9w/1878/bus" dev="sda1" ino=16389 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.3'.

Crashes (7):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/07/24 16:09 linux-4.14.y 69b94dd6dcd1 554af388 .config console log report ci2-linux-4-14
2020/06/05 02:57 linux-4.14.y c6db52a88798 2420d1bc .config console log report ci2-linux-4-14
2020/06/02 15:26 linux-4.14.y 4f68020fef1c 52fd7b7d .config console log report ci2-linux-4-14
2020/05/26 02:19 linux-4.14.y a41ba30d9df2 8ca3b7d2 .config console log report ci2-linux-4-14
2020/04/09 17:00 linux-4.14.y 4520f06b03ae a8c6a3f8 .config console log report ci2-linux-4-14
2020/02/03 11:23 linux-4.14.y 9fa690a2a016 93e5e335 .config console log report ci2-linux-4-14
2020/01/12 09:19 linux-4.14.y b0cdffaa546e 4c04afaa .config console log report ci2-linux-4-14
* Struck through repros no longer work on HEAD.