From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751587AbbKDFR3 (ORCPT ); Wed, 4 Nov 2015 00:17:29 -0500 Received: from arcturus.aphlor.org ([188.246.204.175]:36957 "EHLO arcturus.aphlor.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750880AbbKDFR1 (ORCPT ); Wed, 4 Nov 2015 00:17:27 -0500 Date: Wed, 4 Nov 2015 00:17:17 -0500 From: Dave Jones To: Linux Kernel , Peter Zijlstra , Ingo Molnar , Stephane Eranian Subject: perf related lockdep bug Message-ID: <20151104051717.GA6098@codemonkey.org.uk> Mail-Followup-To: Dave Jones , Linux Kernel , Peter Zijlstra , Ingo Molnar , Stephane Eranian MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.24 (2015-08-30) X-Spam-Score: -2.9 (--) X-Spam-Report: Spam report generated by SpamAssassin on "arcturus.aphlor.org" Content analysis details: (-2.9 points, 5.0 required) pts rule name description ---- ---------------------- -------------------------------------------------- -1.0 ALL_TRUSTED Passed through trusted hosts only via SMTP -1.9 BAYES_00 BODY: Bayes spam probability is 0 to 1% [score: 0.0000] X-Authenticated-User: davej@codemonkey.org.uk Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org This is new to me since todays merge window. Dave [ 293.955261] ====================================================== [ 293.955395] [ INFO: possible circular locking dependency detected ] [ 293.955536] 4.3.0-think+ #3 Not tainted [ 293.955618] ------------------------------------------------------- [ 293.955756] trinity-c343/12586 is trying to acquire lock: [ 293.955875] (rcu_node_0){-.-...}, at: [] rcu_report_exp_cpu_mult+0x24/0x70 [ 293.956070] but task is already holding lock: [ 293.956194] (&ctx->lock){-.....}, at: [] perf_lock_task_context+0x53/0x300 [ 293.956386] which lock already depends on the new lock. [ 293.956559] the existing dependency chain (in reverse order) is: [ 293.956720] -> #3 (&ctx->lock){-.....}: [ 293.956807] [] lock_acquire+0xc3/0x1d0 [ 293.956940] [] _raw_spin_lock+0x41/0x80 [ 293.957075] [] __perf_event_task_sched_out+0x276/0x700 [ 293.957239] [] __schedule+0x530/0xaf0 [ 293.957370] [] schedule+0x3f/0x90 [ 293.957493] [] exit_to_usermode_loop+0x76/0xa0 [ 293.957642] [] prepare_exit_to_usermode+0x53/0x60 [ 293.957795] [] retint_user+0x8/0x20 [ 293.957923] -> #2 (&rq->lock){-.-.-.}: [ 293.958008] [] lock_acquire+0xc3/0x1d0 [ 293.958140] [] _raw_spin_lock+0x41/0x80 [ 293.958275] [] sched_move_task+0x4d/0x270 [ 293.958417] [] cpu_cgroup_fork+0xe/0x10 [ 293.958551] [] cgroup_post_fork+0x67/0x160 [ 293.958692] [] copy_process+0x147a/0x1e10 [ 293.958831] [] _do_fork+0x97/0x680 [ 293.958955] [] kernel_thread+0x29/0x30 [ 293.959087] [] rest_init+0x27/0x140 [ 293.959211] [] start_kernel+0x450/0x45d [ 293.959347] [] x86_64_start_reservations+0x2a/0x2c [ 293.959503] [] x86_64_start_kernel+0x168/0x176 [ 293.959652] -> #1 (&p->pi_lock){-.-.-.}: [ 293.959742] [] lock_acquire+0xc3/0x1d0 [ 293.959876] [] _raw_spin_lock_irqsave+0x4c/0x90 [ 293.960026] [] try_to_wake_up+0x30/0x5f0 [ 293.960165] [] wake_up_process+0x23/0x40 [ 293.960300] [] rcu_spawn_gp_kthread+0xd5/0xfd [ 293.960449] [] do_one_initcall+0xb3/0x1f0 [ 293.960587] [] kernel_init_freeable+0x101/0x234 [ 293.960736] [] kernel_init+0xe/0xe0 [ 293.960860] [] ret_from_fork+0x3f/0x70 [ 293.960993] -> #0 (rcu_node_0){-.-...}: [ 293.961081] [] __lock_acquire+0x19d2/0x1cf0 [ 293.961222] [] lock_acquire+0xc3/0x1d0 [ 293.961351] [] _raw_spin_lock_irqsave+0x4c/0x90 [ 293.961501] [] rcu_report_exp_cpu_mult+0x24/0x70 [ 293.961652] [] rcu_read_unlock_special+0x109/0x5e0 [ 293.961808] [] __rcu_read_unlock+0x87/0x90 [ 293.961947] [] perf_lock_task_context+0x19d/0x300 [ 293.962101] [] perf_event_init_task+0x9f/0x370 [ 293.962248] [] copy_process+0x7fa/0x1e10 [ 293.962385] [] _do_fork+0x97/0x680 [ 293.962508] [] SyS_clone+0x19/0x20 [ 293.962631] [] entry_SYSCALL_64_fastpath+0x12/0x6f [ 293.962787] other info that might help us debug this: [ 293.962955] Chain exists of: rcu_node_0 --> &rq->lock --> &ctx->lock [ 293.963106] Possible unsafe locking scenario: [ 293.963233] CPU0 CPU1 [ 293.963332] ---- ---- [ 293.963430] lock(&ctx->lock); [ 293.963500] lock(&rq->lock); [ 293.963627] lock(&ctx->lock); [ 293.963755] lock(rcu_node_0); [ 293.963824] *** DEADLOCK *** [ 293.963947] 2 locks held by trinity-c343/12586: [ 293.964047] #0: (rcu_read_lock){......}, at: [] perf_lock_task_context+0xd0/0x300 [ 293.964258] #1: (&ctx->lock){-.....}, at: [] perf_lock_task_context+0x53/0x300 [ 293.972934] stack backtrace: [ 293.990221] CPU: 3 PID: 12586 Comm: trinity-c343 Not tainted 4.3.0-think+ #3 [ 293.999210] ffff8804fb6824a0 ffff88044a0efa60 ffffffffb03607bc ffffffffb1779630 [ 294.008115] ffff88044a0efaa0 ffffffffb00d1453 ffff88044a0efb10 0000000000000002 [ 294.017066] ffff8804fb682468 ffff8804fb6824a0 0000000000000001 ffff8804fb681b80 [ 294.026109] Call Trace: [ 294.035079] [] dump_stack+0x4e/0x82 [ 294.044014] [] print_circular_bug+0x1e3/0x250 [ 294.052982] [] __lock_acquire+0x19d2/0x1cf0 [ 294.061926] [] ? get_lock_stats+0x19/0x60 [ 294.070878] [] lock_acquire+0xc3/0x1d0 [ 294.079828] [] ? rcu_report_exp_cpu_mult+0x24/0x70 [ 294.088805] [] _raw_spin_lock_irqsave+0x4c/0x90 [ 294.097771] [] ? rcu_report_exp_cpu_mult+0x24/0x70 [ 294.106807] [] rcu_report_exp_cpu_mult+0x24/0x70 [ 294.115823] [] rcu_read_unlock_special+0x109/0x5e0 [ 294.124813] [] ? get_lock_stats+0x19/0x60 [ 294.133801] [] ? perf_lock_task_context+0x53/0x300 [ 294.142790] [] __rcu_read_unlock+0x87/0x90 [ 294.151675] [] perf_lock_task_context+0x19d/0x300 [ 294.160420] [] ? perf_lock_task_context+0xd0/0x300 [ 294.169166] [] perf_event_init_task+0x9f/0x370 [ 294.177832] [] ? preempt_count_sub+0xa5/0xf0 [ 294.186477] [] copy_process+0x7fa/0x1e10 [ 294.195036] [] ? get_lock_stats+0x19/0x60 [ 294.203564] [] ? trace_hardirqs_off+0xd/0x10 [ 294.212042] [] ? __acct_update_integrals+0x91/0xf0 [ 294.220411] [] ? preempt_count_sub+0xa5/0xf0 [ 294.228778] [] _do_fork+0x97/0x680 [ 294.237038] [] ? context_tracking_user_exit+0x13/0x20 [ 294.245322] [] ? enter_from_user_mode+0x1a/0x50 [ 294.253586] [] ? syscall_trace_enter_phase1+0xbc/0x110 [ 294.261919] [] ? trace_hardirqs_on_thunk+0x17/0x19 [ 294.270306] [] SyS_clone+0x19/0x20 [ 294.278672] [] entry_SYSCALL_64_fastpath+0x12/0x6f