summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--Documentation/core-api/printk-formats.rst8
-rw-r--r--include/linux/kern_levels.h2
-rw-r--r--include/linux/printk.h1
-rw-r--r--kernel/printk/printk.c90
-rw-r--r--lib/Kconfig.debug17
-rw-r--r--lib/vsprintf.c1
6 files changed, 96 insertions, 23 deletions
diff --git a/Documentation/core-api/printk-formats.rst b/Documentation/core-api/printk-formats.rst
index a7fae4538946..c37ec7cd9c06 100644
--- a/Documentation/core-api/printk-formats.rst
+++ b/Documentation/core-api/printk-formats.rst
@@ -13,6 +13,10 @@ Integer types
If variable is of Type, use printk format specifier:
------------------------------------------------------------
+ char %hhd or %hhx
+ unsigned char %hhu or %hhx
+ short int %hd or %hx
+ unsigned short int %hu or %hx
int %d or %x
unsigned int %u or %x
long %ld or %lx
@@ -21,6 +25,10 @@ Integer types
unsigned long long %llu or %llx
size_t %zu or %zx
ssize_t %zd or %zx
+ s8 %hhd or %hhx
+ u8 %hhu or %hhx
+ s16 %hd or %hx
+ u16 %hu or %hx
s32 %d or %x
u32 %u or %x
s64 %lld or %llx
diff --git a/include/linux/kern_levels.h b/include/linux/kern_levels.h
index d237fe854ad9..bf2389c26ae3 100644
--- a/include/linux/kern_levels.h
+++ b/include/linux/kern_levels.h
@@ -14,7 +14,7 @@
#define KERN_INFO KERN_SOH "6" /* informational */
#define KERN_DEBUG KERN_SOH "7" /* debug-level messages */
-#define KERN_DEFAULT KERN_SOH "d" /* the default kernel loglevel */
+#define KERN_DEFAULT "" /* the default kernel loglevel */
/*
* Annotation for a "continued" line of log printout (only done after a
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 02b5c115d89b..d7c77ed1a4cb 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -18,7 +18,6 @@ static inline int printk_get_level(const char *buffer)
if (buffer[0] == KERN_SOH_ASCII && buffer[1]) {
switch (buffer[1]) {
case '0' ... '7':
- case 'd': /* KERN_DEFAULT */
case 'c': /* KERN_CONT */
return buffer[1];
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d3d170374ceb..8eee85bb2687 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -344,7 +344,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
enum log_flags {
LOG_NEWLINE = 2, /* text ended with a newline */
- LOG_PREFIX = 4, /* text started with a prefix */
LOG_CONT = 8, /* text is a fragment of a continuation line */
};
@@ -356,6 +355,9 @@ struct printk_log {
u8 facility; /* syslog facility */
u8 flags:5; /* internal record flags */
u8 level:3; /* syslog level */
+#ifdef CONFIG_PRINTK_CALLER
+ u32 caller_id; /* thread id or processor id */
+#endif
}
#ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
__packed __aligned(4)
@@ -422,7 +424,11 @@ static u64 exclusive_console_stop_seq;
static u64 clear_seq;
static u32 clear_idx;
+#ifdef CONFIG_PRINTK_CALLER
+#define PREFIX_MAX 48
+#else
#define PREFIX_MAX 32
+#endif
#define LOG_LINE_MAX (1024 - PREFIX_MAX)
#define LOG_LEVEL(v) ((v) & 0x07)
@@ -577,7 +583,7 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
}
/* insert record into the buffer, discard old ones, update heads */
-static int log_store(int facility, int level,
+static int log_store(u32 caller_id, int facility, int level,
enum log_flags flags, u64 ts_nsec,
const char *dict, u16 dict_len,
const char *text, u16 text_len)
@@ -625,6 +631,9 @@ static int log_store(int facility, int level,
msg->ts_nsec = ts_nsec;
else
msg->ts_nsec = local_clock();
+#ifdef CONFIG_PRINTK_CALLER
+ msg->caller_id = caller_id;
+#endif
memset(log_dict(msg) + dict_len, 0, pad_len);
msg->len = size;
@@ -688,12 +697,21 @@ static ssize_t msg_print_ext_header(char *buf, size_t size,
struct printk_log *msg, u64 seq)
{
u64 ts_usec = msg->ts_nsec;
+ char caller[20];
+#ifdef CONFIG_PRINTK_CALLER
+ u32 id = msg->caller_id;
+
+ snprintf(caller, sizeof(caller), ",caller=%c%u",
+ id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
+#else
+ caller[0] = '\0';
+#endif
do_div(ts_usec, 1000);
- return scnprintf(buf, size, "%u,%llu,%llu,%c;",
- (msg->facility << 3) | msg->level, seq, ts_usec,
- msg->flags & LOG_CONT ? 'c' : '-');
+ return scnprintf(buf, size, "%u,%llu,%llu,%c%s;",
+ (msg->facility << 3) | msg->level, seq, ts_usec,
+ msg->flags & LOG_CONT ? 'c' : '-', caller);
}
static ssize_t msg_print_ext_body(char *buf, size_t size,
@@ -1038,6 +1056,9 @@ void log_buf_vmcoreinfo_setup(void)
VMCOREINFO_OFFSET(printk_log, len);
VMCOREINFO_OFFSET(printk_log, text_len);
VMCOREINFO_OFFSET(printk_log, dict_len);
+#ifdef CONFIG_PRINTK_CALLER
+ VMCOREINFO_OFFSET(printk_log, caller_id);
+#endif
}
#endif
@@ -1236,10 +1257,23 @@ static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec = do_div(ts, 1000000000);
- return sprintf(buf, "[%5lu.%06lu] ",
+ return sprintf(buf, "[%5lu.%06lu]",
(unsigned long)ts, rem_nsec / 1000);
}
+#ifdef CONFIG_PRINTK_CALLER
+static size_t print_caller(u32 id, char *buf)
+{
+ char caller[12];
+
+ snprintf(caller, sizeof(caller), "%c%u",
+ id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
+ return sprintf(buf, "[%6s]", caller);
+}
+#else
+#define print_caller(id, buf) 0
+#endif
+
static size_t print_prefix(const struct printk_log *msg, bool syslog,
bool time, char *buf)
{
@@ -1247,8 +1281,17 @@ static size_t print_prefix(const struct printk_log *msg, bool syslog,
if (syslog)
len = print_syslog((msg->facility << 3) | msg->level, buf);
+
if (time)
len += print_time(msg->ts_nsec, buf + len);
+
+ len += print_caller(msg->caller_id, buf + len);
+
+ if (IS_ENABLED(CONFIG_PRINTK_CALLER) || time) {
+ buf[len++] = ' ';
+ buf[len] = '\0';
+ }
+
return len;
}
@@ -1752,6 +1795,12 @@ static inline void printk_delay(void)
}
}
+static inline u32 printk_caller_id(void)
+{
+ return in_task() ? task_pid_nr(current) :
+ 0x80000000 + raw_smp_processor_id();
+}
+
/*
* Continuation lines are buffered, and not committed to the record buffer
* until the line is complete, or a race forces it. The line fragments
@@ -1761,7 +1810,7 @@ static inline void printk_delay(void)
static struct cont {
char buf[LOG_LINE_MAX];
size_t len; /* length == 0 means unused buffer */
- struct task_struct *owner; /* task of first print*/
+ u32 caller_id; /* printk_caller_id() of first print */
u64 ts_nsec; /* time of first print */
u8 level; /* log level of first message */
u8 facility; /* log facility of first message */
@@ -1773,12 +1822,13 @@ static void cont_flush(void)
if (cont.len == 0)
return;
- log_store(cont.facility, cont.level, cont.flags, cont.ts_nsec,
- NULL, 0, cont.buf, cont.len);
+ log_store(cont.caller_id, cont.facility, cont.level, cont.flags,
+ cont.ts_nsec, NULL, 0, cont.buf, cont.len);
cont.len = 0;
}
-static bool cont_add(int facility, int level, enum log_flags flags, const char *text, size_t len)
+static bool cont_add(u32 caller_id, int facility, int level,
+ enum log_flags flags, const char *text, size_t len)
{
/* If the line gets too long, split it up in separate records. */
if (cont.len + len > sizeof(cont.buf)) {
@@ -1789,7 +1839,7 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char *
if (!cont.len) {
cont.facility = facility;
cont.level = level;
- cont.owner = current;
+ cont.caller_id = caller_id;
cont.ts_nsec = local_clock();
cont.flags = flags;
}
@@ -1809,13 +1859,15 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char *
static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len)
{
+ const u32 caller_id = printk_caller_id();
+
/*
* If an earlier line was buffered, and we're a continuation
- * write from the same process, try to add it to the buffer.
+ * write from the same context, try to add it to the buffer.
*/
if (cont.len) {
- if (cont.owner == current && (lflags & LOG_CONT)) {
- if (cont_add(facility, level, lflags, text, text_len))
+ if (cont.caller_id == caller_id && (lflags & LOG_CONT)) {
+ if (cont_add(caller_id, facility, level, lflags, text, text_len))
return text_len;
}
/* Otherwise, make sure it's flushed */
@@ -1828,12 +1880,13 @@ static size_t log_output(int facility, int level, enum log_flags lflags, const c
/* If it doesn't end in a newline, try to buffer the current line */
if (!(lflags & LOG_NEWLINE)) {
- if (cont_add(facility, level, lflags, text, text_len))
+ if (cont_add(caller_id, facility, level, lflags, text, text_len))
return text_len;
}
/* Store it in the record log */
- return log_store(facility, level, lflags, 0, dict, dictlen, text, text_len);
+ return log_store(caller_id, facility, level, lflags, 0,
+ dict, dictlen, text, text_len);
}
/* Must be called under logbuf_lock. */
@@ -1867,9 +1920,6 @@ int vprintk_store(int facility, int level,
case '0' ... '7':
if (level == LOGLEVEL_DEFAULT)
level = kern_level - '0';
- /* fallthrough */
- case 'd': /* KERN_DEFAULT */
- lflags |= LOG_PREFIX;
break;
case 'c': /* KERN_CONT */
lflags |= LOG_CONT;
@@ -1884,7 +1934,7 @@ int vprintk_store(int facility, int level,
level = default_message_loglevel;
if (dict)
- lflags |= LOG_PREFIX|LOG_NEWLINE;
+ lflags |= LOG_NEWLINE;
return log_output(facility, level, lflags,
dict, dictlen, text, text_len);
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index e718487c97c3..91ed81250fb3 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -17,6 +17,23 @@ config PRINTK_TIME
The behavior is also controlled by the kernel command line
parameter printk.time=1. See Documentation/admin-guide/kernel-parameters.rst
+config PRINTK_CALLER
+ bool "Show caller information on printks"
+ depends on PRINTK
+ help
+ Selecting this option causes printk() to add a caller "thread id" (if
+ in task context) or a caller "processor id" (if not in task context)
+ to every message.
+
+ This option is intended for environments where multiple threads
+ concurrently call printk() for many times, for it is difficult to
+ interpret without knowing where these lines (or sometimes individual
+ line which was divided into multiple lines due to race) came from.
+
+ Since toggling after boot makes the code racy, currently there is
+ no option to enable/disable at the kernel command line parameter or
+ sysfs interface.
+
config CONSOLE_LOGLEVEL_DEFAULT
int "Default console loglevel (1-15)"
range 1 15
diff --git a/lib/vsprintf.c b/lib/vsprintf.c
index 30b00de4f321..791b6fa36905 100644
--- a/lib/vsprintf.c
+++ b/lib/vsprintf.c
@@ -1931,7 +1931,6 @@ char *device_node_string(char *buf, char *end, struct device_node *dn,
* (legacy clock framework) of the clock
* - 'Cn' For a clock, it prints the name (Common Clock Framework) or address
* (legacy clock framework) of the clock
- * - 'Cr' For a clock, it prints the current rate of the clock
* - 'G' For flags to be printed as a collection of symbolic strings that would
* construct the specific value. Supported flags given by option:
* p page flags (see struct page) given as pointer to unsigned long
generated by cgit v1.2.3-58-ga151 (git 2.39.0) at 2024-12-24 07:11:04 +0000