2022-06-21 00:15:25

by John Ogness

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

On 2022-06-20, "Paul E. McKenney" <[email protected]> wrote:
> The rcutorture test suite produces quite a bit of console output
> at the end of a test. This means that the new 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().
>
> This commit therefore invokes pr_flush(1000, true) to flush this
> pending console output before invoking kernel_power_off().
>
> Fixes: 8e274732115f ("printk: extend console_lock for per-console locking")
> Cc: John Ogness <[email protected]>
> Signed-off-by: Paul E. McKenney <[email protected]>

Reviewed-by: John Ogness <[email protected]>


2022-06-21 00:18:29

by Paul E. McKenney

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

On Tue, Jun 21, 2022 at 01:29:04AM +0206, John Ogness wrote:
> On 2022-06-20, "Paul E. McKenney" <[email protected]> wrote:
> > The rcutorture test suite produces quite a bit of console output
> > at the end of a test. This means that the new 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().
> >
> > This commit therefore invokes pr_flush(1000, true) to flush this
> > pending console output before invoking kernel_power_off().
> >
> > Fixes: 8e274732115f ("printk: extend console_lock for per-console locking")
> > Cc: John Ogness <[email protected]>
> > Signed-off-by: Paul E. McKenney <[email protected]>
>
> Reviewed-by: John Ogness <[email protected]>

Thank you, John!

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

Thanx, Paul

2022-06-21 08:40:29

by John Ogness

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

On 2022-06-20, "Paul E. McKenney" <[email protected]> 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.

John Ogness

2022-06-21 18:28:25

by Paul E. McKenney

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

On Tue, Jun 21, 2022 at 10:15:29AM +0206, John Ogness wrote:
> On 2022-06-20, "Paul E. McKenney" <[email protected]> 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 <[email protected]>
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 <[email protected]>
Signed-off-by: Paul E. McKenney <[email protected]>

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;
}

2022-06-21 21:27:12

by John Ogness

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

On 2022-06-21, "Paul E. McKenney" <[email protected]> wrote:
> 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?

I feel like this is dirtying the torture.* bootarg namespace a
bit. Also, I am not sure how useful it is as a dynamic option. I assume
that users would generally avoid using it, so its very existence might
just be more noise in the documentation and code. It is an unusual
feature:

"In case some bug shows up, here is a flag to avoid it."

I personally would just drop the patch and rely on a correctly
functional kernel. But I am also not an rcutorture user. If _you_ think
that such a flag is useful, feel free to include the patch.

> commit 204bf1e2a5a2fb68c15b4b64793ad0896db6f705
> Author: Paul E. McKenney <[email protected]>
> 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 <[email protected]>
> Signed-off-by: Paul E. McKenney <[email protected]>

Reviewed-by: John Ogness <[email protected]>