INIT: Entering runlevel: 2 [info] Using makefile-style concurrent boot in runlevel 2. [....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[ ok 8[?25h[?0c. Debian GNU/Linux 7 syzkaller ttyS0 Warning: Permanently added 'ci-upstream-next-kasan-gce-4,10.128.0.32' (ECDSA) to the list of known hosts. 2017/09/15 23:52:50 parsed 1 programs 2017/09/15 23:52:50 executed programs: 0 syzkaller login: [ 31.677546] [ 31.677920] ====================================================== [ 31.678787] WARNING: possible circular locking dependency detected [ 31.679617] 4.13.0-next-20170915+ #23 Not tainted [ 31.680256] ------------------------------------------------------ [ 31.681086] syz-executor0/2996 is trying to acquire lock: [ 31.681814] (event_mutex){+.+.}, at: [] perf_trace_init+0x58/0xab0 [ 31.682869] [ 31.682869] but task is already holding lock: [ 31.683655] (&ctx->mutex){+.+.}, at: [] perf_event_init_task+0x25b/0x890 [ 31.684771] [ 31.684771] which lock already depends on the new lock. [ 31.684771] [ 31.685857] [ 31.685857] the existing dependency chain (in reverse order) is: [ 31.686856] [ 31.686856] -> #8 (&ctx->mutex){+.+.}: [ 31.687577] __lock_acquire+0x328f/0x4620 [ 31.688196] lock_acquire+0x1d5/0x580 [ 31.688772] __mutex_lock+0x16f/0x1870 [ 31.689357] mutex_lock_nested+0x16/0x20 [ 31.689965] perf_event_ctx_lock_nested+0x1dc/0x3c0 [ 31.690694] perf_read+0xb9/0x970 [ 31.691225] do_iter_read+0x3db/0x5b0 [ 31.691799] vfs_readv+0x121/0x1c0 [ 31.692392] default_file_splice_read+0x508/0xae0 [ 31.693101] do_splice_to+0x110/0x170 [ 31.693675] SyS_splice+0x11a8/0x1630 [ 31.694252] entry_SYSCALL_64_fastpath+0x1f/0xbe [ 31.694966] [ 31.694966] -> #7 (&pipe->mutex/1){+.+.}: [ 31.695714] __lock_acquire+0x328f/0x4620 [ 31.696334] lock_acquire+0x1d5/0x580 [ 31.696908] __mutex_lock+0x16f/0x1870 [ 31.697495] mutex_lock_nested+0x16/0x20 [ 31.698127] pipe_lock+0x56/0x70 [ 31.701976] iter_file_splice_write+0x264/0xf50 [ 31.707127] SyS_splice+0x7d5/0x1630 [ 31.711325] entry_SYSCALL_64_fastpath+0x1f/0xbe [ 31.716563] [ 31.716563] -> #6 (sb_writers){.+.+}: [ 31.721808] __sb_start_write+0x18f/0x290 [ 31.726440] mnt_want_write+0x3f/0xb0 [ 31.730724] filename_create+0x12b/0x520 [ 31.735268] kern_path_create+0x33/0x40 [ 31.739726] handle_create+0xc0/0x760 [ 31.744011] [ 31.744011] -> #5 ((complete)&req.done){+.+.}: [ 31.750037] __lock_acquire+0x328f/0x4620 [ 31.754669] lock_acquire+0x1d5/0x580 [ 31.758952] wait_for_completion+0xc8/0x770 [ 31.763759] devtmpfs_create_node+0x32b/0x4a0 [ 31.768738] device_add+0x120f/0x1640 [ 31.773024] device_create_groups_vargs+0x1f3/0x250 [ 31.778523] device_create+0xda/0x110 [ 31.782807] msr_device_create+0x26/0x40 [ 31.787352] cpuhp_invoke_callback+0x256/0x14d0 [ 31.792503] cpuhp_thread_fun+0x265/0x520 [ 31.797137] smpboot_thread_fn+0x489/0x850 [ 31.801857] kthread+0x39c/0x470 [ 31.806025] ret_from_fork+0x2a/0x40 [ 31.810223] [ 31.810223] -> #4 (cpuhp_state){+.+.}: [ 31.815558] __lock_acquire+0x328f/0x4620 [ 31.820190] lock_acquire+0x1d5/0x580 [ 31.824474] cpuhp_issue_call+0x1a2/0x3e0 [ 31.829107] __cpuhp_setup_state_cpuslocked+0x2d6/0x5f0 [ 31.834953] __cpuhp_setup_state+0xb0/0x140 [ 31.839761] page_writeback_init+0x4d/0x71 [ 31.844481] pagecache_init+0x48/0x4f [ 31.848768] start_kernel+0x6c1/0x754 [ 31.853057] x86_64_start_reservations+0x2a/0x2c [ 31.858298] x86_64_start_kernel+0x77/0x7a [ 31.863019] verify_cpu+0x0/0xfb [ 31.866872] [ 31.866872] -> #3 (cpuhp_state_mutex){+.+.}: [ 31.872727] __lock_acquire+0x328f/0x4620 [ 31.877357] lock_acquire+0x1d5/0x580 [ 31.881642] __mutex_lock+0x16f/0x1870 [ 31.886012] mutex_lock_nested+0x16/0x20 [ 31.890556] __cpuhp_setup_state_cpuslocked+0x5b/0x5f0 [ 31.896315] __cpuhp_setup_state+0xb0/0x140 [ 31.901121] kvm_guest_init+0x1f3/0x20f [ 31.905580] setup_arch+0x1879/0x1a93 [ 31.909866] start_kernel+0xa5/0x754 [ 31.914064] x86_64_start_reservations+0x2a/0x2c [ 31.919303] x86_64_start_kernel+0x77/0x7a [ 31.924022] verify_cpu+0x0/0xfb [ 31.927870] [ 31.927870] -> #2 (cpu_hotplug_lock.rw_sem){++++}: [ 31.934243] __lock_acquire+0x328f/0x4620 [ 31.938875] lock_acquire+0x1d5/0x580 [ 31.943159] cpus_read_lock+0x42/0x90 [ 31.947445] static_key_slow_inc+0x9d/0x3c0 [ 31.952250] tracepoint_probe_register_prio+0x80d/0x9a0 [ 31.958097] tracepoint_probe_register+0x2a/0x40 [ 31.963338] trace_event_reg+0x167/0x320 [ 31.967882] perf_trace_init+0x4f9/0xab0 [ 31.972429] perf_tp_event_init+0x7d/0xf0 [ 31.977059] perf_try_init_event+0xc9/0x1f0 [ 31.981863] perf_event_alloc+0x1c5b/0x2a00 [ 31.986669] SYSC_perf_event_open+0x84e/0x2e00 [ 31.991736] SyS_perf_event_open+0x39/0x50 [ 31.996453] entry_SYSCALL_64_fastpath+0x1f/0xbe [ 32.001689] [ 32.001689] -> #1 (tracepoints_mutex){+.+.}: [ 32.007540] __lock_acquire+0x328f/0x4620 [ 32.012174] lock_acquire+0x1d5/0x580 [ 32.016457] __mutex_lock+0x16f/0x1870 [ 32.020829] mutex_lock_nested+0x16/0x20 [ 32.025380] tracepoint_probe_register_prio+0xa0/0x9a0 [ 32.031139] tracepoint_probe_register+0x2a/0x40 [ 32.036378] trace_event_reg+0x167/0x320 [ 32.040922] perf_trace_init+0x4f9/0xab0 [ 32.045466] perf_tp_event_init+0x7d/0xf0 [ 32.050096] perf_try_init_event+0xc9/0x1f0 [ 32.054901] perf_event_alloc+0x1c5b/0x2a00 [ 32.059706] SYSC_perf_event_open+0x84e/0x2e00 [ 32.064771] SyS_perf_event_open+0x39/0x50 [ 32.069488] entry_SYSCALL_64_fastpath+0x1f/0xbe [ 32.074725] [ 32.074725] -> #0 (event_mutex){+.+.}: [ 32.080058] check_prev_add+0x865/0x1520 [ 32.084603] __lock_acquire+0x328f/0x4620 [ 32.089233] lock_acquire+0x1d5/0x580 [ 32.093516] __mutex_lock+0x16f/0x1870 [ 32.097889] mutex_lock_nested+0x16/0x20 [ 32.102432] perf_trace_init+0x58/0xab0 [ 32.106889] perf_tp_event_init+0x7d/0xf0 [ 32.111520] perf_try_init_event+0xc9/0x1f0 [ 32.116323] perf_event_alloc+0x10fa/0x2a00 [ 32.121128] inherit_event.isra.93+0x15b/0x910 [ 32.126193] inherit_task_group.isra.95.part.96+0x73/0x240 [ 32.132302] perf_event_init_task+0x348/0x890 [ 32.137283] copy_process.part.36+0x173b/0x4af0 [ 32.142433] _do_fork+0x1ef/0xfe0 [ 32.146369] SyS_clone+0x37/0x50 [ 32.150219] do_syscall_64+0x26c/0x8c0 [ 32.154591] return_from_SYSCALL_64+0x0/0x7a [ 32.159490] [ 32.159490] other info that might help us debug this: [ 32.159490] [ 32.167592] Chain exists of: [ 32.167592] event_mutex --> &pipe->mutex/1 --> &ctx->mutex [ 32.167592] [ 32.177701] Possible unsafe locking scenario: [ 32.177701] [ 32.183718] CPU0 CPU1 [ 32.188347] ---- ---- [ 32.192975] lock(&ctx->mutex); [ 32.196303] lock(&pipe->mutex/1); [ 32.202419] lock(&ctx->mutex); [ 32.208264] lock(event_mutex); [ 32.211593] [ 32.211593] *** DEADLOCK *** [ 32.211593] [ 32.217614] 2 locks held by syz-executor0/2996: [ 32.222244] #0: (&ctx->mutex){+.+.}, at: [] perf_event_init_task+0x25b/0x890 [ 32.231134] #1: (&pmus_srcu){....}, at: [] perf_event_alloc+0x104a/0x2a00 [ 32.239764] [ 32.239764] stack backtrace: [ 32.244227] CPU: 1 PID: 2996 Comm: syz-executor0 Not tainted 4.13.0-next-20170915+ #23 [ 32.252252] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 32.261570] Call Trace: [ 32.264127] dump_stack+0x194/0x257 [ 32.267717] ? arch_local_irq_restore+0x53/0x53 [ 32.272352] print_circular_bug+0x503/0x710 [ 32.276640] ? print_circular_bug_entry+0xb0/0xb0 [ 32.281449] check_prev_add+0x865/0x1520 [ 32.285474] ? copy_trace+0x1d0/0x1d0 [ 32.289240] ? check_usage+0xb70/0xb70 [ 32.293091] ? __lock_acquire+0x732/0x4620 [ 32.297292] ? hlock_class+0x140/0x140 [ 32.301155] ? unwind_next_frame.part.6+0x1ae/0xc70 [ 32.306134] ? copy_trace+0x1d0/0x1d0 [ 32.309901] __lock_acquire+0x328f/0x4620 [ 32.314012] ? __lock_acquire+0x328f/0x4620 [ 32.318308] ? copy_trace+0x1d0/0x1d0 [ 32.322075] ? debug_check_no_locks_freed+0x3d0/0x3d0 [ 32.327229] ? __save_stack_trace+0x61/0xd0 [ 32.331517] ? perf_event_alloc+0x200/0x2a00 [ 32.335891] ? save_stack_trace+0x16/0x20 [ 32.340002] ? __lock_acquire+0x20fd/0x4620 [ 32.344289] ? debug_check_no_locks_freed+0x3d0/0x3d0 [ 32.349446] ? debug_check_no_locks_freed+0x3d0/0x3d0 [ 32.354599] ? unwind_next_frame.part.6+0x1ae/0xc70 [ 32.359578] ? unwind_dump+0x4c0/0x4c0 [ 32.363429] ? print_usage_bug+0x480/0x480 [ 32.367629] ? unwind_get_return_address+0x61/0xa0 [ 32.372531] ? __save_stack_trace+0x61/0xd0 [ 32.376821] ? check_noncircular+0x20/0x20 [ 32.381020] ? check_noncircular+0x20/0x20 [ 32.385224] lock_acquire+0x1d5/0x580 [ 32.388988] ? perf_trace_init+0x58/0xab0 [ 32.393099] ? lock_release+0xd70/0xd70 [ 32.397038] ? check_same_owner+0x320/0x320 [ 32.401324] ? debug_check_no_locks_freed+0x3d0/0x3d0 [ 32.406477] ? __might_sleep+0x95/0x190 [ 32.410414] ? perf_trace_init+0x58/0xab0 [ 32.414529] __mutex_lock+0x16f/0x1870 [ 32.418377] ? perf_trace_init+0x58/0xab0 [ 32.422490] ? perf_trace_init+0x58/0xab0 [ 32.426601] ? mutex_lock_io_nested+0x1740/0x1740 [ 32.431406] ? do_raw_spin_trylock+0x190/0x190 [ 32.435953] ? print_usage_bug+0x480/0x480 [ 32.440153] ? mark_held_locks+0xb2/0x100 [ 32.444266] ? _raw_spin_unlock_irqrestore+0x31/0xba [ 32.449331] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 32.454309] ? print_usage_bug+0x480/0x480 [ 32.458510] ? depot_save_stack+0x3b5/0x490 [ 32.462799] ? print_usage_bug+0x480/0x480 [ 32.466997] ? save_stack_trace+0x16/0x20 [ 32.471110] ? save_stack+0x43/0xd0 [ 32.474698] ? kasan_kmalloc+0xad/0xe0 [ 32.478547] ? kmem_cache_alloc_trace+0x136/0x750 [ 32.483354] ? perf_event_alloc+0x200/0x2a00 [ 32.487726] ? inherit_event.isra.93+0x15b/0x910 [ 32.492443] ? inherit_task_group.isra.95.part.96+0x73/0x240 [ 32.498202] ? perf_event_init_task+0x348/0x890 [ 32.502837] ? copy_process.part.36+0x173b/0x4af0 [ 32.507640] ? _do_fork+0x1ef/0xfe0 [ 32.511231] ? SyS_clone+0x37/0x50 [ 32.514735] ? do_syscall_64+0x26c/0x8c0 [ 32.518759] ? entry_SYSCALL64_slow_path+0x25/0x25 [ 32.523654] ? mark_held_locks+0xb2/0x100 [ 32.527764] ? debug_mutex_init+0x1c/0x60 [ 32.531876] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 32.536856] ? __lockdep_init_map+0xe4/0x650 [ 32.541228] ? lockdep_init_map+0x3d/0x70 [ 32.545341] ? module_unload_free+0x5b0/0x5b0 [ 32.549803] ? perf_event_alloc+0x104a/0x2a00 [ 32.554263] mutex_lock_nested+0x16/0x20 [ 32.558288] ? mutex_lock_nested+0x16/0x20 [ 32.562486] perf_trace_init+0x58/0xab0 [ 32.566424] ? refcount_inc_not_zero+0xfe/0x180 [ 32.571056] ? refcount_add+0x60/0x60 [ 32.574821] ? __lockdep_init_map+0xe4/0x650 [ 32.579193] perf_tp_event_init+0x7d/0xf0 [ 32.583303] perf_try_init_event+0xc9/0x1f0 [ 32.587588] perf_event_alloc+0x10fa/0x2a00 [ 32.591881] ? perf_trace_run_bpf_submit+0x2a0/0x2a0 [ 32.596951] ? lock_downgrade+0x990/0x990 [ 32.601064] ? print_usage_bug+0x480/0x480 [ 32.605264] ? unwind_dump+0x4c0/0x4c0 [ 32.609118] ? do_raw_spin_trylock+0x190/0x190 [ 32.613664] ? mark_held_locks+0xb2/0x100 [ 32.617776] ? mark_held_locks+0xb2/0x100 [ 32.621890] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 32.626869] ? debug_mutex_init+0x1c/0x60 [ 32.630983] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 32.635966] ? lockdep_init_map+0x3d/0x70 [ 32.640079] ? debug_mutex_init+0x2d/0x60 [ 32.644193] ? __mutex_init+0x1c7/0x2a0 [ 32.648130] ? kmem_cache_alloc_trace+0x136/0x750 [ 32.652934] ? alloc_perf_context+0x4c/0xe0 [ 32.657218] ? SyS_membarrier+0x430/0x430 [ 32.661329] ? mark_held_locks+0xb2/0x100 [ 32.665439] ? __raw_spin_lock_init+0x1c/0x100 [ 32.669986] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 32.674965] ? __lockdep_init_map+0xe4/0x650