Re: frequent lockups in 3.18rc4

From: Paul E. McKenney
Date: Mon Dec 15 2014 - 01:33:44 EST


On Sun, Dec 14, 2014 at 08:20:13PM -0500, Sasha Levin wrote:
> On 12/14/2014 07:11 PM, Paul E. McKenney wrote:
> >> Does it depend on anything not currently in -next? My build fails with
> >> >
> >> > kernel/rcu/tree.c: In function ârcu_report_qs_rdpâ:
> >> > kernel/rcu/tree.c:2099:6: error: âstruct rcu_dataâ has no member named âgpwrapâ
> >> > rdp->gpwrap) {
> > Indeed it does. Please see below for a port to current mainline.
>
> With the patch:
>
>
> [ 620.340045] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 620.341087] (detected by 22, t=8407 jiffies, g=10452, c=10451, q=3622)
> [ 620.342154] All QSes seen, last rcu_preempt kthread activity 4294990929/4294999330, jiffies_till_next_fqs=1

OK, 8401 jiffies since the grace-period kthread ran. This is without
the "Run grace-period kthreads at real-time priority" patch?

> [ 643.710049] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 643.710073] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 643.710093] 0: (6 ticks this GP) idle=bd5/140000000000002/0 softirq=12421/12421 fqs=0 last_accelerate: 5283/8643, nonlazy_posted: 643841, ..
> [ 643.710110] (detected by 1, t=2102 jiffies, g=-292, c=-293, q=0)

But this one is real.

> [ 643.710112] Task dump for CPU 0:
> [ 643.710129] kworker/0:1 R running task 13016 628 2 0x10080008
> [ 643.710148] Workqueue: events vmstat_update
> [ 643.710156] ffffffffb0301dc4 ffff88006be15000 ffff880060ba1c70 0000000000000000
> [ 643.710161] ffff88006be10680 ffff8800633efde8 ffffffffa0461f1b ffff88006a776000
> [ 643.710166] ffff880060ba1cb8 ffff880060ba1c78 ffff880060ba1c80 ffff880060ba1c90
> [ 643.710168] Call Trace:
> [ 643.710181] [<ffffffffb0301dc4>] ? _raw_spin_unlock_irq+0x64/0x200
> [ 643.710191] [<ffffffffa0461f1b>] ? process_one_work+0x5fb/0x1660
> [ 643.710197] [<ffffffffa0463545>] ? worker_thread+0x5c5/0x1680
> [ 643.710205] [<ffffffffb02f0b6f>] ? __schedule+0xf6f/0x2fc0
> [ 643.710211] [<ffffffffa0462f80>] ? process_one_work+0x1660/0x1660
> [ 643.710216] [<ffffffffa047ae22>] ? kthread+0x1f2/0x2b0
> [ 643.710221] [<ffffffffa047ac30>] ? kthread_worker_fn+0x6a0/0x6a0
> [ 643.710226] [<ffffffffb030243c>] ? ret_from_fork+0x7c/0xb0
> [ 643.710233] [<ffffffffa047ac30>] ? kthread_worker_fn+0x6a0/0x6a0

Which in theory should have been addressed by the "Make
cond_resched_rcu_qs() apply to normal RCU flavors" patch,
given that this is CPU 0, which should be taking scheduling
clock interrupts. Well, I guess that theory and practice
are only the same in theory. :-/

Will dig into it more.

Thanx, Paul

> [ 643.711486]
> [ 643.711486] (detected by 22, t=2104 jiffies, g=10453, c=10452, q=1570)
> [ 643.711486] All QSes seen, last rcu_preempt kthread activity 4294999565/4295001669, jiffies_till_next_fqs=1
>
>
> Thanks,
> Sasha
>

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/