linux-kernel - Re: [PATCH v12 0/3] printk: Make printk() completely async

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: <20160712164650.GA451@swordfish>
Date:	Wed, 13 Jul 2016 01:46:50 +0900
From:	Sergey Senozhatsky <sergey.senozhatsky@...il.com>
To:	Petr Mladek <pmladek@...e.com>
Cc:	Viresh Kumar <viresh.kumar@...aro.org>,
	Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Jan Kara <jack@...e.com>, Tejun Heo <tj@...nel.org>,
	Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>,
	"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
	Byungchul Park <byungchul.park@....com>,
	Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
Subject: Re: [PATCH v12 0/3] printk: Make printk() completely async

On (07/12/16 17:59), Petr Mladek wrote:
[..]
> > [   12.874909] sched: RT throttling activated for rt_rq ffffffc0ac13fcd0 (cpu 0)
> > [   12.874909] potential CPU hogs:
> > [   12.874909]  printk (292)
> > 
> > On my system, the excessive printing happens during suspend/resume and this
> > happened after all the non-boot CPUs were offlined. So, only CPU 0 was left and
> > that was doing printing for a long time and so these errors :)
> > 
> > It resulted in missing some print messages eventually as the scheduler probably
> > didn't schedule this thread for sometime after that.
> > 
> > Will it be fine to get the priority of this kthread to a somewhat lower value,
> > etc ?
> 
> I think that this patch helped only by chance. It causes that any
> message without a new line will force printk to the sync mode.
> Then it will print even the buffered messages immediately. It
> causes printk to behave more or less in the sync mode all the time.

KERN_CONT messages are not so often, because they are not SMP-safe, any intruding
non-KERN_CONT message will wake_up() printk_kthread. there is a chance, you are
right, that printk will operate in sync mode for some time, when we would want it
to be async, so 0004 probably better try harder.

but KERN_CONT is not what's going on in this case, I think. at lest 
"[   12.874909]  printk (292)" line suggests so -- printk was in async
mode... and somehow non-preemptible for some time... a delay from spin_lock()
in call_console_drivers()->write()?... but why would async printk worsen it.

> I am still scratching my head about the problem fixed by this patch
> and also about suspend problems.

yeah, quite puzzled myself. thanks Petr and Viresh for digging this up.
I need some sleep now, it's 2 am here, will return back tomorrow.

	-ss