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

[Paul E. McKenney]

On Wed, Feb 05, 2025 at 10:28:06PM +0106, John Ogness wrote:
> 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.

I picked 500ms randomly, so I am happy to make it be 1000ms.

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

OK, so I don't need to add "if (IS_ENABLED(CONFIG_PREEMPT_RT))" to guard
it, then?

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

Sounds eminently reasonable to me!

> > ------------------------------------------------------------------------
> >
> > 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.

Thank you, will do!

> >  #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.

Hey, of the two of us, you are the printk() expert, so I will make it
be 1000.  ;-)

							Thanx, Paul

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