possible deadlock in perf_trace

possible deadlock in perf_trace_destroy (3)
Status: upstream: reported on 2018/08/09 11:51
Reported-by: syzbot+8a284974371a58b241d1@syzkaller.appspotmail.com
First crash: 258d, last: 125d

similar bugs (4):
Kernel	Title	Repro	Count	Last	Reported	Patched	Status
upstream	possible deadlock in perf_trace_destroy (2)	C	2006	443d	528d	6/13	fixed on 2018/04/24 21:47
android-414	possible deadlock in perf_trace_destroy (2)		1	12d	6d02h	0/1	public: reported on 2019/04/14 08:52
upstream	possible deadlock in perf_trace_destroy	C	525	550d	534d	0/13	closed as invalid on 2017/11/01 19:39
linux-4.14	possible deadlock in perf_trace_destroy	C	25	1h25m	4d21h	0/1	upstream: reported C repro on 2019/04/15 13:38

Sample crash report:

======================================================
WARNING: possible circular locking dependency detected
4.18.0-rc7+ #177 Not tainted
------------------------------------------------------
syz-executor0/7368 is trying to acquire lock:
0000000055a8b790 (event_mutex){+.+.}, at: perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235

but task is already holding lock:
00000000866fdc62 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x1b5/0x2c0 mm/util.c:355

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&mm->mmap_sem){++++}:
       down_write_killable+0x92/0x150 kernel/locking/rwsem.c:84
       dup_mmap kernel/fork.c:430 [inline]
       dup_mm kernel/fork.c:1266 [inline]
       copy_mm kernel/fork.c:1320 [inline]
       copy_process.part.39+0x2430/0x70b0 kernel/fork.c:1826
       copy_process kernel/fork.c:1639 [inline]
       _do_fork+0x291/0x12a0 kernel/fork.c:2122
       __do_sys_clone kernel/fork.c:2229 [inline]
       __se_sys_clone kernel/fork.c:2223 [inline]
       __x64_sys_clone+0xbf/0x150 kernel/fork.c:2223
       do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #2 (&dup_mmap_sem){++++}:
       down_write+0x8f/0x130 kernel/locking/rwsem.c:70
       percpu_down_write+0xaf/0x520 kernel/locking/percpu-rwsem.c:145
       register_for_each_vma+0x8c/0xdf0 kernel/events/uprobes.c:796
       __uprobe_register kernel/events/uprobes.c:846 [inline]
       uprobe_register+0x47c/0x7c0 kernel/events/uprobes.c:907
       probe_event_enable+0x5f5/0xe90 kernel/trace/trace_uprobe.c:920
       trace_uprobe_register+0x4c9/0xcf0 kernel/trace/trace_uprobe.c:1205
       perf_trace_event_reg kernel/trace/trace_event_perf.c:123 [inline]
       perf_trace_event_init+0x4fe/0x990 kernel/trace/trace_event_perf.c:198
       perf_uprobe_init+0x1e5/0x280 kernel/trace/trace_event_perf.c:327
       perf_uprobe_event_init+0xff/0x190 kernel/events/core.c:8467
       perf_try_init_event+0x137/0x2f0 kernel/events/core.c:9739
       perf_init_event kernel/events/core.c:9770 [inline]
       perf_event_alloc.part.93+0x1955/0x30b0 kernel/events/core.c:10043
       perf_event_alloc kernel/events/core.c:10399 [inline]
       __do_sys_perf_event_open+0xab2/0x30f0 kernel/events/core.c:10500
       __se_sys_perf_event_open kernel/events/core.c:10389 [inline]
       __x64_sys_perf_event_open+0xbe/0x150 kernel/events/core.c:10389
       do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&uprobe->register_rwsem){+.+.}:
       down_write+0x8f/0x130 kernel/locking/rwsem.c:70
       uprobe_register+0x3dd/0x7c0 kernel/events/uprobes.c:904
       probe_event_enable+0x5f5/0xe90 kernel/trace/trace_uprobe.c:920
       trace_uprobe_register+0x4c9/0xcf0 kernel/trace/trace_uprobe.c:1205
       perf_trace_event_reg kernel/trace/trace_event_perf.c:123 [inline]
       perf_trace_event_init+0x4fe/0x990 kernel/trace/trace_event_perf.c:198
       perf_uprobe_init+0x1e5/0x280 kernel/trace/trace_event_perf.c:327
       perf_uprobe_event_init+0xff/0x190 kernel/events/core.c:8467
       perf_try_init_event+0x137/0x2f0 kernel/events/core.c:9739
       perf_init_event kernel/events/core.c:9770 [inline]
       perf_event_alloc.part.93+0x1955/0x30b0 kernel/events/core.c:10043
       perf_event_alloc kernel/events/core.c:10399 [inline]
       __do_sys_perf_event_open+0xab2/0x30f0 kernel/events/core.c:10500
       __se_sys_perf_event_open kernel/events/core.c:10389 [inline]
       __x64_sys_perf_event_open+0xbe/0x150 kernel/events/core.c:10389
       do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (event_mutex){+.+.}:
       lock_acquire+0x1e4/0x540 kernel/locking/lockdep.c:3924
       __mutex_lock_common kernel/locking/mutex.c:757 [inline]
       __mutex_lock+0x176/0x1820 kernel/locking/mutex.c:894
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:909
       perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
       tp_perf_event_destroy+0x15/0x20 kernel/events/core.c:8329
       _free_event+0x407/0x1440 kernel/events/core.c:4445
       put_event+0x48/0x60 kernel/events/core.c:4531
       perf_mmap_close+0x615/0x1190 kernel/events/core.c:5514
       remove_vma+0xb6/0x180 mm/mmap.c:181
       remove_vma_list mm/mmap.c:2549 [inline]
       do_munmap+0x743/0xf90 mm/mmap.c:2785
       mmap_region+0x61f/0x16b0 mm/mmap.c:1705
       do_mmap+0xa06/0x1320 mm/mmap.c:1535
       do_mmap_pgoff include/linux/mm.h:2306 [inline]
       vm_mmap_pgoff+0x213/0x2c0 mm/util.c:357
       ksys_mmap_pgoff+0xf1/0x660 mm/mmap.c:1585
       __do_sys_mmap arch/x86/kernel/sys_x86_64.c:100 [inline]
       __se_sys_mmap arch/x86/kernel/sys_x86_64.c:91 [inline]
       __x64_sys_mmap+0xe9/0x1b0 arch/x86/kernel/sys_x86_64.c:91
       do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  event_mutex --> &dup_mmap_sem --> &mm->mmap_sem

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&mm->mmap_sem);
                               lock(&dup_mmap_sem);
                               lock(&mm->mmap_sem);
  lock(event_mutex);

 *** DEADLOCK ***

