From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752256AbcALUDl (ORCPT ); Tue, 12 Jan 2016 15:03:41 -0500 Received: from userp1040.oracle.com ([156.151.31.81]:46731 "EHLO userp1040.oracle.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751156AbcALUDj (ORCPT ); Tue, 12 Jan 2016 15:03:39 -0500 From: Sasha Levin Subject: timers: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected X-Enigmail-Draft-Status: N1110 To: Thomas Gleixner , LKML Message-ID: <56955C0F.1090005@oracle.com> Date: Tue, 12 Jan 2016 15:03:27 -0500 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.4.0 MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-Source-IP: aserv0021.oracle.com [141.146.126.233] Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi all, While fuzzing with trinity inside a KVM tools guest, running the latest -next kernel, I've hit the following lockdep warning: [ 3408.411602] ====================================================== [ 3408.418607] [ INFO: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected ] [ 3408.419322] 4.4.0-rc8-next-20160111-sasha-00024-g376a9c2-dirty #2782 Not tainted [ 3408.420171] ------------------------------------------------------ [ 3408.420984] trinity-c65/30907 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 3408.421869] (&lock->wait_lock){+.+...}, at: rt_mutex_slowunlock (kernel/locking/rtmutex.c:1266) [ 3408.423182] [ 3408.423182] and this task is already holding: [ 3408.423916] (&(&new_timer->it_lock)->rlock){-.-...}, at: __lock_timer (kernel/time/posix-timers.c:707) [ 3408.425281] which would create a new lock dependency: [ 3408.425942] (&(&new_timer->it_lock)->rlock){-.-...} -> (&lock->wait_lock){+.+...} [ 3408.427118] [ 3408.427118] but this new dependency connects a HARDIRQ-irq-safe lock: [ 3408.428093] (&(&new_timer->it_lock)->rlock){-.-...} ... which became HARDIRQ-irq-safe at: [ 3408.429232] __lock_acquire (kernel/locking/lockdep.c:2796 kernel/locking/lockdep.c:3162) [ 3408.430075] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.430814] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.431584] run_posix_cpu_timers (include/linux/list.h:156 kernel/time/posix-cpu-timers.c:1231) [ 3408.437683] update_process_times (kernel/time/timer.c:1427) [ 3408.438528] tick_sched_handle (kernel/time/tick-sched.c:152) [ 3408.439305] tick_sched_timer (kernel/time/tick-sched.c:1089) [ 3408.440086] __hrtimer_run_queues (kernel/time/hrtimer.c:1233 kernel/time/hrtimer.c:1295) [ 3408.446607] hrtimer_interrupt (kernel/time/hrtimer.c:1332) [ 3408.447427] smp_trace_apic_timer_interrupt (./arch/x86/include/asm/apic.h:659 arch/x86/kernel/apic/apic.c:953) [ 3408.448406] smp_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:956) [ 3408.460706] apic_timer_interrupt (arch/x86/entry/entry_64.S:687) [ 3408.461517] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.462259] sync_inodes_sb (fs/fs-writeback.c:2133 fs/fs-writeback.c:2292) [ 3408.463042] sync_inodes_one_sb (fs/sync.c:74) [ 3408.463826] iterate_supers (fs/super.c:535) [ 3408.464583] sys_sync (fs/sync.c:113) [ 3408.465239] entry_SYSCALL_64_fastpath (arch/x86/entry/entry_64.S:186) [ 3408.466074] [ 3408.466074] to a HARDIRQ-irq-unsafe lock: [ 3408.466732] (&lock->wait_lock){+.+...} ... which became HARDIRQ-irq-unsafe at: [ 3408.467701] ... __lock_acquire (kernel/locking/lockdep.c:2813 kernel/locking/lockdep.c:3162) [ 3408.468551] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.469240] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.469987] rt_mutex_slowlock (kernel/locking/rtmutex.c:1184) [ 3408.470722] rt_mutex_lock (kernel/locking/rtmutex.c:1402) [ 3408.471416] rcu_boost_kthread (kernel/rcu/tree_plugin.h:1033 kernel/rcu/tree_plugin.h:1055) [ 3408.472253] kthread (kernel/kthread.c:209) [ 3408.472937] ret_from_fork (arch/x86/entry/entry_64.S:469) [ 3408.473642] [ 3408.473642] other info that might help us debug this: [ 3408.473642] [ 3408.474461] Possible interrupt unsafe locking scenario: [ 3408.474461] [ 3408.475239] CPU0 CPU1 [ 3408.475809] ---- ---- [ 3408.476380] lock(&lock->wait_lock); [ 3408.476925] local_irq_disable(); [ 3408.477640] lock(&(&new_timer->it_lock)->rlock); [ 3408.478607] lock(&lock->wait_lock); [ 3408.479445] [ 3408.479796] lock(&(&new_timer->it_lock)->rlock); [ 3408.480504] [ 3408.480504] *** DEADLOCK *** [ 3408.480504] [ 3408.481270] 2 locks held by trinity-c65/30907: [ 3408.481826] #0: (rcu_read_lock){......}, at: __lock_timer (include/linux/rcupdate.h:872 kernel/time/posix-timers.c:704) [ 3408.483007] #1: (&(&new_timer->it_lock)->rlock){-.-...}, at: __lock_timer (kernel/time/posix-timers.c:707) [ 3408.484369] the dependencies between HARDIRQ-irq-safe lock and the holding lock: [ 3408.485317] -> (&(&new_timer->it_lock)->rlock){-.-...} ops: 3448 { [ 3408.486264] IN-HARDIRQ-W at: [ 3408.486707] __lock_acquire (kernel/locking/lockdep.c:2796 kernel/locking/lockdep.c:3162) [ 3408.487670] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.504632] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.505511] run_posix_cpu_timers (include/linux/list.h:156 kernel/time/posix-cpu-timers.c:1231) [ 3408.506496] update_process_times (kernel/time/timer.c:1427) [ 3408.507473] tick_sched_handle (kernel/time/tick-sched.c:152) [ 3408.508447] tick_sched_timer (kernel/time/tick-sched.c:1089) [ 3408.509366] __hrtimer_run_queues (kernel/time/hrtimer.c:1233 kernel/time/hrtimer.c:1295) [ 3408.510356] hrtimer_interrupt (kernel/time/hrtimer.c:1332) [ 3408.511308] smp_trace_apic_timer_interrupt (./arch/x86/include/asm/apic.h:659 arch/x86/kernel/apic/apic.c:953) [ 3408.512386] smp_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:956) [ 3408.513380] apic_timer_interrupt (arch/x86/entry/entry_64.S:687) [ 3408.514351] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.515112] sync_inodes_sb (fs/fs-writeback.c:2133 fs/fs-writeback.c:2292) [ 3408.528093] sync_inodes_one_sb (fs/sync.c:74) [ 3408.529101] iterate_supers (fs/super.c:535) [ 3408.530052] sys_sync (fs/sync.c:113) [ 3408.530926] entry_SYSCALL_64_fastpath (arch/x86/entry/entry_64.S:186) [ 3408.531988] IN-SOFTIRQ-W at: [ 3408.532442] __lock_acquire (kernel/locking/lockdep.c:2799 kernel/locking/lockdep.c:3162) [ 3408.533415] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.534345] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.535239] run_posix_cpu_timers (include/linux/list.h:156 kernel/time/posix-cpu-timers.c:1231) [ 3408.552300] update_process_times (kernel/time/timer.c:1427) [ 3408.553305] tick_sched_handle (kernel/time/tick-sched.c:152) [ 3408.554283] tick_sched_timer (kernel/time/tick-sched.c:1089) [ 3408.555241] __hrtimer_run_queues (kernel/time/hrtimer.c:1233 kernel/time/hrtimer.c:1295) [ 3408.556226] hrtimer_interrupt (kernel/time/hrtimer.c:1332) [ 3408.557101] smp_trace_apic_timer_interrupt (./arch/x86/include/asm/apic.h:659 arch/x86/kernel/apic/apic.c:953) [ 3408.558131] smp_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:956) [ 3408.559122] apic_timer_interrupt (arch/x86/entry/entry_64.S:687) [ 3408.560128] irq_exit (kernel/softirq.c:350 kernel/softirq.c:391) [ 3408.561008] smp_trace_apic_timer_interrupt (./arch/x86/include/asm/irq_regs.h:26 arch/x86/kernel/apic/apic.c:955) [ 3408.562123] smp_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:956) [ 3408.563153] apic_timer_interrupt (arch/x86/entry/entry_64.S:687) [ 3408.566483] INITIAL USE at: [ 3408.566917] __lock_acquire (kernel/locking/lockdep.c:3166) [ 3408.567903] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.568826] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:119 kernel/locking/spinlock.c:159) [ 3408.569824] exit_itimers (kernel/time/posix-timers.c:936 kernel/time/posix-timers.c:983 kernel/time/posix-timers.c:1008) [ 3408.570725] do_exit (kernel/exit.c:724) [ 3408.571606] do_group_exit (kernel/exit.c:862) [ 3408.572539] get_signal (kernel/signal.c:2327) [ 3408.573458] do_signal (arch/x86/kernel/signal.c:781) [ 3408.574357] exit_to_usermode_loop (arch/x86/entry/common.c:249) [ 3408.575335] syscall_return_slowpath (./arch/x86/include/asm/jump_label.h:35 include/linux/context_tracking_state.h:30 include/linux/context_tracking.h:24 arch/x86/entry/common.c:284 arch/x86/entry/common.c:344) [ 3408.576356] int_ret_from_sys_call (arch/x86/entry/entry_64.S:282) [ 3408.577326] } [ 3408.577574] ... key at: __key.35766 (??:?) [ 3408.578477] ... acquired at: [ 3408.578863] check_irq_usage (kernel/locking/lockdep.c:1649) [ 3408.579640] __lock_acquire (kernel/locking/lockdep_states.h:7 kernel/locking/lockdep.c:1857 kernel/locking/lockdep.c:1958 kernel/locking/lockdep.c:2144 kernel/locking/lockdep.c:3206) [ 3408.596505] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.597191] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.597965] rt_mutex_slowunlock (kernel/locking/rtmutex.c:1266) [ 3408.598720] rt_mutex_unlock (kernel/locking/rtmutex.c:1384 kernel/locking/rtmutex.c:1486) [ 3408.599499] rcu_read_unlock_special (kernel/rcu/tree_plugin.h:503) [ 3408.603731] __rcu_read_unlock (kernel/rcu/update.c:223) [ 3408.604452] __lock_timer (include/linux/rcupdate.h:495 include/linux/rcupdate.h:930 kernel/time/posix-timers.c:709) [ 3408.605221] SyS_timer_settime (kernel/time/posix-timers.c:903 kernel/time/posix-timers.c:881) [ 3408.605982] entry_SYSCALL_64_fastpath (arch/x86/entry/entry_64.S:186) [ 3408.606791] [ 3408.607008] the dependencies between the lock to be acquired and HARDIRQ-irq-unsafe lock: [ 3408.608038] -> (&lock->wait_lock){+.+...} ops: 134 { [ 3408.608843] HARDIRQ-ON-W at: [ 3408.609209] __lock_acquire (kernel/locking/lockdep.c:2813 kernel/locking/lockdep.c:3162) [ 3408.610199] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.611069] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.611996] rt_mutex_slowlock (kernel/locking/rtmutex.c:1184) [ 3408.612972] rt_mutex_lock (kernel/locking/rtmutex.c:1402) [ 3408.613856] rcu_boost_kthread (kernel/rcu/tree_plugin.h:1033 kernel/rcu/tree_plugin.h:1055) [ 3408.614733] kthread (kernel/kthread.c:209) [ 3408.615599] ret_from_fork (arch/x86/entry/entry_64.S:469) [ 3408.628604] SOFTIRQ-ON-W at: [ 3408.629055] __lock_acquire (kernel/locking/lockdep.c:2817 kernel/locking/lockdep.c:3162) [ 3408.630046] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.630992] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.638480] rt_mutex_slowlock (kernel/locking/rtmutex.c:1184) [ 3408.640811] rt_mutex_lock (kernel/locking/rtmutex.c:1402) [ 3408.644207] rcu_boost_kthread (kernel/rcu/tree_plugin.h:1033 kernel/rcu/tree_plugin.h:1055) [ 3408.647236] kthread (kernel/kthread.c:209) [ 3408.650140] ret_from_fork (arch/x86/entry/entry_64.S:469) [ 3408.653122] INITIAL USE at: [ 3408.654723] __lock_acquire (kernel/locking/lockdep.c:3166) [ 3408.656792] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.658136] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.659612] rt_mutex_slowlock (kernel/locking/rtmutex.c:1184) [ 3408.660998] rt_mutex_lock (kernel/locking/rtmutex.c:1402) [ 3408.663768] rcu_boost_kthread (kernel/rcu/tree_plugin.h:1033 kernel/rcu/tree_plugin.h:1055) [ 3408.672030] kthread (kernel/kthread.c:209) [ 3408.675053] ret_from_fork (arch/x86/entry/entry_64.S:469) [ 3408.678075] } [ 3408.678996] ... key at: __key.19737 (??:?) [ 3408.681194] ... acquired at: [ 3408.682967] check_irq_usage (kernel/locking/lockdep.c:1649) [ 3408.684098] __lock_acquire (kernel/locking/lockdep_states.h:7 kernel/locking/lockdep.c:1857 kernel/locking/lockdep.c:1958 kernel/locking/lockdep.c:2144 kernel/locking/lockdep.c:3206) [ 3408.685496] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.686597] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.687693] rt_mutex_slowunlock (kernel/locking/rtmutex.c:1266) [ 3408.688916] rt_mutex_unlock (kernel/locking/rtmutex.c:1384 kernel/locking/rtmutex.c:1486) [ 3408.690042] rcu_read_unlock_special (kernel/rcu/tree_plugin.h:503) [ 3408.691451] __rcu_read_unlock (kernel/rcu/update.c:223) [ 3408.692629] __lock_timer (include/linux/rcupdate.h:495 include/linux/rcupdate.h:930 kernel/time/posix-timers.c:709) [ 3408.693743] SyS_timer_settime (kernel/time/posix-timers.c:903 kernel/time/posix-timers.c:881) [ 3408.694978] entry_SYSCALL_64_fastpath (arch/x86/entry/entry_64.S:186) [ 3408.696162] [ 3408.696629] [ 3408.696629] stack backtrace: [ 3408.697558] CPU: 0 PID: 30907 Comm: trinity-c65 Not tainted 4.4.0-rc8-next-20160111-sasha-00024-g376a9c2-dirty #2782 [ 3408.699544] 1ffff100188b2ecd 000000003efba18a ffff8800c45976e8 ffffffffa401ab02 [ 3408.701068] 0000000041b58ab3 ffffffffaf1b73b8 ffffffffa401aa37 ffff8800c45976e8 [ 3408.702589] ffffffffa245a127 000000003efba18a 000000005046ad48 0000000000000001 [ 3408.703754] Call Trace: [ 3408.704185] dump_stack (lib/dump_stack.c:52) [ 3408.707084] check_usage (kernel/locking/lockdep.c:1561) [ 3408.714764] check_irq_usage (kernel/locking/lockdep.c:1649) [ 3408.715747] __lock_acquire (kernel/locking/lockdep_states.h:7 kernel/locking/lockdep.c:1857 kernel/locking/lockdep.c:1958 kernel/locking/lockdep.c:2144 kernel/locking/lockdep.c:3206) [ 3408.722807] lock_acquire (./arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3587) [ 3408.726723] _raw_spin_lock (include/linux/spinlock_api_smp.h:145 kernel/locking/spinlock.c:151) [ 3408.728982] rt_mutex_slowunlock (kernel/locking/rtmutex.c:1266) [ 3408.730066] rt_mutex_unlock (kernel/locking/rtmutex.c:1384 kernel/locking/rtmutex.c:1486) [ 3408.733192] rcu_read_unlock_special (kernel/rcu/tree_plugin.h:503) [ 3408.735155] __rcu_read_unlock (kernel/rcu/update.c:223) [ 3408.736090] __lock_timer (include/linux/rcupdate.h:495 include/linux/rcupdate.h:930 kernel/time/posix-timers.c:709) [ 3408.737947] SyS_timer_settime (kernel/time/posix-timers.c:903 kernel/time/posix-timers.c:881) [ 3408.744580] entry_SYSCALL_64_fastpath (arch/x86/entry/entry_64.S:186)