It can be difficult to sort printk out if multiple processors are
printing simultaneously. Add the processor number to the printk
output to allow the messages to be sorted.

Signed-off-by: John Ogness <[email protected]>
---
 kernel/printk/printk.c | 19 +++++++++++++++----
 1 file changed, 15 insertions(+), 4 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b97d4195b09a..cde036d8487a 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -331,6 +331,7 @@ enum log_flags {
 
 struct printk_log {
        u64 ts_nsec;            /* timestamp in nanoseconds */
+       u16 cpu;                /* cpu that generated record */
        u16 len;                /* length of entire record */
        u16 text_len;           /* length of text buffer */
        u16 dict_len;           /* length of dictionary buffer */
@@ -475,7 +476,7 @@ static u32 log_next(u32 idx)
 
 /* insert record into the buffer, discard old ones, update heads */
 static int log_store(int facility, int level,
-                    enum log_flags flags, u64 ts_nsec,
+                    enum log_flags flags, u64 ts_nsec, u16 cpu,
                     const char *dict, u16 dict_len,
                     const char *text, u16 text_len)
 {
@@ -506,6 +507,7 @@ static int log_store(int facility, int level,
        msg->level = level & 7;
        msg->flags = flags & 0x1f;
        msg->ts_nsec = ts_nsec;
+       msg->cpu = cpu;
        msg->len = size;
 
        /* insert message */
@@ -570,9 +572,9 @@ static ssize_t msg_print_ext_header(char *buf, size_t size,
 
        do_div(ts_usec, 1000);
 
-       return scnprintf(buf, size, "%u,%llu,%llu,%c;",
+       return scnprintf(buf, size, "%u,%llu,%llu,%c,%hu;",
                       (msg->facility << 3) | msg->level, seq, ts_usec,
-                      msg->flags & LOG_CONT ? 'c' : '-');
+                      msg->flags & LOG_CONT ? 'c' : '-', msg->cpu);
 }
 
 static ssize_t msg_print_ext_body(char *buf, size_t size,
@@ -1110,6 +1112,11 @@ static inline void boot_delay_msec(int level)
 static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
+static size_t print_cpu(u16 cpu, char *buf)
+{
+       return sprintf(buf, "%03hu: ", cpu);
+}
+
 static size_t print_syslog(unsigned int level, char *buf)
 {
        return sprintf(buf, "<%u>", level);
@@ -1132,6 +1139,7 @@ static size_t print_prefix(const struct printk_log *msg, 
bool syslog,
                len = print_syslog((msg->facility << 3) | msg->level, buf);
        if (time)
                len += print_time(msg->ts_nsec, buf + len);
+       len += print_cpu(msg->cpu, buf + len);
        return len;
 }
 
@@ -1698,6 +1706,7 @@ asmlinkage int vprintk_emit(int facility, int level,
        u64 ts_nsec;
        char *text;
        char *rbuf;
+       int cpu;
 
        ts_nsec = local_clock();
 
@@ -1707,6 +1716,8 @@ asmlinkage int vprintk_emit(int facility, int level,
                return printed_len;
        }
 
+       cpu = raw_smp_processor_id();
+
        text = rbuf;
        text_len = vscnprintf(text, PRINTK_SPRINT_MAX, fmt, args);
 
@@ -1744,7 +1755,7 @@ asmlinkage int vprintk_emit(int facility, int level,
        if (dict)
                lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-       printed_len = log_store(facility, level, lflags, ts_nsec,
+       printed_len = log_store(facility, level, lflags, ts_nsec, cpu,
                                dict, dictlen, text, text_len);
 
        prb_commit(&h);
-- 
2.11.0

Reply via email to