* [PATCH] printk: make line continuation not result in stray emergency errors
@ 2018-11-20 20:50 Roland Hieber
2018-11-20 21:06 ` Roland Hieber
2018-11-21 8:51 ` Sascha Hauer
0 siblings, 2 replies; 4+ messages in thread
From: Roland Hieber @ 2018-11-20 20:50 UTC (permalink / raw)
To: barebox; +Cc: Roland Hieber
The levels of pr_emerg() and pr_cont() are both set to 0. When pr_cont()
is used to continue a previous line, and colored console output is
enabled, this can result in garbled log messages being printed, e.g.:
ERROR: HABv4: -------- HAB warning Event 0 --------
ERROR: HABv4: event data:
ERROR: HABv4: dbEMERG: 00EMERG: 24EMERG: 42EMERG: 69EMERG: 30EMERG: e1EMERG: 1d
ERROR: HABv4: 00EMERG: 04EMERG: 00EMERG: 02EMERG: 40EMERG: 00EMERG: 36EMERG: 06
ERROR: HABv4: 55EMERG: 55EMERG: 00EMERG: 03EMERG: 00EMERG: 00EMERG: 00EMERG: 00
ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00
ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 01EMERG:
ERROR: HABv4: Status: Operation completed with warning (0x69)
Note the additional "EMERG: " in front of each continuation, which is
inserted by pr_cont(buf) being expanded to pr_printk(0, buf). These
additional strings show up in deep red on the console (which is not
supported in Git commit messages…). One might argue that this is the
same color as the "ERROR: " prefix, but when pr_cont() is used with
pr_notice() and pr_warning(), which are printed in blue and yellow
respectively, at least then the change in color would lead to additional
confusion.
The log level argument to pr_printk is defined as int, so we can solve
this by defining the level for pr_cont() to -1, which is not used for
any loglevel:
ERROR: HABv4: -------- HAB warning Event 0 --------
ERROR: HABv4: event data:
ERROR: HABv4: db 00 24 42 69 30 e1 1d
ERROR: HABv4: 00 04 00 02 40 00 36 06
ERROR: HABv4: 55 55 00 03 00 00 00 00
ERROR: HABv4: 00 00 00 00 00 00 00 00
ERROR: HABv4: 00 00 00 01
ERROR: HABv4: Status: Operation completed with warning (0x69)
Fixes: 0fcefdd9369050f35a88b41dcd42cc5a3c6c6b33 ("printk: Add pr_cont")
Fixes: ea0e077ed65a003e4d7a1e023aee38cbe2d14898 ("printk: Fix pr_cont")
Signed-off-by: Roland Hieber <r.hieber@pengutronix.de>
---
include/printk.h | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/include/printk.h b/include/printk.h
index 4384fb85ea..858e800543 100644
--- a/include/printk.h
+++ b/include/printk.h
@@ -84,21 +84,21 @@ static inline int pr_print(int level, const char *format, ...)
#define pr_emerg(fmt, arg...) __pr_printk(0, pr_fmt(fmt), ##arg)
#define pr_alert(fmt, arg...) __pr_printk(1, pr_fmt(fmt), ##arg)
#define pr_crit(fmt, arg...) __pr_printk(2, pr_fmt(fmt), ##arg)
#define pr_err(fmt, arg...) __pr_printk(3, pr_fmt(fmt), ##arg)
#define pr_warning(fmt, arg...) __pr_printk(4, pr_fmt(fmt), ##arg)
#define pr_notice(fmt, arg...) __pr_printk(5, pr_fmt(fmt), ##arg)
#define pr_info(fmt, arg...) __pr_printk(6, pr_fmt(fmt), ##arg)
#define pr_debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
#define debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
#define pr_vdebug(fmt, arg...) __pr_printk(8, pr_fmt(fmt), ##arg)
-#define pr_cont(fmt, arg...) __pr_printk(0, fmt, ##arg)
+#define pr_cont(fmt, arg...) __pr_printk(-1, fmt, ##arg)
#define printk_once(fmt, ...) \
({ \
static bool __print_once ; \
\
if (!__print_once) { \
__print_once = true; \
printk(fmt, ##__VA_ARGS__); \
} \
})
--
2.19.1
_______________________________________________
barebox mailing list
barebox@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/barebox
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] printk: make line continuation not result in stray emergency errors
2018-11-20 20:50 [PATCH] printk: make line continuation not result in stray emergency errors Roland Hieber
@ 2018-11-20 21:06 ` Roland Hieber
2018-11-21 8:43 ` Sascha Hauer
2018-11-21 8:51 ` Sascha Hauer
1 sibling, 1 reply; 4+ messages in thread
From: Roland Hieber @ 2018-11-20 21:06 UTC (permalink / raw)
To: barebox
On Tue, Nov 20, 2018 at 09:50:44PM +0100, Roland Hieber wrote:
> The levels of pr_emerg() and pr_cont() are both set to 0. When pr_cont()
> is used to continue a previous line, and colored console output is
> enabled, this can result in garbled log messages being printed, e.g.:
>
> ERROR: HABv4: -------- HAB warning Event 0 --------
> ERROR: HABv4: event data:
> ERROR: HABv4: dbEMERG: 00EMERG: 24EMERG: 42EMERG: 69EMERG: 30EMERG: e1EMERG: 1d
> ERROR: HABv4: 00EMERG: 04EMERG: 00EMERG: 02EMERG: 40EMERG: 00EMERG: 36EMERG: 06
> ERROR: HABv4: 55EMERG: 55EMERG: 00EMERG: 03EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 01EMERG:
> ERROR: HABv4: Status: Operation completed with warning (0x69)
>
> Note the additional "EMERG: " in front of each continuation, which is
> inserted by pr_cont(buf) being expanded to pr_printk(0, buf). These
> additional strings show up in deep red on the console (which is not
> supported in Git commit messages…). One might argue that this is the
> same color as the "ERROR: " prefix, but when pr_cont() is used with
> pr_notice() and pr_warning(), which are printed in blue and yellow
> respectively, at least then the change in color would lead to additional
> confusion.
>
> The log level argument to pr_printk is defined as int, so we can solve
> this by defining the level for pr_cont() to -1, which is not used for
> any loglevel:
>
> ERROR: HABv4: -------- HAB warning Event 0 --------
> ERROR: HABv4: event data:
> ERROR: HABv4: db 00 24 42 69 30 e1 1d
> ERROR: HABv4: 00 04 00 02 40 00 36 06
> ERROR: HABv4: 55 55 00 03 00 00 00 00
> ERROR: HABv4: 00 00 00 00 00 00 00 00
> ERROR: HABv4: 00 00 00 01
> ERROR: HABv4: Status: Operation completed with warning (0x69)
>
> Fixes: 0fcefdd9369050f35a88b41dcd42cc5a3c6c6b33 ("printk: Add pr_cont")
> Fixes: ea0e077ed65a003e4d7a1e023aee38cbe2d14898 ("printk: Fix pr_cont")
> Signed-off-by: Roland Hieber <r.hieber@pengutronix.de>
> ---
> include/printk.h | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/include/printk.h b/include/printk.h
> index 4384fb85ea..858e800543 100644
> --- a/include/printk.h
> +++ b/include/printk.h
> @@ -84,21 +84,21 @@ static inline int pr_print(int level, const char *format, ...)
> #define pr_emerg(fmt, arg...) __pr_printk(0, pr_fmt(fmt), ##arg)
> #define pr_alert(fmt, arg...) __pr_printk(1, pr_fmt(fmt), ##arg)
> #define pr_crit(fmt, arg...) __pr_printk(2, pr_fmt(fmt), ##arg)
> #define pr_err(fmt, arg...) __pr_printk(3, pr_fmt(fmt), ##arg)
> #define pr_warning(fmt, arg...) __pr_printk(4, pr_fmt(fmt), ##arg)
> #define pr_notice(fmt, arg...) __pr_printk(5, pr_fmt(fmt), ##arg)
> #define pr_info(fmt, arg...) __pr_printk(6, pr_fmt(fmt), ##arg)
> #define pr_debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
> #define debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
> #define pr_vdebug(fmt, arg...) __pr_printk(8, pr_fmt(fmt), ##arg)
> -#define pr_cont(fmt, arg...) __pr_printk(0, fmt, ##arg)
> +#define pr_cont(fmt, arg...) __pr_printk(-1, fmt, ##arg)
Hmmm. There is a different ugly detail here: pr_cont()s are always
printed regardless of the current loglevel, also with the old
implementation. I think we could remember the last used loglevel in
pr_debug(), pr_err(), pr_info() etc. code paths and let pr_printk()
decide on that basis if pr_cont() should be printed or not, i.e. from
which loglevel the current pr_cont() is a continuation.
But for now, this is out of scope of this patch. :)
- Roland
>
> #define printk_once(fmt, ...) \
> ({ \
> static bool __print_once ; \
> \
> if (!__print_once) { \
> __print_once = true; \
> printk(fmt, ##__VA_ARGS__); \
> } \
> })
> --
> 2.19.1
>
>
> _______________________________________________
> barebox mailing list
> barebox@lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/barebox
--
Roland Hieber | r.hieber@pengutronix.de |
Pengutronix e.K. | https://www.pengutronix.de/ |
Peiner Str. 6-8, 31137 Hildesheim | Phone: +49-5121-206917-5086 |
Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-5555 |
_______________________________________________
barebox mailing list
barebox@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/barebox
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] printk: make line continuation not result in stray emergency errors
2018-11-20 21:06 ` Roland Hieber
@ 2018-11-21 8:43 ` Sascha Hauer
0 siblings, 0 replies; 4+ messages in thread
From: Sascha Hauer @ 2018-11-21 8:43 UTC (permalink / raw)
To: Roland Hieber; +Cc: barebox
On Tue, Nov 20, 2018 at 10:06:39PM +0100, Roland Hieber wrote:
> On Tue, Nov 20, 2018 at 09:50:44PM +0100, Roland Hieber wrote:
> > The levels of pr_emerg() and pr_cont() are both set to 0. When pr_cont()
> > is used to continue a previous line, and colored console output is
> > enabled, this can result in garbled log messages being printed, e.g.:
> >
> > ERROR: HABv4: -------- HAB warning Event 0 --------
> > ERROR: HABv4: event data:
> > ERROR: HABv4: dbEMERG: 00EMERG: 24EMERG: 42EMERG: 69EMERG: 30EMERG: e1EMERG: 1d
> > ERROR: HABv4: 00EMERG: 04EMERG: 00EMERG: 02EMERG: 40EMERG: 00EMERG: 36EMERG: 06
> > ERROR: HABv4: 55EMERG: 55EMERG: 00EMERG: 03EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> > ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> > ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 01EMERG:
> > ERROR: HABv4: Status: Operation completed with warning (0x69)
> >
> > Note the additional "EMERG: " in front of each continuation, which is
> > inserted by pr_cont(buf) being expanded to pr_printk(0, buf). These
> > additional strings show up in deep red on the console (which is not
> > supported in Git commit messages…). One might argue that this is the
> > same color as the "ERROR: " prefix, but when pr_cont() is used with
> > pr_notice() and pr_warning(), which are printed in blue and yellow
> > respectively, at least then the change in color would lead to additional
> > confusion.
> >
> > The log level argument to pr_printk is defined as int, so we can solve
> > this by defining the level for pr_cont() to -1, which is not used for
> > any loglevel:
> >
> > ERROR: HABv4: -------- HAB warning Event 0 --------
> > ERROR: HABv4: event data:
> > ERROR: HABv4: db 00 24 42 69 30 e1 1d
> > ERROR: HABv4: 00 04 00 02 40 00 36 06
> > ERROR: HABv4: 55 55 00 03 00 00 00 00
> > ERROR: HABv4: 00 00 00 00 00 00 00 00
> > ERROR: HABv4: 00 00 00 01
> > ERROR: HABv4: Status: Operation completed with warning (0x69)
> >
> > Fixes: 0fcefdd9369050f35a88b41dcd42cc5a3c6c6b33 ("printk: Add pr_cont")
> > Fixes: ea0e077ed65a003e4d7a1e023aee38cbe2d14898 ("printk: Fix pr_cont")
> > Signed-off-by: Roland Hieber <r.hieber@pengutronix.de>
> > ---
> > include/printk.h | 2 +-
> > 1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/include/printk.h b/include/printk.h
> > index 4384fb85ea..858e800543 100644
> > --- a/include/printk.h
> > +++ b/include/printk.h
> > @@ -84,21 +84,21 @@ static inline int pr_print(int level, const char *format, ...)
> > #define pr_emerg(fmt, arg...) __pr_printk(0, pr_fmt(fmt), ##arg)
> > #define pr_alert(fmt, arg...) __pr_printk(1, pr_fmt(fmt), ##arg)
> > #define pr_crit(fmt, arg...) __pr_printk(2, pr_fmt(fmt), ##arg)
> > #define pr_err(fmt, arg...) __pr_printk(3, pr_fmt(fmt), ##arg)
> > #define pr_warning(fmt, arg...) __pr_printk(4, pr_fmt(fmt), ##arg)
> > #define pr_notice(fmt, arg...) __pr_printk(5, pr_fmt(fmt), ##arg)
> > #define pr_info(fmt, arg...) __pr_printk(6, pr_fmt(fmt), ##arg)
> > #define pr_debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
> > #define debug(fmt, arg...) __pr_printk(7, pr_fmt(fmt), ##arg)
> > #define pr_vdebug(fmt, arg...) __pr_printk(8, pr_fmt(fmt), ##arg)
> > -#define pr_cont(fmt, arg...) __pr_printk(0, fmt, ##arg)
> > +#define pr_cont(fmt, arg...) __pr_printk(-1, fmt, ##arg)
>
> Hmmm. There is a different ugly detail here: pr_cont()s are always
> printed regardless of the current loglevel, also with the old
> implementation. I think we could remember the last used loglevel in
> pr_debug(), pr_err(), pr_info() etc. code paths and let pr_printk()
> decide on that basis if pr_cont() should be printed or not, i.e. from
> which loglevel the current pr_cont() is a continuation.
I just gave it a try and there's a problem with this. Right now with
default settings pr_debug is completely optimized out. If we have to
store the state in pr_debug in order to safe it for a pr_cont then
pr_debug is no longer fully optimized away and the binary gets
significantly bigger.
Sascha
--
Pengutronix e.K. | |
Industrial Linux Solutions | http://www.pengutronix.de/ |
Peiner Str. 6-8, 31137 Hildesheim, Germany | Phone: +49-5121-206917-0 |
Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-5555 |
_______________________________________________
barebox mailing list
barebox@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/barebox
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] printk: make line continuation not result in stray emergency errors
2018-11-20 20:50 [PATCH] printk: make line continuation not result in stray emergency errors Roland Hieber
2018-11-20 21:06 ` Roland Hieber
@ 2018-11-21 8:51 ` Sascha Hauer
1 sibling, 0 replies; 4+ messages in thread
From: Sascha Hauer @ 2018-11-21 8:51 UTC (permalink / raw)
To: Roland Hieber; +Cc: barebox
On Tue, Nov 20, 2018 at 09:50:44PM +0100, Roland Hieber wrote:
> The levels of pr_emerg() and pr_cont() are both set to 0. When pr_cont()
> is used to continue a previous line, and colored console output is
> enabled, this can result in garbled log messages being printed, e.g.:
>
> ERROR: HABv4: -------- HAB warning Event 0 --------
> ERROR: HABv4: event data:
> ERROR: HABv4: dbEMERG: 00EMERG: 24EMERG: 42EMERG: 69EMERG: 30EMERG: e1EMERG: 1d
> ERROR: HABv4: 00EMERG: 04EMERG: 00EMERG: 02EMERG: 40EMERG: 00EMERG: 36EMERG: 06
> ERROR: HABv4: 55EMERG: 55EMERG: 00EMERG: 03EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00EMERG: 00
> ERROR: HABv4: 00EMERG: 00EMERG: 00EMERG: 01EMERG:
> ERROR: HABv4: Status: Operation completed with warning (0x69)
>
> Note the additional "EMERG: " in front of each continuation, which is
> inserted by pr_cont(buf) being expanded to pr_printk(0, buf). These
> additional strings show up in deep red on the console (which is not
> supported in Git commit messages…). One might argue that this is the
> same color as the "ERROR: " prefix, but when pr_cont() is used with
> pr_notice() and pr_warning(), which are printed in blue and yellow
> respectively, at least then the change in color would lead to additional
> confusion.
>
> The log level argument to pr_printk is defined as int, so we can solve
> this by defining the level for pr_cont() to -1, which is not used for
> any loglevel:
>
> ERROR: HABv4: -------- HAB warning Event 0 --------
> ERROR: HABv4: event data:
> ERROR: HABv4: db 00 24 42 69 30 e1 1d
> ERROR: HABv4: 00 04 00 02 40 00 36 06
> ERROR: HABv4: 55 55 00 03 00 00 00 00
> ERROR: HABv4: 00 00 00 00 00 00 00 00
> ERROR: HABv4: 00 00 00 01
> ERROR: HABv4: Status: Operation completed with warning (0x69)
>
> Fixes: 0fcefdd9369050f35a88b41dcd42cc5a3c6c6b33 ("printk: Add pr_cont")
> Fixes: ea0e077ed65a003e4d7a1e023aee38cbe2d14898 ("printk: Fix pr_cont")
> Signed-off-by: Roland Hieber <r.hieber@pengutronix.de>
> ---
Since it improved things: Applied, thanks.
However, I think we should make our minds if we keep pr_cont or if it's
just unnecessary ballast. Right now we only have a few users which could
be removed without much hassle.
Sascha
--
Pengutronix e.K. | |
Industrial Linux Solutions | http://www.pengutronix.de/ |
Peiner Str. 6-8, 31137 Hildesheim, Germany | Phone: +49-5121-206917-0 |
Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-5555 |
_______________________________________________
barebox mailing list
barebox@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/barebox
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-11-21 8:52 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-11-20 20:50 [PATCH] printk: make line continuation not result in stray emergency errors Roland Hieber
2018-11-20 21:06 ` Roland Hieber
2018-11-21 8:43 ` Sascha Hauer
2018-11-21 8:51 ` Sascha Hauer
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox