Re: [PATCH] printk: inject caller information into the body of message

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

On (09/13/18 21:22), Steven Rostedt wrote:
> > Good call. It was a fast path for pr_cont("\n").
> > But it made me wondering and I did some grepping
> > 
> 
> [..]
> 
> > kernel/trace/ftrace.c:          pr_cont("\n expected tramp: %lx\n", ip);
> 
> Note, looking at the history of that, I was just combining a lone "\n"
> with the next string. The code before this print add info to the line
> depending on the input, thus none do a "\n". The "expected tramp" part
> is added to the next line, but I'm fine if you want to break this up.
> This print is very unlikely done with other prints happening. It
> happens when modifying (serially) ftrace nops to calls or back to nops.
> 
> Feel free to send a patch that breaks it up into:
> 
> 	pr_cont("\n");
> 	pr_info(" expected tramp: %lx\n", ip);

I didn't mean to criticize anyone with my "Lovely" comment. Sorry if it
appeared to sound harsh.

I'm fine with the way it is, but we *probably* (up to you) will touch
this code once pr_line is available. As of now, the less pr_cont() calls
we make the better. This

	pr_cont("a");
	pr_cont("b");
	pr_cont("c\n");

in the worst case can be log_store-d as 3 log entries (2 preliminary
flushes). So, from this point of view, this

	pr_cont("ab");
	pr_cont("c\n");

is better, because it can be log_store-d as 2 log entries.
And with pr_line() we can log_store it in 1 log entry [but we will
use some extra stack space for that].

Overall, I counted around 100 cases of printk("\n...."), and around 20+ cases
of pr_cont("\n...") and probably around 10 or 15 printk(KERN_CONT "\n....")
cases. That's what I meant when I said that converting it to pr_line()
will take us some time. Especially given that some of lockdep developers
have really warm feelings toward printk ;)

	-ss