[PATCH] printk: Add printk log prefix information.

[chunlei.wang <Chunlei.wang@mediatek.com>]

Add prefix status/cpu_id/pid/process_name to each kernel log.
example:
[ 8408.806432] (4)[19963:kworker/4:1]wifi_fw: ring_emi_seg.sz=4164,
ring_cache_pt=000000004f5ca8fa, ring_cache_seg.sz=4164
[ 8408.806729]-(4)[19963:kworker/4:1]connlog_log_data_handler: 1
callbacks suppressed
Status now only include irq status. If in ISR print too much log, will
cause performance issue, we can check the log to find which module. We
also can expand the status in future.
cpu_id mean which cpu print this log, we can check specific cpu's
action.
pocess_name show the log process id and name.
These information is very useful in embedded system, it can provide more
information to analyze issue.

Feature: printk
Signed-off-by: Chunlei Wang <chunlei.wang@mediatek.com>
---
 kernel/printk/printk.c | 52 ++++++++++++++++++++++++++++++++++++++++--
 lib/Kconfig.debug      |  9 ++++++++
 2 files changed, 59 insertions(+), 2 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1ef6f75d92f1..9cb2a4c2157b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -60,6 +60,11 @@
 #include "braille.h"
 #include "internal.h"
 
+
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+static DEFINE_PER_CPU(char, printk_state);
+#endif
+
 int console_printk[4] = {
        CONSOLE_LOGLEVEL_DEFAULT,       /* console_loglevel */
        MESSAGE_LOGLEVEL_DEFAULT,       /* default_message_loglevel */
@@ -610,8 +615,35 @@ static int log_store(u32 caller_id, int facility,
int level,
        u32 size, pad_len;
        u16 trunc_msg_len = 0;
 
-       /* number of '\0' padding bytes to next message */
-       size = msg_used_size(text_len, dict_len, &pad_len);
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+       int this_cpu = smp_processor_id();
+       char state = this_cpu_read(printk_state);
+       char tbuf[50];
+       unsigned int tlen = 0;
+#endif
+
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+               if (state == 0) {
+                       this_cpu_write(printk_state, ' ');
+                       state = ' ';
+               }
+               if (!(flags & LOG_CONT)) {
+                       if (console_suspended == 0)
+                               tlen = snprintf(tbuf, sizeof(tbuf),
+                                       "%c(%x)[%d:%s]", state,
this_cpu,
+                                       current->pid, current->comm);
+                       else
+                               tlen = snprintf(tbuf, sizeof(tbuf), "%
c(%x)",
+                                       state, this_cpu);
+               }
+#endif
+
+               /* number of '\0' padding bytes to next message */
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+               size = msg_used_size(text_len + tlen, dict_len,
&pad_len);
+#else
+               size = msg_used_size(text_len, dict_len, &pad_len);
+#endif
 
        if (log_make_free_space(size)) {
                /* truncate the message if it is too long for empty
buffer */
@@ -634,7 +666,16 @@ static int log_store(u32 caller_id, int facility,
int level,
 
        /* fill message */
        msg = (struct printk_log *)(log_buf + log_next_idx);
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+       memcpy(log_text(msg), tbuf, tlen);
+       if (tlen + text_len > LOG_LINE_MAX)
+               text_len = LOG_LINE_MAX - tlen;
+
+       memcpy(log_text(msg) + tlen, text, text_len);
+       text_len += tlen;
+#else
        memcpy(log_text(msg), text, text_len);
+#endif
        msg->text_len = text_len;
        if (trunc_msg_len) {
                memcpy(log_text(msg) + text_len, trunc_msg,
trunc_msg_len);
@@ -1964,6 +2005,13 @@ asmlinkage int vprintk_emit(int facility, int
level,
        if (unlikely(suppress_printk))
                return 0;
 
+#ifdef CONFIG_PRINTK_PREFIX_ENHANCE
+       if (irqs_disabled())
+               this_cpu_write(printk_state, '-');
+       else
+               this_cpu_write(printk_state, ' ');
+#endif
+
        if (level == LOGLEVEL_SCHED) {
                level = LOGLEVEL_DEFAULT;
                in_sched = true;
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index d1842fe756d5..6e6c783cd570 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -35,6 +35,15 @@ config PRINTK_CALLER
          no option to enable/disable at the kernel command line
parameter or
          sysfs interface.
 
+config PRINTK_PREFIX_ENHANCE
+       bool "Prefix cpu_id/status/pid/process_name to each kernel log"
+       depends on PRINTK
+       help
+         PRINTK_PREFIX_ENHANCE which is used to control whether to show
+         other information about this log. The information include
+         which cpu about this process in, whether in isr, pid and
thread
+         name. These information can help to analyze issue.
+
 config CONSOLE_LOGLEVEL_DEFAULT
        int "Default console loglevel (1-15)"
        range 1 15
-- 
2.18.0

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel