possible deadlock in prepare_binprm

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: b0cdffaa Linux 4.14.163
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=10a7d421e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=19269c071a1fe30
dashboard link: https://syzkaller.appspot.com/bug?extid=c76c418166f8aaa8c3c9
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+c76c41...@syzkaller.appspotmail.com

======================================================
WARNING: possible circular locking dependency detected
4.14.163-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/15723 is trying to acquire lock:
(&ovl_i_mutex_key[depth]#2){+.+.}, at: [<ffffffff8190b00c>] inode_lock
include/linux/fs.h:718 [inline]
(&ovl_i_mutex_key[depth]#2){+.+.}, at: [<ffffffff8190b00c>] bprm_fill_uid
fs/exec.c:1522 [inline]
(&ovl_i_mutex_key[depth]#2){+.+.}, at: [<ffffffff8190b00c>]
prepare_binprm+0x31c/0x7f0 fs/exec.c:1557

but task is already holding lock:
(&sig->cred_guard_mutex){+.+.}, at: [<ffffffff8190fcc5>]
prepare_bprm_creds+0x55/0x120 fs/exec.c:1389

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&sig->cred_guard_mutex){+.+.}:
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xe8/0x1470 kernel/locking/mutex.c:893
mutex_lock_killable_nested+0x16/0x20 kernel/locking/mutex.c:923
do_io_accounting+0x1d6/0x7b0 fs/proc/base.c:2726
proc_tgid_io_accounting+0x23/0x30 fs/proc/base.c:2775
proc_single_show+0xf0/0x160 fs/proc/base.c:761
autofs4:pid:15730:autofs4_fill_super: called with bogus options
seq_read+0x51a/0x1280 fs/seq_file.c:237
__vfs_read+0x105/0x6a0 fs/read_write.c:411
vfs_read+0x137/0x350 fs/read_write.c:447
SYSC_read fs/read_write.c:574 [inline]
SyS_read+0xfd/0x230 fs/read_write.c:567
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #2 (&p->lock){+.+.}:
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xe8/0x1470 kernel/locking/mutex.c:893
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
seq_read+0xc1/0x1280 fs/seq_file.c:165
do_loop_readv_writev fs/read_write.c:695 [inline]
do_loop_readv_writev fs/read_write.c:682 [inline]
do_iter_read+0x3e2/0x5b0 fs/read_write.c:919
vfs_readv+0xd3/0x130 fs/read_write.c:981
kernel_readv fs/splice.c:361 [inline]
default_file_splice_read+0x421/0x870 fs/splice.c:416
do_splice_to+0x105/0x170 fs/splice.c:880
splice_direct_to_actor+0x222/0x7b0 fs/splice.c:952
do_splice_direct+0x18d/0x230 fs/splice.c:1061
do_sendfile+0x4db/0xbd0 fs/read_write.c:1441
SYSC_sendfile64 fs/read_write.c:1502 [inline]
SyS_sendfile64+0x102/0x110 fs/read_write.c:1488
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #1 (sb_writers#4){.+.+}:
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
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+0x1ae/0x2f0 fs/super.c:1363
sb_start_write include/linux/fs.h:1548 [inline]
mnt_want_write+0x3f/0xb0 fs/namespace.c:386
ovl_want_write+0x76/0xa0 fs/overlayfs/util.c:25
ovl_do_remove+0x68/0xbd0 fs/overlayfs/dir.c:759
ovl_unlink+0x18/0x20 fs/overlayfs/dir.c:792
vfs_unlink+0x281/0x480 fs/namei.c:4024
do_unlinkat+0x33d/0x600 fs/namei.c:4089
SYSC_unlink fs/namei.c:4136 [inline]
SyS_unlink+0x1b/0x20 fs/namei.c:4134
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #0 (&ovl_i_mutex_key[depth]#2){+.+.}:
check_prev_add kernel/locking/lockdep.c:1901 [inline]
check_prevs_add kernel/locking/lockdep.c:2018 [inline]
validate_chain kernel/locking/lockdep.c:2460 [inline]
__lock_acquire+0x2cb3/0x4620 kernel/locking/lockdep.c:3487
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
down_write+0x38/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:718 [inline]
bprm_fill_uid fs/exec.c:1522 [inline]
prepare_binprm+0x31c/0x7f0 fs/exec.c:1557
do_execveat_common.isra.0+0xd81/0x1dd0 fs/exec.c:1783
do_execve fs/exec.c:1847 [inline]
SYSC_execve fs/exec.c:1928 [inline]
SyS_execve+0x39/0x50 fs/exec.c:1923
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7

other info that might help us debug this:

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

Possible unsafe locking scenario:

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

*** DEADLOCK ***

1 lock held by syz-executor.0/15723:
#0: (&sig->cred_guard_mutex){+.+.}, at: [<ffffffff8190fcc5>]
prepare_bprm_creds+0x55/0x120 fs/exec.c:1389

stack backtrace:
CPU: 1 PID: 15723 Comm: syz-executor.0 Not tainted 4.14.163-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+0x142/0x197 lib/dump_stack.c:58
print_circular_bug.isra.0.cold+0x1cc/0x28f kernel/locking/lockdep.c:1258
check_prev_add kernel/locking/lockdep.c:1901 [inline]
check_prevs_add kernel/locking/lockdep.c:2018 [inline]
validate_chain kernel/locking/lockdep.c:2460 [inline]
__lock_acquire+0x2cb3/0x4620 kernel/locking/lockdep.c:3487
lock_acquire+0x16f/0x430 kernel/locking/lockdep.c:3994
down_write+0x38/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:718 [inline]
bprm_fill_uid fs/exec.c:1522 [inline]
prepare_binprm+0x31c/0x7f0 fs/exec.c:1557
do_execveat_common.isra.0+0xd81/0x1dd0 fs/exec.c:1783
do_execve fs/exec.c:1847 [inline]
SYSC_execve fs/exec.c:1928 [inline]
SyS_execve+0x39/0x50 fs/exec.c:1923
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45af49
RSP: 002b:00007fe64485cc78 EFLAGS: 00000246 ORIG_RAX: 000000000000003b
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045af49
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000140
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fe64485d6d4
R13: 00000000004c198f R14: 00000000004d6b10 R15: 00000000ffffffff
autofs4:pid:15739:autofs4_fill_super: called with bogus options
autofs4:pid:15748:autofs4_fill_super: called with bogus options
autofs4:pid:15760:autofs4_fill_super: called with bogus options
autofs4:pid:15762:autofs4_fill_super: called with bogus options
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
kauditd_printk_skb: 35 callbacks suppressed
audit: type=1804 audit(1578820766.922:4336): pid=15778 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/315/bus" dev="sda1"
ino=17141 res=1
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
autofs4:pid:15789:autofs4_fill_super: called with bogus options
audit: type=1800 audit(1578820766.922:4337): pid=15778 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="collect_data"
cause="failed(directio)" comm="syz-executor.2" name="bus" dev="sda1"
ino=17141 res=0
audit: type=1804 audit(1578820766.932:4338): pid=15778 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/315/bus" dev="sda1"
ino=17141 res=1
audit: type=1804 audit(1578820766.982:4339): pid=15785 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/316/bus" dev="sda1"
ino=17141 res=1
audit: type=1800 audit(1578820766.982:4340): pid=15785 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="collect_data"
cause="failed(directio)" comm="syz-executor.2" name="bus" dev="sda1"
ino=17141 res=0
audit: type=1804 audit(1578820766.982:4341): pid=15785 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/316/bus" dev="sda1"
ino=17141 res=1
audit: type=1804 audit(1578820767.202:4342): pid=15795 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/317/bus" dev="sda1"
ino=17141 res=1
audit: type=1800 audit(1578820767.202:4343): pid=15795 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="collect_data"
cause="failed(directio)" comm="syz-executor.2" name="bus" dev="sda1"
ino=17141 res=0
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
audit: type=1804 audit(1578820767.372:4344): pid=15803 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/318/bus" dev="sda1"
ino=17141 res=1
audit: type=1800 audit(1578820767.412:4345): pid=15803 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="collect_data"
cause="failed(directio)" comm="syz-executor.2" name="bus" dev="sda1"
ino=17141 res=0
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
autofs4:pid:15816:autofs4_fill_super: called with bogus options
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
autofs4:pid:15842:autofs4_fill_super: called with bogus options
autofs4:pid:15842:autofs4_fill_super: called with bogus options
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
autofs4:pid:15863:autofs4_fill_super: called with bogus options
IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
8021q: adding VLAN 0 to HW filter on device bond0
IPv6: ADDRCONF(NETDEV_UP): team0: link is not ready
8021q: adding VLAN 0 to HW filter on device team0
chnl_net:chnl_net_open(): err: Unable to register and open device, Err:-19
caif:caif_disconnect_client(): nothing to disconnect
chnl_net:chnl_flowctrl_cb(): NET flowctrl func called flow: CLOSE/DEINIT
chnl_net:chnl_net_open(): state disconnected
A link change request failed with some changes committed already. Interface
caif0 may have been left with an inconsistent configuration, please check.
autofs4:pid:15923:autofs4_fill_super: called with bogus options
autofs4:pid:15930:autofs4_fill_super: called with bogus options
autofs4:pid:15930:autofs4_fill_super: called with bogus options
autofs4:pid:15951:autofs4_fill_super: called with bogus options
autofs4:pid:15962:autofs4_fill_super: called with bogus options
autofs4:pid:15969:autofs4_fill_super: called with bogus options
kauditd_printk_skb: 7 callbacks suppressed
audit: type=1804 audit(1578820772.632:4353): pid=16034 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/336/bus" dev="sda1"
ino=17696 res=1
audit: type=1804 audit(1578820772.682:4354): pid=16034 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/336/bus" dev="sda1"
ino=17696 res=1
autofs4:pid:16043:autofs4_fill_super: called with bogus options
autofs4:pid:16048:autofs4_fill_super: called with bogus options
audit: type=1804 audit(1578820772.762:4355): pid=16047 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/337/bus" dev="sda1"
ino=17679 res=1
audit: type=1804 audit(1578820772.762:4356): pid=16047 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/337/bus" dev="sda1"
ino=17679 res=1
autofs4:pid:16069:autofs4_fill_super: called with bogus options
audit: type=1804 audit(1578820773.502:4357): pid=16068 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/338/bus" dev="sda1"
ino=17710 res=1
audit: type=1804 audit(1578820773.522:4358): pid=16068 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/338/bus" dev="sda1"
ino=17710 res=1
audit: type=1804 audit(1578820773.612:4359): pid=16078 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/339/bus" dev="sda1"
ino=17704 res=1
audit: type=1804 audit(1578820773.642:4360): pid=16078 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/339/bus" dev="sda1"
ino=17704 res=1
audit: type=1804 audit(1578820773.682:4361): pid=16085 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/340/bus" dev="sda1"
ino=17689 res=1
audit: type=1804 audit(1578820773.682:4362): pid=16085 uid=0
auid=4294967295 ses=4294967295
subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 op="invalid_pcr"
cause="ToMToU" comm="syz-executor.2"
name="/root/syzkaller-testdir735506959/syzkaller.qDTwDf/340/bus" dev="sda1"
ino=17689 res=1
autofs4:pid:16069:autofs4_fill_super: called with bogus options
autofs4:pid:16093:autofs4_fill_super: called with bogus options
autofs4:pid:16093:autofs4_fill_super: called with bogus options


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.