Re: [PATCH 1/3] printk: Make printk() completely async

[Jan Kara]

On Thu 03-03-16 20:26:55, Tetsuo Handa wrote:
> On 2016/03/03 0:59, Jan Kara wrote:
> > This patch makes printk() completely asynchronous (similar to what
> > printk_deferred() did until now). It appends message to the kernel
> > printk buffer and queues work to do the printing to console. This has
> > the advantage that printing always happens from a schedulable contex and
> > thus we don't lockup any particular CPU or even interrupts. Also it has
> > the advantage that printk() is fast and thus kernel booting is not
> > slowed down by slow serial console. Disadvantage of this method is that
> > in case of crash there is higher chance that important messages won't
> > appear in console output (we may need working scheduling to print
> > message to console). We somewhat mitigate this risk by switching printk
> > to the original method of immediate printing to console if oops is in
> > progress.  Also for debugging purposes we provide printk.synchronous
> > kernel parameter which resorts to the original printk behavior.
> 
> A few questions.
> 
> (1) How do you handle PM/suspend? I think kernel threads including
>     workqueue will be frozen during suspend operation. Maybe we can use
>     an atomic_t counter (like oom_victims) which forces synchronous
>     printing if counter value > 0.

Well, it depends on whether you make the workqueue freezable or not... I
don't think printk workqueue should be actually freezable. But it's a good
think to have in mind.

> (2) Can we have a method for waiting for pending data to be flushed
>     with timeout? If I want to emit as much messages as SysRq-t from
>     schedulable context, I want to wait for flush before proceeding.
>     This is different from using atomic_t counter suggested in (1), for
>     asynchronous printk() helps reducing RCU duration; queuing to string
>     buffer from RCU context and emitting from !RCU context will be
>     preferable.

Separate problem => separate patch please. This was hard to push through
already as is.

> (3) Is reliability of SysRq-t changed by this patch? I mean, does this
>     patch make SysRq-t prone to drop traces if the logbuf was not large
>     enough?

Qualitatively no - even currently Sysrq-t can see console_lock locked
(because there's some other printk happening as well) and thus will just
dump all the information into kernel buffer. Quantitatively - likely yes -
now the printing will be always async, previous it was only when racing
with other printk. But you should have large enough printk buffer to
accommodate full sysrq-t output if you care about it being complete.

> (4) This will be outside of this proposal's scope, but it would be nice
>     if we can selectively allow each console driver to control loglevel
>     to emit. For example, send all kernel messages to serial console
>     (console=ttyS0,115200n8) but send only critical messages to login
>     console (console=tty0). I'm interested in logging via serial console
>     and netconsole but not via login console. Since traces sent to login
>     console is swept away soon, waiting for login console is wasteful.

Yes, that's a completely separate issue. But it would be nice, yes.

> (5) This will be outside of this proposal's scope, but it would be nice
>     if printk() can combine multiple logs and pass to console drivers.
>     For example, logging via netconsole will become significantly faster
>     if printk() can combine multiple logs up to ethernet packet's size.
>     A single stack trace can likely be sent using one ethernet packet.

This would be rather non-trivial to achieve I suspect since the console
code is pretty much line-oriented...

								Honza
-- 
Jan Kara <jack@xxxxxxxx>
SUSE Labs, CR