1 lock held by syz-executor0/7368:
 #0: 00000000866fdc62 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x1b5/0x2c0 mm/util.c:355

stack backtrace:
CPU: 0 PID: 7368 Comm: syz-executor0 Not tainted 4.18.0-rc7+ #177
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
 print_circular_bug.isra.36.cold.57+0x1bd/0x27d kernel/locking/lockdep.c:1227
 check_prev_add kernel/locking/lockdep.c:1867 [inline]
 check_prevs_add kernel/locking/lockdep.c:1980 [inline]
 validate_chain kernel/locking/lockdep.c:2421 [inline]
 __lock_acquire+0x3449/0x5020 kernel/locking/lockdep.c:3435
 lock_acquire+0x1e4/0x540 kernel/locking/lockdep.c:3924
 __mutex_lock_common kernel/locking/mutex.c:757 [inline]
 __mutex_lock+0x176/0x1820 kernel/locking/mutex.c:894
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:909
 perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
 tp_perf_event_destroy+0x15/0x20 kernel/events/core.c:8329
 _free_event+0x407/0x1440 kernel/events/core.c:4445
 put_event+0x48/0x60 kernel/events/core.c:4531
 perf_mmap_close+0x615/0x1190 kernel/events/core.c:5514
 remove_vma+0xb6/0x180 mm/mmap.c:181
 remove_vma_list mm/mmap.c:2549 [inline]
 do_munmap+0x743/0xf90 mm/mmap.c:2785
 mmap_region+0x61f/0x16b0 mm/mmap.c:1705
 do_mmap+0xa06/0x1320 mm/mmap.c:1535
 do_mmap_pgoff include/linux/mm.h:2306 [inline]
 vm_mmap_pgoff+0x213/0x2c0 mm/util.c:357
 ksys_mmap_pgoff+0xf1/0x660 mm/mmap.c:1585
 __do_sys_mmap arch/x86/kernel/sys_x86_64.c:100 [inline]
 __se_sys_mmap arch/x86/kernel/sys_x86_64.c:91 [inline]
 __x64_sys_mmap+0xe9/0x1b0 arch/x86/kernel/sys_x86_64.c:91
 do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x456b29
Code: fd b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 
RSP: 002b:00007fe9fd1ecc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000009
RAX: ffffffffffffffda RBX: 00007fe9fd1ed6d4 RCX: 0000000000456b29
RDX: 0000000000000000 RSI: 0000000000200000 RDI: 00000000205a1000
RBP: 00000000009300a0 R08: ffffffffffffffff R09: 0000000000000000
R10: 0000000000008031 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004d1b50 R14: 00000000004c72d5 R15: 0000000000000000
capability: warning: `syz-executor6' uses deprecated v2 capabilities in a way that may be insecure
ntfs: (device loop3): parse_options(): The umask option requires an argument.
ntfs: (device loop3): parse_options(): The umask option requires an argument.
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
bridge0: port 1(bridge_slave_0) entered disabled state
IPv6: ADDRCONF(NETDEV_UP): bridge_slave_0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered forwarding state
bridge0: port 1(bridge_slave_0) entered disabled state
mmap: syz-executor4 (7501): VmData 18391040 exceed data ulimit 0. Update limits or use boot option ignore_rlimit_data.
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl
QAT: Invalid ioctl

All crashes (12):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Maintainers
ci-upstream-kasan-gce-root	2018/08/05 10:42	upstream	60f5a217	3476a2df	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-smack-root	2018/12/16 09:17	upstream	6531e115	def91db3	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-smack-root	2018/11/23 04:45	upstream	edeca3a7	87815d9d	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/10/14 19:29	upstream	3a272031	caf12900	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-smack-root	2018/09/07 10:53	upstream	ca16eb34	e30d3b52	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-selinux-root	2018/09/06 23:21	upstream	ca16eb34	e30d3b52	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/09/06 06:17	upstream	b36fdc68	873745f2	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/08/10 15:35	upstream	112cbae2	1fb62d58	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/08/07 23:53	upstream	1236568e	1beb8136	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/08/07 05:41	upstream	1236568e	1beb8136	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-kasan-gce-root	2018/08/06 14:35	upstream	1ffaddd0	1beb8136	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org
ci-upstream-linux-next-kasan-gce-root	2018/10/26 09:11	linux-next	8c60c36d	a8292de9	.config	log	report	linux-kernel@vger.kernel.org, mingo@redhat.com, rostedt@goodmis.org