linux-kernel - Re: INFO: rcu detected stall in sys_exit

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] [day] [month] [year] [list]

Date:   Tue, 24 Sep 2019 16:02:41 +0200
From:   Petr Mladek <pmladek@...e.com>
To:     Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>
Cc:     Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Dmitry Vyukov <dvyukov@...gle.com>, paulmck@...nel.org,
        Christian Brauner <christian@...uner.io>,
        prsood@...eaurora.org, avagin@...il.com,
        syzkaller-bugs <syzkaller-bugs@...glegroups.com>,
        Tejun Heo <tj@...nel.org>,
        Thomas Gleixner <tglx@...utronix.de>,
        Andrew Morton <akpm@...ux-foundation.org>,
        Andrea Arcangeli <aarcange@...hat.com>,
        Oleg Nesterov <oleg@...hat.com>, dbueso@...e.de,
        syzbot <syzbot+18379f2a19bc62c12565@...kaller.appspotmail.com>,
        LKML <linux-kernel@...r.kernel.org>,
        John Ogness <john.ogness@...utronix.de>
Subject: Re: INFO: rcu detected stall in sys_exit_group

On Fri 2019-09-20 19:22:10, Tetsuo Handa wrote:
> Calling printk() people.
> 
> On 2019/09/20 16:50, Dmitry Vyukov wrote:
> >>>                                   How it runs on top of an interrupt?
> >>
> >> It is not running on top of an interrupt.  Its stack was dumped
> >> separately.
> > 
> > I see. Usually the first stack is the traceback of the current stack.
> > So I was confused.
> > 
> >>> And why one cpu tracebacks another one?
> >>
> >> The usual reason is because neither CPU's quiescent state was reported
> >> to the RCU core, so the stall-warning code dumped both stacks.
> > 
> > But should the other CPU traceback _itself_? Rather than being traced
> > back by another CPU?
> > E.g. see this report:
> > https://github.com/google/syzkaller/blob/master/pkg/report/testdata/linux/report/350#L61-L83
> > Here the overall problem was detected by C2, but then C1 traces back itself.
> > 
> > ... however even in that case C0 and C3 are traced by C2:
> > https://github.com/google/syzkaller/blob/master/pkg/report/testdata/linux/report/350#L84-L149
> > I can't understand this...
> > This makes understanding what happened harder because it's not easy to
> > exclude things on other CPUs.
> 
> I think this should be
> https://github.com/google/syzkaller/blob/master/pkg/report/testdata/linux/report/350#L84-L172
> than #L84-L149 .
> 
> Is the reason these lines have "[    C2]" is that these lines were flushed (printk_caller_id()
> was called) from log_output() from vprintk_store() from vprintk_emit() from vprintk_deferred()
>  from printk_deferred() from printk_safe_flush_line() from __printk_safe_flush() from
> printk_safe_flush() from printk_safe_flush_on_panic() from panic() ?

It seems to be the case. CPU2 is clearly flushing per-CPU buffers
from NMI context, for example:

[ 1098.703114][    C2] NMI backtrace for cpu 0
[...]
[ 1098.703295][    C2] NMI backtrace for cpu 3

A solution would be to store all these metadata (timestamp, caller
info) already into the per-CPU buffers. I think that it would be
doable.

But much better solution is a lockless ring buffer. John Ogness is
working hard on it. The plan is to have it ready for 5.5 or 5.6.
I would prefer to concentrate on this solution for the moment.

Best Regards,
Petr