possible deadlock in perf_event_ctx_lock_nested

6 views
Skip to first unread message

syzbot

unread,
Jun 2, 2020, 5:36:15 AM6/2/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 4f68020f Linux 4.14.182
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=15d1aaa6100000
kernel config: https://syzkaller.appspot.com/x/.config?x=512ec6eb8f94d0c8
dashboard link: https://syzkaller.appspot.com/bug?extid=3ec4ef0f1532d4e7378c
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+3ec4ef...@syzkaller.appspotmail.com

======================================================
WARNING: possible circular locking dependency detected
4.14.182-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/19888 is trying to acquire lock:
(&mm->mmap_sem){++++}, at: [<ffffffff817969b4>] __might_fault+0xd4/0x1b0 mm/memory.c:4583

but task is already holding lock:
(&cpuctx_mutex){+.+.}, at: [<ffffffff81691dfd>] perf_event_ctx_lock_nested+0x14d/0x2c0 kernel/events/core.c:1235

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&cpuctx_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xe8/0x1430 kernel/locking/mutex.c:893
perf_event_init_cpu+0xb7/0x170 kernel/events/core.c:11244
perf_event_init+0x2cc/0x308 kernel/events/core.c:11291
start_kernel+0x46b/0x771 init/main.c:620
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:240

-> #2 (pmus_lock){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xe8/0x1430 kernel/locking/mutex.c:893
perf_event_init_cpu+0x2c/0x170 kernel/events/core.c:11238
cpuhp_invoke_callback+0x1e6/0x1a90 kernel/cpu.c:184
cpuhp_up_callbacks kernel/cpu.c:572 [inline]
_cpu_up+0x21a/0x520 kernel/cpu.c:1140
do_cpu_up kernel/cpu.c:1175 [inline]
do_cpu_up+0x9a/0x160 kernel/cpu.c:1147
smp_init+0x197/0x1ac kernel/smp.c:578
kernel_init_freeable+0x3f4/0x615 init/main.c:1068
kernel_init+0xd/0x15b init/main.c:1000
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

-> #1 (cpu_hotplug_lock.rw_sem){++++}:
percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36 [inline]
percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
cpus_read_lock+0x39/0xc0 kernel/cpu.c:295
__static_key_slow_dec kernel/jump_label.c:213 [inline]
static_key_slow_dec+0x47/0x70 kernel/jump_label.c:228
sw_perf_event_destroy+0x7b/0x110 kernel/events/core.c:7940
_free_event+0x328/0xe50 kernel/events/core.c:4238
put_event+0x20/0x30 kernel/events/core.c:4324
perf_mmap_close+0x3d9/0xc00 kernel/events/core.c:5283
remove_vma+0xa9/0x1a0 mm/mmap.c:167
remove_vma_list mm/mmap.c:2505 [inline]
do_munmap+0x5cc/0xc40 mm/mmap.c:2746
mmap_region+0x16e/0x1060 mm/mmap.c:1658
do_mmap+0x5b3/0xcb0 mm/mmap.c:1495
do_mmap_pgoff include/linux/mm.h:2173 [inline]
vm_mmap_pgoff+0x14e/0x1a0 mm/util.c:333
SYSC_mmap_pgoff mm/mmap.c:1545 [inline]
SyS_mmap_pgoff+0x249/0x510 mm/mmap.c:1503
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb

-> #0 (&mm->mmap_sem){++++}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
__might_fault mm/memory.c:4584 [inline]
__might_fault+0x137/0x1b0 mm/memory.c:4569
_copy_to_user+0x27/0xd0 lib/usercopy.c:25
copy_to_user include/linux/uaccess.h:155 [inline]
perf_read_one kernel/events/core.c:4577 [inline]
__perf_read kernel/events/core.c:4620 [inline]
perf_read+0x54c/0x7c0 kernel/events/core.c:4633
do_loop_readv_writev fs/read_write.c:695 [inline]
do_loop_readv_writev fs/read_write.c:682 [inline]
do_iter_read+0x3e3/0x5a0 fs/read_write.c:919
vfs_readv+0xd3/0x130 fs/read_write.c:981
do_readv+0xfc/0x2c0 fs/read_write.c:1014
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:
&mm->mmap_sem --> pmus_lock --> &cpuctx_mutex

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&cpuctx_mutex);
lock(pmus_lock);
lock(&cpuctx_mutex);
lock(&mm->mmap_sem);

*** DEADLOCK ***

1 lock held by syz-executor.3/19888:
#0: (&cpuctx_mutex){+.+.}, at: [<ffffffff81691dfd>] perf_event_ctx_lock_nested+0x14d/0x2c0 kernel/events/core.c:1235

stack backtrace:
CPU: 0 PID: 19888 Comm: syz-executor.3 Not tainted 4.14.182-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.isra.0.cold+0x2dc/0x425 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+0x3057/0x42a0 kernel/locking/lockdep.c:3491
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
__might_fault mm/memory.c:4584 [inline]
__might_fault+0x137/0x1b0 mm/memory.c:4569
_copy_to_user+0x27/0xd0 lib/usercopy.c:25
copy_to_user include/linux/uaccess.h:155 [inline]
perf_read_one kernel/events/core.c:4577 [inline]
__perf_read kernel/events/core.c:4620 [inline]
perf_read+0x54c/0x7c0 kernel/events/core.c:4633
do_loop_readv_writev fs/read_write.c:695 [inline]
do_loop_readv_writev fs/read_write.c:682 [inline]
do_iter_read+0x3e3/0x5a0 fs/read_write.c:919
vfs_readv+0xd3/0x130 fs/read_write.c:981
do_readv+0xfc/0x2c0 fs/read_write.c:1014
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45ca69
RSP: 002b:00007f11b1aadc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000013
RAX: ffffffffffffffda RBX: 00000000004fb300 RCX: 000000000045ca69
RDX: 0000000000000004 RSI: 000000002058c000 RDI: 0000000000000005
RBP: 000000000078bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000892 R14: 00000000004cb498 R15: 00007f11b1aae6d4
netlink: 20 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 20 bytes leftover after parsing attributes in process `syz-executor.5'.
ceph: device name is missing path (no : separator in [d::],0::6:<=6縓��̻<:�."� � "V� g ��)
audit: type=1800 audit(1591090552.517:220): pid=19965 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="file0" dev="sda1" ino=16323 res=0
MINIX-fs: mounting unchecked file system, running fsck is recommended
ceph: device name is missing path (no : separator in [d::],0::6:<=6縓��̻<:�."� � "V� g ��)
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
minix_free_inode: bit 1 already cleared
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: upperdir is in-use by another mount, mount with '-o index=off' to override exclusive upperdir protection.
9pnet: p9_fd_create_tcp (19961): problem connecting socket to 127.0.0.1
9pnet: p9_fd_create_tcp (19975): problem connecting socket to 127.0.0.1
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
netlink: 5 bytes leftover after parsing attributes in process `syz-executor.1'.
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
ip_tables: iptables: counters copy to user failed while replacing table
overlayfs: unrecognized mount option "wor dir=./file1\" or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
overlayfs: unrecognized mount option "wor dir=./file1\" or missing value
overlayfs: unrecognized mount option "upperd�� $� �?e " or missing value
ip_tables: iptables: counters copy to user failed while replacing table
audit: type=1804 audit(1591090555.967:221): pid=20216 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir732893578/syzkaller.wRtKPT/275/bus" dev="sda1" ino=16324 res=1
audit: type=1804 audit(1591090556.007:222): pid=20216 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="ToMToU" comm="syz-executor.2" name="/root/syzkaller-testdir732893578/syzkaller.wRtKPT/275/bus" dev="sda1" ino=16324 res=1
audit: type=1804 audit(1591090556.557:223): pid=20221 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir732893578/syzkaller.wRtKPT/275/bus" dev="sda1" ino=16324 res=1
ISOFS: Logical zone size(0) < hardware blocksize(1024)
BTRFS: device fsid fff6f2a2-2997-48ae-b81e-1b00b10efd9a devid 0 transid 0 /dev/loop5
ISOFS: Logical zone size(0) < hardware blocksize(1024)
BTRFS error (device loop5): superblock checksum mismatch
BTRFS error (device loop5): open_ctree failed
BTRFS error (device loop5): superblock checksum mismatch
BTRFS error (device loop5): open_ctree failed
XFS (loop2): bad version
XFS (loop2): SB validate failed with error -22.
XFS (loop2): bad version
XFS (loop2): SB validate failed with error -22.
new mount options do not match the existing superblock, will be ignored
new mount options do not match the existing superblock, will be ignored
nla_parse: 17 callbacks suppressed
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
overlayfs: filesystem on './file0' not supported as upperdir
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
ieee80211 phy13: Selected rate control algorithm 'minstrel_ht'
ieee80211 phy13: hwaddr 02:00:00:00:0d:00 registered
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
hfsplus: invalid gid specified
hfsplus: unable to parse mount options
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
audit: type=1804 audit(1591090559.467:224): pid=20552 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir165900567/syzkaller.XX9o0T/223/bus" dev="sda1" ino=16133 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
audit: type=1804 audit(1591090559.497:225): pid=20552 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir165900567/syzkaller.XX9o0T/223/bus" dev="sda1" ino=16133 res=1
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
binder: 20592:20598 ioctl c0306201 20000540 returned -14
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
ieee80211 phy14: Selected rate control algorithm 'minstrel_ht'
ieee80211 phy14: hwaddr 02:00:00:00:0e:00 registered
ieee80211 phy15: Selected rate control algorithm 'minstrel_ht'
ieee80211 phy15: hwaddr 02:00:00:00:0f:00 registered
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 24 bytes leftover after parsing attributes in process `syz-executor.5'.
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 1
CPU: 0 PID: 20679 Comm: syz-executor.4 Not tainted 4.14.182-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
fail_dump lib/fault-inject.c:51 [inline]
should_fail.cold+0x10a/0x154 lib/fault-inject.c:149
should_failslab+0xd6/0x130 mm/failslab.c:32
slab_pre_alloc_hook mm/slab.h:421 [inline]
slab_alloc mm/slab.c:3376 [inline]
kmem_cache_alloc_trace+0x2b7/0x3f0 mm/slab.c:3616
kmalloc include/linux/slab.h:488 [inline]
kzalloc include/linux/slab.h:661 [inline]
rtentry_to_fib_config net/ipv4/fib_frontend.c:545 [inline]
ip_rt_ioctl+0x7e4/0xce0 net/ipv4/fib_frontend.c:585
inet_ioctl+0x124/0x190 net/ipv4/af_inet.c:882
sock_do_ioctl+0x5f/0xa0 net/socket.c:974
sock_ioctl+0x28d/0x450 net/socket.c:1071
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xfe0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45ca69
RSP: 002b:00007f404ba39c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00000000004f3f00 RCX: 000000000045ca69
RDX: 0000000020000600 RSI: 000000000000890b RDI: 0000000000000003
RBP: 000000000078bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000004
R13: 00000000000006c2 R14: 00000000004c9a4f R15: 00007f404ba3a6d4


---
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

unread,
Sep 30, 2020, 5:36:12 AM9/30/20
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