Re: [PATCH rcu v2] 4/5] rcu-tasks: Move RCU Tasks self-tests to core_initcall()

[John Ogness]

On 2025-02-05, "Paul E. McKenney" <paulmck@xxxxxxxxxx> wrote:
>> Would it make sense to put a call to pr_flush() at the beginning of the
>> kernel_power_off() function?  I suspect that would take care of much
>> more than just rcutorture.
>> 
>> Or maybe after the pr_emerg("Power down\n"), since that is normally
>> the last thing that shows up on rcutorture's console logs.

Yes, after the pr_emerg("Power down\n"), as in your patch below.

> And that does the trick!  I specified 500ms, but maybe -1 would be
> better?  You tell me!  ;-)

I probably would have chosen 1000ms, but if the kthread has made no
forward progress after a few max timeslices, it probably is dead or will
not be scheduled anyway.

If there is no backlog, pr_flush() returns immediately.

I recommend _not_ using timeout_ms=-1 here, in case the kthread cannot
be scheduled (for whatever reason).

> ------------------------------------------------------------------------
>
> commit 172b692a79ec5801eab57cb55d2f9c398f244c62
> Author: Paul E. McKenney <paulmck@xxxxxxxxxx>
> Date:   Wed Feb 5 12:27:23 2025 -0800
>
>     printk: Flush console log from kernel_power_off()
>     
>     Kernels built with CONFIG_PREEMPT_RT=y can lose significant console output
>     and shutdown time, which hides shutdown-time RCU issues from rcutorture.
>     Therefore, make pr_flush() public and invoke it after then last print
>     in kernel_power_off().
>     
>     Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxx>
>     Cc: Petr Mladek <pmladek@xxxxxxxx>
>     Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
>     Cc: John Ogness <john.ogness@xxxxxxxxxxxxx>
>     Cc: Sergey Senozhatsky <senozhatsky@xxxxxxxxxxxx>
>
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index 4217a9f412b2..b3e88ff1ecc3 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -806,4 +806,6 @@ static inline void print_hex_dump_debug(const char *prefix_str, int prefix_type,
>  #define print_hex_dump_bytes(prefix_str, prefix_type, buf, len)	\
>  	print_hex_dump_debug(prefix_str, prefix_type, 16, 1, buf, len, true)
>  
> +
> +bool pr_flush(int timeout_ms, bool reset_on_progress);

This will fail to link for !CONFIG_PRINTK.

In kernel/printk/printk.c currently there is:

#ifdef CONFIG_PRINTK
static bool pr_flush(int timeout_ms, bool reset_on_progress);
#else
static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
#endif

This would need to move to include/linux/printk.h

There you will find an existing CONFIG_PRINTK if/else block to move
those to.

>  #endif
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 80910bc3470c..e0c6e5a99897 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2461,7 +2461,7 @@ asmlinkage __visible int _printk(const char *fmt, ...)
>  }
>  EXPORT_SYMBOL(_printk);
>  
> -static bool pr_flush(int timeout_ms, bool reset_on_progress);
> +bool pr_flush(int timeout_ms, bool reset_on_progress);
>  static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress);
>  
>  #else /* CONFIG_PRINTK */
> @@ -4466,7 +4466,7 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
>   * Context: Process context. May sleep while acquiring console lock.
>   * Return: true if all usable printers are caught up.
>   */
> -static bool pr_flush(int timeout_ms, bool reset_on_progress)
> +bool pr_flush(int timeout_ms, bool reset_on_progress)
>  {
>  	return __pr_flush(NULL, timeout_ms, reset_on_progress);
>  }
> diff --git a/kernel/reboot.c b/kernel/reboot.c
> index a701000bab34..3448e6ae3556 100644
> --- a/kernel/reboot.c
> +++ b/kernel/reboot.c
> @@ -704,6 +704,7 @@ void kernel_power_off(void)
>  	migrate_to_reboot_cpu();
>  	syscore_shutdown();
>  	pr_emerg("Power down\n");
> +	pr_flush(500, 1);

I would have chosen:

	pr_flush(1000, true);

but I really don't have an argument either way.

>  	kmsg_dump(KMSG_DUMP_SHUTDOWN);
>  	machine_power_off();
>  }

John Ogness