[PATCH] pstore: Fix printing of duplicate boot messages to console

[PATCH] pstore: Fix printing of duplicate boot messages to console

[Sai Prakash Ranjan]

Since commit f92b070f2dc8 ("printk: Do not miss new messages
when replaying the log"), CON_PRINTBUFFER flag causes the
duplicate boot messages to be printed on the console when
PSTORE_CONSOLE and earlycon (boot console) is enabled.
Pstore console registers to boot console when earlycon is
enabled during pstore_register_console as a part of ramoops
initialization in postcore_initcall and the printk core
checks for CON_PRINTBUFFER flag and replays the log buffer
to registered console (in this case pstore console which
just registered to boot console) causing duplicate messages
to be printed. Remove the CON_PRINTBUFFER flag from pstore
console since pstore is not concerned with the printing of
buffer to console but with writing of the buffer to the
backend.

Console log with earlycon and pstore console enabled:

[    0.008342] Console: colour dummy device 80x25
[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
...
[    1.244049] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]

Fixes: f92b070f2dc8 ("printk: Do not miss new messages when replaying the log")
Reported-by: Douglas Anderson <dianders@chromium.org>
Signed-off-by: Sai Prakash Ranjan <saiprakash.ranjan@codeaurora.org>
---
 fs/pstore/platform.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index d896457e7c11..271b00db0973 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -505,7 +505,7 @@ static void pstore_console_write(struct console *con, const char *s, unsigned c)
 static struct console pstore_console = {
 	.name	= "pstore",
 	.write	= pstore_console_write,
-	.flags	= CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME,
+	.flags	= CON_ENABLED | CON_ANYTIME,
 	.index	= -1,
 };
 
-- 
QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member
of Code Aurora Forum, hosted by The Linux Foundation

Re: [PATCH] pstore: Fix printing of duplicate boot messages to console

[Stephen Boyd]

Quoting Sai Prakash Ranjan (2020-01-23 08:00:31)
> Since commit f92b070f2dc8 ("printk: Do not miss new messages
> when replaying the log"), CON_PRINTBUFFER flag causes the
> duplicate boot messages to be printed on the console when
> PSTORE_CONSOLE and earlycon (boot console) is enabled.
> Pstore console registers to boot console when earlycon is
> enabled during pstore_register_console as a part of ramoops
> initialization in postcore_initcall and the printk core
> checks for CON_PRINTBUFFER flag and replays the log buffer
> to registered console (in this case pstore console which
> just registered to boot console) causing duplicate messages
> to be printed. Remove the CON_PRINTBUFFER flag from pstore
> console since pstore is not concerned with the printing of
> buffer to console but with writing of the buffer to the
> backend.
> 
> Console log with earlycon and pstore console enabled:
> 
> [    0.008342] Console: colour dummy device 80x25
> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
> ...
> [    1.244049] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
> 
> Fixes: f92b070f2dc8 ("printk: Do not miss new messages when replaying the log")
> Reported-by: Douglas Anderson <dianders@chromium.org>
> Signed-off-by: Sai Prakash Ranjan <saiprakash.ranjan@codeaurora.org>
> ---

While I like the idea, it seems that this breaks console-ramoops by
removing all the text that is printed in the kernel log before this
console is registered. I reboot and see that
/sys/fs/pstore/console-ramoops-1 starts like this now:

	localhost ~ # cat /sys/fs/pstore/console-ramoops-0
	[    0.943472] printk: console [pstore-1] enabled

Maybe this console can be "special" and not require anything to be
printed out to visible consoles but still get the entire log contents?
Or we should just not worry about it.

Re: [PATCH] pstore: Fix printing of duplicate boot messages to console

[Sai Prakash Ranjan]

On 2020-01-24 01:19, Stephen Boyd wrote:
> Quoting Sai Prakash Ranjan (2020-01-23 08:00:31)
>> Since commit f92b070f2dc8 ("printk: Do not miss new messages
>> when replaying the log"), CON_PRINTBUFFER flag causes the
>> duplicate boot messages to be printed on the console when
>> PSTORE_CONSOLE and earlycon (boot console) is enabled.
>> Pstore console registers to boot console when earlycon is
>> enabled during pstore_register_console as a part of ramoops
>> initialization in postcore_initcall and the printk core
>> checks for CON_PRINTBUFFER flag and replays the log buffer
>> to registered console (in this case pstore console which
>> just registered to boot console) causing duplicate messages
>> to be printed. Remove the CON_PRINTBUFFER flag from pstore
>> console since pstore is not concerned with the printing of
>> buffer to console but with writing of the buffer to the
>> backend.
>> 
>> Console log with earlycon and pstore console enabled:
>> 
>> [    0.008342] Console: colour dummy device 80x25
>> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
>> ...
>> [    1.244049] hw-breakpoint: found 6 breakpoint and 4 watchpoint 
>> registers.
>> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
>> 
>> Fixes: f92b070f2dc8 ("printk: Do not miss new messages when replaying 
>> the log")
>> Reported-by: Douglas Anderson <dianders@chromium.org>
>> Signed-off-by: Sai Prakash Ranjan <saiprakash.ranjan@codeaurora.org>
>> ---
> 
> While I like the idea, it seems that this breaks console-ramoops by
> removing all the text that is printed in the kernel log before this
> console is registered. I reboot and see that
> /sys/fs/pstore/console-ramoops-1 starts like this now:
> 
> 	localhost ~ # cat /sys/fs/pstore/console-ramoops-0
> 	[    0.943472] printk: console [pstore-1] enabled
> 
> Maybe this console can be "special" and not require anything to be
> printed out to visible consoles but still get the entire log contents?
> Or we should just not worry about it.

Thanks for testing this out Stephen, I should have tested this some 
more.
Lets drop this patch.

-Sai

-- 
QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a 
member
of Code Aurora Forum, hosted by The Linux Foundation

Re: [PATCH] pstore: Fix printing of duplicate boot messages to console

[Kees Cook]

On Thu, Jan 23, 2020 at 09:30:31PM +0530, Sai Prakash Ranjan wrote:
> Since commit f92b070f2dc8 ("printk: Do not miss new messages
> when replaying the log"), CON_PRINTBUFFER flag causes the
> duplicate boot messages to be printed on the console when
> PSTORE_CONSOLE and earlycon (boot console) is enabled.
> Pstore console registers to boot console when earlycon is
> enabled during pstore_register_console as a part of ramoops
> initialization in postcore_initcall and the printk core
> checks for CON_PRINTBUFFER flag and replays the log buffer
> to registered console (in this case pstore console which
> just registered to boot console) causing duplicate messages
> to be printed. Remove the CON_PRINTBUFFER flag from pstore
> console since pstore is not concerned with the printing of
> buffer to console but with writing of the buffer to the
> backend.

I agree this patch isn't the solution, but I'm trying to understand
where better logic could be added. Is the issue that printk sees both
earlycon and CON_PRINTBUFFER active? Can we add a new CON_* flag that
means "not actually printing anything"? (Or maybe a new flag for
non-printing to replace CON_PRINTBUFFER that lets pstore still work?)

-Kees

> 
> Console log with earlycon and pstore console enabled:
> 
> [    0.008342] Console: colour dummy device 80x25
> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
> ...
> [    1.244049] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x51df805e]
> 
> Fixes: f92b070f2dc8 ("printk: Do not miss new messages when replaying the log")
> Reported-by: Douglas Anderson <dianders@chromium.org>
> Signed-off-by: Sai Prakash Ranjan <saiprakash.ranjan@codeaurora.org>
> ---
>  fs/pstore/platform.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
> index d896457e7c11..271b00db0973 100644
> --- a/fs/pstore/platform.c
> +++ b/fs/pstore/platform.c
> @@ -505,7 +505,7 @@ static void pstore_console_write(struct console *con, const char *s, unsigned c)
>  static struct console pstore_console = {
>  	.name	= "pstore",
>  	.write	= pstore_console_write,
> -	.flags	= CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME,
> +	.flags	= CON_ENABLED | CON_ANYTIME,
>  	.index	= -1,
>  };
>  
> -- 
> QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member
> of Code Aurora Forum, hosted by The Linux Foundation

-- 
Kees Cook

Re: [PATCH] pstore: Fix printing of duplicate boot messages to console

[Stephen Boyd]

Quoting Kees Cook (2020-01-27 15:27:33)
> On Thu, Jan 23, 2020 at 09:30:31PM +0530, Sai Prakash Ranjan wrote:
> > Since commit f92b070f2dc8 ("printk: Do not miss new messages
> > when replaying the log"), CON_PRINTBUFFER flag causes the
> > duplicate boot messages to be printed on the console when
> > PSTORE_CONSOLE and earlycon (boot console) is enabled.
> > Pstore console registers to boot console when earlycon is
> > enabled during pstore_register_console as a part of ramoops
> > initialization in postcore_initcall and the printk core
> > checks for CON_PRINTBUFFER flag and replays the log buffer
> > to registered console (in this case pstore console which
> > just registered to boot console) causing duplicate messages
> > to be printed. Remove the CON_PRINTBUFFER flag from pstore
> > console since pstore is not concerned with the printing of
> > buffer to console but with writing of the buffer to the
> > backend.
> 
> I agree this patch isn't the solution, but I'm trying to understand
> where better logic could be added. Is the issue that printk sees both
> earlycon and CON_PRINTBUFFER active? Can we add a new CON_* flag that
> means "not actually printing anything"? (Or maybe a new flag for
> non-printing to replace CON_PRINTBUFFER that lets pstore still work?)
> 

This seems to be fixed by commit def97da13651 ("printk: fix
exclusive_console replaying"). I think there's nothing to do.