Re: [RFC PATCH] printk: Introduce "store now but print later" prefix.

Sergey Senozhatsky
2019-03-05T07:52:12Z

On (03/05/19 10:23), Tetsuo Handa wrote:
> > > > [..]
> > > >> This patch tries to address "don't lockup the system" with minimal risk of
> > > >> failing to "print out printk() messages", by allowing printk() callers to
> > > >> tell printk() "store $body_text_lines lines into logbuf but start actual
> > > >> printing after $trailer_text_line line is stored into logbuf". This patch
> > > >> is different from existing printk_deferred(), for printk_deferred() is
> > > >> intended for scheduler/timekeeping use only. Moreover, what this patch
> > > >> wants to do is "do not try to print out printk() messages as soon as
> > > >> possible", for accumulated stalling period cannot be decreased if
> > > >> printk_deferred() from e.g. dump_tasks() from out_of_memory() immediately
> > > >> prints out the messages. The point of this patch is to defer the stalling
> > > >> duration to after leaving the critical section.
> > > >
> > > > We can export printk deferred, I guess; but I'm not sure if it's going
> > > > to be easy to switch OOM to printk_deferred - there are lots of direct
> > > > printk callers: warn-s, dump_stacks, etc; it might even be simpler to
> > > > start re-directing OOM printouts to printk_safe buffer.
> >
> > Exactly. OOM calls many functions that are called also in other situations.
> > The async messages are not pushed to the console unless someone calls
> > a non-async printk.
> >
> > How do you want to guarantee that the non-async printk will get called
> > in all situations? The async printk() API is too error-prone.
>
> I'm suggesting to use a non-async printk() for $trailer_text_line line. I think
> that changing all printk() called from out_of_memory() to async is doable, if
> the caller of out_of_memory() wakes up a dedicated kthread described below.

I'm not objecting Petr's opinion on this.

But, personally, I think that this idea of "put this into logbuf,
but don't poke serial consoles now" is not bad. Sort of a buffering,
but not precisely buffering, because we keep messages in the logbuf,
so any other CPU can flush pending messages for us, and we don't mix
up messages' order and don't lose messages (unless we can't flush
logbuf).

This buffering is better than printk_safe(); first, because printk_safe()
buffers are much smaller in size, second, printk_safe() results in
out-of-order messages and timestamps (some people hate this) and, third,
printk_safe() eventually attempts to console_unlock() from IRQ.

And it's better than printk_deferred(), because printk_deferred() does
console_unlock() from IRQ.

But, at the same time, it's yet another buffering. I understand Petr's
concerns. And, in this particular case, this buffering might look like
we are fixing the problem on the wrong side (printk). Who knows, we
may find some use cases for this buffered printk, unrelated to OOM.
Just my 5 cents.

-ss