audit: type=1400 audit(1545934198.796:25648): avc: denied { map } for pid=26837 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 ====================================================== WARNING: possible circular locking dependency detected 4.14.90+ #29 Not tainted ------------------------------------------------------ syz-executor1/26884 is trying to acquire lock: (&event->child_mutex){+.+.}, at: [] perf_event_for_each_child+0x82/0x150 kernel/events/core.c:4687 but task is already holding lock: (&cpuctx_mutex){+.+.}, at: [] 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:11213 perf_event_init+0x295/0x2d4 kernel/events/core.c:11260 start_kernel+0x444/0x73f 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:11207 cpuhp_invoke_callback+0x1b5/0x1960 kernel/cpu.c:184 cpuhp_up_callbacks kernel/cpu.c:574 [inline] _cpu_up+0x22c/0x520 kernel/cpu.c:1134 do_cpu_up+0x13f/0x180 kernel/cpu.c:1169 smp_init+0x137/0x14e kernel/smp.c:578 kernel_init_freeable+0x189/0x3a5 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:295 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:2732 [inline] shmem_add_seals+0x4db/0x1230 mm/shmem.c:2841 shmem_fcntl+0xea/0x120 mm/shmem.c:2876 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:715 [inline] shmem_fallocate+0x149/0xb20 mm/shmem.c:2902 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:1789 [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:4555 _copy_to_user+0x27/0xc0 lib/usercopy.c:25 copy_to_user include/linux/uaccess.h:155 [inline] filldir+0x192/0x340 fs/readdir.c:197 dir_emit_dot include/linux/fs.h:3371 [inline] dir_emit_dots include/linux/fs.h:3382 [inline] dcache_readdir+0x12f/0x5d0 fs/libfs.c:192 iterate_dir+0x19f/0x5e0 fs/readdir.c:52 SYSC_getdents fs/readdir.c:232 [inline] SyS_getdents+0x146/0x270 fs/readdir.c:213 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:715 [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+0x2e5/0x3a5 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:4243 free_event+0x31/0x40 kernel/events/core.c:4270 perf_event_release_kernel+0x37b/0x890 kernel/events/core.c:4414 EXT4-fs warning (device sda1): verify_group_input:123: Last group not full perf_release+0x33/0x40 kernel/events/core.c:4440 __fput+0x25e/0x6f0 fs/file_table.c:210 task_work_run+0x116/0x190 kernel/task_work.c:113 exit_task_work include/linux/task_work.h:22 [inline] do_exit+0x8fb/0x28c0 kernel/exit.c:865 do_group_exit+0x100/0x2e0 kernel/exit.c:968 get_signal+0x4e5/0x1470 kernel/signal.c:2348 do_signal+0x8f/0x1660 arch/x86/kernel/signal.c:809 exit_to_usermode_loop+0x116/0x150 arch/x86/entry/common.c:159 prepare_exit_to_usermode+0x124/0x150 arch/x86/entry/common.c:198 retint_user+0x8/0x18 -> #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:4687 EXT4-fs warning (device sda1): verify_group_input:123: Last group not full perf_event_task_enable+0x8f/0x110 kernel/events/core.c:4909 SYSC_prctl kernel/sys.c:2440 [inline] SyS_prctl+0x4c5/0x1320 kernel/sys.c:2346 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 *** 2 locks held by syz-executor1/26884: #0: (&child->perf_event_mutex){+.+.}, at: [] perf_event_task_enable+0x20/0x110 kernel/events/core.c:4906 #1: (&cpuctx_mutex){+.+.}, at: [] perf_event_ctx_lock_nested+0x149/0x2f0 kernel/events/core.c:1240 stack backtrace: CPU: 1 PID: 26884 Comm: syz-executor1 Not tainted 4.14.90+ #29 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:4687 perf_event_task_enable+0x8f/0x110 kernel/events/core.c:4909 SYSC_prctl kernel/sys.c:2440 [inline] SyS_prctl+0x4c5/0x1320 kernel/sys.c:2346 do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x4579b9 RSP: 002b:00007f29117bfc78 EFLAGS: 00000246 ORIG_RAX: 000000000000009d RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00000000004579b9 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000020 RBP: 000000000073bf00 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 00007f29117c06d4 R13: 00000000004cb190 R14: 00000000004d7458 R15: 00000000ffffffff EXT4-fs warning (device sda1): verify_group_input:123: Last group not full ip6_tunnel: ip6tnl3 xmit: Local address not yet configured! EXT4-fs warning (device sda1): verify_group_input:123: Last group not full kauditd_printk_skb: 183 callbacks suppressed audit: type=1400 audit(1545934203.746:25832): avc: denied { create } for pid=26991 comm="syz-executor1" 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 audit: type=1400 audit(1545934203.746:25833): avc: denied { write } for pid=26991 comm="syz-executor1" 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 EXT4-fs warning (device sda1): verify_group_input:123: Last group not full audit: type=1400 audit(1545934203.776:25834): avc: denied { map } for pid=26998 comm="blkid" path="/sbin/blkid" dev="sda1" ino=16128 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.786:25835): avc: denied { map } for pid=26998 comm="blkid" path="/sbin/blkid" dev="sda1" ino=16128 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.806:25836): avc: denied { map } for pid=26998 comm="blkid" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.816:25837): avc: denied { map } for pid=27001 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.816:25838): avc: denied { map } for pid=27001 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.816:25839): avc: denied { map } for pid=26998 comm="blkid" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.826:25840): avc: denied { map } for pid=26998 comm="blkid" path="/etc/ld.so.cache" dev="sda1" ino=2503 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934203.826:25841): avc: denied { map } for pid=27001 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 EXT4-fs warning (device sda1): verify_group_input:123: Last group not full EXT4-fs warning (device sda1): verify_group_input:123: Last group not full EXT4-fs warning (device sda1): verify_group_input:123: Last group not full ip6_tunnel: ip6tnl2 xmit: Local address not yet configured! kauditd_printk_skb: 123 callbacks suppressed audit: type=1400 audit(1545934208.796:25965): avc: denied { write } for pid=27142 comm="syz-executor0" 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 audit: type=1400 audit(1545934208.866:25966): avc: denied { map } for pid=27154 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.876:25967): avc: denied { map } for pid=27154 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.886:25968): avc: denied { map } for pid=27156 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.886:25969): avc: denied { map } for pid=27156 comm="modprobe" path="/bin/kmod" dev="sda1" ino=1440 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.886:25971): avc: denied { map } for pid=27154 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.886:25970): avc: denied { map } for pid=27156 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.896:25972): avc: denied { map } for pid=27156 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.896:25973): avc: denied { map } for pid=27154 comm="modprobe" path="/lib/x86_64-linux-gnu/ld-2.13.so" dev="sda1" ino=2668 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 audit: type=1400 audit(1545934208.926:25974): avc: denied { map } for pid=27154 comm="modprobe" path="/etc/ld.so.cache" dev="sda1" ino=2503 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1