Re: Weird character in kernel message

From: Jan Kara
Date: Tue Sep 16 2014 - 10:15:30 EST


On Mon 15-09-14 18:37:40, Markus Trippelsdorf wrote:
> On 2014.09.14 at 11:13 +0200, Geert Uytterhoeven wrote:
> > On Sun, Sep 14, 2014 at 7:54 AM, Markus Trippelsdorf
> > <markus@xxxxxxxxxxxxxxx> wrote:
> > > On 2014.09.14 at 07:09 +0200, Markus Trippelsdorf wrote:
> > >> Just noticed this today:
> > >>
> > >> Sep 14 06:51:57 x4 kernel: [sched_delayed] ^a4CE: hpet increased min_delta_ns to 20115 nsec
> > >>
> > >> in hex:
> > >> 20 01 34 43 45 3A 20
> > >>
> > >> Must be a recent regression.
> > >
> > > It looks like a combination of commit 504d58745c9ca and commit
> > > 458df9fd4815b causes the issue.
> > > 458df9fd4815b changed the loglevel of printk_deferred to a hardcoded
> > > KERN_WARNING. And 504d58745c9ca changed the printk in
> > > kernel/time/clockevents.c to printk_deferred.
> > > But now the KERN_WARNING loglevel of printk_deferred in
> > > kernel/time/clockevents.c is redundant and responsible for the weird
> > > 01 34 character combination (KERN_SOH "4").
> >
> > vprintk_emit() has:
> >
> > if (in_sched)
> > text_len = scnprintf(text, sizeof(textbuf),
> > KERN_WARNING "[sched_delayed] ");
> >
> > text_len += vscnprintf(text + text_len,
> > sizeof(textbuf) - text_len, fmt, args);
> >
> > Hence if in_sched, "[sched_delayed] " is inserted before the printed
> > message. As most printed messages have a KERN_* prefix, this
> > prefix now ends up in the middle of the message, causing the issue.
> >
> > A simple solution is to print a newline after the "[sched_delayed]", but
> > this will break the line.
> >
> > Better, but more complicated, would be to remove the KERN_* prefix
> > (if it exists) from the next message if in_sched is set.
>
> Or just get rid of the "[sched_delayed] " thing. Does it really convey
> useful information to the user?
Yeah, you're right the prefix isn't that useful IMHO. So feel free to
add:
Acked-by: Jan Kara <jack@xxxxxxx>

Honza
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1ce770687ea8..b13c8650a751 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1680,12 +1680,8 @@ asmlinkage int vprintk_emit(int facility, int level,
> * The printf needs to come first; we need the syslog
> * prefix which might be passed-in as a parameter.
> */
> - if (in_sched)
> - text_len = scnprintf(text, sizeof(textbuf),
> - KERN_WARNING "[sched_delayed] ");
>
> - text_len += vscnprintf(text + text_len,
> - sizeof(textbuf) - text_len, fmt, args);
> + text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
>
> /* mark and strip a trailing newline */
> if (text_len && text[text_len-1] == '\n') {
>
> --
> Markus
--
Jan Kara <jack@xxxxxxx>
SUSE Labs, CR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/