linux-kernel - Re: sched: serial port lockdep warning when offlining CPUs

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: <20170928103032.GA2380@jagdpanzerIV.localdomain>
Date:   Thu, 28 Sep 2017 19:30:32 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To:     Peter Zijlstra <peterz@...radead.org>
Cc:     Sasha Levin <levinsasha928@...il.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        Ingo Molnar <mingo@...e.hu>,
        "linux-kernel@...r.kernel.org List" <linux-kernel@...r.kernel.org>,
        alexander.levin@...izon.com, pmladek@...e.com,
        sergey.senozhatsky@...il.com, rostedt@...dmis.org
Subject: Re: sched: serial port lockdep warning when offlining CPUs

Hi all,

Peter, thanks for Cc-ing.

On (09/28/17 11:38), Peter Zijlstra wrote:
> On Thu, Sep 28, 2017 at 02:19:46AM -0700, Sasha Levin wrote:
> > Hi all,
> > 
> > I seem to be hitting the following warning when offlining CPUs on the
> > latest -next kernel:
> > 
> > [289683102.607076] Unregister pv shared memory for cpu 8
> > [289683102.622922] select_fallback_rq: 3 callbacks suppressed
> 
> This is because you hit a printk() from the scheduler, that's known
> broken (along with the rest of printk).
> 
> You forgot to actually include that printk() though I suspect it reads
> like:
> 
>   "process %d (%s) no longer affine to cpu%d\n"
> 
> Now that uses printk_deferred() which _should_ work lots better, but
> clearly the printk() stuff went wobbly again.
> 
> > [289683102.626292] vprintk_emit (kernel/printk/printk.c:1876)
> > [289683102.626294] vprintk_default (kernel/printk/printk.c:1918)
> > [289683102.626295] vprintk_func (kernel/printk/printk_safe.c:382)
> > [289683102.626297] printk (kernel/printk/printk.c:1943)
> > [289683102.626299] ? show_regs_print_info (kernel/printk/printk.c:1943)
> > [289683102.626301] ? lock_acquire (kernel/locking/lockdep.c:4004)
> > [289683102.626306] ___ratelimit (lib/ratelimit.c:52)
> > [289683102.626309] __printk_ratelimit (kernel/printk/printk.c:2874)
> > [289683102.626311] select_fallback_rq (kernel/sched/core.c:1525 (discriminator 1))
> > [289683102.626313] sched_cpu_dying (kernel/sched/core.c:5500 kernel/sched/core.c:5687)
> 
> Also, could you pretty please not line wrap logs?

I think it's

	if (p->mm && printk_ratelimit())

which calls int ___ratelimit(), which ends up doing

	pr_warn("%s: %d callbacks suppressed\n", func, rs->missed);


which is a "normal" printk from within the scheduler.


out of curiosity, will the following fix the warning

---

 lib/ratelimit.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/lib/ratelimit.c b/lib/ratelimit.c
index 08f8043cac61..bddc55834c2e 100644
--- a/lib/ratelimit.c
+++ b/lib/ratelimit.c
@@ -48,7 +48,8 @@ int ___ratelimit(struct ratelimit_state *rs, const char *func)
 	if (time_is_before_jiffies(rs->begin + rs->interval)) {
 		if (rs->missed) {
 			if (!(rs->flags & RATELIMIT_MSG_ON_RELEASE)) {
-				pr_warn("%s: %d callbacks suppressed\n", func, rs->missed);
+				printk_deferred(KERN_WARN "%s: %d callbacks suppressed\n",
+						func, rs->missed);
 				rs->missed = 0;
 			}
 		}