Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/12/18 15:33), Petr Mladek wrote:
> > console_trylock();
> > console_may_schedule = 0;
> > + if (exclusive_console) {
> > + exclusive_console = NULL;
> > + console_seq = rollback_console_seq;
>
> This might be controversial. Yes, it might help in some situations
> (slow exclusive console). But it might be counterproductive
> when the exclusive console is the one that is readable
> after the crash, used for debugging and this change causes
> an incomplete log.
Well, OK. We still print oops messages, just get to this point sooner.
> I would do this change only when people complains about
> the current behavior.
OK. Agreed.
> I think that more important is to do:
[..]
> IMHO, this is a clear win. It fixes a clear mistake.
>
> I would just rename the variable to exclusive_console_seq_stop or so.
OK. Send a patch.
Reported-by: Sergey Senozhatsky
Acked-by: Sergey Senozhatsky
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/12/18 15:33), Petr Mladek wrote:
> > console_trylock();
> > console_may_schedule = 0;
> > + if (exclusive_console) {
> > + exclusive_console = NULL;
> > + console_seq = rollback_console_seq;
>
> This might be controversial. Yes, it might help in some situations
> (slow exclusive console). But it might be counterproductive
> when the exclusive console is the one that is readable
> after the crash, used for debugging and this change causes
> an incomplete log.
Well, OK. We still print oops messages, just get to this point sooner.
> I would do this change only when people complains about
> the current behavior.
OK. Agreed.
> I think that more important is to do:
[..]
> IMHO, this is a clear win. It fixes a clear mistake.
>
> I would just rename the variable to exclusive_console_seq_stop or so.
OK. Send a patch.
Reported-by: Sergey Senozhatsky
Acked-by: Sergey Senozhatsky
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-12 16:49:30, Sergey Senozhatsky wrote:
> On (09/11/18 10:47), Petr Mladek wrote:
> > > > Most problems should probably be solved when we store console_seq
> > > > before setting exclusive_console. Then we could clear
> > > > exclusive_console when reaching the stored sequence number.
>
> Hmm, wouldn't the same "it might be problematic with slow consoles"
> argument apply to this solution as well?
It would just fix a clear bug.
> So maybe we can do the following:
>
> - store console_seq when we register exclusive console
> - in flush_on_panic, if we have exclusive console set
> - clear exclusive console
> - rollback console_seq to the value it had before we set exclusive console
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 53c94cbce0af..4ef199572df7 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -424,6 +424,7 @@ static u32 log_next_idx;
> /* the next printk record to write to the console */
> static u64 console_seq;
> static u32 console_idx;
> +static u64 rollback_console_seq;
>
> /* the next printk record to read after the last 'clear' command */
> static u64 clear_seq;
> @@ -2592,6 +2593,10 @@ void console_flush_on_panic(void)
>*/
> console_trylock();
> console_may_schedule = 0;
> + if (exclusive_console) {
> + exclusive_console = NULL;
> + console_seq = rollback_console_seq;
This might be controversial. Yes, it might help in some situations
(slow exclusive console). But it might be counterproductive
when the exclusive console is the one that is readable
after the crash, used for debugging and this change causes
an incomplete log.
I would do this change only when people complains about
the current behavior.
I think that more important is to do:
@@ -2415,6 +2415,9 @@ void console_unlock(void)
console_seq++;
raw_spin_unlock(_lock);
+ if (exclusive_console && console_seq >= rollback_console_seq)
+ exclusive_console = NULL;
+
/*
* While actively printing out messages, if another printk()
* were to occur on another CPU, it may wait for this one to
IMHO, this is a clear win. It fixes a clear mistake.
I would just rename the variable to exclusive_console_seq_stop or so.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-12 16:49:30, Sergey Senozhatsky wrote:
> On (09/11/18 10:47), Petr Mladek wrote:
> > > > Most problems should probably be solved when we store console_seq
> > > > before setting exclusive_console. Then we could clear
> > > > exclusive_console when reaching the stored sequence number.
>
> Hmm, wouldn't the same "it might be problematic with slow consoles"
> argument apply to this solution as well?
It would just fix a clear bug.
> So maybe we can do the following:
>
> - store console_seq when we register exclusive console
> - in flush_on_panic, if we have exclusive console set
> - clear exclusive console
> - rollback console_seq to the value it had before we set exclusive console
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 53c94cbce0af..4ef199572df7 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -424,6 +424,7 @@ static u32 log_next_idx;
> /* the next printk record to write to the console */
> static u64 console_seq;
> static u32 console_idx;
> +static u64 rollback_console_seq;
>
> /* the next printk record to read after the last 'clear' command */
> static u64 clear_seq;
> @@ -2592,6 +2593,10 @@ void console_flush_on_panic(void)
>*/
> console_trylock();
> console_may_schedule = 0;
> + if (exclusive_console) {
> + exclusive_console = NULL;
> + console_seq = rollback_console_seq;
This might be controversial. Yes, it might help in some situations
(slow exclusive console). But it might be counterproductive
when the exclusive console is the one that is readable
after the crash, used for debugging and this change causes
an incomplete log.
I would do this change only when people complains about
the current behavior.
I think that more important is to do:
@@ -2415,6 +2415,9 @@ void console_unlock(void)
console_seq++;
raw_spin_unlock(_lock);
+ if (exclusive_console && console_seq >= rollback_console_seq)
+ exclusive_console = NULL;
+
/*
* While actively printing out messages, if another printk()
* were to occur on another CPU, it may wait for this one to
IMHO, this is a clear win. It fixes a clear mistake.
I would just rename the variable to exclusive_console_seq_stop or so.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/11/18 10:47), Petr Mladek wrote:
> > Oh, that was intentional. I consider repeated messages to be less
> > problematic than the missing ones.
>
> It makes some sense. But it might be problematic with slow consoles.
Right. And this is why I brought up Jan's patch.
And I agree that we better discuss that approach in a separate thread.
> > > Most problems should probably be solved when we store console_seq
> > > before setting exclusive_console. Then we could clear
> > > exclusive_console when reaching the stored sequence number.
> > >
> > > Can this be that simple? ;-)
> >
> > This can work, yes.
>
> I'll try to cook up a patch later this week.
Hmm, wouldn't the same "it might be problematic with slow consoles"
argument apply to this solution as well? If we flush_on_panic(), and
have a slow exclusive_console then flushing logbuf to that slow
exclusive_console can take quite some time, before we even begin to
flush oops messages.
So maybe we can do the following:
- store console_seq when we register exclusive console
- in flush_on_panic, if we have exclusive console set
- clear exclusive console
- rollback console_seq to the value it had before we set exclusive console
So we will not re-flush all logbuf messages, but only the new ones and
should get to oops messages sooner.
IOW, something like this?
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 53c94cbce0af..4ef199572df7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -424,6 +424,7 @@ static u32 log_next_idx;
/* the next printk record to write to the console */
static u64 console_seq;
static u32 console_idx;
+static u64 rollback_console_seq;
/* the next printk record to read after the last 'clear' command */
static u64 clear_seq;
@@ -2592,6 +2593,10 @@ void console_flush_on_panic(void)
*/
console_trylock();
console_may_schedule = 0;
+ if (exclusive_console) {
+ exclusive_console = NULL;
+ console_seq = rollback_console_seq;
+ }
console_unlock();
}
@@ -2793,6 +2798,7 @@ void register_console(struct console *newcon)
* for us.
*/
logbuf_lock_irqsave(flags);
+ rollback_console_seq = console_seq;
console_seq = syslog_seq;
console_idx = syslog_idx;
logbuf_unlock_irqrestore(flags);
---
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/11/18 10:47), Petr Mladek wrote:
> > Oh, that was intentional. I consider repeated messages to be less
> > problematic than the missing ones.
>
> It makes some sense. But it might be problematic with slow consoles.
Right. And this is why I brought up Jan's patch.
And I agree that we better discuss that approach in a separate thread.
> > > Most problems should probably be solved when we store console_seq
> > > before setting exclusive_console. Then we could clear
> > > exclusive_console when reaching the stored sequence number.
> > >
> > > Can this be that simple? ;-)
> >
> > This can work, yes.
>
> I'll try to cook up a patch later this week.
Hmm, wouldn't the same "it might be problematic with slow consoles"
argument apply to this solution as well? If we flush_on_panic(), and
have a slow exclusive_console then flushing logbuf to that slow
exclusive_console can take quite some time, before we even begin to
flush oops messages.
So maybe we can do the following:
- store console_seq when we register exclusive console
- in flush_on_panic, if we have exclusive console set
- clear exclusive console
- rollback console_seq to the value it had before we set exclusive console
So we will not re-flush all logbuf messages, but only the new ones and
should get to oops messages sooner.
IOW, something like this?
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 53c94cbce0af..4ef199572df7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -424,6 +424,7 @@ static u32 log_next_idx;
/* the next printk record to write to the console */
static u64 console_seq;
static u32 console_idx;
+static u64 rollback_console_seq;
/* the next printk record to read after the last 'clear' command */
static u64 clear_seq;
@@ -2592,6 +2593,10 @@ void console_flush_on_panic(void)
*/
console_trylock();
console_may_schedule = 0;
+ if (exclusive_console) {
+ exclusive_console = NULL;
+ console_seq = rollback_console_seq;
+ }
console_unlock();
}
@@ -2793,6 +2798,7 @@ void register_console(struct console *newcon)
* for us.
*/
logbuf_lock_irqsave(flags);
+ rollback_console_seq = console_seq;
console_seq = syslog_seq;
console_idx = syslog_idx;
logbuf_unlock_irqrestore(flags);
---
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Tue 2018-09-11 11:30:39, Sergey Senozhatsky wrote:
> On (09/10/18 16:57), Petr Mladek wrote:
> >
> > Good catch.
> >
> > > ---
> > >
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index c036f128cdc3..ede29a7ba6db 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
> > >* ensure may_schedule is cleared.
> > >*/
> > > console_trylock();
> > > + exclusive_console = NULL;
> >
> > This is not be enough. It would cause replying old messages
> > on all consoles.
>
> Oh, that was intentional. I consider repeated messages to be less
> problematic than the missing ones.
It makes some sense. But it might be problematic with slow consoles.
I prefer to avoid it if there is a better solution.
> > Most problems should probably be solved when we store console_seq
> > before setting exclusive_console. Then we could clear
> > exclusive_console when reaching the stored sequence number.
> >
> > Can this be that simple? ;-)
>
> This can work, yes.
I'll try to cook up a patch later this week.
> I also thought about doing it the way Linus, Jan Kara and Hannes
> Reinecke proposed:
>
> - store the console_seq nr of the first oops_in_progress message
> (oops_console_seq) and flush only messages that are in
> [oops_console_seq - 200, log_next_seq] range, as opposed to complete
> logbuf flush.
>
> Hannes asked for this several times. And it was in Jan's printk patches
> long time ago (if I'm not mistaken - sorry if I am -- Jan said that Linus
> wanted that "just N messages prior to oops" thing).
>
> Jan's patch:
>
> https://lore.kernel.org/lkml/1457964820-4642-3-git-send-email-sergey.senozhat...@gmail.com/T/#u
The patch might be useful but it also might be controversial. It would
deserve discussion with a wide audience in a dedicated thread.
> > This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
> >
> > Reported-by: Hans de Goede
> > Signed-off-by: Petr Mladek
>
> Acked-by: Sergey Senozhatsky
I have just pushed the patch into printk.git, for-4.19-rc4 branch.
Note that I merged also a revert of the build fix
commit ffaa619af1b06 ("printk: Fix warning about unused
suppress_message_printing"). I am sorry that I missed
it in the original patch. It is an obvious oneliner.
It should not invalidate the acks.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Tue 2018-09-11 11:30:39, Sergey Senozhatsky wrote:
> On (09/10/18 16:57), Petr Mladek wrote:
> >
> > Good catch.
> >
> > > ---
> > >
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index c036f128cdc3..ede29a7ba6db 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
> > >* ensure may_schedule is cleared.
> > >*/
> > > console_trylock();
> > > + exclusive_console = NULL;
> >
> > This is not be enough. It would cause replying old messages
> > on all consoles.
>
> Oh, that was intentional. I consider repeated messages to be less
> problematic than the missing ones.
It makes some sense. But it might be problematic with slow consoles.
I prefer to avoid it if there is a better solution.
> > Most problems should probably be solved when we store console_seq
> > before setting exclusive_console. Then we could clear
> > exclusive_console when reaching the stored sequence number.
> >
> > Can this be that simple? ;-)
>
> This can work, yes.
I'll try to cook up a patch later this week.
> I also thought about doing it the way Linus, Jan Kara and Hannes
> Reinecke proposed:
>
> - store the console_seq nr of the first oops_in_progress message
> (oops_console_seq) and flush only messages that are in
> [oops_console_seq - 200, log_next_seq] range, as opposed to complete
> logbuf flush.
>
> Hannes asked for this several times. And it was in Jan's printk patches
> long time ago (if I'm not mistaken - sorry if I am -- Jan said that Linus
> wanted that "just N messages prior to oops" thing).
>
> Jan's patch:
>
> https://lore.kernel.org/lkml/1457964820-4642-3-git-send-email-sergey.senozhat...@gmail.com/T/#u
The patch might be useful but it also might be controversial. It would
deserve discussion with a wide audience in a dedicated thread.
> > This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
> >
> > Reported-by: Hans de Goede
> > Signed-off-by: Petr Mladek
>
> Acked-by: Sergey Senozhatsky
I have just pushed the patch into printk.git, for-4.19-rc4 branch.
Note that I merged also a revert of the build fix
commit ffaa619af1b06 ("printk: Fix warning about unused
suppress_message_printing"). I am sorry that I missed
it in the original patch. It is an obvious oneliner.
It should not invalidate the acks.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/10/18 16:57), Petr Mladek wrote: > > Good catch. > > > --- > > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > > index c036f128cdc3..ede29a7ba6db 100644 > > --- a/kernel/printk/printk.c > > +++ b/kernel/printk/printk.c > > @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void) > > * ensure may_schedule is cleared. > > */ > > console_trylock(); > > + exclusive_console = NULL; > > This is not be enough. It would cause replying old messages > on all consoles. Oh, that was intentional. I consider repeated messages to be less problematic than the missing ones. > Most problems should probably be solved when we store console_seq > before setting exclusive_console. Then we could clear > exclusive_console when reaching the stored sequence number. > > Can this be that simple? ;-) This can work, yes. I also thought about doing it the way Linus, Jan Kara and Hannes Reinecke proposed: - store the console_seq nr of the first oops_in_progress message (oops_console_seq) and flush only messages that are in [oops_console_seq - 200, log_next_seq] range, as opposed to complete logbuf flush. Hannes asked for this several times. And it was in Jan's printk patches long time ago (if I'm not mistaken - sorry if I am -- Jan said that Linus wanted that "just N messages prior to oops" thing). Jan's patch: https://lore.kernel.org/lkml/1457964820-4642-3-git-send-email-sergey.senozhat...@gmail.com/T/#u > This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a. > > Reported-by: Hans de Goede > Signed-off-by: Petr Mladek Acked-by: Sergey Senozhatsky -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/10/18 16:57), Petr Mladek wrote: > > Good catch. > > > --- > > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > > index c036f128cdc3..ede29a7ba6db 100644 > > --- a/kernel/printk/printk.c > > +++ b/kernel/printk/printk.c > > @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void) > > * ensure may_schedule is cleared. > > */ > > console_trylock(); > > + exclusive_console = NULL; > > This is not be enough. It would cause replying old messages > on all consoles. Oh, that was intentional. I consider repeated messages to be less problematic than the missing ones. > Most problems should probably be solved when we store console_seq > before setting exclusive_console. Then we could clear > exclusive_console when reaching the stored sequence number. > > Can this be that simple? ;-) This can work, yes. I also thought about doing it the way Linus, Jan Kara and Hannes Reinecke proposed: - store the console_seq nr of the first oops_in_progress message (oops_console_seq) and flush only messages that are in [oops_console_seq - 200, log_next_seq] range, as opposed to complete logbuf flush. Hannes asked for this several times. And it was in Jan's printk patches long time ago (if I'm not mistaken - sorry if I am -- Jan said that Linus wanted that "just N messages prior to oops" thing). Jan's patch: https://lore.kernel.org/lkml/1457964820-4642-3-git-send-email-sergey.senozhat...@gmail.com/T/#u > This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a. > > Reported-by: Hans de Goede > Signed-off-by: Petr Mladek Acked-by: Sergey Senozhatsky -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On 10-09-18 16:57, Petr Mladek wrote:
On Fri 2018-09-07 13:21:32, Sergey Senozhatsky wrote:
On (09/06/18 16:28), Petr Mladek wrote:
On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
On (09/05/18 13:02), Petr Mladek wrote:
Note that the first registered console prints all messages
even without this flag.
Hmm, OK, interesting point.
I assumed that the first console usually has CON_PRINTBUFFER bit set.
Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
makes sense to have CON_PRINTBUFFER for the first console. Any later
consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
And the first console has CON_PRINTBUFFER bit set. Well, just because
it sounds reasonable. Those were the main assumptions behind my code
snippet. Was any of those assumptions wrong?
This assumption makes sense. In fact, I was wrong. I thought that
console_seq/console_idx were not updated until the first console
was registered. But it is not the case.
It means that the hack with exclusive_console might be usable.
Yeah, it is a hack. But not as dirty as it might appear, I think. In some
sense it's aligned with what we do for exlusive_consoles - we treat exclusive
consoles specially. So specially that even if the system panics while we
re-flush logbuf messages to a new exclusive console, we flush_on_panic() only
to that exclusive console, ignoring the rest of them.
I consider this a bug. Another bug is that other consoles might miss
messages that appear while the older messages are being
replayed on exclusive_console.
AFAIK, nobody complains about it. But I not comfortable with reusing
this racy pattern even more ;-)
Not sure if it's totally right. There can be a netcon, for instance,
available, which will not see panic flush() because of a exclusive
console:
Good catch.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..ede29a7ba6db 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
* ensure may_schedule is cleared.
*/
console_trylock();
+ exclusive_console = NULL;
This is not be enough. It would cause replying old messages
on all consoles.
Most problems should probably be solved when we store console_seq
before setting exclusive_console. Then we could clear
exclusive_console when reaching the stored sequence number.
Can this be that simple? ;-)
I prefer the revert for now.
OK, agreed.
IIRC I didn't see any upstream code which would have been fixed
by the commit in question.
My proposal for 4.19:
From 46ceb577021c8899edd1977a52929b309a5ebf85 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Mon, 10 Sep 2018 15:52:06 +0200
Subject: [PATCH] Revert "printk: make sure to print log on console."
This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
The visibility of early messages did not longer take into account
"quiet", "debug", and "loglevel" early parameters.
It would be possible to invalidate and recompute LOG_NOCONS flag
for the affected messages. But it would be hairy.
Instead this patch just reverts the problematic commit. We could
come up with a better solution for the original problem. For example,
we could simplify the logic and just mark messages that should always
be visible or always invisible on the console.
Also this patch does not put back the unused LOG_NOCONS flag.
Reported-by: Hans de Goede
Signed-off-by: Petr Mladek
Sounds like a good solution to me:
Acked-by: Hans de Goede
Regards,
Hans
---
kernel/printk/printk.c | 11 ---
1 file changed, 4 insertions(+), 7 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..5fae295fcb75 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -351,7 +351,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
*/
enum log_flags {
- LOG_NOCONS = 1,/* suppress print, do not print to console */
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
@@ -1881,9 +1880,6 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
- lflags |= LOG_NOCONS;
-
return log_output(facility, level, lflags,
dict, dictlen, text, text_len);
}
@@ -2368,10 +2364,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (suppress_message_printing(msg->level)) {
/*
-* Skip record if !ignore_loglevel, and
-* record has level above the console loglevel.
+* Skip record we have buffered
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On 10-09-18 16:57, Petr Mladek wrote:
On Fri 2018-09-07 13:21:32, Sergey Senozhatsky wrote:
On (09/06/18 16:28), Petr Mladek wrote:
On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
On (09/05/18 13:02), Petr Mladek wrote:
Note that the first registered console prints all messages
even without this flag.
Hmm, OK, interesting point.
I assumed that the first console usually has CON_PRINTBUFFER bit set.
Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
makes sense to have CON_PRINTBUFFER for the first console. Any later
consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
And the first console has CON_PRINTBUFFER bit set. Well, just because
it sounds reasonable. Those were the main assumptions behind my code
snippet. Was any of those assumptions wrong?
This assumption makes sense. In fact, I was wrong. I thought that
console_seq/console_idx were not updated until the first console
was registered. But it is not the case.
It means that the hack with exclusive_console might be usable.
Yeah, it is a hack. But not as dirty as it might appear, I think. In some
sense it's aligned with what we do for exlusive_consoles - we treat exclusive
consoles specially. So specially that even if the system panics while we
re-flush logbuf messages to a new exclusive console, we flush_on_panic() only
to that exclusive console, ignoring the rest of them.
I consider this a bug. Another bug is that other consoles might miss
messages that appear while the older messages are being
replayed on exclusive_console.
AFAIK, nobody complains about it. But I not comfortable with reusing
this racy pattern even more ;-)
Not sure if it's totally right. There can be a netcon, for instance,
available, which will not see panic flush() because of a exclusive
console:
Good catch.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..ede29a7ba6db 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
* ensure may_schedule is cleared.
*/
console_trylock();
+ exclusive_console = NULL;
This is not be enough. It would cause replying old messages
on all consoles.
Most problems should probably be solved when we store console_seq
before setting exclusive_console. Then we could clear
exclusive_console when reaching the stored sequence number.
Can this be that simple? ;-)
I prefer the revert for now.
OK, agreed.
IIRC I didn't see any upstream code which would have been fixed
by the commit in question.
My proposal for 4.19:
From 46ceb577021c8899edd1977a52929b309a5ebf85 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Mon, 10 Sep 2018 15:52:06 +0200
Subject: [PATCH] Revert "printk: make sure to print log on console."
This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
The visibility of early messages did not longer take into account
"quiet", "debug", and "loglevel" early parameters.
It would be possible to invalidate and recompute LOG_NOCONS flag
for the affected messages. But it would be hairy.
Instead this patch just reverts the problematic commit. We could
come up with a better solution for the original problem. For example,
we could simplify the logic and just mark messages that should always
be visible or always invisible on the console.
Also this patch does not put back the unused LOG_NOCONS flag.
Reported-by: Hans de Goede
Signed-off-by: Petr Mladek
Sounds like a good solution to me:
Acked-by: Hans de Goede
Regards,
Hans
---
kernel/printk/printk.c | 11 ---
1 file changed, 4 insertions(+), 7 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..5fae295fcb75 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -351,7 +351,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
*/
enum log_flags {
- LOG_NOCONS = 1,/* suppress print, do not print to console */
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
@@ -1881,9 +1880,6 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
- lflags |= LOG_NOCONS;
-
return log_output(facility, level, lflags,
dict, dictlen, text, text_len);
}
@@ -2368,10 +2364,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (suppress_message_printing(msg->level)) {
/*
-* Skip record if !ignore_loglevel, and
-* record has level above the console loglevel.
+* Skip record we have buffered
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Fri 2018-09-07 13:21:32, Sergey Senozhatsky wrote:
> On (09/06/18 16:28), Petr Mladek wrote:
> > On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
> > > On (09/05/18 13:02), Petr Mladek wrote:
> > > > Note that the first registered console prints all messages
> > > > even without this flag.
> > >
> > > Hmm, OK, interesting point.
> > >
> > > I assumed that the first console usually has CON_PRINTBUFFER bit set.
> > > Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
> > > makes sense to have CON_PRINTBUFFER for the first console. Any later
> > > consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
> > >
> > > And the first console has CON_PRINTBUFFER bit set. Well, just because
> > > it sounds reasonable. Those were the main assumptions behind my code
> > > snippet. Was any of those assumptions wrong?
> >
> > This assumption makes sense. In fact, I was wrong. I thought that
> > console_seq/console_idx were not updated until the first console
> > was registered. But it is not the case.
> >
> > It means that the hack with exclusive_console might be usable.
>
> Yeah, it is a hack. But not as dirty as it might appear, I think. In some
> sense it's aligned with what we do for exlusive_consoles - we treat exclusive
> consoles specially. So specially that even if the system panics while we
> re-flush logbuf messages to a new exclusive console, we flush_on_panic() only
> to that exclusive console, ignoring the rest of them.
I consider this a bug. Another bug is that other consoles might miss
messages that appear while the older messages are being
replayed on exclusive_console.
AFAIK, nobody complains about it. But I not comfortable with reusing
this racy pattern even more ;-)
> Not sure if it's totally right. There can be a netcon, for instance,
> available, which will not see panic flush() because of a exclusive
> console:
Good catch.
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..ede29a7ba6db 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
>* ensure may_schedule is cleared.
>*/
> console_trylock();
> + exclusive_console = NULL;
This is not be enough. It would cause replying old messages
on all consoles.
Most problems should probably be solved when we store console_seq
before setting exclusive_console. Then we could clear
exclusive_console when reaching the stored sequence number.
Can this be that simple? ;-)
> > I prefer the revert for now.
>
> OK, agreed.
> IIRC I didn't see any upstream code which would have been fixed
> by the commit in question.
My proposal for 4.19:
>From 46ceb577021c8899edd1977a52929b309a5ebf85 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Mon, 10 Sep 2018 15:52:06 +0200
Subject: [PATCH] Revert "printk: make sure to print log on console."
This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
The visibility of early messages did not longer take into account
"quiet", "debug", and "loglevel" early parameters.
It would be possible to invalidate and recompute LOG_NOCONS flag
for the affected messages. But it would be hairy.
Instead this patch just reverts the problematic commit. We could
come up with a better solution for the original problem. For example,
we could simplify the logic and just mark messages that should always
be visible or always invisible on the console.
Also this patch does not put back the unused LOG_NOCONS flag.
Reported-by: Hans de Goede
Signed-off-by: Petr Mladek
---
kernel/printk/printk.c | 11 ---
1 file changed, 4 insertions(+), 7 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..5fae295fcb75 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -351,7 +351,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
*/
enum log_flags {
- LOG_NOCONS = 1,/* suppress print, do not print to console */
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
@@ -1881,9 +1880,6 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
- lflags |= LOG_NOCONS;
-
return log_output(facility, level, lflags,
dict, dictlen, text, text_len);
}
@@ -2368,10 +2364,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (suppress_message_printing(msg->level)) {
/*
-* Skip record if !ignore_loglevel, and
-* record has level above the console loglevel.
+* Skip
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Fri 2018-09-07 13:21:32, Sergey Senozhatsky wrote:
> On (09/06/18 16:28), Petr Mladek wrote:
> > On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
> > > On (09/05/18 13:02), Petr Mladek wrote:
> > > > Note that the first registered console prints all messages
> > > > even without this flag.
> > >
> > > Hmm, OK, interesting point.
> > >
> > > I assumed that the first console usually has CON_PRINTBUFFER bit set.
> > > Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
> > > makes sense to have CON_PRINTBUFFER for the first console. Any later
> > > consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
> > >
> > > And the first console has CON_PRINTBUFFER bit set. Well, just because
> > > it sounds reasonable. Those were the main assumptions behind my code
> > > snippet. Was any of those assumptions wrong?
> >
> > This assumption makes sense. In fact, I was wrong. I thought that
> > console_seq/console_idx were not updated until the first console
> > was registered. But it is not the case.
> >
> > It means that the hack with exclusive_console might be usable.
>
> Yeah, it is a hack. But not as dirty as it might appear, I think. In some
> sense it's aligned with what we do for exlusive_consoles - we treat exclusive
> consoles specially. So specially that even if the system panics while we
> re-flush logbuf messages to a new exclusive console, we flush_on_panic() only
> to that exclusive console, ignoring the rest of them.
I consider this a bug. Another bug is that other consoles might miss
messages that appear while the older messages are being
replayed on exclusive_console.
AFAIK, nobody complains about it. But I not comfortable with reusing
this racy pattern even more ;-)
> Not sure if it's totally right. There can be a netcon, for instance,
> available, which will not see panic flush() because of a exclusive
> console:
Good catch.
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..ede29a7ba6db 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void)
>* ensure may_schedule is cleared.
>*/
> console_trylock();
> + exclusive_console = NULL;
This is not be enough. It would cause replying old messages
on all consoles.
Most problems should probably be solved when we store console_seq
before setting exclusive_console. Then we could clear
exclusive_console when reaching the stored sequence number.
Can this be that simple? ;-)
> > I prefer the revert for now.
>
> OK, agreed.
> IIRC I didn't see any upstream code which would have been fixed
> by the commit in question.
My proposal for 4.19:
>From 46ceb577021c8899edd1977a52929b309a5ebf85 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Mon, 10 Sep 2018 15:52:06 +0200
Subject: [PATCH] Revert "printk: make sure to print log on console."
This reverts commit 375899cddcbb26881b03cb3fbdcfd600e4e67f4a.
The visibility of early messages did not longer take into account
"quiet", "debug", and "loglevel" early parameters.
It would be possible to invalidate and recompute LOG_NOCONS flag
for the affected messages. But it would be hairy.
Instead this patch just reverts the problematic commit. We could
come up with a better solution for the original problem. For example,
we could simplify the logic and just mark messages that should always
be visible or always invisible on the console.
Also this patch does not put back the unused LOG_NOCONS flag.
Reported-by: Hans de Goede
Signed-off-by: Petr Mladek
---
kernel/printk/printk.c | 11 ---
1 file changed, 4 insertions(+), 7 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..5fae295fcb75 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -351,7 +351,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
*/
enum log_flags {
- LOG_NOCONS = 1,/* suppress print, do not print to console */
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
@@ -1881,9 +1880,6 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
- lflags |= LOG_NOCONS;
-
return log_output(facility, level, lflags,
dict, dictlen, text, text_len);
}
@@ -2368,10 +2364,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (suppress_message_printing(msg->level)) {
/*
-* Skip record if !ignore_loglevel, and
-* record has level above the console loglevel.
+* Skip
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/06/18 16:28), Petr Mladek wrote: > On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote: > > On (09/05/18 13:02), Petr Mladek wrote: > > > Note that the first registered console prints all messages > > > even without this flag. > > > > Hmm, OK, interesting point. > > > > I assumed that the first console usually has CON_PRINTBUFFER bit set. > > Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of > > makes sense to have CON_PRINTBUFFER for the first console. Any later > > consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER. > > > > And the first console has CON_PRINTBUFFER bit set. Well, just because > > it sounds reasonable. Those were the main assumptions behind my code > > snippet. Was any of those assumptions wrong? > > This assumption makes sense. In fact, I was wrong. I thought that > console_seq/console_idx were not updated until the first console > was registered. But it is not the case. > > It means that the hack with exclusive_console might be usable. Yeah, it is a hack. But not as dirty as it might appear, I think. In some sense it's aligned with what we do for exlusive_consoles - we treat exclusive consoles specially. So specially that even if the system panics while we re-flush logbuf messages to a new exclusive console, we flush_on_panic() only to that exclusive console, ignoring the rest of them. Not sure if it's totally right. There can be a netcon, for instance, available, which will not see panic flush() because of a exclusive console: --- diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index c036f128cdc3..ede29a7ba6db 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void) * ensure may_schedule is cleared. */ console_trylock(); + exclusive_console = NULL; console_may_schedule = 0; console_unlock(); } --- Opinions? > But I would prefer to do it a cleaner way. OK. > But it is rather complicated, still hacky, ... Right. > > > > I can agree, definitely. That's one of the options. > > I prefer the revert for now. OK, agreed. IIRC I didn't see any upstream code which would have been fixed by the commit in question. -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/06/18 16:28), Petr Mladek wrote: > On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote: > > On (09/05/18 13:02), Petr Mladek wrote: > > > Note that the first registered console prints all messages > > > even without this flag. > > > > Hmm, OK, interesting point. > > > > I assumed that the first console usually has CON_PRINTBUFFER bit set. > > Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of > > makes sense to have CON_PRINTBUFFER for the first console. Any later > > consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER. > > > > And the first console has CON_PRINTBUFFER bit set. Well, just because > > it sounds reasonable. Those were the main assumptions behind my code > > snippet. Was any of those assumptions wrong? > > This assumption makes sense. In fact, I was wrong. I thought that > console_seq/console_idx were not updated until the first console > was registered. But it is not the case. > > It means that the hack with exclusive_console might be usable. Yeah, it is a hack. But not as dirty as it might appear, I think. In some sense it's aligned with what we do for exlusive_consoles - we treat exclusive consoles specially. So specially that even if the system panics while we re-flush logbuf messages to a new exclusive console, we flush_on_panic() only to that exclusive console, ignoring the rest of them. Not sure if it's totally right. There can be a netcon, for instance, available, which will not see panic flush() because of a exclusive console: --- diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index c036f128cdc3..ede29a7ba6db 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -2545,6 +2545,7 @@ void console_flush_on_panic(void) * ensure may_schedule is cleared. */ console_trylock(); + exclusive_console = NULL; console_may_schedule = 0; console_unlock(); } --- Opinions? > But I would prefer to do it a cleaner way. OK. > But it is rather complicated, still hacky, ... Right. > > > > I can agree, definitely. That's one of the options. > > I prefer the revert for now. OK, agreed. IIRC I didn't see any upstream code which would have been fixed by the commit in question. -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi Hans,
I love your patch! Yet something to improve:
[auto build test ERROR on linus/master]
[also build test ERROR on v4.19-rc2 next-20180906]
[if your patch is applied to the wrong git tree, please drop us a note to help
improve the system]
url:
https://github.com/0day-ci/linux/commits/Hans-de-Goede/printk-For-early-boot-messages-check-loglevel-when-flushing-the-buffer/20180906-215356
config: parisc-allnoconfig (attached as .config)
compiler: hppa-linux-gnu-gcc (Debian 7.2.0-11) 7.2.0
reproduce:
wget
https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O
~/bin/make.cross
chmod +x ~/bin/make.cross
# save the attached .config to linux build tree
GCC_VERSION=7.2.0 make.cross ARCH=parisc
All errors (new ones prefixed by >>):
kernel/printk/printk.c: In function 'console_unlock':
>> kernel/printk/printk.c:2377:5: error: implicit declaration of function
>> 'suppress_message_printing' [-Werror=implicit-function-declaration]
suppress_message_printing(msg->level))) {
^
cc1: some warnings being treated as errors
vim +/suppress_message_printing +2377 kernel/printk/printk.c
2297
2298 /**
2299 * console_unlock - unlock the console system
2300 *
2301 * Releases the console_lock which the caller holds on the console
system
2302 * and the console driver list.
2303 *
2304 * While the console_lock was held, console output may have been
buffered
2305 * by printk(). If this is the case, console_unlock(); emits
2306 * the output prior to releasing the lock.
2307 *
2308 * If there is output waiting, we wake /dev/kmsg and syslog() users.
2309 *
2310 * console_unlock(); may be called from any context.
2311 */
2312 void console_unlock(void)
2313 {
2314 static char ext_text[CONSOLE_EXT_LOG_MAX];
2315 static char text[LOG_LINE_MAX + PREFIX_MAX];
2316 unsigned long flags;
2317 bool do_cond_resched, retry;
2318
2319 if (console_suspended) {
2320 up_console_sem();
2321 return;
2322 }
2323
2324 /*
2325 * Console drivers are called with interrupts disabled, so
2326 * @console_may_schedule should be cleared before; however, we
may
2327 * end up dumping a lot of lines, for example, if called from
2328 * console registration path, and should invoke cond_resched()
2329 * between lines if allowable. Not doing so can cause a very
long
2330 * scheduling stall on a slow console leading to RCU stall and
2331 * softlockup warnings which exacerbate the issue with more
2332 * messages practically incapacitating the system.
2333 *
2334 * console_trylock() is not able to detect the preemptive
2335 * context reliably. Therefore the value must be stored before
2336 * and cleared after the the "again" goto label.
2337 */
2338 do_cond_resched = console_may_schedule;
2339 again:
2340 console_may_schedule = 0;
2341
2342 /*
2343 * We released the console_sem lock, so we need to recheck if
2344 * cpu is online and (if not) is there at least one CON_ANYTIME
2345 * console.
2346 */
2347 if (!can_use_console()) {
2348 console_locked = 0;
2349 up_console_sem();
2350 return;
2351 }
2352
2353 for (;;) {
2354 struct printk_log *msg;
2355 size_t ext_len = 0;
2356 size_t len;
2357
2358 printk_safe_enter_irqsave(flags);
2359 raw_spin_lock(_lock);
2360 if (console_seq < log_first_seq) {
2361 len = sprintf(text, "** %u printk messages
dropped **\n",
2362(unsigned)(log_first_seq -
console_seq));
2363
2364 /* messages are gone, move to first one */
2365 console_seq = log_first_seq;
2366 console_idx = log_first_idx;
2367 } else {
2368 len = 0;
2369 }
2370 skip:
2371 if (console_seq == log_next_seq)
2372 break;
2373
2374 msg = log_from_idx(console_idx);
2375 if ((msg->flags & LOG_NOCONS) ||
2376 ((msg->flags & LOG_CHK_LEVEL) &&
> 2377 suppress_message_printing(msg->level)))
> {
2378 /*
2379 * Skip record if !ignore_loglevel, and
2380 * record has level above the console
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi Hans,
I love your patch! Yet something to improve:
[auto build test ERROR on linus/master]
[also build test ERROR on v4.19-rc2 next-20180906]
[if your patch is applied to the wrong git tree, please drop us a note to help
improve the system]
url:
https://github.com/0day-ci/linux/commits/Hans-de-Goede/printk-For-early-boot-messages-check-loglevel-when-flushing-the-buffer/20180906-215356
config: parisc-allnoconfig (attached as .config)
compiler: hppa-linux-gnu-gcc (Debian 7.2.0-11) 7.2.0
reproduce:
wget
https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O
~/bin/make.cross
chmod +x ~/bin/make.cross
# save the attached .config to linux build tree
GCC_VERSION=7.2.0 make.cross ARCH=parisc
All errors (new ones prefixed by >>):
kernel/printk/printk.c: In function 'console_unlock':
>> kernel/printk/printk.c:2377:5: error: implicit declaration of function
>> 'suppress_message_printing' [-Werror=implicit-function-declaration]
suppress_message_printing(msg->level))) {
^
cc1: some warnings being treated as errors
vim +/suppress_message_printing +2377 kernel/printk/printk.c
2297
2298 /**
2299 * console_unlock - unlock the console system
2300 *
2301 * Releases the console_lock which the caller holds on the console
system
2302 * and the console driver list.
2303 *
2304 * While the console_lock was held, console output may have been
buffered
2305 * by printk(). If this is the case, console_unlock(); emits
2306 * the output prior to releasing the lock.
2307 *
2308 * If there is output waiting, we wake /dev/kmsg and syslog() users.
2309 *
2310 * console_unlock(); may be called from any context.
2311 */
2312 void console_unlock(void)
2313 {
2314 static char ext_text[CONSOLE_EXT_LOG_MAX];
2315 static char text[LOG_LINE_MAX + PREFIX_MAX];
2316 unsigned long flags;
2317 bool do_cond_resched, retry;
2318
2319 if (console_suspended) {
2320 up_console_sem();
2321 return;
2322 }
2323
2324 /*
2325 * Console drivers are called with interrupts disabled, so
2326 * @console_may_schedule should be cleared before; however, we
may
2327 * end up dumping a lot of lines, for example, if called from
2328 * console registration path, and should invoke cond_resched()
2329 * between lines if allowable. Not doing so can cause a very
long
2330 * scheduling stall on a slow console leading to RCU stall and
2331 * softlockup warnings which exacerbate the issue with more
2332 * messages practically incapacitating the system.
2333 *
2334 * console_trylock() is not able to detect the preemptive
2335 * context reliably. Therefore the value must be stored before
2336 * and cleared after the the "again" goto label.
2337 */
2338 do_cond_resched = console_may_schedule;
2339 again:
2340 console_may_schedule = 0;
2341
2342 /*
2343 * We released the console_sem lock, so we need to recheck if
2344 * cpu is online and (if not) is there at least one CON_ANYTIME
2345 * console.
2346 */
2347 if (!can_use_console()) {
2348 console_locked = 0;
2349 up_console_sem();
2350 return;
2351 }
2352
2353 for (;;) {
2354 struct printk_log *msg;
2355 size_t ext_len = 0;
2356 size_t len;
2357
2358 printk_safe_enter_irqsave(flags);
2359 raw_spin_lock(_lock);
2360 if (console_seq < log_first_seq) {
2361 len = sprintf(text, "** %u printk messages
dropped **\n",
2362(unsigned)(log_first_seq -
console_seq));
2363
2364 /* messages are gone, move to first one */
2365 console_seq = log_first_seq;
2366 console_idx = log_first_idx;
2367 } else {
2368 len = 0;
2369 }
2370 skip:
2371 if (console_seq == log_next_seq)
2372 break;
2373
2374 msg = log_from_idx(console_idx);
2375 if ((msg->flags & LOG_NOCONS) ||
2376 ((msg->flags & LOG_CHK_LEVEL) &&
> 2377 suppress_message_printing(msg->level)))
> {
2378 /*
2379 * Skip record if !ignore_loglevel, and
2380 * record has level above the console
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-05 17:20:53, Hans de Goede wrote:
> HI,
>
> On 05-09-18 13:02, Petr Mladek wrote:
> > On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
> > > On (09/05/18 14:36), Sergey Senozhatsky wrote:
> > > >
> > > > Just a demonstration of the idea. It does not look very good, tho.
> > > > I'd rather have just one suppress_message_printing() in printk code.
> > > >
> > > > // This is not a proposed patch, hence the 80-cols violation.
> > > >
> > > > ---
> > > >
> > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > > index c036f128cdc3..231ac18423e1 100644
> > > > --- a/kernel/printk/printk.c
> > > > +++ b/kernel/printk/printk.c
> > > > @@ -2416,7 +2416,7 @@ void console_unlock(void)
> > > > break;
> > > > msg = log_from_idx(console_idx);
> > > > - if (msg->flags & LOG_NOCONS) {
> > > > + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> > > > suppress_message_printing(msg->level))) {
> > > > /*
> > > > * Skip record if !ignore_loglevel, and
> > > > * record has level above the console loglevel.
> > >
> > > D'oh... Sorry about that, but, believe it or not, this is completely
> > > not what I had in my mind. What I had, was something like this:
> > >
> > > ---
> > >
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index c036f128cdc3..dadb8c11b0d6 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -2416,6 +2416,11 @@ void console_unlock(void)
> > > break;
> > > msg = log_from_idx(console_idx);
> > > +
> > > + if (exclusive_console &&
> > > + !suppress_message_printing(msg->level))
> > > + msg->flags &= ~LOG_NOCONS;
> >
> > Hmm, this does not help with consoles without CON_PRINTBUFFER
> > flag. Note that the first registered console prints all messages
> > even without this flag.
> >
> > Also there is "debug" earlyparam where we need the opposite. I mean
> > that we want to show messages that were suppressed by default.
> >
> > I played with another solution, see the patch below. It defines
> > which messages have a valid NOCONS flag according to the msg_seq
> > number. IMHO, it is a bit more straightforward but it is still
> > a hack. I am not super happy about it.
> >
> >
> > Hmm, I seriously think about reverting the commit 375899cddcbb
> > ("printk: make sure to print log on console.") and solving it
> > another way.
> >
> > For example, the commit was primary about locations that
> > wanted to make some messages always visible or always
> > suppressed. We could create LOG_FORCE_NOCONS and
> > LOG_FORCE_CONS for these two special cases.
> >
> >
> >
> > Possible solution:
>
> So do you want me to give this solution a try or was this mainly for
> discussion purposes? If you've a fix which you think you are
> happy with and plan to merge I would be happy to try it.
It was rather for discussion purposes. I prefer the revert
for the moment.
If nobody comes with a better idea or is not against, I am going
to send the revert.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-05 17:20:53, Hans de Goede wrote:
> HI,
>
> On 05-09-18 13:02, Petr Mladek wrote:
> > On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
> > > On (09/05/18 14:36), Sergey Senozhatsky wrote:
> > > >
> > > > Just a demonstration of the idea. It does not look very good, tho.
> > > > I'd rather have just one suppress_message_printing() in printk code.
> > > >
> > > > // This is not a proposed patch, hence the 80-cols violation.
> > > >
> > > > ---
> > > >
> > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > > index c036f128cdc3..231ac18423e1 100644
> > > > --- a/kernel/printk/printk.c
> > > > +++ b/kernel/printk/printk.c
> > > > @@ -2416,7 +2416,7 @@ void console_unlock(void)
> > > > break;
> > > > msg = log_from_idx(console_idx);
> > > > - if (msg->flags & LOG_NOCONS) {
> > > > + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> > > > suppress_message_printing(msg->level))) {
> > > > /*
> > > > * Skip record if !ignore_loglevel, and
> > > > * record has level above the console loglevel.
> > >
> > > D'oh... Sorry about that, but, believe it or not, this is completely
> > > not what I had in my mind. What I had, was something like this:
> > >
> > > ---
> > >
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index c036f128cdc3..dadb8c11b0d6 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -2416,6 +2416,11 @@ void console_unlock(void)
> > > break;
> > > msg = log_from_idx(console_idx);
> > > +
> > > + if (exclusive_console &&
> > > + !suppress_message_printing(msg->level))
> > > + msg->flags &= ~LOG_NOCONS;
> >
> > Hmm, this does not help with consoles without CON_PRINTBUFFER
> > flag. Note that the first registered console prints all messages
> > even without this flag.
> >
> > Also there is "debug" earlyparam where we need the opposite. I mean
> > that we want to show messages that were suppressed by default.
> >
> > I played with another solution, see the patch below. It defines
> > which messages have a valid NOCONS flag according to the msg_seq
> > number. IMHO, it is a bit more straightforward but it is still
> > a hack. I am not super happy about it.
> >
> >
> > Hmm, I seriously think about reverting the commit 375899cddcbb
> > ("printk: make sure to print log on console.") and solving it
> > another way.
> >
> > For example, the commit was primary about locations that
> > wanted to make some messages always visible or always
> > suppressed. We could create LOG_FORCE_NOCONS and
> > LOG_FORCE_CONS for these two special cases.
> >
> >
> >
> > Possible solution:
>
> So do you want me to give this solution a try or was this mainly for
> discussion purposes? If you've a fix which you think you are
> happy with and plan to merge I would be happy to try it.
It was rather for discussion purposes. I prefer the revert
for the moment.
If nobody comes with a better idea or is not against, I am going
to send the revert.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
> On (09/05/18 13:02), Petr Mladek wrote:
> > Note that the first registered console prints all messages
> > even without this flag.
>
> Hmm, OK, interesting point.
>
> I assumed that the first console usually has CON_PRINTBUFFER bit set.
> Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
> makes sense to have CON_PRINTBUFFER for the first console. Any later
> consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
>
> And the first console has CON_PRINTBUFFER bit set. Well, just because
> it sounds reasonable. Those were the main assumptions behind my code
> snippet. Was any of those assumptions wrong?
This assumption makes sense. In fact, I was wrong. I thought that
console_seq/console_idx were not updated until the first console
was registered. But it is not the case.
It means that the hack with exclusive_console might be usable.
But I would prefer to do it a cleaner way.
> > I played with another solution, see the patch below. It defines
> > which messages have a valid NOCONS flag according to the msg_seq
> > number. IMHO, it is a bit more straightforward but it is still
> > a hack. I am not super happy about it.
>
> I just skimmed through it, and probably missed some parts. But I sort
> of expected to see some console_valid_nocons_seq manipulations in
> register_console(), when we register a new CON_PRINTBUFFER console
> on already running system.
I do not see any reason for this. If quiet/debug/loglevel kernel
parameters are proceed before register_console() call then
console_valid_nocons_seq is already set to the right sequence
number. Otherwise console_loglevel should be still the default
value and there is no reason to re-calculate nocons flag.
But it is rather complicated, still hacky, ...
> > Hmm, I seriously think about reverting the commit 375899cddcbb
> > ("printk: make sure to print log on console.") and solving it
> > another way.
>
> I can agree, definitely. That's one of the options.
I prefer the revert for now.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Thu 2018-09-06 16:29:40, Sergey Senozhatsky wrote:
> On (09/05/18 13:02), Petr Mladek wrote:
> > Note that the first registered console prints all messages
> > even without this flag.
>
> Hmm, OK, interesting point.
>
> I assumed that the first console usually has CON_PRINTBUFFER bit set.
> Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
> makes sense to have CON_PRINTBUFFER for the first console. Any later
> consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
>
> And the first console has CON_PRINTBUFFER bit set. Well, just because
> it sounds reasonable. Those were the main assumptions behind my code
> snippet. Was any of those assumptions wrong?
This assumption makes sense. In fact, I was wrong. I thought that
console_seq/console_idx were not updated until the first console
was registered. But it is not the case.
It means that the hack with exclusive_console might be usable.
But I would prefer to do it a cleaner way.
> > I played with another solution, see the patch below. It defines
> > which messages have a valid NOCONS flag according to the msg_seq
> > number. IMHO, it is a bit more straightforward but it is still
> > a hack. I am not super happy about it.
>
> I just skimmed through it, and probably missed some parts. But I sort
> of expected to see some console_valid_nocons_seq manipulations in
> register_console(), when we register a new CON_PRINTBUFFER console
> on already running system.
I do not see any reason for this. If quiet/debug/loglevel kernel
parameters are proceed before register_console() call then
console_valid_nocons_seq is already set to the right sequence
number. Otherwise console_loglevel should be still the default
value and there is no reason to re-calculate nocons flag.
But it is rather complicated, still hacky, ...
> > Hmm, I seriously think about reverting the commit 375899cddcbb
> > ("printk: make sure to print log on console.") and solving it
> > another way.
>
> I can agree, definitely. That's one of the options.
I prefer the revert for now.
Best Regards,
Petr
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 13:02), Petr Mladek wrote:
> Note that the first registered console prints all messages
> even without this flag.
Hmm, OK, interesting point.
I assumed that the first console usually has CON_PRINTBUFFER bit set.
Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
makes sense to have CON_PRINTBUFFER for the first console. Any later
consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
So by the time we have callable console "quite" param should be already
parsed [except the earlycon case perhaps]:
kernel_init_freeable
do_one_initcall
register_console
happens after
setup_arch
parse_early_param
quiet_kernel/debug_kernel.
And
setup_arch
parse_early_param
quiet_kernel/debug_kernel
happens before
console_init
con_init
register_console.
And the first console has CON_PRINTBUFFER bit set. Well, just because
it sounds reasonable. Those were the main assumptions behind my code
snippet. Was any of those assumptions wrong?
> I played with another solution, see the patch below. It defines
> which messages have a valid NOCONS flag according to the msg_seq
> number. IMHO, it is a bit more straightforward but it is still
> a hack. I am not super happy about it.
I just skimmed through it, and probably missed some parts. But I sort
of expected to see some console_valid_nocons_seq manipulations in
register_console(), when we register a new CON_PRINTBUFFER console
on already running system.
> Hmm, I seriously think about reverting the commit 375899cddcbb
> ("printk: make sure to print log on console.") and solving it
> another way.
I can agree, definitely. That's one of the options.
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 13:02), Petr Mladek wrote:
> Note that the first registered console prints all messages
> even without this flag.
Hmm, OK, interesting point.
I assumed that the first console usually has CON_PRINTBUFFER bit set.
Or even a CON_PRINTBUFFER | CON_ANYTIME combo. E.g. 8250. It sort of
makes sense to have CON_PRINTBUFFER for the first console. Any later
consoles [e.g. fbcon, netcon] don't necessarily have CON_PRINTBUFFER.
So by the time we have callable console "quite" param should be already
parsed [except the earlycon case perhaps]:
kernel_init_freeable
do_one_initcall
register_console
happens after
setup_arch
parse_early_param
quiet_kernel/debug_kernel.
And
setup_arch
parse_early_param
quiet_kernel/debug_kernel
happens before
console_init
con_init
register_console.
And the first console has CON_PRINTBUFFER bit set. Well, just because
it sounds reasonable. Those were the main assumptions behind my code
snippet. Was any of those assumptions wrong?
> I played with another solution, see the patch below. It defines
> which messages have a valid NOCONS flag according to the msg_seq
> number. IMHO, it is a bit more straightforward but it is still
> a hack. I am not super happy about it.
I just skimmed through it, and probably missed some parts. But I sort
of expected to see some console_valid_nocons_seq manipulations in
register_console(), when we register a new CON_PRINTBUFFER console
on already running system.
> Hmm, I seriously think about reverting the commit 375899cddcbb
> ("printk: make sure to print log on console.") and solving it
> another way.
I can agree, definitely. That's one of the options.
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
HI,
On 05-09-18 13:02, Petr Mladek wrote:
On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
On (09/05/18 14:36), Sergey Senozhatsky wrote:
Just a demonstration of the idea. It does not look very good, tho.
I'd rather have just one suppress_message_printing() in printk code.
// This is not a proposed patch, hence the 80-cols violation.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..231ac18423e1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,7 +2416,7 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (msg->flags & LOG_NOCONS || (exclusive_console &&
suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
D'oh... Sorry about that, but, believe it or not, this is completely
not what I had in my mind. What I had, was something like this:
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..dadb8c11b0d6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,6 +2416,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
+
+ if (exclusive_console &&
+ !suppress_message_printing(msg->level))
+ msg->flags &= ~LOG_NOCONS;
Hmm, this does not help with consoles without CON_PRINTBUFFER
flag. Note that the first registered console prints all messages
even without this flag.
Also there is "debug" earlyparam where we need the opposite. I mean
that we want to show messages that were suppressed by default.
I played with another solution, see the patch below. It defines
which messages have a valid NOCONS flag according to the msg_seq
number. IMHO, it is a bit more straightforward but it is still
a hack. I am not super happy about it.
Hmm, I seriously think about reverting the commit 375899cddcbb
("printk: make sure to print log on console.") and solving it
another way.
For example, the commit was primary about locations that
wanted to make some messages always visible or always
suppressed. We could create LOG_FORCE_NOCONS and
LOG_FORCE_CONS for these two special cases.
Possible solution:
So do you want me to give this solution a try or was this mainly for
discussion purposes? If you've a fix which you think you are
happy with and plan to merge I would be happy to try it.
Regards,
Hans
From c0fb2d83ca3ca0bab5e1de5a6e29a1b96756a530 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Wed, 5 Sep 2018 12:57:18 +0200
Subject: [RFC PATCH] printk: Possible solution for loglevel manipulation by
earlyparams
Early params that manipulate console_loglevel should invalidate
LOG_NOCONS flag for all the existing messages.
---
include/linux/console.h | 2 ++
init/main.c | 6 +++---
kernel/printk/printk.c | 27 +++
3 files changed, 28 insertions(+), 7 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3d7bab..3d3f7ab8f82e 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -195,6 +195,8 @@ extern bool console_suspend_enabled;
extern void suspend_console(void);
extern void resume_console(void);
+extern void console_set_default_loglevel(int loglevel);
+
int mda_console_init(void);
void prom_con_init(void);
diff --git a/init/main.c b/init/main.c
index 18f8f0140fa0..936466209494 100644
--- a/init/main.c
+++ b/init/main.c
@@ -213,13 +213,13 @@ EXPORT_SYMBOL(loops_per_jiffy);
static int __init debug_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_DEBUG);
return 0;
}
static int __init quiet_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_QUIET;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_QUIET);
return 0;
}
@@ -236,7 +236,7 @@ static int __init loglevel(char *str)
* are quite hard to debug
*/
if (get_option(, )) {
- console_loglevel = newlevel;
+ console_set_default_loglevel(newlevel);
return 0;
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 924e37fb1620..b5a0074302e9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -430,6 +430,9 @@ static u32 console_idx;
static u64 clear_seq;
static u32 clear_idx;
+/* Invalidate nocons flag setting before early param are proceed */
+static u64 console_valid_nocons_seq;
+
#define PREFIX_MAX32
#define LOG_LINE_MAX (1024 - PREFIX_MAX)
@@ -1148,11 +1151,19 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
"ignore
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
HI,
On 05-09-18 13:02, Petr Mladek wrote:
On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
On (09/05/18 14:36), Sergey Senozhatsky wrote:
Just a demonstration of the idea. It does not look very good, tho.
I'd rather have just one suppress_message_printing() in printk code.
// This is not a proposed patch, hence the 80-cols violation.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..231ac18423e1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,7 +2416,7 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (msg->flags & LOG_NOCONS || (exclusive_console &&
suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
D'oh... Sorry about that, but, believe it or not, this is completely
not what I had in my mind. What I had, was something like this:
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..dadb8c11b0d6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,6 +2416,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
+
+ if (exclusive_console &&
+ !suppress_message_printing(msg->level))
+ msg->flags &= ~LOG_NOCONS;
Hmm, this does not help with consoles without CON_PRINTBUFFER
flag. Note that the first registered console prints all messages
even without this flag.
Also there is "debug" earlyparam where we need the opposite. I mean
that we want to show messages that were suppressed by default.
I played with another solution, see the patch below. It defines
which messages have a valid NOCONS flag according to the msg_seq
number. IMHO, it is a bit more straightforward but it is still
a hack. I am not super happy about it.
Hmm, I seriously think about reverting the commit 375899cddcbb
("printk: make sure to print log on console.") and solving it
another way.
For example, the commit was primary about locations that
wanted to make some messages always visible or always
suppressed. We could create LOG_FORCE_NOCONS and
LOG_FORCE_CONS for these two special cases.
Possible solution:
So do you want me to give this solution a try or was this mainly for
discussion purposes? If you've a fix which you think you are
happy with and plan to merge I would be happy to try it.
Regards,
Hans
From c0fb2d83ca3ca0bab5e1de5a6e29a1b96756a530 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Wed, 5 Sep 2018 12:57:18 +0200
Subject: [RFC PATCH] printk: Possible solution for loglevel manipulation by
earlyparams
Early params that manipulate console_loglevel should invalidate
LOG_NOCONS flag for all the existing messages.
---
include/linux/console.h | 2 ++
init/main.c | 6 +++---
kernel/printk/printk.c | 27 +++
3 files changed, 28 insertions(+), 7 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3d7bab..3d3f7ab8f82e 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -195,6 +195,8 @@ extern bool console_suspend_enabled;
extern void suspend_console(void);
extern void resume_console(void);
+extern void console_set_default_loglevel(int loglevel);
+
int mda_console_init(void);
void prom_con_init(void);
diff --git a/init/main.c b/init/main.c
index 18f8f0140fa0..936466209494 100644
--- a/init/main.c
+++ b/init/main.c
@@ -213,13 +213,13 @@ EXPORT_SYMBOL(loops_per_jiffy);
static int __init debug_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_DEBUG);
return 0;
}
static int __init quiet_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_QUIET;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_QUIET);
return 0;
}
@@ -236,7 +236,7 @@ static int __init loglevel(char *str)
* are quite hard to debug
*/
if (get_option(, )) {
- console_loglevel = newlevel;
+ console_set_default_loglevel(newlevel);
return 0;
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 924e37fb1620..b5a0074302e9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -430,6 +430,9 @@ static u32 console_idx;
static u64 clear_seq;
static u32 clear_idx;
+/* Invalidate nocons flag setting before early param are proceed */
+static u64 console_valid_nocons_seq;
+
#define PREFIX_MAX32
#define LOG_LINE_MAX (1024 - PREFIX_MAX)
@@ -1148,11 +1151,19 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
"ignore
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
> On (09/05/18 14:36), Sergey Senozhatsky wrote:
> >
> > Just a demonstration of the idea. It does not look very good, tho.
> > I'd rather have just one suppress_message_printing() in printk code.
> >
> > // This is not a proposed patch, hence the 80-cols violation.
> >
> > ---
> >
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index c036f128cdc3..231ac18423e1 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -2416,7 +2416,7 @@ void console_unlock(void)
> > break;
> >
> > msg = log_from_idx(console_idx);
> > - if (msg->flags & LOG_NOCONS) {
> > + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> > suppress_message_printing(msg->level))) {
> > /*
> > * Skip record if !ignore_loglevel, and
> > * record has level above the console loglevel.
>
> D'oh... Sorry about that, but, believe it or not, this is completely
> not what I had in my mind. What I had, was something like this:
>
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..dadb8c11b0d6 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2416,6 +2416,11 @@ void console_unlock(void)
> break;
>
> msg = log_from_idx(console_idx);
> +
> + if (exclusive_console &&
> + !suppress_message_printing(msg->level))
> + msg->flags &= ~LOG_NOCONS;
Hmm, this does not help with consoles without CON_PRINTBUFFER
flag. Note that the first registered console prints all messages
even without this flag.
Also there is "debug" earlyparam where we need the opposite. I mean
that we want to show messages that were suppressed by default.
I played with another solution, see the patch below. It defines
which messages have a valid NOCONS flag according to the msg_seq
number. IMHO, it is a bit more straightforward but it is still
a hack. I am not super happy about it.
Hmm, I seriously think about reverting the commit 375899cddcbb
("printk: make sure to print log on console.") and solving it
another way.
For example, the commit was primary about locations that
wanted to make some messages always visible or always
suppressed. We could create LOG_FORCE_NOCONS and
LOG_FORCE_CONS for these two special cases.
Possible solution:
>From c0fb2d83ca3ca0bab5e1de5a6e29a1b96756a530 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Wed, 5 Sep 2018 12:57:18 +0200
Subject: [RFC PATCH] printk: Possible solution for loglevel manipulation by
earlyparams
Early params that manipulate console_loglevel should invalidate
LOG_NOCONS flag for all the existing messages.
---
include/linux/console.h | 2 ++
init/main.c | 6 +++---
kernel/printk/printk.c | 27 +++
3 files changed, 28 insertions(+), 7 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3d7bab..3d3f7ab8f82e 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -195,6 +195,8 @@ extern bool console_suspend_enabled;
extern void suspend_console(void);
extern void resume_console(void);
+extern void console_set_default_loglevel(int loglevel);
+
int mda_console_init(void);
void prom_con_init(void);
diff --git a/init/main.c b/init/main.c
index 18f8f0140fa0..936466209494 100644
--- a/init/main.c
+++ b/init/main.c
@@ -213,13 +213,13 @@ EXPORT_SYMBOL(loops_per_jiffy);
static int __init debug_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_DEBUG);
return 0;
}
static int __init quiet_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_QUIET;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_QUIET);
return 0;
}
@@ -236,7 +236,7 @@ static int __init loglevel(char *str)
* are quite hard to debug
*/
if (get_option(, )) {
- console_loglevel = newlevel;
+ console_set_default_loglevel(newlevel);
return 0;
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 924e37fb1620..b5a0074302e9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -430,6 +430,9 @@ static u32 console_idx;
static u64 clear_seq;
static u32 clear_idx;
+/* Invalidate nocons flag setting before early param are proceed */
+static u64 console_valid_nocons_seq;
+
#define PREFIX_MAX 32
#define LOG_LINE_MAX (1024 - PREFIX_MAX)
@@ -1148,11 +1151,19 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
"ignore loglevel setting (prints all kernel messages to the
console)");
-static bool suppress_message_printing(int level)
+static bool nocons_loglevel(int level)
{
return (level >=
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On Wed 2018-09-05 17:33:26, Sergey Senozhatsky wrote:
> On (09/05/18 14:36), Sergey Senozhatsky wrote:
> >
> > Just a demonstration of the idea. It does not look very good, tho.
> > I'd rather have just one suppress_message_printing() in printk code.
> >
> > // This is not a proposed patch, hence the 80-cols violation.
> >
> > ---
> >
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index c036f128cdc3..231ac18423e1 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -2416,7 +2416,7 @@ void console_unlock(void)
> > break;
> >
> > msg = log_from_idx(console_idx);
> > - if (msg->flags & LOG_NOCONS) {
> > + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> > suppress_message_printing(msg->level))) {
> > /*
> > * Skip record if !ignore_loglevel, and
> > * record has level above the console loglevel.
>
> D'oh... Sorry about that, but, believe it or not, this is completely
> not what I had in my mind. What I had, was something like this:
>
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..dadb8c11b0d6 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2416,6 +2416,11 @@ void console_unlock(void)
> break;
>
> msg = log_from_idx(console_idx);
> +
> + if (exclusive_console &&
> + !suppress_message_printing(msg->level))
> + msg->flags &= ~LOG_NOCONS;
Hmm, this does not help with consoles without CON_PRINTBUFFER
flag. Note that the first registered console prints all messages
even without this flag.
Also there is "debug" earlyparam where we need the opposite. I mean
that we want to show messages that were suppressed by default.
I played with another solution, see the patch below. It defines
which messages have a valid NOCONS flag according to the msg_seq
number. IMHO, it is a bit more straightforward but it is still
a hack. I am not super happy about it.
Hmm, I seriously think about reverting the commit 375899cddcbb
("printk: make sure to print log on console.") and solving it
another way.
For example, the commit was primary about locations that
wanted to make some messages always visible or always
suppressed. We could create LOG_FORCE_NOCONS and
LOG_FORCE_CONS for these two special cases.
Possible solution:
>From c0fb2d83ca3ca0bab5e1de5a6e29a1b96756a530 Mon Sep 17 00:00:00 2001
From: Petr Mladek
Date: Wed, 5 Sep 2018 12:57:18 +0200
Subject: [RFC PATCH] printk: Possible solution for loglevel manipulation by
earlyparams
Early params that manipulate console_loglevel should invalidate
LOG_NOCONS flag for all the existing messages.
---
include/linux/console.h | 2 ++
init/main.c | 6 +++---
kernel/printk/printk.c | 27 +++
3 files changed, 28 insertions(+), 7 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3d7bab..3d3f7ab8f82e 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -195,6 +195,8 @@ extern bool console_suspend_enabled;
extern void suspend_console(void);
extern void resume_console(void);
+extern void console_set_default_loglevel(int loglevel);
+
int mda_console_init(void);
void prom_con_init(void);
diff --git a/init/main.c b/init/main.c
index 18f8f0140fa0..936466209494 100644
--- a/init/main.c
+++ b/init/main.c
@@ -213,13 +213,13 @@ EXPORT_SYMBOL(loops_per_jiffy);
static int __init debug_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_DEBUG);
return 0;
}
static int __init quiet_kernel(char *str)
{
- console_loglevel = CONSOLE_LOGLEVEL_QUIET;
+ console_set_default_loglevel(CONSOLE_LOGLEVEL_QUIET);
return 0;
}
@@ -236,7 +236,7 @@ static int __init loglevel(char *str)
* are quite hard to debug
*/
if (get_option(, )) {
- console_loglevel = newlevel;
+ console_set_default_loglevel(newlevel);
return 0;
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 924e37fb1620..b5a0074302e9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -430,6 +430,9 @@ static u32 console_idx;
static u64 clear_seq;
static u32 clear_idx;
+/* Invalidate nocons flag setting before early param are proceed */
+static u64 console_valid_nocons_seq;
+
#define PREFIX_MAX 32
#define LOG_LINE_MAX (1024 - PREFIX_MAX)
@@ -1148,11 +1151,19 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
"ignore loglevel setting (prints all kernel messages to the
console)");
-static bool suppress_message_printing(int level)
+static bool nocons_loglevel(int level)
{
return (level >=
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 14:36), Sergey Senozhatsky wrote:
>
> Just a demonstration of the idea. It does not look very good, tho.
> I'd rather have just one suppress_message_printing() in printk code.
>
> // This is not a proposed patch, hence the 80-cols violation.
>
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..231ac18423e1 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2416,7 +2416,7 @@ void console_unlock(void)
> break;
>
> msg = log_from_idx(console_idx);
> - if (msg->flags & LOG_NOCONS) {
> + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> suppress_message_printing(msg->level))) {
> /*
>* Skip record if !ignore_loglevel, and
>* record has level above the console loglevel.
D'oh... Sorry about that, but, believe it or not, this is completely
not what I had in my mind. What I had, was something like this:
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..dadb8c11b0d6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,6 +2416,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
+
+ if (exclusive_console &&
+ !suppress_message_printing(msg->level))
+ msg->flags &= ~LOG_NOCONS;
+
if (msg->flags & LOG_NOCONS) {
/*
* Skip record if !ignore_loglevel, and
---
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 14:36), Sergey Senozhatsky wrote:
>
> Just a demonstration of the idea. It does not look very good, tho.
> I'd rather have just one suppress_message_printing() in printk code.
>
> // This is not a proposed patch, hence the 80-cols violation.
>
> ---
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c036f128cdc3..231ac18423e1 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2416,7 +2416,7 @@ void console_unlock(void)
> break;
>
> msg = log_from_idx(console_idx);
> - if (msg->flags & LOG_NOCONS) {
> + if (msg->flags & LOG_NOCONS || (exclusive_console &&
> suppress_message_printing(msg->level))) {
> /*
>* Skip record if !ignore_loglevel, and
>* record has level above the console loglevel.
D'oh... Sorry about that, but, believe it or not, this is completely
not what I had in my mind. What I had, was something like this:
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..dadb8c11b0d6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,6 +2416,11 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
+
+ if (exclusive_console &&
+ !suppress_message_printing(msg->level))
+ msg->flags &= ~LOG_NOCONS;
+
if (msg->flags & LOG_NOCONS) {
/*
* Skip record if !ignore_loglevel, and
---
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 14:36), Sergey Senozhatsky wrote: > > OK, thanks for the report! > So I think that your case is CON_PRINTBUFFER related as well. We have > a number of logbuf messages before we parse quiet and console_loglevel. > Those messages pass the suppress_message() test. Then when we finally > register a CON_PRINTBUFFER console we update console_loglevel and flush > all logbuf messages, but console_loglevel does not matter anymore. > Hmm, earlycon can also be affected, probably. But I'm not sure if people do "earlycon" and "quiet" at the same time. May be, who knows... -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 14:36), Sergey Senozhatsky wrote: > > OK, thanks for the report! > So I think that your case is CON_PRINTBUFFER related as well. We have > a number of logbuf messages before we parse quiet and console_loglevel. > Those messages pass the suppress_message() test. Then when we finally > register a CON_PRINTBUFFER console we update console_loglevel and flush > all logbuf messages, but console_loglevel does not matter anymore. > Hmm, earlycon can also be affected, probably. But I'm not sure if people do "earlycon" and "quiet" at the same time. May be, who knows... -ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 06:53), Hans de Goede wrote:
> >
> > Do you use earlycon?
>
> No, I'm seeing this with the regular/normal console stuff.
OK, thanks for the report!
So I think that your case is CON_PRINTBUFFER related as well. We have
a number of logbuf messages before we parse quiet and console_loglevel.
Those messages pass the suppress_message() test. Then when we finally
register a CON_PRINTBUFFER console we update console_loglevel and flush
all logbuf messages, but console_loglevel does not matter anymore.
> > > This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
> > > messages and doing the loglevel check for these while flushing as before.
> > >
> >
> > Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
> > the case that we sort of broke CON_PRINTBUFFER handling.
> >
> > console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
> > register CON_PRINTBUFFER console
> > -> no debug output
> >
> > So I think that when console_unlock() re-flushes already seen logbuf
> > messages to a newly registered exclusive [CON_PRINTBUFFER] console we
> > probably need to look at the current console_loglevel in console_unlock()
> > loop.
>
> So if it breaks quiet and the above use-case maybe we should revert
> 375899cddcbb for now?
Maybe all we need to do is to re-introduce suppress_message() check to
console_unlock() when we have exclusive console set (IOW, when we re-flush
logbuf messages to a CON_PRINTBUFFER console).
Just a demonstration of the idea. It does not look very good, tho.
I'd rather have just one suppress_message_printing() in printk code.
// This is not a proposed patch, hence the 80-cols violation.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..231ac18423e1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,7 +2416,7 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (msg->flags & LOG_NOCONS || (exclusive_console &&
suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
---
We are still early in 4.19 -rcs, let's wait a bit and hear from Steven
and Petr, they have bright ideas oftentimes.
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
On (09/05/18 06:53), Hans de Goede wrote:
> >
> > Do you use earlycon?
>
> No, I'm seeing this with the regular/normal console stuff.
OK, thanks for the report!
So I think that your case is CON_PRINTBUFFER related as well. We have
a number of logbuf messages before we parse quiet and console_loglevel.
Those messages pass the suppress_message() test. Then when we finally
register a CON_PRINTBUFFER console we update console_loglevel and flush
all logbuf messages, but console_loglevel does not matter anymore.
> > > This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
> > > messages and doing the loglevel check for these while flushing as before.
> > >
> >
> > Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
> > the case that we sort of broke CON_PRINTBUFFER handling.
> >
> > console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
> > register CON_PRINTBUFFER console
> > -> no debug output
> >
> > So I think that when console_unlock() re-flushes already seen logbuf
> > messages to a newly registered exclusive [CON_PRINTBUFFER] console we
> > probably need to look at the current console_loglevel in console_unlock()
> > loop.
>
> So if it breaks quiet and the above use-case maybe we should revert
> 375899cddcbb for now?
Maybe all we need to do is to re-introduce suppress_message() check to
console_unlock() when we have exclusive console set (IOW, when we re-flush
logbuf messages to a CON_PRINTBUFFER console).
Just a demonstration of the idea. It does not look very good, tho.
I'd rather have just one suppress_message_printing() in printk code.
// This is not a proposed patch, hence the 80-cols violation.
---
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c036f128cdc3..231ac18423e1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2416,7 +2416,7 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if (msg->flags & LOG_NOCONS || (exclusive_console &&
suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
---
We are still early in 4.19 -rcs, let's wait a bit and hear from Steven
and Petr, they have bright ideas oftentimes.
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On 05-09-18 04:35, Sergey Senozhatsky wrote:
Hi,
On (09/04/18 20:01), Hans de Goede wrote:
Commit 375899cddcbb ("printk: make sure to print log on console."), moved
the checking of the loglevel of messages from flush time to the actual
log time.
This introduces one problem, some early boot messages are printed before
parse_early_param() gets called and thus before kernel commandline options
such as quiet, loglevel and ignore_loglevel are parsed.
Do you use earlycon?
No, I'm seeing this with the regular/normal console stuff.
This causes e.g. the following messages to get printed on x86 systems,
despite the presence of the "quiet" option:
[0.00] BIOS-provided physical RAM map:
[0.00] BIOS-e820: [mem 0x-0x00057fff] usable
...
[0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
messages and doing the loglevel check for these while flushing as before.
Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
the case that we sort of broke CON_PRINTBUFFER handling.
console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
register CON_PRINTBUFFER console
-> no debug output
So I think that when console_unlock() re-flushes already seen logbuf
messages to a newly registered exclusive [CON_PRINTBUFFER] console we
probably need to look at the current console_loglevel in console_unlock()
loop.
So if it breaks quiet and the above use-case maybe we should revert
375899cddcbb for now?
Regards,
Hans
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On 05-09-18 04:35, Sergey Senozhatsky wrote:
Hi,
On (09/04/18 20:01), Hans de Goede wrote:
Commit 375899cddcbb ("printk: make sure to print log on console."), moved
the checking of the loglevel of messages from flush time to the actual
log time.
This introduces one problem, some early boot messages are printed before
parse_early_param() gets called and thus before kernel commandline options
such as quiet, loglevel and ignore_loglevel are parsed.
Do you use earlycon?
No, I'm seeing this with the regular/normal console stuff.
This causes e.g. the following messages to get printed on x86 systems,
despite the presence of the "quiet" option:
[0.00] BIOS-provided physical RAM map:
[0.00] BIOS-e820: [mem 0x-0x00057fff] usable
...
[0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
messages and doing the loglevel check for these while flushing as before.
Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
the case that we sort of broke CON_PRINTBUFFER handling.
console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
register CON_PRINTBUFFER console
-> no debug output
So I think that when console_unlock() re-flushes already seen logbuf
messages to a newly registered exclusive [CON_PRINTBUFFER] console we
probably need to look at the current console_loglevel in console_unlock()
loop.
So if it breaks quiet and the above use-case maybe we should revert
375899cddcbb for now?
Regards,
Hans
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On (09/04/18 20:01), Hans de Goede wrote:
> Commit 375899cddcbb ("printk: make sure to print log on console."), moved
> the checking of the loglevel of messages from flush time to the actual
> log time.
>
> This introduces one problem, some early boot messages are printed before
> parse_early_param() gets called and thus before kernel commandline options
> such as quiet, loglevel and ignore_loglevel are parsed.
Do you use earlycon?
> This causes e.g. the following messages to get printed on x86 systems,
> despite the presence of the "quiet" option:
>
> [0.00] BIOS-provided physical RAM map:
> [0.00] BIOS-e820: [mem 0x-0x00057fff] usable
> ...
> [0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
>
> This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
> messages and doing the loglevel check for these while flushing as before.
>
Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
the case that we sort of broke CON_PRINTBUFFER handling.
console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
register CON_PRINTBUFFER console
-> no debug output
So I think that when console_unlock() re-flushes already seen logbuf
messages to a newly registered exclusive [CON_PRINTBUFFER] console we
probably need to look at the current console_loglevel in console_unlock()
loop.
-ss
Re: [PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Hi,
On (09/04/18 20:01), Hans de Goede wrote:
> Commit 375899cddcbb ("printk: make sure to print log on console."), moved
> the checking of the loglevel of messages from flush time to the actual
> log time.
>
> This introduces one problem, some early boot messages are printed before
> parse_early_param() gets called and thus before kernel commandline options
> such as quiet, loglevel and ignore_loglevel are parsed.
Do you use earlycon?
> This causes e.g. the following messages to get printed on x86 systems,
> despite the presence of the "quiet" option:
>
> [0.00] BIOS-provided physical RAM map:
> [0.00] BIOS-e820: [mem 0x-0x00057fff] usable
> ...
> [0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
>
> This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
> messages and doing the loglevel check for these while flushing as before.
>
Hmm, OK, chances are we need to re-think 375899cddcbb. It might be
the case that we sort of broke CON_PRINTBUFFER handling.
console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH
register CON_PRINTBUFFER console
-> no debug output
So I think that when console_unlock() re-flushes already seen logbuf
messages to a newly registered exclusive [CON_PRINTBUFFER] console we
probably need to look at the current console_loglevel in console_unlock()
loop.
-ss
[PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Commit 375899cddcbb ("printk: make sure to print log on console."), moved
the checking of the loglevel of messages from flush time to the actual
log time.
This introduces one problem, some early boot messages are printed before
parse_early_param() gets called and thus before kernel commandline options
such as quiet, loglevel and ignore_loglevel are parsed.
This causes e.g. the following messages to get printed on x86 systems,
despite the presence of the "quiet" option:
[0.00] BIOS-provided physical RAM map:
[0.00] BIOS-e820: [mem 0x-0x00057fff] usable
...
[0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
messages and doing the loglevel check for these while flushing as before.
Cc: Petr Mladek
Cc: Maninder Singh
Fixes: 375899cddcbb ("printk: make sure to print log on console.")
Signed-off-by: Hans de Goede
---
kernel/printk/printk.c | 10 --
1 file changed, 8 insertions(+), 2 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..c5ffd46239a0 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -355,6 +355,7 @@ enum log_flags {
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
+ LOG_CHK_LEVEL = 16, /* check log level during flush */
};
struct printk_log {
@@ -1881,7 +1882,10 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
+ /* During early boot loglevel is not setup yet, check it later */
+ if (early_boot_irqs_disabled)
+ lflags |= LOG_CHK_LEVEL;
+ else if (suppress_message_printing(level))
lflags |= LOG_NOCONS;
return log_output(facility, level, lflags,
@@ -2368,7 +2372,9 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if ((msg->flags & LOG_NOCONS) ||
+ ((msg->flags & LOG_CHK_LEVEL) &&
+ suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
--
2.19.0.rc0
[PATCH 4.19 regression fix] printk: For early boot messages check loglevel when flushing the buffer
Commit 375899cddcbb ("printk: make sure to print log on console."), moved
the checking of the loglevel of messages from flush time to the actual
log time.
This introduces one problem, some early boot messages are printed before
parse_early_param() gets called and thus before kernel commandline options
such as quiet, loglevel and ignore_loglevel are parsed.
This causes e.g. the following messages to get printed on x86 systems,
despite the presence of the "quiet" option:
[0.00] BIOS-provided physical RAM map:
[0.00] BIOS-e820: [mem 0x-0x00057fff] usable
...
[0.00] BIOS-e820: [mem 0x0001-0x000874ff] usable
This commit fixes this by setting a new LOG_CHK_LEVEL on early boot
messages and doing the loglevel check for these while flushing as before.
Cc: Petr Mladek
Cc: Maninder Singh
Fixes: 375899cddcbb ("printk: make sure to print log on console.")
Signed-off-by: Hans de Goede
---
kernel/printk/printk.c | 10 --
1 file changed, 8 insertions(+), 2 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd6f8ed28e01..c5ffd46239a0 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -355,6 +355,7 @@ enum log_flags {
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
+ LOG_CHK_LEVEL = 16, /* check log level during flush */
};
struct printk_log {
@@ -1881,7 +1882,10 @@ int vprintk_store(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
- if (suppress_message_printing(level))
+ /* During early boot loglevel is not setup yet, check it later */
+ if (early_boot_irqs_disabled)
+ lflags |= LOG_CHK_LEVEL;
+ else if (suppress_message_printing(level))
lflags |= LOG_NOCONS;
return log_output(facility, level, lflags,
@@ -2368,7 +2372,9 @@ void console_unlock(void)
break;
msg = log_from_idx(console_idx);
- if (msg->flags & LOG_NOCONS) {
+ if ((msg->flags & LOG_NOCONS) ||
+ ((msg->flags & LOG_CHK_LEVEL) &&
+ suppress_message_printing(msg->level))) {
/*
* Skip record if !ignore_loglevel, and
* record has level above the console loglevel.
--
2.19.0.rc0
