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

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Fri, 14 Sep 2018 11:15:50 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Petr Mladek <pmladek@...e.com>,
        Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        Alexander Potapenko <glider@...gle.com>,
        Dmitriy Vyukov <dvyukov@...gle.com>,
        penguin-kernel@...ove.sakura.ne.jp,
        kbuild test robot <fengguang.wu@...el.com>,
        syzkaller <syzkaller@...glegroups.com>,
        LKML <linux-kernel@...r.kernel.org>,
        Linus Torvalds <torvalds@...ux-foundation.org>,
        Andrew Morton <akpm@...ux-foundation.org>
Subject: Re: [PATCH] printk: inject caller information into the body of
 message

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