linux-kernel - Re: printk: what is going on with additional newlines?

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:   Tue, 5 Sep 2017 23:18:03 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky@...il.com>
To:     Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>
Cc:     pmladek@...e.com, sergey.senozhatsky.work@...il.com,
        joe@...ches.com, rostedt@...dmis.org,
        torvalds@...ux-foundation.org, pavel@....cz,
        sergey.senozhatsky@...il.com, jack@...e.cz,
        akpm@...ux-foundation.org, jslaby@...e.com, andi@...as.de,
        linux-kernel@...r.kernel.org
Subject: Re: printk: what is going on with additional newlines?

On (09/05/17 21:35), Tetsuo Handa wrote:
[..]
> > Well, what do you think about the extra printed information?
> > For example:
> > 
> >     <timestamp> <PID> <context> message
> > 
> > It looks straightforward to me. These information
> > might be helpful on its own. So, it might be a
> > win-win solution.
> 
> Yes, if buffering multiple lines will not be implemented, I do want
> printk context identifier field for each line. I think <PID> <context>
> part will be something like TASK#pid (if outside interrupt) or
> CPU#cpunum/#irqlevel (if inside interrupt).

well, depending on what's your aim.

it's not always printk() that causes troubles, but console_unlock().
which is busy because of printk()-s. and those are not necessarily
running on the same CPU. so if you want to have a full picture (don't
know what for) then you need to log both vprintk_emit() and
console_unlock() sides. vprintk_emit() side requires changes to
`struct printk_log', console_unlock() does not - you can just sprintf()
the required data to `text' buffer.

for example, I do the following on my PC boxes to keep track the
behaviour of printk kthread offloading.

---

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a4e3f84ef365..ac1fd606d6c5 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2493,15 +2493,16 @@ void console_unlock(void)
                        seen_seq = log_next_seq;
                }
 
+               len = sprintf(text, "{%s/%d/%d}", current->comm,
+                               smp_processor_id(), do_cond_resched);
+
                if (console_seq < log_first_seq) {
-                       len = sprintf(text, "** %u printk messages dropped ** ",
+                       len += sprintf(text + len, "** %u printk messages dropped ** ",
                                      (unsigned)(log_first_seq - console_seq));
 
                        /* messages are gone, move to first one */
                        console_seq = log_first_seq;
                        console_idx = log_first_idx;
-               } else {
-                       len = 0;
                }
 skip:
                if (did_offload || console_seq == log_next_seq)