[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <5aae210e-2553-57ca-e4d5-0b0f20ec92cd@redhat.com>
Date: Mon, 13 Jun 2022 12:01:24 -0400
From: Waiman Long <longman@...hat.com>
To: paulmck@...nel.org
Cc: Frederic Weisbecker <frederic@...nel.org>,
Neeraj Upadhyay <quic_neeraju@...cinc.com>,
Josh Triplett <josh@...htriplett.org>,
Steven Rostedt <rostedt@...dmis.org>,
Mathieu Desnoyers <mathieu.desnoyers@...icios.com>,
Lai Jiangshan <jiangshanlai@...il.com>,
Joel Fernandes <joel@...lfernandes.org>, rcu@...r.kernel.org,
linux-kernel@...r.kernel.org,
"Uladzislau Rezki (Sony)" <urezki@...il.com>
Subject: Re: [PATCH] rcu-tasks: Delay rcu_tasks_verify_self_tests() to avoid
missed callbacks
On 6/10/22 16:58, Paul E. McKenney wrote:
> On Fri, Jun 10, 2022 at 02:42:12PM -0400, Waiman Long wrote:
>> Even though rcu_tasks selftest is initiated early in the boot process,
>> the verification done at late initcall time may not be late enough to
>> catch all the callbacks especially on systems with just a few cpus and
>> small memory.
>>
>> After 12 bootup's On a s390x system, 1 of them had failed rcu_tasks
>> verification test.
>>
>> [ 8.183013] call_rcu_tasks() has been failed.
>> [ 8.183041] WARNING: CPU: 0 PID: 1 at kernel/rcu/tasks.h:1696 rcu_tasks_verify_self_tests+0x64/0xd0
>> [ 8.203246] Callback from call_rcu_tasks() invoked.
>>
>> In this particular case, the callback missed the check by about
>> 20ms. Similar rcu_tasks selftest failures are also seen in ppc64le
>> systems.
>>
>> [ 0.313391] call_rcu_tasks() has been failed.
>> [ 0.313407] WARNING: CPU: 0 PID: 1 at kernel/rcu/tasks.h:1696 rcu_tasks_verify_self_tests+0x5c/0xa0
>> [ 0.335569] Callback from call_rcu_tasks() invoked.
>>
>> Avoid this missed callback by delaying the verification using
>> delayed_work. The delay is set to be about 0.1s which hopefully will
>> be long enough to catch all the callbacks on systems with few cpus and
>> small memory.
>>
>> Fixes: bfba7ed084f8 ("rcu-tasks: Add RCU-tasks self tests")
>> Signed-off-by: Waiman Long <longman@...hat.com>
> Good catch, thank you!
>
> A few days ago, I queued this:
>
> 2585014188d5 ("rcu-tasks: Be more patient for RCU Tasks boot-time testing")
>
> This is shown in full at the end of this email. Does this fix this
> problem for you?
I think your patch should fix the false positive warning and it give
plenty of time for this to happen.
I do have one question though. rcu_tasks_verify_selft_tests() is called
from do_initcalls(). Since it may not be the last late initcall, does
that mean other late initcalls queued after that may be delayed by a
second or more?
Thanks,
Longman
> Thanx, Paul
>
>> ---
>> kernel/rcu/tasks.h | 19 ++++++++++++++++---
>> 1 file changed, 16 insertions(+), 3 deletions(-)
>>
>> diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
>> index 3925e32159b5..25f964a671ba 100644s
>> --- a/kernel/rcu/tasks.h
>> +++ b/kernel/rcu/tasks.h
>> @@ -1735,7 +1735,7 @@ static void rcu_tasks_initiate_self_tests(void)
>> #endif
>> }
>>
>> -static int rcu_tasks_verify_self_tests(void)
>> +static void rcu_tasks_verify_self_tests(struct work_struct *work __maybe_unused)
>> {
>> int ret = 0;
>> int i;
>> @@ -1749,10 +1749,23 @@ static int rcu_tasks_verify_self_tests(void)
>>
>> if (ret)
>> WARN_ON(1);
>> +}
>> +
>> +static struct delayed_work rcu_tasks_verify_work;
>>
>> - return ret;
>> +/*
>> + * The rcu_tasks verification is done indirectly via the work queue to
>> + * introduce an additional 0.1s delay to catch all the callbacks before
>> + * the verification is done as late_initcall time may not be late enough
>> + * to have all the callbacks fired.
>> + */
>> +static int rcu_tasks_verify_schedule_work(void)
>> +{
>> + INIT_DELAYED_WORK(&rcu_tasks_verify_work, rcu_tasks_verify_self_tests);
>> + schedule_delayed_work(&rcu_tasks_verify_work, HZ/10);
>> + return 0;
>> }
>> -late_initcall(rcu_tasks_verify_self_tests);
>> +late_initcall(rcu_tasks_verify_schedule_work);
>> #else /* #ifdef CONFIG_PROVE_RCU */
>> static void rcu_tasks_initiate_self_tests(void) { }
>> #endif /* #else #ifdef CONFIG_PROVE_RCU */
>> --
>> 2.31.1
> ------------------------------------------------------------------------
>
> commit 2585014188d5e66052b4226b42602b6f3d921389
> Author: Paul E. McKenney <paulmck@...nel.org>
> Date: Tue Jun 7 15:23:52 2022 -0700
>
> rcu-tasks: Be more patient for RCU Tasks boot-time testing
>
> The RCU-Tasks family of grace-period primitives can take some time to
> complete, and the amount of time can depend on the exact hardware and
> software configuration. Some configurations boot up fast enough that the
> RCU-Tasks verification process gets false-positive failures. This commit
> therefore allows up to 30 seconds for the grace periods to complete, with
> this value adjustable downwards using the rcupdate.rcu_task_stall_timeout
> kernel boot parameter.
>
> Reported-by: Matthew Wilcox <willy@...radead.org>
> Reported-by: Zhouyi Zhou <zhouzhouyi@...il.com>
> Signed-off-by: Paul E. McKenney <paulmck@...nel.org>
> Tested-by: Zhouyi Zhou <zhouzhouyi@...il.com>
>
> diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
> index df6b2cb2f205d..fcbd0ec33c866 100644
> --- a/kernel/rcu/tasks.h
> +++ b/kernel/rcu/tasks.h
> @@ -145,6 +145,7 @@ static int rcu_task_ipi_delay __read_mostly = RCU_TASK_IPI_DELAY;
> module_param(rcu_task_ipi_delay, int, 0644);
>
> /* Control stall timeouts. Disable with <= 0, otherwise jiffies till stall. */
> +#define RCU_TASK_BOOT_STALL_TIMEOUT (HZ * 30)
> #define RCU_TASK_STALL_TIMEOUT (HZ * 60 * 10)
> static int rcu_task_stall_timeout __read_mostly = RCU_TASK_STALL_TIMEOUT;
> module_param(rcu_task_stall_timeout, int, 0644);
> @@ -1776,23 +1777,24 @@ struct rcu_tasks_test_desc {
> struct rcu_head rh;
> const char *name;
> bool notrun;
> + unsigned long runstart;
> };
>
> static struct rcu_tasks_test_desc tests[] = {
> {
> .name = "call_rcu_tasks()",
> /* If not defined, the test is skipped. */
> - .notrun = !IS_ENABLED(CONFIG_TASKS_RCU),
> + .notrun = IS_ENABLED(CONFIG_TASKS_RCU),
> },
> {
> .name = "call_rcu_tasks_rude()",
> /* If not defined, the test is skipped. */
> - .notrun = !IS_ENABLED(CONFIG_TASKS_RUDE_RCU),
> + .notrun = IS_ENABLED(CONFIG_TASKS_RUDE_RCU),
> },
> {
> .name = "call_rcu_tasks_trace()",
> /* If not defined, the test is skipped. */
> - .notrun = !IS_ENABLED(CONFIG_TASKS_TRACE_RCU)
> + .notrun = IS_ENABLED(CONFIG_TASKS_TRACE_RCU)
> }
> };
>
> @@ -1803,23 +1805,28 @@ static void test_rcu_tasks_callback(struct rcu_head *rhp)
>
> pr_info("Callback from %s invoked.\n", rttd->name);
>
> - rttd->notrun = true;
> + rttd->notrun = false;
> }
>
> static void rcu_tasks_initiate_self_tests(void)
> {
> + unsigned long j = jiffies;
> +
> pr_info("Running RCU-tasks wait API self tests\n");
> #ifdef CONFIG_TASKS_RCU
> + tests[0].runstart = j;
> synchronize_rcu_tasks();
> call_rcu_tasks(&tests[0].rh, test_rcu_tasks_callback);
> #endif
>
> #ifdef CONFIG_TASKS_RUDE_RCU
> + tests[1].runstart = j;
> synchronize_rcu_tasks_rude();
> call_rcu_tasks_rude(&tests[1].rh, test_rcu_tasks_callback);
> #endif
>
> #ifdef CONFIG_TASKS_TRACE_RCU
> + tests[2].runstart = j;
> synchronize_rcu_tasks_trace();
> call_rcu_tasks_trace(&tests[2].rh, test_rcu_tasks_callback);
> #endif
> @@ -1829,11 +1836,18 @@ static int rcu_tasks_verify_self_tests(void)
> {
> int ret = 0;
> int i;
> + unsigned long bst = rcu_task_stall_timeout;
>
> + if (bst <= 0 || bst > RCU_TASK_BOOT_STALL_TIMEOUT)
> + bst = RCU_TASK_BOOT_STALL_TIMEOUT;
> for (i = 0; i < ARRAY_SIZE(tests); i++) {
> - if (!tests[i].notrun) { // still hanging.
> - pr_err("%s has been failed.\n", tests[i].name);
> - ret = -1;
> + while (tests[i].notrun) { // still hanging.
> + if (time_after(jiffies, tests[i].runstart + bst)) {
> + pr_err("%s has failed boot-time tests.\n", tests[i].name);
> + ret = -1;
> + break;
> + }
> + schedule_timeout_uninterruptible(1);
> }
> }
>
>
Powered by blists - more mailing lists