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

[Sergey Senozhatsky <sergey.senozhatsky@gmail.com>]

Hello,

On (03/03/16 20:26), 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.

hm, workqueues should be freezible only when we pass WQ_FREEZABLE.
I allocate printk_wq passing WQ_MEM_RECLAIM only.

I'll post the patch shortly; for a wider testing.

> (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.

well... you can do something like

	console_lock
	printk()
	...
	printk()
	console_unlock

but it can spend much more time in console_unlock(), printing the messages.
in case if you have (or had) additional sources of printk (coming from other
CPUs).

> (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?

hm, not really. printk() and actual printing of the message
can easily be executed on different CPUs.

CPU0                                    CPU1
                                    console_lock
                                    console_unlock
                                      for (;;) {
SysRq
 for (....)                             spin_lock logbuf_lock
                                          read the message from logbuf
  printk()
  {                                     spin_unlock logbuf_lock
   spin_lock logbuf_lock                call_console_drivers
     add message to logbuf            }
   spin_unlock logbuf_lock

   try lock console_lock
   return
  }


so if CPU1 is slow in evicting the messages from logbuf and logbuf is
not large enough then we can lose some messages from CPU0.


> (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, may be later.

> (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.


hm. that's easier to handle in console driver's code, I think. but,
while I understand what you mean here, I'd generally expect that
every message ending with a new line is getting printed asap, w/o any
buffering. well, just saying.

	-ss