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

[Petr Mladek]

On Mon 2019-03-04 20:40:37, Tetsuo Handa wrote:
> On 2019/03/04 12:22, Sergey Senozhatsky wrote:
> > On (02/23/19 13:42), 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 confirmed that printk_deferred() is not suitable for this purpose, for
> it suddenly stalls for seconds at random locations flushing pending output
> accumulated by printk_deferred(). Stalling inside critical section (e.g.
> RCU read lock held) is what I don't like.

I still do not see why your async printk should be significantly
better than printk_deferred(). There is still a random victim
that would be responsible to flush the messages.

It might increase the chance that it will get printed from
normal context. But it also adds the risk that consoles
will not get handled at all.

BTW: The comment above printk_deferred() is there for a reason.
     It is a hack that should not be used widely.

     If you convert half printk() calls into a deferred/async
     module, you will just get into another problems. For example,
     not seeing the messages at all, more lost messages, random
     victims would spend even more time with flushing to the console.

     And not. Handling all messages only from normal context
     or from a dedicated kthread is not acceptable.


> > This is a bit of a strange issue, to be honest. If OOM prints too
> > many messages then we might want to do some work on the OOM side.

To be honest, I am still not sure what messages we are talking about.
Are the messages printed() from OOM killer code? Or are most of
the messages about allocation failures?

Well, both sources of messages would deserve a revision/regulation
if they cause such a big problem.

For example, I would stop printing allocation failures until
the currently running OOM killer succeeds in freeing some memory.
It might print a message about that all further allocation
failures will not get reported and then another message
about the success...

Best Regards,
Petr