linux-kernel - Re: RCU stall

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20160323022902.GA28227@linux.vnet.ibm.com>
Date:	Tue, 22 Mar 2016 19:29:02 -0700
From:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
To:	Bart Van Assche <bart.vanassche@...disk.com>
Cc:	"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: Re: RCU stall

On Tue, Mar 22, 2016 at 06:59:32PM -0700, Paul E. McKenney wrote:
> On Tue, Mar 22, 2016 at 04:53:26PM -0700, Bart Van Assche wrote:
> > On 03/22/2016 01:45 PM, Paul E. McKenney wrote:
> > >You are getting a soft lockup as well as an RCU CPU stall warning, so
> > >it looks like something is taking a very long time in blk_done_softirq().
> > >
> > >You have multiple occurrences at different times, so it looks to be
> > >a long time as opposed to an infinite time.  Are you perhaps doing
> > >something that would make a huge amount of work for blk_done_softirq()?
> > >
> > >See Documentation/RCU/stallwarn.txt in the kernel source tree for more
> > >info on how to debug this sort of thing.
> > 
> > Hello Paul,
> > 
> > None of the drivers involved in the test I ran contain RCU code that
> > has been changed recently. The block and SCSI subsystems processes
> > I/O completions in softirq context but until last week I hadn't seen
> > any RCU lockup complaints when I ran an SRP test against a kernel
> > with lockdep and several other kernel debugging options enabled.
> > This is why I sent an e-mail to you. I have read
> > Documentation/RCU/stallwarn.txt after I received your reply but this
> > didn't provide me any clue about where to look for the root cause.
> > Any further help would be appreciated.
> 
> My suggestion would be to check the block/SCSI softirq handler for
> event traces.  If there are some, enable them and see what the loop
> is doing.  Documentation/trace/ftrace.txt describes how to enable
> existing event tracing.
> 
> If there is no event tracing, consider adding some in your local
> view.  Failing that, there is always printk().  ;-)
> 
> Or perhaps you have some sort of debug setup.
> 
> Either way, the next step is to work out why that CPU is spending
> so much time in that loop.

And the dmesg leading up to the stall might have some clues.

Note that a soft lockup triggered at 10509.568010, well before the RCU
CPU stall warning..  And you have a second soft lockup at 10537.567212,
with the same funtion scsi_request_fn() at the top of the stack in both
stack traces.  That function has a nice big "for (;;)" loop that does
not appear to have any iteration-limiting mechanism.  (Though perhaps
there is such a mechanism implemented in one of the called functions,
but that would be something for you to look into.)  As you saw when
reading stallwarn.txt, having a too-long loop in the kernel is a good
way to get RCU CPU stall warnings.

Also, before the soft lockups, you have a bunch of FAIL indications
and other nasty-looking error messages.  Might you have some sort of
configuration or hardware problem?

							Thanx, Paul