Re: printk: what is going on with additional newlines?

[Sergey Senozhatsky]

On (09/05/17 10:54), Steven Rostedt wrote:
> On Mon, 4 Sep 2017 14:22:46 +0900
> Sergey Senozhatsky <sergey.senozhatsky.work@xxxxxxxxx> wrote:
> 
> > like I said in another email, printk-safe buffer
> > is per-CPU and is also used for actual printk-safe, hence it must be
> > used with local IRQs disabled when we "borrow" the buffer for pr_line
> > (disabled preemption is not enough due to possible IRQ printk-safe
> > print out). this can be a bit annoying.
> 
> You can do what I did with trace_printk(). I have a buffer per context.
> Then you only need to use preempt_disable() to do the print. That is,
> trace_printk() has 4 buffers:
> 
>  1. Normal context
>  2. softirq context
>  3. irq context
>  4. NMI context

thanks. looks interesting.

> It determines which context it is in, disables preemption, and uses the
> corresponding buffer. This way I don't need to worry about being
> preempted by an interrupt or NMI.
> 
> Grant it, it does make the memory needed 4x bigger.

yep. that's a concern. buffered printk must come with a sound number
of users in this case. otherwise people will just see a massive bump
(x2) in memory usage for no particular reason.

> I have an array of 4 buffers, and the following code:
> 
> static char *get_trace_buf(void)
> {
> 	struct trace_buffer_struct *buffer = this_cpu_ptr(trace_percpu_buffer);
> 
> 	if (!buffer || buffer->nesting >= 4)
> 		return NULL;
> 
> 	return &buffer->buffer[buffer->nesting++][0];
> }
> 
> Hmm, I probably need to add a "barrier()" before the return, or use a
> this_cpu_inc() on nesting. As long as the nesting variable is updated
> before the return of the buffer being used, then everything is fine.
> Because we have:
> 
> static void put_trace_buf(void)
> {
> 	this_cpu_dec(trace_percpu_buffer->nesting);
> }
> 
> And anything that preempts this call will have returned it back to its
> original state before returning.

there is a tiny-tiny-tiny chance of losing some very specific messages
from the top most context. consider the following
	trace_printk("fat fingers %o\n", 100);

from the NMI (nesting 3) context. vscnprintf() must

	WARN_ONCE(1, "Unsupported flags modifier: %c\n", fmt[1]);

which will be lost - we are above the nesting limit buffer->nesting >= 4.
// vscnprintf()->... has several more recursion entry points.

	-ss