lkml.org 
[lkml]   [2018]   [Dec]   [17]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Date
From
SubjectRe: [PATCH] printk: Add caller information to printk() output.
On Thu 2018-12-13 21:42:55, Sergey Senozhatsky wrote:
> On (12/13/18 13:18), Petr Mladek wrote:
> > > Sometimes we want to print a series of printk() messages to consoles
> > > without being disturbed by concurrent printk() from interrupts and/or
> > > other threads. But we can't enforce printk() callers to use their local
> > > buffers because we need to ask them to make too much changes. Also, even
> > > buffering up to one line inside printk() might cause failing to emit
> > > an important clue under critical situation.
> > >
> > > Therefore, instead of trying to help buffering, let's try to help
> > > reconstructing messages by saving caller information as of calling
> > > log_store() and adding it as "[T$thread_id]" or "[C$processor_id]"
> > > upon printing to consoles.
> > >
> > Reviewed-by: Petr Mladek <pmladek@suse.com>
>
> Acked-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
>
> > From my point of view, the patch is ready to go into
> > linux-next. Well, I would prefer to keep it there one more
> > release cycle.

I have pushed the patch into printk.git, for-4.22 branch.


Now, I always felt that the "from" name was a bit strange but
nothing better came to my mind until today.

I would like to rename "from" to "caller", see the patch below.
If you agree, I could push it on top or I could even squash it
into the original patch.

What do you think about it, please?


From 230cbd8efaf46e6e132a53768cc746b88589c738 Mon Sep 17 00:00:00 2001
From: Petr Mladek <pmladek@suse.com>
Date: Mon, 17 Dec 2018 14:12:32 +0100
Subject: [PATCH] printk: Rename CONFIG_PRINTK_FROM to CONFIG_PRINTK_CALLER

The name printk_from is a bit unusual and I have troubles
to imagine what it exactly means. For example, @from is used
also for the iterator parameter in devkmsg_write().

I believe that printk_caller is easier to understand.

This patch does not change the existing behavior except
for the names related to PRINTK_FROM feature.

Signed-off-by: Petr Mladek <pmladek@suse.com>
---
kernel/printk/printk.c | 47 ++++++++++++++++++++++++++---------------------
lib/Kconfig.debug | 2 +-
2 files changed, 27 insertions(+), 22 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f8fd63254ca3..b6c5128a1a82 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -357,8 +357,8 @@ struct printk_log {
u8 facility; /* syslog facility */
u8 flags:5; /* internal record flags */
u8 level:3; /* syslog level */
-#ifdef CONFIG_PRINTK_FROM
- u32 from_id; /* thread id or processor id */
+#ifdef CONFIG_PRINTK_CALLER
+ u32 caller_id; /* thread id or processor id */
#endif
}
#ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
@@ -426,7 +426,7 @@ static u64 exclusive_console_stop_seq;
static u64 clear_seq;
static u32 clear_idx;

-#ifdef CONFIG_PRINTK_FROM
+#ifdef CONFIG_PRINTK_CALLER
#define PREFIX_MAX 48
#else
#define PREFIX_MAX 32
@@ -633,11 +633,11 @@ static int log_store(int facility, int level,
msg->ts_nsec = ts_nsec;
else
msg->ts_nsec = local_clock();
-#ifdef CONFIG_PRINTK_FROM
+#ifdef CONFIG_PRINTK_CALLER
if (in_task())
- msg->from_id = task_pid_nr(current);
+ msg->caller_id = task_pid_nr(current);
else
- msg->from_id = 0x80000000 + raw_smp_processor_id();
+ msg->caller_id = 0x80000000 + raw_smp_processor_id();
#endif
memset(log_dict(msg) + dict_len, 0, pad_len);
msg->len = size;
@@ -702,21 +702,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 from[18];
-#ifdef CONFIG_PRINTK_FROM
- u32 id = msg->from_id;
+ char caller[18];
+#ifdef CONFIG_PRINTK_CALLER
+ u32 id = msg->caller_id;

- snprintf(from, sizeof(from), ",from=%c%u",
+ snprintf(caller, sizeof(caller), ",caller=%c%u",
id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
#else
- from[0] = '\0';
+ caller[0] = '\0';
#endif

do_div(ts_usec, 1000);

return scnprintf(buf, size, "%u,%llu,%llu,%c%s;",
(msg->facility << 3) | msg->level, seq, ts_usec,
- msg->flags & LOG_CONT ? 'c' : '-', from);
+ msg->flags & LOG_CONT ? 'c' : '-', caller);
}

static ssize_t msg_print_ext_body(char *buf, size_t size,
@@ -1061,8 +1061,8 @@ 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_FROM
- VMCOREINFO_OFFSET(printk_log, from_id);
+#ifdef CONFIG_PRINTK_CALLER
+ VMCOREINFO_OFFSET(printk_log, caller_id);
#endif
}
#endif
@@ -1266,8 +1266,8 @@ static size_t print_time(u64 ts, char *buf)
(unsigned long)ts, rem_nsec / 1000);
}

-#ifdef CONFIG_PRINTK_FROM
-static size_t print_from(u32 id, char *buf)
+#ifdef CONFIG_PRINTK_CALLER
+static size_t print_caller(u32 id, char *buf)
{
char from[12];

@@ -1275,6 +1275,8 @@ static size_t print_from(u32 id, char *buf)
id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
return sprintf(buf, "[%6s]", from);
}
+#else
+#define print_caller(id, buf) 0
#endif

static size_t print_prefix(const struct printk_log *msg, bool syslog,
@@ -1284,14 +1286,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);
-#ifdef CONFIG_PRINTK_FROM
- len += print_from(msg->from_id, buf + len);
-#endif
- if (IS_ENABLED(CONFIG_PRINTK_FROM) || time)
+
+ len += print_caller(msg->caller_id, buf + len);
+
+ if (IS_ENABLED(CONFIG_PRINTK_CALLER) || time) {
buf[len++] = ' ';
- buf[len] = '\0'; /* For safety in case of accessed as a string. */
+ buf[len] = '\0';
+ }
+
return len;
}

diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 3e8e69e0b3bb..6b1ecd6b67a6 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -17,7 +17,7 @@ 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_FROM
+config PRINTK_CALLER
bool "Show caller information on printks"
depends on PRINTK
help
--
2.13.7
\
 
 \ /
  Last update: 2018-12-17 15:55    [W:0.162 / U:2.652 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site