Re: rcu_prempt stalls / lockup

["Paul E. McKenney" <paulmck@linux.vnet.ibm.com>]

On Tue, Apr 01, 2014 at 01:22:44PM -0400, Dave Jones wrote:
> On Tue, Apr 01, 2014 at 08:30:32AM -0700, Paul E. McKenney wrote:
>  > > [14403.765300] INFO: rcu_preempt detected stalls on CPUs/tasks:
>  > > [14403.766405]  (detected by 0, t=260067 jiffies, g=449892, c=449891, q=0)
>  > > and on and on..
>  > > 
>  > > so kernel space still works like before, but userspace is locked up.
>  > 
>  > Interesting.  I suspect that if you reverted the rest of this merge
>  > window's RCU patches, you would get the same result.
>  > 
>  > >  > If that doesn't work, I will need to put together some diagnostic patches.
>  > >  > Starting with the one below.
>  > > 
>  > > bugger, I forgot to apply this last night. I'll do it on the next run.
>  > 
>  > But let's see what this shows first.
> 
> [ 1173.923463] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1173.924457] 	(detected by 0, t=6502 jiffies, g=47728, c=47727, q=0)
> [ 1173.925199] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1368.859744] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1368.860754] 	(detected by 0, t=26007 jiffies, g=47728, c=47727, q=0)
> [ 1368.861559] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1563.796416] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1563.797426] 	(detected by 0, t=45512 jiffies, g=47728, c=47727, q=0)
> [ 1563.798293] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1758.733747] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1758.734725] 	(detected by 0, t=65017 jiffies, g=47728, c=47727, q=0)
> [ 1758.735526] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1953.670944] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1953.671932] 	(detected by 0, t=84522 jiffies, g=47728, c=47727, q=0)
> [ 1953.672735] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 2148.608132] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 2148.609140] 	(detected by 0, t=104027 jiffies, g=47728, c=47727, q=0)
> etc etc.

Waiting uninterruptibly.  Presumably blocked on mutex_lock().  But
you have CONFIG_PROVE_LOCKING(), so any deadlocks should have been
reported.

Given that you have CONFIG_RCU_TRACE=y, could you please enable the
following trace events and dump the trace before things hang?

	trace_event=rcu:rcu_grace_period,rcu:rcu_grace_period_init

If it is not feasible to dump the trace before things hang, let me
know, and I will work out some other diagnostic regime.

							Thanx, Paul