1# Note: 191-194 have the same root cause. 2TITLE: possible deadlock in perf_event_ctx_lock_nested 3 4[ 189.031888] ====================================================== 5[ 189.038179] WARNING: possible circular locking dependency detected 6[ 189.044467] 4.15.0-rc3+ #222 Not tainted 7[ 189.048497] ------------------------------------------------------ 8[ 189.054779] syz-executor5/24180 is trying to acquire lock: 9[ 189.060366] (&ctx->mutex){+.+.}, at: [<00000000546c47e1>] perf_event_ctx_lock_nested+0x21b/0x450 10[ 189.069358] 11[ 189.069358] but task is already holding lock: 12[ 189.075292] (&pipe->mutex/1){+.+.}, at: [<000000002090b936>] pipe_lock+0x56/0x70 13[ 189.082888] 14[ 189.082888] which lock already depends on the new lock. 15[ 189.082888] 16[ 189.091166] 17[ 189.091166] the existing dependency chain (in reverse order) is: 18[ 189.098751] 19[ 189.098751] -> #8 (&pipe->mutex/1){+.+.}: 20[ 189.104353] lock_acquire+0x1d5/0x580 21[ 189.108648] __mutex_lock+0x16f/0x1a80 22[ 189.113028] mutex_lock_nested+0x16/0x20 23[ 189.117576] pipe_lock+0x56/0x70 24[ 189.121429] iter_file_splice_write+0x264/0xf30 25[ 189.126584] SyS_splice+0x7d5/0x1630 26[ 189.130783] entry_SYSCALL_64_fastpath+0x1f/0x96 27[ 189.136025] 28[ 189.136025] -> #7 (sb_writers){.+.+}: 29[ 189.141276] try_to_wake_up+0xbc/0x1600 30[ 189.145737] default_wake_function+0x30/0x50 31[ 189.150633] __wake_up_common+0x18e/0x780 32[ 189.155268] __wake_up_locked+0x11/0x20 33[ 189.159727] complete+0x5f/0x80 34[ 189.163490] 35[ 189.163490] -> #6 ((completion)&req.done){+.+.}: 36[ 189.169693] lock_acquire+0x1d5/0x580 37[ 189.173982] wait_for_completion+0xcb/0x7b0 38[ 189.178790] devtmpfs_create_node+0x32b/0x4a0 39[ 189.183774] device_add+0x120f/0x1640 40[ 189.188062] device_create_groups_vargs+0x1f3/0x250 41[ 189.193566] device_create+0xda/0x110 42[ 189.197854] msr_device_create+0x26/0x40 43[ 189.202402] cpuhp_invoke_callback+0x2ea/0x1d20 44[ 189.207554] cpuhp_thread_fun+0x48e/0x7e0 45[ 189.212189] smpboot_thread_fn+0x450/0x7c0 46[ 189.216910] kthread+0x37a/0x440 47[ 189.220760] ret_from_fork+0x24/0x30 48[ 189.224956] 49[ 189.224956] -> #5 (cpuhp_state-up){+.+.}: 50[ 189.230553] lock_acquire+0x1d5/0x580 51[ 189.234838] cpuhp_issue_call+0x1e5/0x520 52[ 189.239470] __cpuhp_setup_state_cpuslocked+0x282/0x600 53[ 189.245322] __cpuhp_setup_state+0xb0/0x140 54[ 189.250131] page_writeback_init+0x4d/0x71 55[ 189.254851] pagecache_init+0x48/0x4f 56[ 189.259139] start_kernel+0x6c1/0x754 57[ 189.263426] x86_64_start_reservations+0x2a/0x2c 58[ 189.268665] x86_64_start_kernel+0x77/0x7a 59[ 189.273387] secondary_startup_64+0xa5/0xb0 60[ 189.278189] 61[ 189.278189] -> #4 (cpuhp_state_mutex){+.+.}: 62[ 189.284045] lock_acquire+0x1d5/0x580 63[ 189.288331] __mutex_lock+0x16f/0x1a80 64[ 189.292702] mutex_lock_nested+0x16/0x20 65[ 189.297247] __cpuhp_setup_state_cpuslocked+0x5b/0x600 66[ 189.303012] __cpuhp_setup_state+0xb0/0x140 67[ 189.307822] kvm_guest_init+0x1f3/0x20f 68[ 189.312282] setup_arch+0x17e8/0x1a02 69[ 189.316567] start_kernel+0xa5/0x754 70[ 189.320765] x86_64_start_reservations+0x2a/0x2c 71[ 189.326006] x86_64_start_kernel+0x77/0x7a 72[ 189.330730] secondary_startup_64+0xa5/0xb0 73[ 189.335535] 74[ 189.335535] -> #3 (cpu_hotplug_lock.rw_sem){++++}: 75[ 189.341912] lock_acquire+0x1d5/0x580 76[ 189.346198] cpus_read_lock+0x42/0x90 77[ 189.350485] static_key_slow_inc+0x9d/0x3c0 78[ 189.355296] tracepoint_probe_register_prio+0x80d/0x9a0 79[ 189.361145] tracepoint_probe_register+0x2a/0x40 80[ 189.366386] trace_event_reg+0x167/0x320 81[ 189.370932] perf_trace_init+0x4ef/0xab0 82[ 189.375480] perf_tp_event_init+0x7d/0xf0 83[ 189.380114] perf_try_init_event+0xc9/0x1f0 84[ 189.384919] perf_event_alloc+0x1cc6/0x2b00 85[ 189.389725] SYSC_perf_event_open+0x84e/0x2e00 86[ 189.394792] SyS_perf_event_open+0x39/0x50 87[ 189.399513] entry_SYSCALL_64_fastpath+0x1f/0x96 88[ 189.404750] 89[ 189.404750] -> #2 (tracepoints_mutex){+.+.}: 90[ 189.410606] lock_acquire+0x1d5/0x580 91[ 189.414893] __mutex_lock+0x16f/0x1a80 92[ 189.419266] mutex_lock_nested+0x16/0x20 93[ 189.423813] tracepoint_probe_register_prio+0xa0/0x9a0 94[ 189.429583] tracepoint_probe_register+0x2a/0x40 95[ 189.434824] trace_event_reg+0x167/0x320 96[ 189.439371] perf_trace_init+0x4ef/0xab0 97[ 189.443916] perf_tp_event_init+0x7d/0xf0 98[ 189.448550] perf_try_init_event+0xc9/0x1f0 99[ 189.453357] perf_event_alloc+0x1cc6/0x2b00 100[ 189.458163] SYSC_perf_event_open+0x84e/0x2e00 101[ 189.463232] SyS_perf_event_open+0x39/0x50 102[ 189.467952] entry_SYSCALL_64_fastpath+0x1f/0x96 103[ 189.473191] 104[ 189.473191] -> #1 (event_mutex){+.+.}: 105[ 189.478527] lock_acquire+0x1d5/0x580 106[ 189.482812] __mutex_lock+0x16f/0x1a80 107[ 189.487184] mutex_lock_nested+0x16/0x20 108[ 189.491733] perf_trace_init+0x58/0xab0 109[ 189.496196] perf_tp_event_init+0x7d/0xf0 110[ 189.500829] perf_try_init_event+0xc9/0x1f0 111[ 189.505636] perf_event_alloc+0x1005/0x2b00 112[ 189.510443] inherit_event.isra.92+0x15b/0x920 113[ 189.515514] inherit_task_group.isra.94.part.95+0x73/0x240 114[ 189.521623] perf_event_init_task+0x348/0x890 115[ 189.526605] copy_process.part.36+0x173b/0x4ae0 116[ 189.531759] _do_fork+0x1ef/0xff0 117[ 189.535698] SyS_clone+0x37/0x50 118[ 189.539552] do_syscall_64+0x26c/0x920 119[ 189.543923] return_from_SYSCALL_64+0x0/0x75 120[ 189.548815] 121[ 189.548815] -> #0 (&ctx->mutex){+.+.}: 122[ 189.554152] __lock_acquire+0x3498/0x47f0 123[ 189.558785] lock_acquire+0x1d5/0x580 124[ 189.563072] __mutex_lock+0x16f/0x1a80 125[ 189.567444] mutex_lock_nested+0x16/0x20 126[ 189.571995] perf_event_ctx_lock_nested+0x21b/0x450 127[ 189.577500] perf_read+0xb9/0x970 128[ 189.581443] do_iter_read+0x3db/0x5b0 129[ 189.585730] vfs_readv+0x121/0x1c0 130[ 189.589759] default_file_splice_read+0x508/0xae0 131[ 189.595087] do_splice_to+0x110/0x170 132[ 189.599374] SyS_splice+0x11a8/0x1630 133[ 189.603662] entry_SYSCALL_64_fastpath+0x1f/0x96 134[ 189.608899] 135[ 189.608899] other info that might help us debug this: 136[ 189.608899] 137[ 189.617005] Chain exists of: 138[ 189.617005] &ctx->mutex --> sb_writers --> &pipe->mutex/1 139[ 189.617005] 140[ 189.627034] Possible unsafe locking scenario: 141[ 189.627034] 142[ 189.633055] CPU0 CPU1 143[ 189.637683] ---- ---- 144[ 189.642325] lock(&pipe->mutex/1); 145[ 189.645919] lock(sb_writers); 146[ 189.651681] lock(&pipe->mutex/1); 147[ 189.657792] lock(&ctx->mutex); 148[ 189.661121] 149[ 189.661121] *** DEADLOCK *** 150[ 189.661121] 151[ 189.667148] 1 lock held by syz-executor5/24180: 152[ 189.671777] #0: (&pipe->mutex/1){+.+.}, at: [<000000002090b936>] pipe_lock+0x56/0x70 153[ 189.679805] 154[ 189.679805] stack backtrace: 155[ 189.684270] CPU: 1 PID: 24180 Comm: syz-executor5 Not tainted 4.15.0-rc3+ #222 156[ 189.691592] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 157[ 189.700909] Call Trace: 158[ 189.703468] dump_stack+0x194/0x257 159[ 189.707063] ? arch_local_irq_restore+0x53/0x53 160[ 189.711700] print_circular_bug+0x42d/0x610 161[ 189.715989] ? save_stack_trace+0x1a/0x20 162[ 189.720104] check_prev_add+0x666/0x15f0 163[ 189.724132] ? copy_trace+0x150/0x150 164[ 189.727898] ? check_usage+0xb60/0xb60 165[ 189.731754] ? find_get_context.isra.83+0x670/0x670 166[ 189.736738] __lock_acquire+0x3498/0x47f0 167[ 189.740852] ? __lock_acquire+0x3498/0x47f0 168[ 189.745140] ? perf_trace_buf_update+0x66/0xb0 169[ 189.749693] ? debug_check_no_locks_freed+0x3d0/0x3d0 170[ 189.754849] ? perf_tp_event+0xae0/0xae0 171[ 189.758878] ? memset+0x31/0x40 172[ 189.762124] ? perf_trace_lock_acquire+0x532/0x980 173[ 189.767032] ? print_usage_bug+0x3f0/0x3f0 174[ 189.771232] ? __kernel_text_address+0xd/0x40 175[ 189.775696] lock_acquire+0x1d5/0x580 176[ 189.779465] ? perf_event_ctx_lock_nested+0x21b/0x450 177[ 189.784623] ? lock_release+0xda0/0xda0 178[ 189.788562] ? perf_trace_lock+0xd6/0x900 179[ 189.792676] ? rcu_note_context_switch+0x710/0x710 180[ 189.797571] ? __might_sleep+0x95/0x190 181[ 189.801513] ? perf_event_ctx_lock_nested+0x21b/0x450 182[ 189.806667] __mutex_lock+0x16f/0x1a80 183[ 189.810522] ? perf_event_ctx_lock_nested+0x21b/0x450 184[ 189.815678] ? debug_check_no_locks_freed+0x3d0/0x3d0 185[ 189.820834] ? perf_tp_event+0xae0/0xae0 186[ 189.824860] ? perf_event_ctx_lock_nested+0x21b/0x450 187[ 189.830021] ? mutex_lock_io_nested+0x1900/0x1900 188[ 189.834827] ? perf_trace_lock+0xd6/0x900 189[ 189.838944] ? trace_event_raw_event_lock+0x340/0x340 190[ 189.844102] ? check_noncircular+0x20/0x20 191[ 189.848300] ? perf_trace_lock+0x900/0x900 192[ 189.852503] ? __bpf_address_lookup+0x2b0/0x2b0 193[ 189.857139] ? check_noncircular+0x20/0x20 194[ 189.861339] ? lock_release+0xda0/0xda0 195[ 189.865280] ? find_held_lock+0x39/0x1d0 196[ 189.869311] ? lock_downgrade+0x980/0x980 197[ 189.873429] ? perf_event_ctx_lock_nested+0xaf/0x450 198[ 189.878498] ? lock_release+0xda0/0xda0 199[ 189.882443] mutex_lock_nested+0x16/0x20 200[ 189.886471] ? mutex_lock_nested+0x16/0x20 201[ 189.890672] perf_event_ctx_lock_nested+0x21b/0x450 202[ 189.895654] ? perf_iterate_ctx+0x770/0x770 203[ 189.899945] ? bpf_fd_pass+0x5c/0x280 204[ 189.903712] ? file_has_perm+0x1ee/0x5d0 205[ 189.907738] perf_read+0xb9/0x970 206[ 189.911158] ? perf_event_read_value+0x60/0x60 207[ 189.915705] ? fsnotify_first_mark+0x2b0/0x2b0 208[ 189.920254] ? selinux_file_permission+0x82/0x460 209[ 189.925063] ? security_file_permission+0x89/0x1f0 210[ 189.929960] ? rw_verify_area+0xe5/0x2b0 211[ 189.933989] do_iter_read+0x3db/0x5b0 212[ 189.937757] ? dup_iter+0x260/0x260 213[ 189.941353] vfs_readv+0x121/0x1c0 214[ 189.944867] ? compat_rw_copy_check_uvector+0x2e0/0x2e0 215[ 189.950197] ? lock_acquire+0x1d5/0x580 216[ 189.954136] ? pipe_lock+0x56/0x70 217[ 189.957644] ? lock_release+0xda0/0xda0 218[ 189.961584] ? rcu_note_context_switch+0x710/0x710 219[ 189.966477] ? __might_sleep+0x95/0x190 220[ 189.970418] ? pipe_lock+0x56/0x70 221[ 189.973926] ? __mutex_lock+0x16f/0x1a80 222[ 189.977949] ? pipe_lock+0x56/0x70 223[ 189.981456] default_file_splice_read+0x508/0xae0 224[ 189.986263] ? default_file_splice_read+0x508/0xae0 225[ 189.991249] ? do_splice_direct+0x3d0/0x3d0 226[ 189.995534] ? __lock_is_held+0xbc/0x140 227[ 189.999564] ? __lock_is_held+0xbc/0x140 228[ 190.003595] ? file_has_perm+0x1ee/0x5d0 229[ 190.007623] ? fsnotify+0x7b3/0x1140 230[ 190.011307] ? fsnotify_first_mark+0x2b0/0x2b0 231[ 190.015855] ? selinux_file_permission+0x82/0x460 232[ 190.020663] ? security_file_permission+0x89/0x1f0 233[ 190.025558] ? do_splice_direct+0x3d0/0x3d0 234[ 190.029845] do_splice_to+0x110/0x170 235[ 190.033609] ? do_splice_to+0x110/0x170 236[ 190.037549] SyS_splice+0x11a8/0x1630 237[ 190.041319] ? SyS_futex+0x269/0x390 238[ 190.045004] ? compat_SyS_vmsplice+0x250/0x250 239[ 190.049555] ? trace_hardirqs_on_caller+0x421/0x5c0 240[ 190.054540] ? trace_hardirqs_on_thunk+0x1a/0x1c 241[ 190.059263] entry_SYSCALL_64_fastpath+0x1f/0x96 242[ 190.063986] RIP: 0033:0x452a39 243[ 190.067141] RSP: 002b:00007f4f7d22fc58 EFLAGS: 00000212 ORIG_RAX: 0000000000000113 244[ 190.074814] RAX: ffffffffffffffda RBX: 0000000000758020 RCX: 0000000000452a39 245[ 190.082048] RDX: 0000000000000017 RSI: 0000000000000000 RDI: 0000000000000013 246[ 190.089283] RBP: 000000000000039b R08: 00000000000000b9 R09: 0000000000000001 247[ 190.096517] R10: 0000000000000000 R11: 0000000000000212 R12: 00000000006f3728 248[ 190.103753] R13: 00000000ffffffff R14: 00007f4f7d2306d4 R15: 0000000000000000 249