Re: [PATCH rcu 11/12] torture: Flush printk() buffers before powering off

From: Paul E. McKenney
Date: Tue Jun 21 2022 - 14:13:40 EST


On Tue, Jun 21, 2022 at 10:15:29AM +0206, John Ogness wrote:
> On 2022-06-20, "Paul E. McKenney" <paulmck@xxxxxxxxxx> wrote:
> > But given Petr's and your recent changes that are now in mainline, is
> > this still really needed? (Tests now pass without it, though tests can
> > of course be misleading.)
>
> If all you are interested is if your rcutorture testing was successful,
> then I would keep this change. Then, no matter what the kernel does
> afterwards, you have your test results.
>
> However, the kernel should correctly shutdown and it should flush the
> kernel buffers on shutdown or crash. (It is a kernel bug otherwise.) So
> if you also want to implicitly test this (non-rcutorture) functionality,
> then you should not use this patch.

Why not both? ;-)

The patch below will cause rcutorture to implicitly test this
functionality, unless told otherwise, for example, by using the
--bootargs "torture.printk_shutdown_bug_workaround" kvm.sh
argument.

Thoughts?

Thanx, Paul

------------------------------------------------------------------------

commit 204bf1e2a5a2fb68c15b4b64793ad0896db6f705
Author: Paul E. McKenney <paulmck@xxxxxxxxxx>
Date: Tue Jun 21 11:02:25 2022 -0700

torture: Optionally flush printk() buffers before powering off

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.

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@xxxxxxxxxxxxx>
Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxx>

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index d8de18d8f8875..652f49c4e5990 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -6045,6 +6045,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;
}