All of lore.kernel.org
 help / color / mirror / Atom feed
From: Sasha Levin <sasha.levin@oracle.com>
To: Thomas Gleixner <tglx@linutronix.de>,
	LKML <linux-kernel@vger.kernel.org>
Subject: timers: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected
Date: Tue, 12 Jan 2016 15:03:27 -0500	[thread overview]
Message-ID: <56955C0F.1090005@oracle.com> (raw)

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]   <Interrupt>

[ 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)

             reply	other threads:[~2016-01-12 20:03 UTC|newest]

Thread overview: 15+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2016-01-12 20:03 Sasha Levin [this message]
2016-01-12 20:18 ` timers: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected Peter Zijlstra
2016-01-12 20:52   ` Paul E. McKenney
2016-01-13  9:05 ` Thomas Gleixner
2016-01-13 16:16   ` Paul E. McKenney
2016-01-14 17:43     ` Thomas Gleixner
2016-01-14 18:18       ` Paul E. McKenney
2016-01-14 19:47         ` Thomas Gleixner
2016-01-15  1:42           ` Paul E. McKenney
2016-01-15 10:03             ` Thomas Gleixner
2016-01-15 21:11               ` Paul E. McKenney
2016-01-15 22:10                 ` Paul E. McKenney
2016-01-15 23:14                   ` Paul E. McKenney
2016-01-29 15:27                     ` Peter Zijlstra
2016-01-31  0:28                       ` Paul E. McKenney

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=56955C0F.1090005@oracle.com \
    --to=sasha.levin@oracle.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=tglx@linutronix.de \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.