* [PATCH 1/2] printk: Refactor processing of line severity tokens
@ 2008-04-13 11:53 Nick Andrew
2008-04-13 11:54 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
` (2 more replies)
0 siblings, 3 replies; 11+ messages in thread
From: Nick Andrew @ 2008-04-13 11:53 UTC (permalink / raw
To: Ingo Molnar, Thomas Gleixner, Linus Torvalds
Cc: linux-kernel, Andrew Morton, joe
printk: Refactor processing of line severity tokens
Restructure the logic of vprintk() so the processing of the leading
3 characters of each input line is in one place, regardless whether
printk_time is enabled. This makes the code smaller and easier to
understand.
Signed-off-by: Nick Andrew <nick@nick-andrew.net>
---
kernel/printk.c | 63 +++++++++++++++++++++++++------------------------------
1 files changed, 29 insertions(+), 34 deletions(-)
diff --git a/kernel/printk.c b/kernel/printk.c
index c46a20a..bca9359 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -656,11 +656,12 @@ static int printk_recursion_bug;
asmlinkage int vprintk(const char *fmt, va_list args)
{
- static int log_level_unknown = 1;
+ static int new_text_line = 1;
static char printk_buf[1024];
- unsigned long flags;
int printed_len = 0;
+ int current_log_level = default_message_loglevel;
+ unsigned long flags;
int this_cpu;
char *p;
@@ -702,61 +703,55 @@ asmlinkage int vprintk(const char *fmt, va_list args)
printed_len += vscnprintf(printk_buf + printed_len,
sizeof(printk_buf) - printed_len, fmt, args);
+
/*
* Copy the output into log_buf. If the caller didn't provide
* appropriate log level tags, we insert them here
*/
for (p = printk_buf; *p; p++) {
- if (log_level_unknown) {
- /* log_level_unknown signals the start of a new line */
+ if (new_text_line) {
+ /* If a token, set current_log_level and skip over */
+ if (p[0] == '<' && p[1] >= '0' && p[1] <= '7' &&
+ p[2] == '>') {
+ current_log_level = p[1] - '0';
+ p += 3;
+ printed_len -= 3;
+ } else {
+ current_log_level = default_message_loglevel;
+ }
+
+ /* Always output the token */
+ emit_log_char('<');
+ emit_log_char(current_log_level + '0');
+ emit_log_char('>');
+ printed_len += 3;
+ new_text_line = 0;
+
if (printk_time) {
- int loglev_char;
+ /* Follow the token with the time */
char tbuf[50], *tp;
unsigned tlen;
unsigned long long t;
unsigned long nanosec_rem;
- /*
- * force the log level token to be
- * before the time output.
- */
- if (p[0] == '<' && p[1] >='0' &&
- p[1] <= '7' && p[2] == '>') {
- loglev_char = p[1];
- p += 3;
- printed_len -= 3;
- } else {
- loglev_char = default_message_loglevel
- + '0';
- }
t = cpu_clock(printk_cpu);
nanosec_rem = do_div(t, 1000000000);
- tlen = sprintf(tbuf,
- "<%c>[%5lu.%06lu] ",
- loglev_char,
- (unsigned long)t,
- nanosec_rem/1000);
+ tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+ (unsigned long) t,
+ nanosec_rem / 1000);
for (tp = tbuf; tp < tbuf + tlen; tp++)
emit_log_char(*tp);
printed_len += tlen;
- } else {
- if (p[0] != '<' || p[1] < '0' ||
- p[1] > '7' || p[2] != '>') {
- emit_log_char('<');
- emit_log_char(default_message_loglevel
- + '0');
- emit_log_char('>');
- printed_len += 3;
- }
}
- log_level_unknown = 0;
+
if (!*p)
break;
}
+
emit_log_char(*p);
if (*p == '\n')
- log_level_unknown = 1;
+ new_text_line = 1;
}
/*
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-13 11:53 [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
@ 2008-04-13 11:54 ` Nick Andrew
2008-04-13 12:26 ` [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
2008-04-13 12:27 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
2 siblings, 0 replies; 11+ messages in thread
From: Nick Andrew @ 2008-04-13 11:54 UTC (permalink / raw
To: Ingo Molnar, Thomas Gleixner, Linus Torvalds
Cc: linux-kernel, Andrew Morton, joe
printk: Remember the message level for multi-line output
printk(KERN_ALERT "Danger Will Robinson!\nAlien Approaching!\n");
At present this will result in one message at ALERT level and one
at the current default message loglevel (e.g. WARNING). This is
non-intuitive.
Modify vprintk() to remember the message loglevel each time it
is specified and use it for subsequent lines of output which do
not specify one, within the same call to printk.
Signed-off-by: Nick Andrew <nick@nick-andrew.net>
---
kernel/printk.c | 2 --
1 files changed, 0 insertions(+), 2 deletions(-)
diff --git a/kernel/printk.c b/kernel/printk.c
index bca9359..5c97eb1 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -716,8 +716,6 @@ asmlinkage int vprintk(const char *fmt, va_list args)
current_log_level = p[1] - '0';
p += 3;
printed_len -= 3;
- } else {
- current_log_level = default_message_loglevel;
}
/* Always output the token */
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [PATCH 1/2] printk: Refactor processing of line severity tokens
2008-04-13 11:53 [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
2008-04-13 11:54 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
@ 2008-04-13 12:26 ` Nick Andrew
2008-04-14 7:58 ` Ingo Molnar
2008-04-13 12:27 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
2 siblings, 1 reply; 11+ messages in thread
From: Nick Andrew @ 2008-04-13 12:26 UTC (permalink / raw
To: Ingo Molnar, Thomas Gleixner, Linus Torvalds
Cc: linux-kernel, Andrew Morton, joe
printk: Refactor processing of line severity tokens
Restructure the logic of vprintk() so the processing of the leading
3 characters of each input line is in one place, regardless whether
printk_time is enabled. This makes the code smaller and easier to
understand.
Signed-off-by: Nick Andrew <nick@nick-andrew.net>
---
This is the third revision.
rev 1 - initial patch, refactor + remember current_log_level
rev 2 - split into 2 parts
rev 3 - I realised that rev 2 is inefficient; all I had to do was move
the declaration of current_log_level, to alter the memory
behaviour.
kernel/printk.c | 61 ++++++++++++++++++++++++-------------------------------
1 files changed, 27 insertions(+), 34 deletions(-)
diff --git a/kernel/printk.c b/kernel/printk.c
index c46a20a..02ca845 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -656,11 +656,11 @@ static int printk_recursion_bug;
asmlinkage int vprintk(const char *fmt, va_list args)
{
- static int log_level_unknown = 1;
+ static int new_text_line = 1;
static char printk_buf[1024];
- unsigned long flags;
int printed_len = 0;
+ unsigned long flags;
int this_cpu;
char *p;
@@ -702,61 +702,54 @@ asmlinkage int vprintk(const char *fmt, va_list args)
printed_len += vscnprintf(printk_buf + printed_len,
sizeof(printk_buf) - printed_len, fmt, args);
+
/*
* Copy the output into log_buf. If the caller didn't provide
* appropriate log level tags, we insert them here
*/
for (p = printk_buf; *p; p++) {
- if (log_level_unknown) {
- /* log_level_unknown signals the start of a new line */
+ if (new_text_line) {
+ int current_log_level = default_message_loglevel;
+ /* If a token, set current_log_level and skip over */
+ if (p[0] == '<' && p[1] >= '0' && p[1] <= '7' &&
+ p[2] == '>') {
+ current_log_level = p[1] - '0';
+ p += 3;
+ printed_len -= 3;
+ }
+
+ /* Always output the token */
+ emit_log_char('<');
+ emit_log_char(current_log_level + '0');
+ emit_log_char('>');
+ printed_len += 3;
+ new_text_line = 0;
+
if (printk_time) {
- int loglev_char;
+ /* Follow the token with the time */
char tbuf[50], *tp;
unsigned tlen;
unsigned long long t;
unsigned long nanosec_rem;
- /*
- * force the log level token to be
- * before the time output.
- */
- if (p[0] == '<' && p[1] >='0' &&
- p[1] <= '7' && p[2] == '>') {
- loglev_char = p[1];
- p += 3;
- printed_len -= 3;
- } else {
- loglev_char = default_message_loglevel
- + '0';
- }
t = cpu_clock(printk_cpu);
nanosec_rem = do_div(t, 1000000000);
- tlen = sprintf(tbuf,
- "<%c>[%5lu.%06lu] ",
- loglev_char,
- (unsigned long)t,
- nanosec_rem/1000);
+ tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+ (unsigned long) t,
+ nanosec_rem / 1000);
for (tp = tbuf; tp < tbuf + tlen; tp++)
emit_log_char(*tp);
printed_len += tlen;
- } else {
- if (p[0] != '<' || p[1] < '0' ||
- p[1] > '7' || p[2] != '>') {
- emit_log_char('<');
- emit_log_char(default_message_loglevel
- + '0');
- emit_log_char('>');
- printed_len += 3;
- }
}
- log_level_unknown = 0;
+
if (!*p)
break;
}
+
emit_log_char(*p);
if (*p == '\n')
- log_level_unknown = 1;
+ new_text_line = 1;
}
/*
^ permalink raw reply related [flat|nested] 11+ messages in thread
* [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-13 11:53 [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
2008-04-13 11:54 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
2008-04-13 12:26 ` [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
@ 2008-04-13 12:27 ` Nick Andrew
2008-04-14 8:03 ` Ingo Molnar
2 siblings, 1 reply; 11+ messages in thread
From: Nick Andrew @ 2008-04-13 12:27 UTC (permalink / raw
To: Ingo Molnar, Thomas Gleixner, Linus Torvalds
Cc: linux-kernel, Andrew Morton, joe
printk: Remember the message level for multi-line output
printk(KERN_ALERT "Danger Will Robinson!\nAlien Approaching!\n");
At present this will result in one message at ALERT level and one
at the current default message loglevel (e.g. WARNING). This is
non-intuitive.
Modify vprintk() to remember the message loglevel each time it
is specified and use it for subsequent lines of output which do
not specify one, within the same call to printk.
Signed-off-by: Nick Andrew <nick@nick-andrew.net>
---
This is the third revision.
kernel/printk.c | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/kernel/printk.c b/kernel/printk.c
index 02ca845..5c97eb1 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -660,6 +660,7 @@ asmlinkage int vprintk(const char *fmt, va_list args)
static char printk_buf[1024];
int printed_len = 0;
+ int current_log_level = default_message_loglevel;
unsigned long flags;
int this_cpu;
char *p;
@@ -709,7 +710,6 @@ asmlinkage int vprintk(const char *fmt, va_list args)
*/
for (p = printk_buf; *p; p++) {
if (new_text_line) {
- int current_log_level = default_message_loglevel;
/* If a token, set current_log_level and skip over */
if (p[0] == '<' && p[1] >= '0' && p[1] <= '7' &&
p[2] == '>') {
^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [PATCH 1/2] printk: Refactor processing of line severity tokens
2008-04-13 12:26 ` [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
@ 2008-04-14 7:58 ` Ingo Molnar
0 siblings, 0 replies; 11+ messages in thread
From: Ingo Molnar @ 2008-04-14 7:58 UTC (permalink / raw
To: Nick Andrew
Cc: Thomas Gleixner, Linus Torvalds, linux-kernel, Andrew Morton, joe
* Nick Andrew <nick@nick-andrew.net> wrote:
> printk: Refactor processing of line severity tokens
>
> Restructure the logic of vprintk() so the processing of the leading 3
> characters of each input line is in one place, regardless whether
> printk_time is enabled. This makes the code smaller and easier to
> understand.
thanks, applied - nice cleanup!
i also added the size stats:
text data bss dec hex filename
6157 397 1049804 1056358 101e66 printk.o.before
6117 397 1049804 1056318 101e3e printk.o.after
Ingo
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-13 12:27 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
@ 2008-04-14 8:03 ` Ingo Molnar
2008-04-14 10:12 ` Nick Andrew
0 siblings, 1 reply; 11+ messages in thread
From: Ingo Molnar @ 2008-04-14 8:03 UTC (permalink / raw
To: Nick Andrew
Cc: Thomas Gleixner, Linus Torvalds, linux-kernel, Andrew Morton, joe
* Nick Andrew <nick@nick-andrew.net> wrote:
> printk: Remember the message level for multi-line output
>
> printk(KERN_ALERT "Danger Will Robinson!\nAlien Approaching!\n");
>
> At present this will result in one message at ALERT level and one at
> the current default message loglevel (e.g. WARNING). This is
> non-intuitive.
>
> Modify vprintk() to remember the message loglevel each time it is
> specified and use it for subsequent lines of output which do not
> specify one, within the same call to printk.
i've applied this too for testing.
but multi-line strings are a bit unclean i think: each message line
should have its separate printk.
will your patch leave the behavior of multiple calls to printk alone?
I.e. if i do:
printk(KERN_ALERT "Danger Will Robinson!\n");
printk("Alien Approaching!\n");
then we'll still get a KERN_ALERT plus a default printk, right? In that
case my earlier observation about this patch is moot and i guess it's
fine to do this.
Ingo
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-14 8:03 ` Ingo Molnar
@ 2008-04-14 10:12 ` Nick Andrew
2008-04-14 10:26 ` Ingo Molnar
0 siblings, 1 reply; 11+ messages in thread
From: Nick Andrew @ 2008-04-14 10:12 UTC (permalink / raw
To: Ingo Molnar
Cc: Thomas Gleixner, Linus Torvalds, linux-kernel, Andrew Morton, joe
On Mon, Apr 14, 2008 at 10:03:51AM +0200, Ingo Molnar wrote:
>
> * Nick Andrew <nick@nick-andrew.net> wrote:
>
> > printk: Remember the message level for multi-line output
> >
> > printk(KERN_ALERT "Danger Will Robinson!\nAlien Approaching!\n");
> >
> > At present this will result in one message at ALERT level and one at
> > the current default message loglevel (e.g. WARNING). This is
> > non-intuitive.
> >
> > Modify vprintk() to remember the message loglevel each time it is
> > specified and use it for subsequent lines of output which do not
> > specify one, within the same call to printk.
>
> i've applied this too for testing.
>
> but multi-line strings are a bit unclean i think: each message line
> should have its separate printk.
You'd think. But there are a lot of calls to printk() with multi-line
format strings; developers clearly expect it to "just work" and
that a message level set at the start will be retained across lines.
> will your patch leave the behavior of multiple calls to printk alone?
> I.e. if i do:
>
> printk(KERN_ALERT "Danger Will Robinson!\n");
> printk("Alien Approaching!\n");
>
> then we'll still get a KERN_ALERT plus a default printk, right?
Yes, quite. The state of whether we're inside a line is retained
across calls to printk (from anywhere in the system) - this allows
code like this to usually do what you expect:
printk(KERN_ERR "Error:");
for (i = 0; i < 16; ++i) {
printk(" %02x", i);
}
printk("\n");
But in your example the first printk call contains a \n at the
end of the line and so upon entry to the second printk call
the function knows a new line is beginning.
The message level is a local variable. It's set to the default
at function entry, and is recalculated at the beginning of each
new line. It's changed only if a new line begins with a token.
So subsequent new lines which don't contain a token reuse the
previous value ... only within a single call to printk().
Nick.
--
PGP Key ID = 0x418487E7 http://www.nick-andrew.net/
PGP Key fingerprint = B3ED 6894 8E49 1770 C24A 67E3 6266 6EB9 4184 87E7
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-14 10:12 ` Nick Andrew
@ 2008-04-14 10:26 ` Ingo Molnar
2008-04-14 11:03 ` Nick Andrew
2008-04-14 11:43 ` Johannes Weiner
0 siblings, 2 replies; 11+ messages in thread
From: Ingo Molnar @ 2008-04-14 10:26 UTC (permalink / raw
To: Nick Andrew
Cc: Thomas Gleixner, Linus Torvalds, linux-kernel, Andrew Morton, joe
* Nick Andrew <nick@nick-andrew.net> wrote:
> > i've applied this too for testing.
> >
> > but multi-line strings are a bit unclean i think: each message line
> > should have its separate printk.
>
> You'd think. But there are a lot of calls to printk() with multi-line
> format strings; developers clearly expect it to "just work" and that a
> message level set at the start will be retained across lines.
ok :-)
> > will your patch leave the behavior of multiple calls to printk alone?
> > I.e. if i do:
> >
> > printk(KERN_ALERT "Danger Will Robinson!\n");
> > printk("Alien Approaching!\n");
> >
> > then we'll still get a KERN_ALERT plus a default printk, right?
>
> Yes, quite. The state of whether we're inside a line is retained
> across calls to printk (from anywhere in the system) - this allows
> code like this to usually do what you expect:
>
> printk(KERN_ERR "Error:");
> for (i = 0; i < 16; ++i) {
> printk(" %02x", i);
> }
> printk("\n");
>
> But in your example the first printk call contains a \n at the end of
> the line and so upon entry to the second printk call the function
> knows a new line is beginning.
ok - i think your change is a good one.
btw., we could also start emitting debug warnings that the printk is not
conform. Something like:
"INFO: the previous printk was done without a KERN_ annotation"
?
Ingo
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-14 10:26 ` Ingo Molnar
@ 2008-04-14 11:03 ` Nick Andrew
2008-04-14 11:43 ` Johannes Weiner
1 sibling, 0 replies; 11+ messages in thread
From: Nick Andrew @ 2008-04-14 11:03 UTC (permalink / raw
To: Ingo Molnar
Cc: Thomas Gleixner, Linus Torvalds, linux-kernel, Andrew Morton, joe
On Mon, Apr 14, 2008 at 12:26:34PM +0200, Ingo Molnar wrote:
> * Nick Andrew <nick@nick-andrew.net> wrote:
> > Yes, quite. The state of whether we're inside a line is retained
> > across calls to printk (from anywhere in the system) - this allows
> > code like this to usually do what you expect:
> >
> > printk(KERN_ERR "Error:");
> > for (i = 0; i < 16; ++i) {
> > printk(" %02x", i);
> > }
> > printk("\n");
> >
> > But in your example the first printk call contains a \n at the end of
> > the line and so upon entry to the second printk call the function
> > knows a new line is beginning.
>
> ok - i think your change is a good one.
Thank you.
> btw., we could also start emitting debug warnings that the printk is not
> conform. Something like:
>
> "INFO: the previous printk was done without a KERN_ annotation"
There are 20k+ instances of this in the codebase; we don't need a
runtime message to find them. If you annotate them all, that will
add up to 60k to the binary size. Perhaps it's best to retain the
default support.
Nick.
--
PGP Key ID = 0x418487E7 http://www.nick-andrew.net/
PGP Key fingerprint = B3ED 6894 8E49 1770 C24A 67E3 6266 6EB9 4184 87E7
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-14 10:26 ` Ingo Molnar
2008-04-14 11:03 ` Nick Andrew
@ 2008-04-14 11:43 ` Johannes Weiner
2008-04-14 12:21 ` Ingo Molnar
1 sibling, 1 reply; 11+ messages in thread
From: Johannes Weiner @ 2008-04-14 11:43 UTC (permalink / raw
To: Ingo Molnar
Cc: Nick Andrew, Thomas Gleixner, Linus Torvalds, linux-kernel,
Andrew Morton, joe
Hi Ingo,
Ingo Molnar <mingo@elte.hu> writes:
> btw., we could also start emitting debug warnings that the printk is not
> conform. Something like:
>
> "INFO: the previous printk was done without a KERN_ annotation"
Urgh, that would become very noisy. If, at all, I'd suggest a config
option like CONFIG_DEBUG_PRINTK_USAGE and then add a prefix string to
each printk()ed line missing a severity level.
printk("foo\n");
=> "[FIX PRINTK] foo"
Hannes
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH 2/2] printk: Remember the message level for multi-line output
2008-04-14 11:43 ` Johannes Weiner
@ 2008-04-14 12:21 ` Ingo Molnar
0 siblings, 0 replies; 11+ messages in thread
From: Ingo Molnar @ 2008-04-14 12:21 UTC (permalink / raw
To: Johannes Weiner
Cc: Nick Andrew, Thomas Gleixner, Linus Torvalds, linux-kernel,
Andrew Morton, joe
* Johannes Weiner <hannes@saeurebad.de> wrote:
> Hi Ingo,
>
> Ingo Molnar <mingo@elte.hu> writes:
>
> > btw., we could also start emitting debug warnings that the printk is not
> > conform. Something like:
> >
> > "INFO: the previous printk was done without a KERN_ annotation"
>
> Urgh, that would become very noisy. If, at all, I'd suggest a config
> option like CONFIG_DEBUG_PRINTK_USAGE and then add a prefix string to
> each printk()ed line missing a severity level.
>
> printk("foo\n");
> => "[FIX PRINTK] foo"
yes, of course hidden behind a non-default Kconfig variable, like we do
it with most debug helpers.
Ingo
^ permalink raw reply [flat|nested] 11+ messages in thread
end of thread, other threads:[~2008-04-14 12:22 UTC | newest]
Thread overview: 11+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2008-04-13 11:53 [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
2008-04-13 11:54 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
2008-04-13 12:26 ` [PATCH 1/2] printk: Refactor processing of line severity tokens Nick Andrew
2008-04-14 7:58 ` Ingo Molnar
2008-04-13 12:27 ` [PATCH 2/2] printk: Remember the message level for multi-line output Nick Andrew
2008-04-14 8:03 ` Ingo Molnar
2008-04-14 10:12 ` Nick Andrew
2008-04-14 10:26 ` Ingo Molnar
2008-04-14 11:03 ` Nick Andrew
2008-04-14 11:43 ` Johannes Weiner
2008-04-14 12:21 ` Ingo Molnar
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.