syzbot


possible deadlock in perf_event_ctx_lock_nested

Status: auto-closed as invalid on 2020/09/30 09:36
Reported-by: syzbot+3ec4ef0f1532d4e7378c@syzkaller.appspotmail.com
First crash: 762d, last: 762d
similar bugs (4):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in perf_event_ctx_lock_nested 8914 1661d 1711d 0/22 auto-closed as invalid on 2019/02/22 10:22
linux-4.19 possible deadlock in perf_event_ctx_lock_nested 1 452d 452d 0/1 auto-closed as invalid on 2021/08/06 16:06
linux-4.14 possible deadlock in perf_event_ctx_lock_nested (2) syz 5 16d 622d 0/1 upstream: reported syz repro on 2020/10/20 10:26
upstream possible deadlock in perf_event_ctx_lock_nested (2) syz done 12 256d 413d 0/22 upstream: reported syz repro on 2021/05/17 11:17

Sample crash report:
======================================================
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縓̻<:.""Vg	)
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縓̻<:.""Vg	)
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 "wordir=./file1\" or missing value
overlayfs: unrecognized mount option "upperd$?e" or missing value
overlayfs: unrecognized mount option "wordir=./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

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2020/06/02 09:36 linux-4.14.y 4f68020fef1c a0331e89 .config log report