From: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To: Dave Jones <davej@redhat.com>,
Linux Kernel <linux-kernel@vger.kernel.org>
Subject: Re: rcu_prempt stalls / lockup
Date: Tue, 1 Apr 2014 16:57:24 -0700 [thread overview]
Message-ID: <20140401235724.GD4284@linux.vnet.ibm.com> (raw)
In-Reply-To: <20140401233130.GA25030@redhat.com>
On Tue, Apr 01, 2014 at 07:31:30PM -0400, Dave Jones wrote:
> On Tue, Apr 01, 2014 at 04:18:22PM -0700, Paul E. McKenney wrote:
>
> > > # entries-in-buffer/entries-written: 7/7 #P:4
> > > #
> > > # _-----=> irqs-off
> > > # / _----=> need-resched
> > > # | / _---=> hardirq/softirq
> > > # || / _--=> preempt-depth
> > > # ||| / delay
> > > # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> > > # | | | |||| | |
> > > <idle>-0 [000] dNs3 851.748475: rcu_grace_period: rcu_preempt 21342 cpuend
> > > <idle>-0 [000] dNs3 851.748477: rcu_grace_period: rcu_preempt 21343 cpustart
> > > <idle>-0 [000] dNs3 851.748477: rcu_grace_period: rcu_sched 20080 cpuend
> > > <idle>-0 [000] dN.2 851.748480: rcu_grace_period: rcu_preempt 21343 cpuqs
> > > rcu_preempt-9 [000] ...1 851.748485: rcu_grace_period: rcu_preempt 21343 fqsstart
> > > rcu_preempt-9 [000] ...1 851.748487: rcu_grace_period: rcu_preempt 21343 fqsend
> > > rcu_preempt-9 [000] ...1 851.748487: rcu_grace_period: rcu_preempt 21343 fqswait
> > > # tracer: nop
> > > #
> > > # entries-in-buffer/entries-written: 13/13 #P:4
> > > #
> > > # _-----=> irqs-off
> > > # / _----=> need-resched
> > > # | / _---=> hardirq/softirq
> > > # || / _--=> preempt-depth
> > > # ||| / delay
> > > # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> > > # | | | |||| | |
> > > rcu_preempt-9 [003] d..2 851.878457: rcu_grace_period: rcu_preempt 21349 end
> > > rcu_preempt-9 [003] d..2 851.878459: rcu_grace_period: rcu_preempt 21349 newreq
> > > rcu_preempt-9 [003] ...1 851.878459: rcu_grace_period: rcu_preempt 21349 reqwait
> > > rcu_preempt-9 [003] d..2 851.878460: rcu_grace_period: rcu_preempt 21350 start
> > > rcu_preempt-9 [003] d..2 851.878461: rcu_grace_period: rcu_preempt 21350 cpustart
> > > rcu_preempt-9 [003] d..2 851.878462: rcu_grace_period_init: rcu_preempt 21350 0 0 7 f
> > > rcu_preempt-9 [003] ...1 851.878463: rcu_grace_period: rcu_preempt 21350 fqswait
> > > rcu_preempt-9 [003] d..2 851.878464: rcu_grace_period: rcu_preempt 21350 cpuqs
> > > <idle>-0 [000] dNs3 851.878482: rcu_grace_period: rcu_preempt 21349 cpuend
> > > <idle>-0 [000] dNs3 851.878483: rcu_grace_period: rcu_preempt 21350 cpustart
> > > <idle>-0 [000] dNs3 851.878484: rcu_grace_period: rcu_sched 20086 cpuend
> > > <idle>-0 [000] .N.2 851.878486: rcu_grace_period: rcu_sched 20086 cpuqs
> > > <idle>-0 [000] dN.2 851.878487: rcu_grace_period: rcu_preempt 21350 cpuqs
OK, so the trace ended on grace period #21350...
> > >
> > >
> > > followed by a half dozen 'empty' traces before it totally locked up.
> >
> > Cool, thank you!
> >
> > Could you please also send the RCU CPU stall warning messages?
>
> >From that run they were..
>
> [ 917.790265] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 917.791189] (detected by 0, t=6502 jiffies, g=21390, c=21389, q=0)
But the hang didn't happen until grace period #21390. Sigh! That means
that the trace doesn't tell me about the current grace period.
Thank you for getting this info, but it is beginning to look like
bisection is necessary here. :-(
Thanx, Paul
> [ 917.792058] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 917.792799] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 917.793534] (detected by 0, t=6502 jiffies, g=20128, c=20127, q=0)
> [ 917.794265] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1112.727480] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1112.728425] (detected by 0, t=26007 jiffies, g=21390, c=21389, q=0)
> [ 1112.729300] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1112.730035] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1112.730744] (detected by 0, t=26007 jiffies, g=20128, c=20127, q=0)
> [ 1112.731459] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1307.664710] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1307.665623] (detected by 0, t=45512 jiffies, g=21390, c=21389, q=0)
> [ 1307.666386] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1307.667113] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1307.667839] (detected by 0, t=45512 jiffies, g=20128, c=20127, q=0)
> [ 1307.668572] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1502.601961] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1502.602905] (detected by 0, t=65017 jiffies, g=21390, c=21389, q=0)
> [ 1502.603765] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1502.604550] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1502.605305] (detected by 0, t=65017 jiffies, g=20128, c=20127, q=0)
> [ 1502.606061] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1697.539217] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1697.540189] (detected by 0, t=84522 jiffies, g=21390, c=21389, q=0)
> [ 1697.541052] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1697.541826] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1697.542600] (detected by 0, t=84522 jiffies, g=20128, c=20127, q=0)
> [ 1697.543378] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1892.476433] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1892.477545] (detected by 0, t=104027 jiffies, g=21390, c=21389, q=0)
> [ 1892.478402] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 1892.479208] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 1892.480010] (detected by 0, t=104027 jiffies, g=20128, c=20127, q=0)
> [ 1892.480831] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 2087.413694] INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 2087.414748] (detected by 0, t=123532 jiffies, g=21390, c=21389, q=0)
> [ 2087.415722] INFO: Stall ended before state dump start, gp_kthread state: 0x2
> [ 2087.416558] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 2087.417392] (detected by 0, t=123532 jiffies, g=20128, c=20127, q=0)
> [ 2087.418231] INFO: Stall ended before state dump start, gp_kthread state: 0x2
>
>
>
next prev parent reply other threads:[~2014-04-01 23:57 UTC|newest]
Thread overview: 23+ messages / expand[flat|nested] mbox.gz Atom feed top
2014-03-31 23:02 rcu_prempt stalls / lockup Dave Jones
2014-03-31 23:22 ` Paul E. McKenney
2014-03-31 23:35 ` Dave Jones
2014-04-01 0:48 ` Paul E. McKenney
2014-04-01 15:08 ` Dave Jones
2014-04-01 15:30 ` Paul E. McKenney
2014-04-01 17:22 ` Dave Jones
2014-04-01 17:55 ` Paul E. McKenney
2014-04-01 18:04 ` Dave Jones
2014-04-01 18:32 ` Paul E. McKenney
2014-04-01 22:16 ` Dave Jones
2014-04-01 23:18 ` Paul E. McKenney
2014-04-01 23:31 ` Dave Jones
2014-04-01 23:57 ` Paul E. McKenney [this message]
2014-04-02 0:07 ` Dave Jones
2014-04-02 16:20 ` Paul E. McKenney
2014-04-02 16:23 ` Dave Jones
2014-04-02 22:48 ` Dave Jones
2014-04-03 20:01 ` Dave Jones
2014-04-03 20:46 ` Paul E. McKenney
2014-04-03 21:44 ` Dave Jones
2014-04-03 22:37 ` Dave Jones
2014-04-04 17:06 ` 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=20140401235724.GD4284@linux.vnet.ibm.com \
--to=paulmck@linux.vnet.ibm.com \
--cc=davej@redhat.com \
--cc=linux-kernel@vger.kernel.org \
/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.