possible deadlock in proc_tid_io_accounting

20 views
Skip to first unread message

syzbot

unread,
Jan 12, 2021, 12:52:20 AM1/12/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: ec822b3e Linux 4.14.214
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=163b4ee0d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c7d2eef63e7505
dashboard link: https://syzkaller.appspot.com/bug?extid=95cfd7e72b9dbdaa4bee
compiler: gcc (GCC) 10.1.0-syz 20200507

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

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

======================================================
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
WARNING: possible circular locking dependency detected
4.14.214-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/22785 is trying to acquire lock:
(&sig->cred_guard_mutex){+.+.}, at: [<ffffffff81a30c84>] do_io_accounting fs/proc/base.c:2725 [inline]
(&sig->cred_guard_mutex){+.+.}, at: [<ffffffff81a30c84>] proc_tid_io_accounting+0x184/0x290 fs/proc/base.c:2768

but task is already holding lock:
PF_BRIDGE: br_mdb_parse() with unknown ifindex
(&p->lock){+.+.}, at: [<ffffffff819104fa>] seq_read+0xba/0x1120 fs/seq_file.c:165

which lock already depends on the new lock.

netlink: 16 bytes leftover after parsing attributes in process `syz-executor.3'.

the existing dependency chain (in reverse order) is:

-> #3 (&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
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.3'.
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
EXT4-fs (loop5): Unrecognized mount option "���-̩�3ɣu���� j� �Q5N� � 8!�" or missing value
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
EXT4-fs (loop5): failed to parse options in superblock: ���-̩�3ɣu���� j� �Q5N� � 8!�
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #2 (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:1549 [inline]
mnt_want_write+0x3a/0xb0 fs/namespace.c:386
ovl_do_remove+0x67/0xb90 fs/overlayfs/dir.c:759
vfs_rmdir.part.0+0x144/0x390 fs/namei.c:3908
vfs_rmdir fs/namei.c:3893 [inline]
do_rmdir+0x334/0x3c0 fs/namei.c:3968
EXT4-fs (loop5): Unsupported encryption level 241
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #1 (&ovl_i_mutex_dir_key[depth]#2){++++}:
down_read+0x36/0x80 kernel/locking/rwsem.c:24
inode_lock_shared include/linux/fs.h:729 [inline]
do_last fs/namei.c:3333 [inline]
path_openat+0x149b/0x2970 fs/namei.c:3569
do_filp_open+0x179/0x3c0 fs/namei.c:3603
do_open_execat+0xd3/0x450 fs/exec.c:849
do_execveat_common+0x711/0x1f30 fs/exec.c:1755
do_execve fs/exec.c:1860 [inline]
SYSC_execve fs/exec.c:1941 [inline]
SyS_execve+0x3b/0x50 fs/exec.c:1936
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #0 (&sig->cred_guard_mutex){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
do_io_accounting fs/proc/base.c:2725 [inline]
proc_tid_io_accounting+0x184/0x290 fs/proc/base.c:2768
proc_single_show+0xe7/0x150 fs/proc/base.c:761
seq_read+0x4cf/0x1120 fs/seq_file.c:237
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

other info that might help us debug this:

Chain exists of:
&sig->cred_guard_mutex --> sb_writers#3 --> &p->lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&p->lock);
lock(sb_writers#3);
lock(&p->lock);
lock(&sig->cred_guard_mutex);

*** DEADLOCK ***

1 lock held by syz-executor.0/22785:
#0: (&p->lock){+.+.}, at: [<ffffffff819104fa>] seq_read+0xba/0x1120 fs/seq_file.c:165

stack backtrace:
CPU: 1 PID: 22785 Comm: syz-executor.0 Not tainted 4.14.214-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
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
do_io_accounting fs/proc/base.c:2725 [inline]
proc_tid_io_accounting+0x184/0x290 fs/proc/base.c:2768
proc_single_show+0xe7/0x150 fs/proc/base.c:761
seq_read+0x4cf/0x1120 fs/seq_file.c:237
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
RIP: 0033:0x45e219
RSP: 002b:00007fd5c14d3c68 EFLAGS: 00000246 ORIG_RAX: 0000000000000127
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 000000000045e219
RDX: 000000000000037d RSI: 0000000020000500 RDI: 0000000000000009
RBP: 000000000119bfd0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000119bf8c
R13: 00007ffffd97b8af R14: 00007fd5c14d49c0 R15: 000000000119bf8c
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
FAT-fs (loop3): bogus sectors per cluster 7
FAT-fs (loop3): Can't find a valid FAT filesystem
print_req_error: I/O error, dev loop5, sector 0
Buffer I/O error on dev loop5, logical block 0, async page read
print_req_error: I/O error, dev loop5, sector 4
Buffer I/O error on dev loop5, logical block 2, async page read
print_req_error: I/O error, dev loop5, sector 6
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
Buffer I/O error on dev loop5, logical block 3, async page read
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.2'.
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430719.492:97): pid=22858 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430719.492:98): pid=22858 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
EXT4-fs (loop5): Unrecognized mount option "���-̩�3ɣu���� j� �Q5N� � 8!�" or missing value
Dev loop2: unable to read RDB block 1
loop2: unable to read partition table
EXT4-fs (loop5): failed to parse options in superblock: ���-̩�3ɣu���� j� �Q5N� � 8!�
loop2: partition table beyond EOD,
EXT4-fs (loop5): Unsupported encryption level 241
truncated
audit: type=1804 audit(1610430719.492:99): pid=22858 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
loop_reread_partitions: partition scan of loop2 () failed (rc=-5)
tmpfs: No value for mount option 'dont_hash'
audit: type=1804 audit(1610430720.202:100): pid=22994 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430720.232:101): pid=22995 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430720.242:102): pid=22994 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/104/file0/file0" dev="loop0" ino=17 res=1
Dev loop2: unable to read RDB block 1
loop2: unable to read partition table
loop2: partition table beyond EOD, truncated
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430720.482:103): pid=23015 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/105/file0/file0" dev="loop0" ino=17 res=1
loop_reread_partitions: partition scan of loop2 () failed (rc=-5)
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430720.512:104): pid=23015 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/105/file0/file0" dev="loop0" ino=17 res=1
Dev loop2: unable to read RDB block 1
loop2: unable to read partition table
loop2: partition table beyond EOD, truncated
audit: type=1804 audit(1610430720.522:105): pid=23015 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/105/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430720.592:106): pid=23034 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/67/file0/file0" dev="loop1" ino=17 res=1
audit: type=1804 audit(1610430720.622:107): pid=23034 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/67/file0/file0" dev="loop1" ino=17 res=1
audit: type=1804 audit(1610430720.622:108): pid=23034 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/67/file0/file0" dev="loop1" ino=17 res=1
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430721.022:109): pid=23080 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/106/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430721.022:110): pid=23080 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/106/file0/file0" dev="loop0" ino=17 res=1
IPVS: ftp: loaded support on port[0] = 21
audit: type=1804 audit(1610430721.022:111): pid=23080 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/106/file0/file0" dev="loop0" ino=17 res=1
IPVS: ftp: loaded support on port[0] = 21
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430721.922:112): pid=23228 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/107/file0/file0" dev="loop0" ino=17 res=1
IPVS: ftp: loaded support on port[0] = 21
print_req_error: I/O error, dev loop3, sector 0
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
kauditd_printk_skb: 14 callbacks suppressed
audit: type=1804 audit(1610430725.593:127): pid=23587 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/111/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430725.593:128): pid=23598 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/73/file0/file0" dev="loop1" ino=17 res=1
audit: type=1804 audit(1610430725.623:129): pid=23598 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/73/file0/file0" dev="loop1" ino=17 res=1
audit: type=1804 audit(1610430725.633:130): pid=23598 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir479885645/syzkaller.pHM7NX/73/file0/file0" dev="loop1" ino=17 res=1
audit: type=1804 audit(1610430725.633:131): pid=23587 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/111/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430725.653:132): pid=23587 uid=0 auid=0 ses=4 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/111/file0/file0" dev="loop0" ino=17 res=1
audit: type=1804 audit(1610430726.423:133): pid=23657 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir281140180/syzkaller.nW2IS5/400/bus" dev="sda1" ino=16507 res=1
audit: type=1804 audit(1610430726.453:134): pid=23657 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir281140180/syzkaller.nW2IS5/400/bus" dev="sda1" ino=16507 res=1
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1804 audit(1610430726.573:135): pid=23688 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/112/file0/file0" dev="sda1" ino=16541 res=1
audit: type=1804 audit(1610430726.573:136): pid=23658 uid=0 auid=0 ses=4 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir163383587/syzkaller.QgRtns/112/file0/file0" dev="sda1" ino=16541 res=1
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop2): mounted filesystem without journal. Opts: ,errors=continue


---
This report 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 issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Jul 31, 2021, 1:58:16 AM7/31/21
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages