syzbot

 sign-in | mailing list | source | docs
🞠Open [995] ≡ Subsystems 🞠Fixed [5242] 🞠Invalid [12514] ⬇ Missing Backports [83] 📈 Kernel Health 📈 Bug Lifetimes 📈 Fuzzing 📈 Crashes 💬 Send us feedback

possible deadlock in perf_event_for_each_child

Status: auto-closed as invalid on 2019/02/22 10:22
Subsystems: perf
[Documentation on labels]
Reported-by: syzbot+a146e1aa3546ae373077@syzkaller.appspotmail.com
First crash: 2286d, last: 2276d
▶ ▼ Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.14 possible deadlock in perf_event_for_each_child C 1482 423d 1839d 0/1 upstream: reported C repro on 2019/04/14 09:58
android-414 possible deadlock in perf_event_for_each_child 9 1713d 1840d 0/1 auto-closed as invalid on 2019/12/15 20:17

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
4.15.0-rc9+ #9 Not tainted
------------------------------------------------------
syz-executor1/6389 is trying to acquire lock:
 (&event->child_mutex){+.+.}, at: [<000000000857a1c0>] perf_event_for_each_child+0x8a/0x150 kernel/events/core.c:4557

but task is already holding lock:
 (&cpuctx_mutex){+.+.}, at: [<00000000a77e48ee>] perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #5 (&cpuctx_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
       perf_event_init_cpu+0xb6/0x160 kernel/events/core.c:11076
       perf_event_init+0x4e9/0x549 kernel/events/core.c:11123
       start_kernel+0x4cc/0x819 init/main.c:627
       x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
       x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
       secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #4 (pmus_lock){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
       perf_event_init_cpu+0x2f/0x160 kernel/events/core.c:11070
       cpuhp_invoke_callback+0x2ea/0x1d20 kernel/cpu.c:182
       cpuhp_up_callbacks kernel/cpu.c:477 [inline]
       _cpu_up+0x216/0x510 kernel/cpu.c:1036
       do_cpu_up+0x73/0xa0 kernel/cpu.c:1066
       cpu_up+0x18/0x20 kernel/cpu.c:1074
       smp_init+0x13a/0x152 kernel/smp.c:578
       kernel_init_freeable+0x2fe/0x521 init/main.c:1067
       kernel_init+0x13/0x180 init/main.c:999
       ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:541

-> #3 (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+0x42/0x90 kernel/cpu.c:293
       static_key_slow_inc+0x9d/0x3c0 kernel/jump_label.c:123
       tracepoint_add_func kernel/tracepoint.c:223 [inline]
       tracepoint_probe_register_prio+0x80d/0x9a0 kernel/tracepoint.c:283
       tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:304
       trace_event_reg+0x167/0x320 kernel/trace/trace_events.c:305
       perf_trace_event_reg kernel/trace/trace_event_perf.c:122 [inline]
       perf_trace_event_init kernel/trace/trace_event_perf.c:197 [inline]
       perf_trace_init+0x4ef/0xab0 kernel/trace/trace_event_perf.c:221
       perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:7959
       perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9192
       perf_init_event kernel/events/core.c:9230 [inline]
       perf_event_alloc+0x1cc6/0x2b00 kernel/events/core.c:9494
       SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:9949
       SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9835
       entry_SYSCALL_64_fastpath+0x29/0xa0

-> #2 (tracepoints_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
       tracepoint_probe_register_prio+0xa0/0x9a0 kernel/tracepoint.c:279
       tracepoint_probe_register+0x2a/0x40 kernel/tracepoint.c:304
       trace_event_reg+0x167/0x320 kernel/trace/trace_events.c:305
       perf_trace_event_reg kernel/trace/trace_event_perf.c:122 [inline]
       perf_trace_event_init kernel/trace/trace_event_perf.c:197 [inline]
       perf_trace_init+0x4ef/0xab0 kernel/trace/trace_event_perf.c:221
       perf_tp_event_init+0x7d/0xf0 kernel/events/core.c:7959
       perf_try_init_event+0xc9/0x1f0 kernel/events/core.c:9192
       perf_init_event kernel/events/core.c:9230 [inline]
       perf_event_alloc+0x1cc6/0x2b00 kernel/events/core.c:9494
       SYSC_perf_event_open+0x84e/0x2e00 kernel/events/core.c:9949
       SyS_perf_event_open+0x39/0x50 kernel/events/core.c:9835
       entry_SYSCALL_64_fastpath+0x29/0xa0

-> #1 (event_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
       perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:234
       tp_perf_event_destroy+0x15/0x20 kernel/events/core.c:7943
       _free_event+0x3bd/0x10f0 kernel/events/core.c:4104
       free_event+0x84/0x150 kernel/events/core.c:4128
       perf_event_release_kernel+0x54e/0xc10 kernel/events/core.c:4272
       perf_release+0x37/0x50 kernel/events/core.c:4298
       __fput+0x327/0x7e0 fs/file_table.c:210
       ____fput+0x15/0x20 fs/file_table.c:244
       task_work_run+0x199/0x270 kernel/task_work.c:113
       exit_task_work include/linux/task_work.h:22 [inline]
       do_exit+0x9bb/0x1ad0 kernel/exit.c:865
       do_group_exit+0x149/0x400 kernel/exit.c:968
       get_signal+0x73f/0x16c0 kernel/signal.c:2335
       do_signal+0x90/0x1eb0 arch/x86/kernel/signal.c:809
       exit_to_usermode_loop+0x214/0x310 arch/x86/entry/common.c:158
       prepare_exit_to_usermode arch/x86/entry/common.c:195 [inline]
       syscall_return_slowpath+0x490/0x550 arch/x86/entry/common.c:264
       entry_SYSCALL_64_fastpath+0x9e/0xa0

-> #0 (&event->child_mutex){+.+.}:
       lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3914
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
       perf_event_for_each_child+0x8a/0x150 kernel/events/core.c:4557
       _perf_ioctl kernel/events/core.c:4736 [inline]
       perf_ioctl+0x35a/0x1430 kernel/events/core.c:4748
       vfs_ioctl fs/ioctl.c:46 [inline]
       do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:686
       SYSC_ioctl fs/ioctl.c:701 [inline]
       SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
       entry_SYSCALL_64_fastpath+0x29/0xa0

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-executor1/6389:
 #0:  (&cpuctx_mutex){+.+.}, at: [<00000000a77e48ee>] perf_event_ctx_lock_nested+0x21b/0x450 kernel/events/core.c:1249

stack backtrace:
CPU: 1 PID: 6389 Comm: syz-executor1 Not tainted 4.15.0-rc9+ #9
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+0x194/0x257 lib/dump_stack.c:53
 print_circular_bug.isra.37+0x2cd/0x2dc kernel/locking/lockdep.c:1218
 check_prev_add kernel/locking/lockdep.c:1858 [inline]
 check_prevs_add kernel/locking/lockdep.c:1971 [inline]
 validate_chain kernel/locking/lockdep.c:2412 [inline]
 __lock_acquire+0x30a8/0x3e00 kernel/locking/lockdep.c:3426
 lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3914
 __mutex_lock_common kernel/locking/mutex.c:756 [inline]
 __mutex_lock+0x16f/0x1a80 kernel/locking/mutex.c:893
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908
 perf_event_for_each_child+0x8a/0x150 kernel/events/core.c:4557
 _perf_ioctl kernel/events/core.c:4736 [inline]
 perf_ioctl+0x35a/0x1430 kernel/events/core.c:4748
 vfs_ioctl fs/ioctl.c:46 [inline]
 do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:686
 SYSC_ioctl fs/ioctl.c:701 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
 entry_SYSCALL_64_fastpath+0x29/0xa0
RIP: 0033:0x453299
RSP: 002b:00007f5aeb166c58 EFLAGS: 00000212 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f5aeb167700 RCX: 0000000000453299
RDX: 0000000000000000 RSI: 0000000000002401 RDI: 0000000000000012
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: 0000000000000000
R13: 00007fffc57787af R14: 00007f5aeb1679c0 R15: 0000000000000000
IPVS: ftp: loaded support on port[0] = 21
audit: type=1400 audit(1517476544.574:18): avc:  denied  { create } for  pid=6427 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
IPVS: ftp: loaded support on port[0] = 21
audit: type=1400 audit(1517476546.822:19): avc:  denied  { setopt } for  pid=6616 comm="syz-executor7" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:unlabeled_t:s0 tclass=socket permissive=1
overlayfs: unrecognized mount option ")ä" or missing value
overlayfs: unrecognized mount option ")ä" or missing value
autofs4:pid:6824:autofs4_fill_super: called with bogus options
tmpfs: No value for mount option 'âÛ÷${	 ë6<,3'
autofs4:pid:6835:autofs4_fill_super: called with bogus options
tmpfs: No value for mount option 'âÛ÷${	 ë6<,3'
IPVS: ftp: loaded support on port[0] = 21
rpcbind: RPC call returned error 22
autofs4:pid:6954:autofs4_fill_super: called with bogus options
autofs4:pid:6969:autofs4_fill_super: called with bogus options
IPVS: ftp: loaded support on port[0] = 21
tmpfs: No value for mount option 'bü^Å<S[ñ'
audit: type=1400 audit(1517476550.136:20): avc:  denied  { map } for  pid=7212 comm="syz-executor1" path="socket:[21220]" dev="sockfs" ino=21220 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=unix_dgram_socket permissive=1
can: request_module (can-proto-3) failed.
can: request_module (can-proto-3) failed.
syz-executor4[7338] is installing a program with bpf_probe_write_user helper that may corrupt user memory!
cgroup: cgroup2: unknown option ""
syz-executor4[7338] is installing a program with bpf_probe_write_user helper that may corrupt user memory!
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21

Crashes (135):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2018/02/01 09:15 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/02/01 05:40 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/02/01 05:09 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 22:03 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 21:04 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 20:45 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 17:20 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 10:39 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 09:41 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 08:10 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 08:07 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 07:42 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 05:49 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/31 05:33 bpf-next 868c36dcc949 02553e22 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 23:47 bpf-next 868c36dcc949 a899be78 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 23:46 bpf-next 868c36dcc949 a899be78 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 21:31 bpf-next 868c36dcc949 a899be78 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 19:27 bpf-next 868c36dcc949 a899be78 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 17:24 bpf-next 868c36dcc949 a899be78 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 12:13 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 08:31 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/30 01:35 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 19:29 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 16:52 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 15:51 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 10:19 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 09:36 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 07:23 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 05:35 bpf-next 868c36dcc949 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/29 03:27 bpf-next 8223967fe0b8 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/28 22:31 bpf-next 8223967fe0b8 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/28 21:34 bpf-next 8223967fe0b8 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/28 20:27 bpf-next 8223967fe0b8 08d47756 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/27 23:37 bpf-next 8223967fe0b8 08146b1a .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/27 21:13 bpf-next 8223967fe0b8 08146b1a .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/27 06:04 bpf-next 8223967fe0b8 1d18b112 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/27 00:17 bpf-next 9c147b56fc71 1d18b112 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/26 13:51 bpf-next 82f1e0f3acf0 1d18b112 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/26 13:11 bpf-next 82f1e0f3acf0 1d18b112 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/26 12:33 bpf-next 82f1e0f3acf0 1d18b112 .config console log report ci-upstream-bpf-next-kasan-gce
2018/01/22 18:42 bpf-next ebdd7b491b8a 228e3d95 .config console log report ci-upstream-bpf-next-kasan-gce
* Struck through repros no longer work on HEAD.