| 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
| ||
|
Date: Fri, 3 Aug 2012 02:16:18 -0700
From: Vikram Pandita <vikram.pandita@...com>
To: <gregkh@...uxfoundation.org>, <kay@...y.org>
CC: <linux-kernel@...r.kernel.org>,
Vikram Pandita <vikram.pandita@...com>,
Mike Turquette <mturquette@...aro.org>,
Vimarsh Zutshi <vimarsh.zutshi@...il.com>
Subject: [PATCH v2] printk: add option to print cpu id
From: Vikram Pandita <vikram.pandita@...com>
Introduce config option to enable CPU id reporting for printk() calls.
Example logs with this option enabled look like:
[1] [ 2.328613] usbcore: registered new interface driver libusual
[1] [ 2.335418] usbcore: registered new interface driver usbtest
[1] [ 2.342803] mousedev: PS/2 mouse device common for all mice
[0] [ 2.352600] twl_rtc twl_rtc: Power up reset detected.
[0] [ 2.359191] twl_rtc twl_rtc: Enabling TWL-RTC
[1] [ 2.367797] twl_rtc twl_rtc: rtc core: registered twl_rtc as rtc0
[1] [ 2.375274] i2c /dev entries driver
[1] [ 2.382324] Driver for 1-wire Dallas network protocol.
Its sometimes very useful to have printk also print the CPU Identifier
that executed the call. This has helped to debug various SMP issues on shipping
products.
Known limitation is if the system gets preempted between function call and
actual printk, the reported cpu-id might not be accurate. But most of the
times its seen to give a good feel of how the N cpu's in the system are
getting loaded.
Signed-off-by: Vikram Pandita <vikram.pandita@...com>
Cc: Kay Sievers <kay@...y.org>
Cc: Mike Turquette <mturquette@...aro.org>
Cc: Vimarsh Zutshi <vimarsh.zutshi@...il.com>
---
v1: initial version - had wrong cpuid logging mechanism
v2: fixed as per review comments from Kay Sievers
kernel/printk.c | 51 +++++++++++++++++++++++++++++++++++++++++----------
lib/Kconfig.debug | 13 +++++++++++++
2 files changed, 54 insertions(+), 10 deletions(-)
diff --git a/kernel/printk.c b/kernel/printk.c
index 6a76ab9..64f4a1b 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -208,6 +208,7 @@ struct log {
u8 facility; /* syslog facility */
u8 flags:5; /* internal record flags */
u8 level:3; /* syslog level */
+ u8 cpuid; /* cpu invoking the log */
};
/*
@@ -305,7 +306,8 @@ static u32 log_next(u32 idx)
static void log_store(int facility, int level,
enum log_flags flags, u64 ts_nsec,
const char *dict, u16 dict_len,
- const char *text, u16 text_len)
+ const char *text, u16 text_len,
+ const u8 cpuid)
{
struct log *msg;
u32 size, pad_len;
@@ -356,6 +358,7 @@ static void log_store(int facility, int level,
msg->ts_nsec = local_clock();
memset(log_dict(msg) + dict_len, 0, pad_len);
msg->len = sizeof(struct log) + text_len + dict_len + pad_len;
+ msg->cpuid = cpuid;
/* insert message */
log_next_idx += msg->len;
@@ -855,6 +858,25 @@ static size_t print_time(u64 ts, char *buf)
(unsigned long)ts, rem_nsec / 1000);
}
+#if defined(CONFIG_PRINTK_CPUID)
+static bool printk_cpuid = 1;
+#else
+static bool printk_cpuid;
+#endif
+module_param_named(cpuid, printk_cpuid, bool, S_IRUGO | S_IWUSR);
+
+static size_t print_cpuid(u8 cpuid, char *buf)
+{
+
+ if (!printk_cpuid)
+ return 0;
+
+ if (!buf)
+ return 4;
+
+ return sprintf(buf, "[%1d] ", cpuid);
+}
+
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
{
size_t len = 0;
@@ -874,6 +896,7 @@ static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
}
}
+ len += print_cpuid(msg->cpuid, buf ? buf + len : NULL);
len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
return len;
}
@@ -1387,6 +1410,7 @@ static struct cont {
u64 ts_nsec; /* time of first print */
u8 level; /* log level of first message */
u8 facility; /* log level of first message */
+ u8 cpuid; /* cpu invoking the logging request */
enum log_flags flags; /* prefix, newline flags */
bool flushed:1; /* buffer sealed and committed */
} cont;
@@ -1405,7 +1429,8 @@ static void cont_flush(enum log_flags flags)
* line. LOG_NOCONS suppresses a duplicated output.
*/
log_store(cont.facility, cont.level, flags | LOG_NOCONS,
- cont.ts_nsec, NULL, 0, cont.buf, cont.len);
+ cont.ts_nsec, NULL, 0, cont.buf, cont.len,
+ cont.cpuid);
cont.flags = flags;
cont.flushed = true;
} else {
@@ -1414,12 +1439,14 @@ static void cont_flush(enum log_flags flags)
* just submit it to the store and free the buffer.
*/
log_store(cont.facility, cont.level, flags, 0,
- NULL, 0, cont.buf, cont.len);
+ NULL, 0, cont.buf, cont.len,
+ cont.cpuid);
cont.len = 0;
}
}
-static bool cont_add(int facility, int level, const char *text, size_t len)
+static bool cont_add(int facility, int level, const char *text, size_t len,
+ const u8 cpuid)
{
if (cont.len && cont.flushed)
return false;
@@ -1442,6 +1469,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
memcpy(cont.buf + cont.len, text, len);
cont.len += len;
+ cont.cpuid = cpuid;
if (cont.len > (sizeof(cont.buf) * 80) / 100)
cont_flush(LOG_CONT);
@@ -1455,7 +1483,8 @@ static size_t cont_print_text(char *text, size_t size)
size_t len;
if (cont.cons == 0 && (console_prev & LOG_NEWLINE)) {
- textlen += print_time(cont.ts_nsec, text);
+ textlen += print_cpuid(cont.cpuid, text);
+ textlen += print_time(cont.ts_nsec, text + textlen);
size -= textlen;
}
@@ -1527,7 +1556,7 @@ asmlinkage int vprintk_emit(int facility, int level,
printed_len += strlen(recursion_msg);
/* emit KERN_CRIT message */
log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
- NULL, 0, recursion_msg, printed_len);
+ NULL, 0, recursion_msg, printed_len, this_cpu);
}
/*
@@ -1577,9 +1606,9 @@ asmlinkage int vprintk_emit(int facility, int level,
cont_flush(LOG_NEWLINE);
/* buffer line if possible, otherwise store it right away */
- if (!cont_add(facility, level, text, text_len))
+ if (!cont_add(facility, level, text, text_len, this_cpu))
log_store(facility, level, lflags | LOG_CONT, 0,
- dict, dictlen, text, text_len);
+ dict, dictlen, text, text_len, this_cpu);
} else {
bool stored = false;
@@ -1591,13 +1620,15 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (cont.len && cont.owner == current) {
if (!(lflags & LOG_PREFIX))
- stored = cont_add(facility, level, text, text_len);
+ stored = cont_add(facility, level, text, text_len,
+ this_cpu);
cont_flush(LOG_NEWLINE);
}
if (!stored)
log_store(facility, level, lflags, 0,
- dict, dictlen, text, text_len);
+ dict, dictlen, text, text_len,
+ this_cpu);
}
printed_len += text_len;
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 2403a63..139b2b1 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -14,6 +14,19 @@ config PRINTK_TIME
The behavior is also controlled by the kernel command line
parameter printk.time=1. See Documentation/kernel-parameters.txt
+config PRINTK_CPUID
+ bool "Show cpu id information on printks"
+ depends on PRINTK
+ help
+ Selecting this option causes cpu identifier to be added to the
+ output of the syslog() system call and at the console.
+
+ This flag just specifies if the cpu-id should
+ be included.
+
+ The behavior is also controlled by the kernel command line
+ parameter printk.cpuid=1.
+
config DEFAULT_MESSAGE_LOGLEVEL
int "Default message log level (1-7)"
range 1 7
--
1.7.9.5
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists