On Thu, Sep 01, 2022 at 11:18:20AM +0206, John Ogness wrote:
> Added CC the rest of the printk folks since this would be the first use
> of pr_flush() outside of the printk subsystem. And it is a controversial
> usage, since it is used to work around potential (future) bugs in
> printk.
>
> On 2022-08-31, "Paul E. McKenney" <paulmck@kernel.org> wrote:
> > The rcutorture test suite produces quite a bit of console output at
> > the end of a test. This means that the new-in-2022 printk() kthreads
> > are likely to be in the process of flushing output at the time of the
> > torture_shutdown() function's call to kernel_power_off(). Normally,
> > rcutorture relies on printk() to flush any pending output upon shutdown,
> > the better to detect bugs in this area, for example, the one introduced
> > by 8e274732115f ("printk: extend console_lock for per-console locking").
> > However, once such a bug is detected and reported, it is necessary to
> > test the rest of the system, without noise from the already-reported bug.
>
> Since the printk kthread implementation has been reverted, this is no
> longer an issue. When a kthread implementation is re-introduced, this
> issue will need to have been considered and handled.
>
> IMHO this patch is premature at this time and hopefully will never
> become necessary (in the form of a bug workaround).
Very well, I will drop it, for the time being, anyway. ;-)
Thanx, Paul
> > This commit therefore adds a torture.printk_shutdown_bug_workaround
> > kernel parameter, which causes torture_shutdown() to invoke pr_flush(),
> > and print an informative message on the console, immediately before
> > invoking kernel_power_off(). When this kernel parameter is not specified,
> > it is up to printk() to flush its own buffers.
> >
> > Suggested-by: John Ogness <john.ogness@linutronix.de>
> > Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
> > ---
> > Documentation/admin-guide/kernel-parameters.txt | 6 ++++++
> > kernel/torture.c | 7 +++++++
> > 2 files changed, 13 insertions(+)
> >
> > diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> > index d7f30902fda02..ba1b8776aab83 100644
> > --- a/Documentation/admin-guide/kernel-parameters.txt
> > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > @@ -6143,6 +6143,12 @@
> > are running concurrently, especially on systems
> > with rotating-rust storage.
> >
> > + torture.printk_shutdown_bug_workaround= [KNL]
> > + Execute pr_flush(1000, true) just before invoking
> > + kernel_power_off() to work around any bugs that
> > + might prevent printk() from flushing its buffers
> > + at shutdown time.
> > +
> > torture.verbose_sleep_frequency= [KNL]
> > Specifies how many verbose printk()s should be
> > emitted between each sleep. The default of zero
> > diff --git a/kernel/torture.c b/kernel/torture.c
> > index 789aeb0e1159c..7cd2016b02076 100644
> > --- a/kernel/torture.c
> > +++ b/kernel/torture.c
> > @@ -48,6 +48,9 @@ module_param(disable_onoff_at_boot, bool, 0444);
> > static bool ftrace_dump_at_shutdown;
> > module_param(ftrace_dump_at_shutdown, bool, 0444);
> >
> > +static bool printk_shutdown_bug_workaround;
> > +module_param(printk_shutdown_bug_workaround, bool, 0444);
> > +
> > static int verbose_sleep_frequency;
> > module_param(verbose_sleep_frequency, int, 0444);
> >
> > @@ -651,6 +654,10 @@ static int torture_shutdown(void *arg)
> > VERBOSE_TOROUT_STRING("No torture_shutdown_hook(), skipping.");
> > if (ftrace_dump_at_shutdown)
> > rcu_ftrace_dump(DUMP_ALL);
> > + if (printk_shutdown_bug_workaround) {
> > + pr_info("%s: Flushing printk() buffers at power-down time.\n", __func__);
> > + pr_flush(1000, true);
> > + }
> > kernel_power_off(); /* Shut down the system. */
> > return 0;
> > }
> > --
> > 2.31.1.189.g2e36527f23
>
> John Ogness