[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180517115248.GA409@jagdpanzerIV>
Date: Thu, 17 May 2018 20:52:48 +0900
From: Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To: Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
Cc: Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>,
dvyukov@...gle.com, pmladek@...e.com, sergey.senozhatsky@...il.com,
syzkaller@...glegroups.com, rostedt@...dmis.org,
fengguang.wu@...el.com, linux-kernel@...r.kernel.org,
torvalds@...ux-foundation.org, akpm@...ux-foundation.org
Subject: Re: [PATCH] printk: inject caller information into the body of
message
On (05/17/18 20:21), Sergey Senozhatsky wrote:
> Dunno...
> For instance, can we store context tracking info as a extended record
> data? We have that dict/dict_len thing. So may we can store tracking
> info there? Extended records will appear on the serial console /* if
> console supports extended data */ or can be read in via devkmsg_read().
Those extended records are already there for exactly the same
reason - people want to attach a special context to printk() entries.
See dev_vprintk_emit() and create_syslog_header(). So we can add more
key/value data to that context. Sounds kinda-sorta reasonable.
So, for example, this output
cat /dev/kmsg
6,577,3156036,-;snd_hda_codec_generic hdaudioC1D0: autoconfig for Generic: line_outs=0 (0x0/0x0/0x0/0x0/0x0) type:line
SUBSYSTEM=hdaudio
DEVICE=+hdaudio:hdaudioC1D
6,578,3156807,-;snd_hda_codec_generic hdaudioC1D0: speaker_outs=0 (0x0/0x0/0x0/0x0/0x0)
SUBSYSTEM=hdaudio
DEVICE=+hdaudio:hdaudioC1D
Becomes this:
6,566,3033752,-;snd_hda_codec_realtek hdaudioC0D0: Front Mic=0x19
3/207: 0/0/0
SUBSYSTEM=hdaudio
DEVICE=+hdaudio:hdaudioC0D
6,567,3033754,-;snd_hda_codec_realtek hdaudioC0D0: Rear Mic=0x18
3/207: 0/0/0
SUBSYSTEM=hdaudio
DEVICE=+hdaudio:hdaudioC0D
"3/207: 0/0/0" is smp_processor_id/task_pid_nr and then masked
out bits of preempt count: hard irq, soft irq, nmi.
We definitely can change the format, etc. This is just a very quick and
dirty PoC.
Something as follows?
/* just to demonstrate the idea */
---
kernel/printk/printk.c | 22 +++++++++++++++++++++-
1 file changed, 21 insertions(+), 1 deletion(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2f4af216bd6e..4a82d52a343d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -580,16 +580,33 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
}
+static size_t add_log_origin(char *buf, size_t buf_len)
+{
+ return snprintf(buf,
+ buf_len,
+ "%d/%d: %lu/%lu/%lu",
+ raw_smp_processor_id(),
+ task_pid_nr(current),
+ preempt_count() & HARDIRQ_MASK,
+ preempt_count() & SOFTIRQ_MASK,
+ preempt_count() & NMI_MASK);
+}
+
/* 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,
const char *dict, u16 dict_len,
const char *text, u16 text_len)
{
+ static char log_origin[64];
+ static size_t log_origin_len;
struct printk_log *msg;
u32 size, pad_len;
u16 trunc_msg_len = 0;
+ log_origin_len = add_log_origin(log_origin, sizeof(log_origin));
+ dict_len += log_origin_len;
+
/* number of '\0' padding bytes to next message */
size = msg_used_size(text_len, dict_len, &pad_len);
@@ -620,7 +637,10 @@ static int log_store(int facility, int level,
memcpy(log_text(msg) + text_len, trunc_msg, trunc_msg_len);
msg->text_len += trunc_msg_len;
}
- memcpy(log_dict(msg), dict, dict_len);
+ memcpy(log_dict(msg), log_origin, log_origin_len);
+ memcpy(log_dict(msg) + log_origin_len + 1,
+ dict,
+ dict_len - log_origin_len);
msg->dict_len = dict_len;
msg->facility = facility;
msg->level = level & 7;
Powered by blists - more mailing lists