Re: [RFC][PATCHv2 6/7] printk: report printk recursion from alt_printk flush

[Petr Mladek <pmladek@suse.com>]

On Sat 2016-10-01 00:17:57, Sergey Senozhatsky wrote:
> If we end up executing vprintk_alt() then we have a printk
> recursion. Set alt_printk_ctx `ALT_PRINTK_RECURSION_MASK' bit
> in vprintk_alt() to indicate that recutsion and report the
> "BUG: recent printk recursion!" problem later from
> __alt_printk_flush().
> 
> Example:
> 
>  BUG: recent printk recursion!
>  ------------[ cut here ]------------
>  WARNING: CPU: 3 PID: 366 at kernel/printk/printk.c:1803 vprintk_emit+0x139/0x38c
>  CPU: 3 PID: 366 Comm: bash
>  Call Trace:
>   [<ffffffff811be508>] dump_stack+0x4d/0x63
>   [<ffffffff81039932>] __warn+0xb8/0xd3
>   [<ffffffff810399b3>] warn_slowpath_null+0x18/0x1a
>   [<ffffffff8106bfdb>] vprintk_emit+0x139/0x38c
>   [<ffffffff8106c390>] vprintk_default+0x18/0x1a
>   [<ffffffff8106d1e6>] vprintk_func+0x65/0x67
>   [<ffffffff810ab27f>] printk+0x3e/0x46
> [..]
>   [<ffffffff8145fb60>] entry_SYSCALL_64_fastpath+0x13/0x94
>   ---[ end trace ]---
> 
> Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> ---
>  kernel/printk/alt_printk.c | 9 +++++++++
>  kernel/printk/internal.h   | 1 +
>  2 files changed, 10 insertions(+)
> 
> diff --git a/kernel/printk/alt_printk.c b/kernel/printk/alt_printk.c
> index db0bfc8..0010089 100644
> --- a/kernel/printk/alt_printk.c
> +++ b/kernel/printk/alt_printk.c
> @@ -150,6 +150,13 @@ static void __alt_printk_flush(struct irq_work *work)
>  more:
>  	len = atomic_read(&s->len);
>  
> +	if (this_cpu_read(alt_printk_ctx) & ALT_PRINTK_RECURSION_MASK) {
> +		const char *msg = "BUG: recent printk recursion!\n";
> +
> +		this_cpu_and(alt_printk_ctx, ~ALT_PRINTK_RECURSION_MASK);
> +		alt_printk_flush_line(msg, strlen(msg));
> +	}
> +
>  	/*
>  	 * This is just a paranoid check that nobody has manipulated
>  	 * the buffer an unexpected way. If we printed something then
> @@ -290,6 +297,8 @@ static int vprintk_alt(const char *fmt, va_list args)
>  {
>  	struct alt_printk_seq_buf *s = this_cpu_ptr(&alt_print_seq);
>  
> +	/* There is only one way to get here -- a printk recursion. */
> +	this_cpu_or(alt_printk_ctx, ALT_PRINTK_RECURSION_MASK);

Is it really a bug? In most cases, the message that is being printed
describes a bug. We just allow to print it this alternative way to
avoid a possible deadlock. IMHO, this might cause a confusion.

Instead I would print an error when we missed some messages
because the alternative buffer was not big enough.

Best Regards,
Petr