possible deadlock in perf_event_for_each_child

11 views
Skip to first unread message

syzbot

unread,
Apr 13, 2019, 3:01:27 AM4/13/19
Hello,

syzbot found the following crash on:

HEAD commit: d33692e8 Merge 4.14.74 into android-4.14
git tree: android-4.14
console output: https://syzkaller.appspot.com/x/log.txt?x=12e4157e400000
kernel config: https://syzkaller.appspot.com/x/.config?x=decf36ad71cd0a75
dashboard link: https://syzkaller.appspot.com/bug?extid=f38c077282be87991690
compiler: gcc (GCC) 8.0.1 20180413 (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: [email protected]

FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem

======================================================
WARNING: possible circular locking dependency detected
4.14.74+ #17 Not tainted
------------------------------------------------------
syz-executor4/15221 is trying to acquire lock:
(&event->child_mutex){+.+.}, at: [<ffffffff87de2ae2>]
perf_event_for_each_child+0x82/0x150 kernel/events/core.c:4681

but task is already holding lock:
(&cpuctx_mutex){+.+.}, at: [<ffffffff87deb5d9>]
perf_event_ctx_lock_nested+0x149/0x2f0 kernel/events/core.c:1240

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #8 (&cpuctx_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
perf_event_init_cpu+0xab/0x150 kernel/events/core.c:11210
perf_event_init+0x295/0x2d4 kernel/events/core.c:11257
start_kernel+0x441/0x739 init/main.c:621
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:240

-> #7 (pmus_lock){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
perf_event_init_cpu+0x2c/0x150 kernel/events/core.c:11204
cpuhp_invoke_callback+0x1b5/0x1960 kernel/cpu.c:183
cpuhp_up_callbacks kernel/cpu.c:567 [inline]
_cpu_up+0x22c/0x520 kernel/cpu.c:1126
do_cpu_up+0x13f/0x180 kernel/cpu.c:1160
smp_init+0x137/0x14b kernel/smp.c:578
kernel_init_freeable+0x186/0x39f init/main.c:1068
kernel_init+0xc/0x157 init/main.c:1000
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402

-> #6 (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/0xb0 kernel/cpu.c:294
get_online_cpus include/linux/cpu.h:138 [inline]
lru_add_drain_all+0xa/0x20 mm/swap.c:729
shmem_wait_for_pins mm/shmem.c:2683 [inline]
shmem_add_seals+0x4db/0x1230 mm/shmem.c:2791
shmem_fcntl+0xea/0x120 mm/shmem.c:2826
do_fcntl+0x966/0xea0 fs/fcntl.c:421
SYSC_fcntl fs/fcntl.c:463 [inline]
SyS_fcntl+0xc7/0x100 fs/fcntl.c:448
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #5 (&sb->s_type->i_mutex_key#10){+.+.}:
down_write+0x34/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:713 [inline]
shmem_fallocate+0x149/0xb20 mm/shmem.c:2852
ashmem_shrink_scan+0x1b6/0x4e0 drivers/staging/android/ashmem.c:453
ashmem_ioctl+0x2cc/0xe20 drivers/staging/android/ashmem.c:795
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #4 (ashmem_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
ashmem_mmap+0x4c/0x430 drivers/staging/android/ashmem.c:369
call_mmap include/linux/fs.h:1787 [inline]
mmap_region+0x836/0xfb0 mm/mmap.c:1731
do_mmap+0x551/0xb80 mm/mmap.c:1509
do_mmap_pgoff include/linux/mm.h:2167 [inline]
vm_mmap_pgoff+0x180/0x1d0 mm/util.c:333
SYSC_mmap_pgoff mm/mmap.c:1559 [inline]
SyS_mmap_pgoff+0xf8/0x1a0 mm/mmap.c:1517
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #3 (&mm->mmap_sem){++++}:
__might_fault+0x137/0x1b0 mm/memory.c:4529
_copy_to_user+0x27/0xc0 lib/usercopy.c:25
copy_to_user include/linux/uaccess.h:155 [inline]
filldir64+0x1c1/0x350 fs/readdir.c:282
dir_emit_dot include/linux/fs.h:3380 [inline]
dir_emit_dots include/linux/fs.h:3391 [inline]
dcache_readdir+0x12f/0x5d0 fs/libfs.c:192
iterate_dir+0x19f/0x5e0 fs/readdir.c:52
SYSC_getdents64 fs/readdir.c:315 [inline]
SyS_getdents64+0x141/0x250 fs/readdir.c:296
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #2 (&sb->s_type->i_mutex_key#5){++++}:
down_write+0x34/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:713 [inline]
start_creating.part.2+0x4c/0x160 fs/tracefs/inode.c:335
start_creating fs/tracefs/inode.c:324 [inline]
tracefs_create_file+0x75/0x450 fs/tracefs/inode.c:400
create_event_toplevel_files+0x2d/0x150
kernel/trace/trace_events.c:2912
early_event_add_tracer kernel/trace/trace_events.c:2999 [inline]
event_trace_init+0x30a/0x4e3 kernel/trace/trace_events.c:3164
do_one_initcall+0x99/0x1aa init/main.c:826
do_initcall_level init/main.c:892 [inline]
do_initcalls init/main.c:900 [inline]
do_basic_setup init/main.c:918 [inline]
kernel_init_freeable+0x2df/0x39f init/main.c:1073
kernel_init+0xc/0x157 init/main.c:1000
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402

-> #1 (event_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
perf_trace_destroy+0x23/0x100 kernel/trace/trace_event_perf.c:234
_free_event+0x293/0xb00 kernel/events/core.c:4237
free_event+0x31/0x40 kernel/events/core.c:4264
perf_event_release_kernel+0x37b/0x890 kernel/events/core.c:4408
perf_release+0x33/0x40 kernel/events/core.c:4434
__fput+0x25e/0x6f0 fs/file_table.c:210
task_work_run+0x116/0x190 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:191 [inline]
exit_to_usermode_loop+0x12e/0x150 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:267 [inline]
do_syscall_64+0x35d/0x4b0 arch/x86/entry/common.c:294
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #0 (&event->child_mutex){+.+.}:
lock_acquire+0x10f/0x380 kernel/locking/lockdep.c:3991
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
perf_event_for_each_child+0x82/0x150 kernel/events/core.c:4681
_perf_ioctl kernel/events/core.c:4857 [inline]
perf_ioctl+0x5de/0x1bb0 kernel/events/core.c:4869
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

other info that might help us debug this:

Chain exists of:
&event->child_mutex --> pmus_lock --> &cpuctx_mutex

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&cpuctx_mutex);
lock(pmus_lock);
lock(&cpuctx_mutex);
lock(&event->child_mutex);

*** DEADLOCK ***

1 lock held by syz-executor4/15221:
#0: (&cpuctx_mutex){+.+.}, at: [<ffffffff87deb5d9>]
perf_event_ctx_lock_nested+0x149/0x2f0 kernel/events/core.c:1240

stack backtrace:
CPU: 0 PID: 15221 Comm: syz-executor4 Not tainted 4.14.74+ #17
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0xb9/0x11b lib/dump_stack.c:53
print_circular_bug.isra.18.cold.43+0x2d3/0x40c
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+0x2ff9/0x4320 kernel/locking/lockdep.c:3487
lock_acquire+0x10f/0x380 kernel/locking/lockdep.c:3991
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xf5/0x1480 kernel/locking/mutex.c:893
perf_event_for_each_child+0x82/0x150 kernel/events/core.c:4681
_perf_ioctl kernel/events/core.c:4857 [inline]
perf_ioctl+0x5de/0x1bb0 kernel/events/core.c:4869
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1a0/0x1030 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7e/0xb0 fs/ioctl.c:692
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x457579
RSP: 002b:00007f5d374fac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000457579
RDX: 0000000000000000 RSI: 0000000000002403 RDI: 0000000000000006
RBP: 000000000072bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f5d374fb6d4
R13: 00000000004c0605 R14: 00000000004d07f8 R15: 00000000ffffffff
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): Unrecognized mount
option "8b.i���[[ �� ��+�$ \���B�-�WJ���&������ 㵫
l:� ;�>}�WE��4=��$zz�G+�& �
r�*���a�� � ����W[��a�>��l`�"�)�_�S�{A �(7k���ŧW���!����=U 4%k ����� \.׌� �
;W �g�]�� ᴡ0� ;N5 �I�� �� �g��~ ȯ�� D�3j Km.z<��
y�Q�hW�I߬����K4�" or missing value
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
input: syz1 as /devices/virtual/input/input28
input: syz1 as /devices/virtual/input/input29
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
netlink: 3 bytes leftover after parsing attributes in process
`syz-executor4'.
netlink: 3 bytes leftover after parsing attributes in process
`syz-executor4'.
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15566:15569 transaction failed 29189/-3, size 0-0 line 3135
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15566:15588 transaction failed 29189/-3, size 0-0 line 3135
binder: undelivered TRANSACTION_ERROR: 29189
binder: undelivered TRANSACTION_ERROR: 29189
FAT-fs (loop5): Can't find a valid FAT filesystem
device lo entered promiscuous mode
keychord: keycode 29300 out of range
FAT-fs (loop1): Unrecognized mount
option "A��R* �Q��f5ə��eǓ�i�E ������ ��Є* ��s s ̀m�E������"�
[����s 뾀�J+��
ù+.� �K:r�c ��fH_�N8�
��ށ��lЯ��� {�>URnI� �(r2�i�> Z � t����" T�-^U�_n�� x$��Ut-�O�~� �wB�F"
or
missing value
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
Y�4��`Ҙ: renamed from lo
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
binder: 15720:15725 got transaction to invalid handle
binder: 15720:15725 transaction failed 29201/-22, size 0-0 line 3012
binder: BINDER_SET_CONTEXT_MGR already set
binder: 15721:15726 ioctl 40046207 0 returned -16
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15721:15726 transaction failed 29189/-3, size 0-0 line 3135
binder: 15721:15726 unknown command 134243083
binder: 15721:15726 ioctl c0306201 200000c0 returned -22
binder: 15721:15726 BC_FREE_BUFFER u0000000000000000 no match
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15721:15726 transaction failed 29189/-3, size 0-0 line 3135
binder_alloc: binder_alloc_mmap_handler: 15721 20001000-20004000 already
mapped failed -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 15721:15726 ioctl 40046207 0 returned -16
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15721:15727 transaction failed 29189/-3, size 0-0 line 3135
binder: 15721:15726 unknown command 134243083
binder: 15721:15726 ioctl c0306201 200000c0 returned -22
binder: 15721:15727 BC_FREE_BUFFER u0000000000000000 no match
binder_alloc: 7026: binder_alloc_buf, no vma
binder: 15721:15727 transaction failed 29189/-3, size 0-0 line 3135
binder: undelivered TRANSACTION_ERROR: 29189
binder: undelivered TRANSACTION_ERROR: 29189
binder: undelivered TRANSACTION_ERROR: 29189
binder: undelivered TRANSACTION_ERROR: 29189
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: unknown main item tag 0x0
hid-generic 0000:0000:0000.0005: hidraw0: <UNKNOWN> HID v0.00 Device [syz1]
on syz1
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: unknown main item tag 0x0
hid-generic 0000:0000:0000.0006: hidraw0: <UNKNOWN> HID v0.00 Device [syz1]
on syz1
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
binder: undelivered TRANSACTION_ERROR: 29201
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=39240
sclass=netlink_route_socket pig=15863 comm=syz-executor3
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=39240
sclass=netlink_route_socket pig=15866 comm=syz-executor3
FAT-fs (loop1): Unrecognized mount option "jfs" or missing value
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem


---
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 [email protected].

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

syzbot

unread,
Dec 15, 2019, 11:17:06 PM12/15/19
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