2022-06-20 22:24:00

by Paul E. McKenney

[permalink] [raw]
Subject: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine

From: Patrick Wang <[email protected]>

Stop-machine recently started calling additional functions while waiting:

----------------------------------------------------------------
Former stop machine wait loop:
do {
cpu_relax(); => macro
...
} while (curstate != STOPMACHINE_EXIT);
-----------------------------------------------------------------
Current stop machine wait loop:
do {
stop_machine_yield(cpumask); => function (notraced)
...
touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
...
rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
} while (curstate != MULTI_STOP_EXIT);
------------------------------------------------------------------

These functions (and the functions that they call) must be marked
notrace to prevent them from being updated while they are executing.
The consequences of failing to mark these functions can be severe:

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
(detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
Task dump for CPU 1:
task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:
Task dump for CPU 3:
task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:
rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: Possible timer handling issue on cpu=2 timer-softirq=594
rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
Call Trace:
schedule+0x56/0xc2
schedule_timeout+0x82/0x184
rcu_gp_fqs_loop+0x19a/0x318
rcu_gp_kthread+0x11a/0x140
kthread+0xee/0x118
ret_from_exception+0x0/0x14
rcu: Stack dump where RCU GP kthread last ran:
Task dump for CPU 2:
task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:

This commit therefore marks these functions notrace:
rcu_preempt_deferred_qs()
rcu_preempt_need_deferred_qs()
rcu_preempt_deferred_qs_irqrestore()

Signed-off-by: Patrick Wang <[email protected]>
Acked-by: Steven Rostedt (Google) <[email protected]>
Signed-off-by: Paul E. McKenney <[email protected]>
---
kernel/rcu/tree_plugin.h | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
index c8ba0fe17267c..440d9e02a26e0 100644
--- a/kernel/rcu/tree_plugin.h
+++ b/kernel/rcu/tree_plugin.h
@@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
* be quite short, for example, in the case of the call from
* rcu_read_unlock_special().
*/
-static void
+static notrace void
rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
{
bool empty_exp;
@@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
* is disabled. This function cannot be expected to understand these
* nuances, so the caller must handle them.
*/
-static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
+static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
{
return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
READ_ONCE(t->rcu_read_unlock_special.s)) &&
@@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
* evaluate safety in terms of interrupt, softirq, and preemption
* disabling.
*/
-static void rcu_preempt_deferred_qs(struct task_struct *t)
+static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
{
unsigned long flags;

--
2.31.1.189.g2e36527f23


2022-06-21 06:15:08

by Neeraj Upadhyay

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine



On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
> From: Patrick Wang <[email protected]>
>
> Stop-machine recently started calling additional functions while waiting:
>
> ----------------------------------------------------------------
> Former stop machine wait loop:
> do {
> cpu_relax(); => macro
> ...
> } while (curstate != STOPMACHINE_EXIT);
> -----------------------------------------------------------------
> Current stop machine wait loop:
> do {
> stop_machine_yield(cpumask); => function (notraced)
> ...
> touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> ...
> rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> } while (curstate != MULTI_STOP_EXIT);
> ------------------------------------------------------------------
>
> These functions (and the functions that they call) must be marked
> notrace to prevent them from being updated while they are executing.
> The consequences of failing to mark these functions can be severe:
>
> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> Task dump for CPU 1:
> task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
> Task dump for CPU 3:
> task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
> rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> rcu: RCU grace-period kthread stack dump:
> task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> Call Trace:
> schedule+0x56/0xc2
> schedule_timeout+0x82/0x184
> rcu_gp_fqs_loop+0x19a/0x318
> rcu_gp_kthread+0x11a/0x140
> kthread+0xee/0x118
> ret_from_exception+0x0/0x14
> rcu: Stack dump where RCU GP kthread last ran:
> Task dump for CPU 2:
> task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
>
> This commit therefore marks these functions notrace:
> rcu_preempt_deferred_qs()
> rcu_preempt_need_deferred_qs()
> rcu_preempt_deferred_qs_irqrestore()
>

Only the preemptible RCU definitions are updated; so, this change is not
required for non-preemptible RCU case?


Thanks
Neeraj

> Signed-off-by: Patrick Wang <[email protected]>
> Acked-by: Steven Rostedt (Google) <[email protected]>
> Signed-off-by: Paul E. McKenney <[email protected]>
> ---
> kernel/rcu/tree_plugin.h | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> index c8ba0fe17267c..440d9e02a26e0 100644
> --- a/kernel/rcu/tree_plugin.h
> +++ b/kernel/rcu/tree_plugin.h
> @@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> * be quite short, for example, in the case of the call from
> * rcu_read_unlock_special().
> */
> -static void
> +static notrace void
> rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> {
> bool empty_exp;
> @@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> * is disabled. This function cannot be expected to understand these
> * nuances, so the caller must handle them.
> */
> -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> {
> return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
> READ_ONCE(t->rcu_read_unlock_special.s)) &&
> @@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> * evaluate safety in terms of interrupt, softirq, and preemption
> * disabling.
> */
> -static void rcu_preempt_deferred_qs(struct task_struct *t)
> +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> {
> unsigned long flags;
>

2022-06-21 22:46:39

by Paul E. McKenney

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine

On Tue, Jun 21, 2022 at 11:17:10AM +0530, Neeraj Upadhyay wrote:
>
>
> On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
> > From: Patrick Wang <[email protected]>
> >
> > Stop-machine recently started calling additional functions while waiting:
> >
> > ----------------------------------------------------------------
> > Former stop machine wait loop:
> > do {
> > cpu_relax(); => macro
> > ...
> > } while (curstate != STOPMACHINE_EXIT);
> > -----------------------------------------------------------------
> > Current stop machine wait loop:
> > do {
> > stop_machine_yield(cpumask); => function (notraced)
> > ...
> > touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> > ...
> > rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> > } while (curstate != MULTI_STOP_EXIT);
> > ------------------------------------------------------------------
> >
> > These functions (and the functions that they call) must be marked
> > notrace to prevent them from being updated while they are executing.
> > The consequences of failing to mark these functions can be severe:
> >
> > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> > rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> > (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> > Task dump for CPU 1:
> > task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> > Task dump for CPU 3:
> > task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> > rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> > rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> > rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> > rcu: RCU grace-period kthread stack dump:
> > task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> > Call Trace:
> > schedule+0x56/0xc2
> > schedule_timeout+0x82/0x184
> > rcu_gp_fqs_loop+0x19a/0x318
> > rcu_gp_kthread+0x11a/0x140
> > kthread+0xee/0x118
> > ret_from_exception+0x0/0x14
> > rcu: Stack dump where RCU GP kthread last ran:
> > Task dump for CPU 2:
> > task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> >
> > This commit therefore marks these functions notrace:
> > rcu_preempt_deferred_qs()
> > rcu_preempt_need_deferred_qs()
> > rcu_preempt_deferred_qs_irqrestore()
> >
>
> Only the preemptible RCU definitions are updated; so, this change is not
> required for non-preemptible RCU case?

It appears to me to be required. How about as shown below?

Thanx, Paul

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

commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
Author: Patrick Wang <[email protected]>
Date: Tue Apr 26 18:45:02 2022 +0800

rcu: Avoid tracing a few functions executed in stop machine

Stop-machine recently started calling additional functions while waiting:

----------------------------------------------------------------
Former stop machine wait loop:
do {
cpu_relax(); => macro
...
} while (curstate != STOPMACHINE_EXIT);
-----------------------------------------------------------------
Current stop machine wait loop:
do {
stop_machine_yield(cpumask); => function (notraced)
...
touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
...
rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
} while (curstate != MULTI_STOP_EXIT);
------------------------------------------------------------------

These functions (and the functions that they call) must be marked
notrace to prevent them from being updated while they are executing.
The consequences of failing to mark these functions can be severe:

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
(detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
Task dump for CPU 1:
task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:
Task dump for CPU 3:
task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:
rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: Possible timer handling issue on cpu=2 timer-softirq=594
rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
Call Trace:
schedule+0x56/0xc2
schedule_timeout+0x82/0x184
rcu_gp_fqs_loop+0x19a/0x318
rcu_gp_kthread+0x11a/0x140
kthread+0xee/0x118
ret_from_exception+0x0/0x14
rcu: Stack dump where RCU GP kthread last ran:
Task dump for CPU 2:
task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
Call Trace:

This commit therefore marks these functions notrace:
rcu_preempt_deferred_qs()
rcu_preempt_need_deferred_qs()
rcu_preempt_deferred_qs_irqrestore()

[ paulmck: Apply feedback from Neeraj Upadhyay. ]

Signed-off-by: Patrick Wang <[email protected]>
Acked-by: Steven Rostedt (Google) <[email protected]>
Signed-off-by: Paul E. McKenney <[email protected]>

diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
index c8ba0fe17267c..7a07f2ca153e2 100644
--- a/kernel/rcu/tree_plugin.h
+++ b/kernel/rcu/tree_plugin.h
@@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
* be quite short, for example, in the case of the call from
* rcu_read_unlock_special().
*/
-static void
+static notrace void
rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
{
bool empty_exp;
@@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
* is disabled. This function cannot be expected to understand these
* nuances, so the caller must handle them.
*/
-static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
+static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
{
return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
READ_ONCE(t->rcu_read_unlock_special.s)) &&
@@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
* evaluate safety in terms of interrupt, softirq, and preemption
* disabling.
*/
-static void rcu_preempt_deferred_qs(struct task_struct *t)
+static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
{
unsigned long flags;

@@ -926,7 +926,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
* Because there is no preemptible RCU, there can be no deferred quiescent
* states.
*/
-static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
+static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
{
return false;
}
@@ -935,7 +935,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
// period for a quiescent state from this CPU. Note that requests from
// tasks are handled when removing the task from the blocked-tasks list
// below.
-static void rcu_preempt_deferred_qs(struct task_struct *t)
+static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
{
struct rcu_data *rdp = this_cpu_ptr(&rcu_data);

2022-06-22 12:20:36

by Neeraj Upadhyay

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine



On 6/22/2022 3:51 AM, Paul E. McKenney wrote:
> On Tue, Jun 21, 2022 at 11:17:10AM +0530, Neeraj Upadhyay wrote:
>>
>>
>> On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
>>> From: Patrick Wang <[email protected]>
>>>
>>> Stop-machine recently started calling additional functions while waiting:
>>>
>>> ----------------------------------------------------------------
>>> Former stop machine wait loop:
>>> do {
>>> cpu_relax(); => macro
>>> ...
>>> } while (curstate != STOPMACHINE_EXIT);
>>> -----------------------------------------------------------------
>>> Current stop machine wait loop:
>>> do {
>>> stop_machine_yield(cpumask); => function (notraced)
>>> ...
>>> touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
>>> ...
>>> rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
>>> } while (curstate != MULTI_STOP_EXIT);
>>> ------------------------------------------------------------------
>>>
>>> These functions (and the functions that they call) must be marked
>>> notrace to prevent them from being updated while they are executing.
>>> The consequences of failing to mark these functions can be severe:
>>>
>>> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
>>> rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
>>> rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
>>> (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
>>> Task dump for CPU 1:
>>> task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>> Task dump for CPU 3:
>>> task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>> rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
>>> rcu: Possible timer handling issue on cpu=2 timer-softirq=594
>>> rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
>>> rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
>>> rcu: RCU grace-period kthread stack dump:
>>> task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
>>> Call Trace:
>>> schedule+0x56/0xc2
>>> schedule_timeout+0x82/0x184
>>> rcu_gp_fqs_loop+0x19a/0x318
>>> rcu_gp_kthread+0x11a/0x140
>>> kthread+0xee/0x118
>>> ret_from_exception+0x0/0x14
>>> rcu: Stack dump where RCU GP kthread last ran:
>>> Task dump for CPU 2:
>>> task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>>
>>> This commit therefore marks these functions notrace:
>>> rcu_preempt_deferred_qs()
>>> rcu_preempt_need_deferred_qs()
>>> rcu_preempt_deferred_qs_irqrestore()
>>>
>>
>> Only the preemptible RCU definitions are updated; so, this change is not
>> required for non-preemptible RCU case?
>
> It appears to me to be required. How about as shown below?
>

Looks good to me.


Thanks
Neeraj

> Thanx, Paul
>
> ------------------------------------------------------------------------
>
> commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
> Author: Patrick Wang <[email protected]>
> Date: Tue Apr 26 18:45:02 2022 +0800
>
> rcu: Avoid tracing a few functions executed in stop machine
>
> Stop-machine recently started calling additional functions while waiting:
>
> ----------------------------------------------------------------
> Former stop machine wait loop:
> do {
> cpu_relax(); => macro
> ...
> } while (curstate != STOPMACHINE_EXIT);
> -----------------------------------------------------------------
> Current stop machine wait loop:
> do {
> stop_machine_yield(cpumask); => function (notraced)
> ...
> touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> ...
> rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> } while (curstate != MULTI_STOP_EXIT);
> ------------------------------------------------------------------
>
> These functions (and the functions that they call) must be marked
> notrace to prevent them from being updated while they are executing.
> The consequences of failing to mark these functions can be severe:
>
> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> Task dump for CPU 1:
> task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
> Task dump for CPU 3:
> task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
> rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> rcu: RCU grace-period kthread stack dump:
> task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> Call Trace:
> schedule+0x56/0xc2
> schedule_timeout+0x82/0x184
> rcu_gp_fqs_loop+0x19a/0x318
> rcu_gp_kthread+0x11a/0x140
> kthread+0xee/0x118
> ret_from_exception+0x0/0x14
> rcu: Stack dump where RCU GP kthread last ran:
> Task dump for CPU 2:
> task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> Call Trace:
>
> This commit therefore marks these functions notrace:
> rcu_preempt_deferred_qs()
> rcu_preempt_need_deferred_qs()
> rcu_preempt_deferred_qs_irqrestore()
>
> [ paulmck: Apply feedback from Neeraj Upadhyay. ]
>
> Signed-off-by: Patrick Wang <[email protected]>
> Acked-by: Steven Rostedt (Google) <[email protected]>
> Signed-off-by: Paul E. McKenney <[email protected]>
>
> diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> index c8ba0fe17267c..7a07f2ca153e2 100644
> --- a/kernel/rcu/tree_plugin.h
> +++ b/kernel/rcu/tree_plugin.h
> @@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> * be quite short, for example, in the case of the call from
> * rcu_read_unlock_special().
> */
> -static void
> +static notrace void
> rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> {
> bool empty_exp;
> @@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> * is disabled. This function cannot be expected to understand these
> * nuances, so the caller must handle them.
> */
> -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> {
> return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
> READ_ONCE(t->rcu_read_unlock_special.s)) &&
> @@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> * evaluate safety in terms of interrupt, softirq, and preemption
> * disabling.
> */
> -static void rcu_preempt_deferred_qs(struct task_struct *t)
> +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> {
> unsigned long flags;
>
> @@ -926,7 +926,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> * Because there is no preemptible RCU, there can be no deferred quiescent
> * states.
> */
> -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> {
> return false;
> }
> @@ -935,7 +935,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> // period for a quiescent state from this CPU. Note that requests from
> // tasks are handled when removing the task from the blocked-tasks list
> // below.
> -static void rcu_preempt_deferred_qs(struct task_struct *t)
> +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> {
> struct rcu_data *rdp = this_cpu_ptr(&rcu_data);
>

2022-06-22 15:54:36

by Neeraj Upadhyay

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine



On 6/22/2022 9:05 PM, Paul E. McKenney wrote:
> On Wed, Jun 22, 2022 at 05:20:35PM +0530, Neeraj Upadhyay wrote:
>>
>>
>> On 6/22/2022 3:51 AM, Paul E. McKenney wrote:
>>> On Tue, Jun 21, 2022 at 11:17:10AM +0530, Neeraj Upadhyay wrote:
>>>>
>>>>
>>>> On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
>>>>> From: Patrick Wang <[email protected]>
>>>>>
>>>>> Stop-machine recently started calling additional functions while waiting:
>>>>>
>>>>> ----------------------------------------------------------------
>>>>> Former stop machine wait loop:
>>>>> do {
>>>>> cpu_relax(); => macro
>>>>> ...
>>>>> } while (curstate != STOPMACHINE_EXIT);
>>>>> -----------------------------------------------------------------
>>>>> Current stop machine wait loop:
>>>>> do {
>>>>> stop_machine_yield(cpumask); => function (notraced)
>>>>> ...
>>>>> touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
>>>>> ...
>>>>> rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
>>>>> } while (curstate != MULTI_STOP_EXIT);
>>>>> ------------------------------------------------------------------
>>>>>
>>>>> These functions (and the functions that they call) must be marked
>>>>> notrace to prevent them from being updated while they are executing.
>>>>> The consequences of failing to mark these functions can be severe:
>>>>>
>>>>> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
>>>>> rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
>>>>> rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
>>>>> (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
>>>>> Task dump for CPU 1:
>>>>> task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
>>>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>>>> Call Trace:
>>>>> Task dump for CPU 3:
>>>>> task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
>>>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>>>> Call Trace:
>>>>> rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
>>>>> rcu: Possible timer handling issue on cpu=2 timer-softirq=594
>>>>> rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
>>>>> rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
>>>>> rcu: RCU grace-period kthread stack dump:
>>>>> task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
>>>>> Call Trace:
>>>>> schedule+0x56/0xc2
>>>>> schedule_timeout+0x82/0x184
>>>>> rcu_gp_fqs_loop+0x19a/0x318
>>>>> rcu_gp_kthread+0x11a/0x140
>>>>> kthread+0xee/0x118
>>>>> ret_from_exception+0x0/0x14
>>>>> rcu: Stack dump where RCU GP kthread last ran:
>>>>> Task dump for CPU 2:
>>>>> task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
>>>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>>>> Call Trace:
>>>>>
>>>>> This commit therefore marks these functions notrace:
>>>>> rcu_preempt_deferred_qs()
>>>>> rcu_preempt_need_deferred_qs()
>>>>> rcu_preempt_deferred_qs_irqrestore()
>>>>>
>>>>
>>>> Only the preemptible RCU definitions are updated; so, this change is not
>>>> required for non-preemptible RCU case?
>>>
>>> It appears to me to be required. How about as shown below?
>>>
>>
>> Looks good to me.
>
> Thank you! May I apply your Reviewed-by to both of these? (1/12 and
> 2/12.)
>

Yes, sure.

Reviewed-by: Neeraj Upadhyay <[email protected]>


Thanks
Neeraj

> Thanx, Paul
>
>> Thanks
>> Neeraj
>>
>>> Thanx, Paul
>>>
>>> ------------------------------------------------------------------------
>>>
>>> commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
>>> Author: Patrick Wang <[email protected]>
>>> Date: Tue Apr 26 18:45:02 2022 +0800
>>>
>>> rcu: Avoid tracing a few functions executed in stop machine
>>> Stop-machine recently started calling additional functions while waiting:
>>> ----------------------------------------------------------------
>>> Former stop machine wait loop:
>>> do {
>>> cpu_relax(); => macro
>>> ...
>>> } while (curstate != STOPMACHINE_EXIT);
>>> -----------------------------------------------------------------
>>> Current stop machine wait loop:
>>> do {
>>> stop_machine_yield(cpumask); => function (notraced)
>>> ...
>>> touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
>>> ...
>>> rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
>>> } while (curstate != MULTI_STOP_EXIT);
>>> ------------------------------------------------------------------
>>> These functions (and the functions that they call) must be marked
>>> notrace to prevent them from being updated while they are executing.
>>> The consequences of failing to mark these functions can be severe:
>>> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
>>> rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
>>> rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
>>> (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
>>> Task dump for CPU 1:
>>> task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>> Task dump for CPU 3:
>>> task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>> rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
>>> rcu: Possible timer handling issue on cpu=2 timer-softirq=594
>>> rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
>>> rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
>>> rcu: RCU grace-period kthread stack dump:
>>> task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
>>> Call Trace:
>>> schedule+0x56/0xc2
>>> schedule_timeout+0x82/0x184
>>> rcu_gp_fqs_loop+0x19a/0x318
>>> rcu_gp_kthread+0x11a/0x140
>>> kthread+0xee/0x118
>>> ret_from_exception+0x0/0x14
>>> rcu: Stack dump where RCU GP kthread last ran:
>>> Task dump for CPU 2:
>>> task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
>>> Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
>>> Call Trace:
>>> This commit therefore marks these functions notrace:
>>> rcu_preempt_deferred_qs()
>>> rcu_preempt_need_deferred_qs()
>>> rcu_preempt_deferred_qs_irqrestore()
>>> [ paulmck: Apply feedback from Neeraj Upadhyay. ]
>>> Signed-off-by: Patrick Wang <[email protected]>
>>> Acked-by: Steven Rostedt (Google) <[email protected]>
>>> Signed-off-by: Paul E. McKenney <[email protected]>
>>>
>>> diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
>>> index c8ba0fe17267c..7a07f2ca153e2 100644
>>> --- a/kernel/rcu/tree_plugin.h
>>> +++ b/kernel/rcu/tree_plugin.h
>>> @@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
>>> * be quite short, for example, in the case of the call from
>>> * rcu_read_unlock_special().
>>> */
>>> -static void
>>> +static notrace void
>>> rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
>>> {
>>> bool empty_exp;
>>> @@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
>>> * is disabled. This function cannot be expected to understand these
>>> * nuances, so the caller must handle them.
>>> */
>>> -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> {
>>> return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
>>> READ_ONCE(t->rcu_read_unlock_special.s)) &&
>>> @@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> * evaluate safety in terms of interrupt, softirq, and preemption
>>> * disabling.
>>> */
>>> -static void rcu_preempt_deferred_qs(struct task_struct *t)
>>> +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
>>> {
>>> unsigned long flags;
>>> @@ -926,7 +926,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
>>> * Because there is no preemptible RCU, there can be no deferred quiescent
>>> * states.
>>> */
>>> -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> {
>>> return false;
>>> }
>>> @@ -935,7 +935,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
>>> // period for a quiescent state from this CPU. Note that requests from
>>> // tasks are handled when removing the task from the blocked-tasks list
>>> // below.
>>> -static void rcu_preempt_deferred_qs(struct task_struct *t)
>>> +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
>>> {
>>> struct rcu_data *rdp = this_cpu_ptr(&rcu_data);

2022-06-22 16:08:21

by Paul E. McKenney

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine

On Wed, Jun 22, 2022 at 05:20:35PM +0530, Neeraj Upadhyay wrote:
>
>
> On 6/22/2022 3:51 AM, Paul E. McKenney wrote:
> > On Tue, Jun 21, 2022 at 11:17:10AM +0530, Neeraj Upadhyay wrote:
> > >
> > >
> > > On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
> > > > From: Patrick Wang <[email protected]>
> > > >
> > > > Stop-machine recently started calling additional functions while waiting:
> > > >
> > > > ----------------------------------------------------------------
> > > > Former stop machine wait loop:
> > > > do {
> > > > cpu_relax(); => macro
> > > > ...
> > > > } while (curstate != STOPMACHINE_EXIT);
> > > > -----------------------------------------------------------------
> > > > Current stop machine wait loop:
> > > > do {
> > > > stop_machine_yield(cpumask); => function (notraced)
> > > > ...
> > > > touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> > > > ...
> > > > rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> > > > } while (curstate != MULTI_STOP_EXIT);
> > > > ------------------------------------------------------------------
> > > >
> > > > These functions (and the functions that they call) must be marked
> > > > notrace to prevent them from being updated while they are executing.
> > > > The consequences of failing to mark these functions can be severe:
> > > >
> > > > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > > > rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> > > > rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> > > > (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> > > > Task dump for CPU 1:
> > > > task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > > Task dump for CPU 3:
> > > > task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > > rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> > > > rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> > > > rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> > > > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> > > > rcu: RCU grace-period kthread stack dump:
> > > > task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> > > > Call Trace:
> > > > schedule+0x56/0xc2
> > > > schedule_timeout+0x82/0x184
> > > > rcu_gp_fqs_loop+0x19a/0x318
> > > > rcu_gp_kthread+0x11a/0x140
> > > > kthread+0xee/0x118
> > > > ret_from_exception+0x0/0x14
> > > > rcu: Stack dump where RCU GP kthread last ran:
> > > > Task dump for CPU 2:
> > > > task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > >
> > > > This commit therefore marks these functions notrace:
> > > > rcu_preempt_deferred_qs()
> > > > rcu_preempt_need_deferred_qs()
> > > > rcu_preempt_deferred_qs_irqrestore()
> > > >
> > >
> > > Only the preemptible RCU definitions are updated; so, this change is not
> > > required for non-preemptible RCU case?
> >
> > It appears to me to be required. How about as shown below?
> >
>
> Looks good to me.

Thank you! May I apply your Reviewed-by to both of these? (1/12 and
2/12.)

Thanx, Paul

> Thanks
> Neeraj
>
> > Thanx, Paul
> >
> > ------------------------------------------------------------------------
> >
> > commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
> > Author: Patrick Wang <[email protected]>
> > Date: Tue Apr 26 18:45:02 2022 +0800
> >
> > rcu: Avoid tracing a few functions executed in stop machine
> > Stop-machine recently started calling additional functions while waiting:
> > ----------------------------------------------------------------
> > Former stop machine wait loop:
> > do {
> > cpu_relax(); => macro
> > ...
> > } while (curstate != STOPMACHINE_EXIT);
> > -----------------------------------------------------------------
> > Current stop machine wait loop:
> > do {
> > stop_machine_yield(cpumask); => function (notraced)
> > ...
> > touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> > ...
> > rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> > } while (curstate != MULTI_STOP_EXIT);
> > ------------------------------------------------------------------
> > These functions (and the functions that they call) must be marked
> > notrace to prevent them from being updated while they are executing.
> > The consequences of failing to mark these functions can be severe:
> > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> > rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> > (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> > Task dump for CPU 1:
> > task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> > Task dump for CPU 3:
> > task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> > rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> > rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> > rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> > rcu: RCU grace-period kthread stack dump:
> > task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> > Call Trace:
> > schedule+0x56/0xc2
> > schedule_timeout+0x82/0x184
> > rcu_gp_fqs_loop+0x19a/0x318
> > rcu_gp_kthread+0x11a/0x140
> > kthread+0xee/0x118
> > ret_from_exception+0x0/0x14
> > rcu: Stack dump where RCU GP kthread last ran:
> > Task dump for CPU 2:
> > task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > Call Trace:
> > This commit therefore marks these functions notrace:
> > rcu_preempt_deferred_qs()
> > rcu_preempt_need_deferred_qs()
> > rcu_preempt_deferred_qs_irqrestore()
> > [ paulmck: Apply feedback from Neeraj Upadhyay. ]
> > Signed-off-by: Patrick Wang <[email protected]>
> > Acked-by: Steven Rostedt (Google) <[email protected]>
> > Signed-off-by: Paul E. McKenney <[email protected]>
> >
> > diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> > index c8ba0fe17267c..7a07f2ca153e2 100644
> > --- a/kernel/rcu/tree_plugin.h
> > +++ b/kernel/rcu/tree_plugin.h
> > @@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> > * be quite short, for example, in the case of the call from
> > * rcu_read_unlock_special().
> > */
> > -static void
> > +static notrace void
> > rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> > {
> > bool empty_exp;
> > @@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> > * is disabled. This function cannot be expected to understand these
> > * nuances, so the caller must handle them.
> > */
> > -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > {
> > return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
> > READ_ONCE(t->rcu_read_unlock_special.s)) &&
> > @@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > * evaluate safety in terms of interrupt, softirq, and preemption
> > * disabling.
> > */
> > -static void rcu_preempt_deferred_qs(struct task_struct *t)
> > +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> > {
> > unsigned long flags;
> > @@ -926,7 +926,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> > * Because there is no preemptible RCU, there can be no deferred quiescent
> > * states.
> > */
> > -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > {
> > return false;
> > }
> > @@ -935,7 +935,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > // period for a quiescent state from this CPU. Note that requests from
> > // tasks are handled when removing the task from the blocked-tasks list
> > // below.
> > -static void rcu_preempt_deferred_qs(struct task_struct *t)
> > +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> > {
> > struct rcu_data *rdp = this_cpu_ptr(&rcu_data);

2022-06-23 01:04:14

by Paul E. McKenney

[permalink] [raw]
Subject: Re: [PATCH rcu 02/12] rcu: Avoid tracing a few functions executed in stop machine

On Wed, Jun 22, 2022 at 09:19:25PM +0530, Neeraj Upadhyay wrote:
>
>
> On 6/22/2022 9:05 PM, Paul E. McKenney wrote:
> > On Wed, Jun 22, 2022 at 05:20:35PM +0530, Neeraj Upadhyay wrote:
> > >
> > >
> > > On 6/22/2022 3:51 AM, Paul E. McKenney wrote:
> > > > On Tue, Jun 21, 2022 at 11:17:10AM +0530, Neeraj Upadhyay wrote:
> > > > >
> > > > >
> > > > > On 6/21/2022 3:50 AM, Paul E. McKenney wrote:
> > > > > > From: Patrick Wang <[email protected]>
> > > > > >
> > > > > > Stop-machine recently started calling additional functions while waiting:
> > > > > >
> > > > > > ----------------------------------------------------------------
> > > > > > Former stop machine wait loop:
> > > > > > do {
> > > > > > cpu_relax(); => macro
> > > > > > ...
> > > > > > } while (curstate != STOPMACHINE_EXIT);
> > > > > > -----------------------------------------------------------------
> > > > > > Current stop machine wait loop:
> > > > > > do {
> > > > > > stop_machine_yield(cpumask); => function (notraced)
> > > > > > ...
> > > > > > touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> > > > > > ...
> > > > > > rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> > > > > > } while (curstate != MULTI_STOP_EXIT);
> > > > > > ------------------------------------------------------------------
> > > > > >
> > > > > > These functions (and the functions that they call) must be marked
> > > > > > notrace to prevent them from being updated while they are executing.
> > > > > > The consequences of failing to mark these functions can be severe:
> > > > > >
> > > > > > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > > > > > rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> > > > > > rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> > > > > > (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> > > > > > Task dump for CPU 1:
> > > > > > task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> > > > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > > > Call Trace:
> > > > > > Task dump for CPU 3:
> > > > > > task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> > > > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > > > Call Trace:
> > > > > > rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> > > > > > rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> > > > > > rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> > > > > > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> > > > > > rcu: RCU grace-period kthread stack dump:
> > > > > > task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> > > > > > Call Trace:
> > > > > > schedule+0x56/0xc2
> > > > > > schedule_timeout+0x82/0x184
> > > > > > rcu_gp_fqs_loop+0x19a/0x318
> > > > > > rcu_gp_kthread+0x11a/0x140
> > > > > > kthread+0xee/0x118
> > > > > > ret_from_exception+0x0/0x14
> > > > > > rcu: Stack dump where RCU GP kthread last ran:
> > > > > > Task dump for CPU 2:
> > > > > > task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> > > > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > > > Call Trace:
> > > > > >
> > > > > > This commit therefore marks these functions notrace:
> > > > > > rcu_preempt_deferred_qs()
> > > > > > rcu_preempt_need_deferred_qs()
> > > > > > rcu_preempt_deferred_qs_irqrestore()
> > > > > >
> > > > >
> > > > > Only the preemptible RCU definitions are updated; so, this change is not
> > > > > required for non-preemptible RCU case?
> > > >
> > > > It appears to me to be required. How about as shown below?
> > > >
> > >
> > > Looks good to me.
> >
> > Thank you! May I apply your Reviewed-by to both of these? (1/12 and
> > 2/12.)
> >
>
> Yes, sure.
>
> Reviewed-by: Neeraj Upadhyay <[email protected]>

Very good, thank you! I will apply these on my next rebase.

Thanx, Paul

> Thanks
> Neeraj
>
> > Thanx, Paul
> >
> > > Thanks
> > > Neeraj
> > >
> > > > Thanx, Paul
> > > >
> > > > ------------------------------------------------------------------------
> > > >
> > > > commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
> > > > Author: Patrick Wang <[email protected]>
> > > > Date: Tue Apr 26 18:45:02 2022 +0800
> > > >
> > > > rcu: Avoid tracing a few functions executed in stop machine
> > > > Stop-machine recently started calling additional functions while waiting:
> > > > ----------------------------------------------------------------
> > > > Former stop machine wait loop:
> > > > do {
> > > > cpu_relax(); => macro
> > > > ...
> > > > } while (curstate != STOPMACHINE_EXIT);
> > > > -----------------------------------------------------------------
> > > > Current stop machine wait loop:
> > > > do {
> > > > stop_machine_yield(cpumask); => function (notraced)
> > > > ...
> > > > touch_nmi_watchdog(); => function (notraced, inside calls also notraced)
> > > > ...
> > > > rcu_momentary_dyntick_idle(); => function (notraced, inside calls traced)
> > > > } while (curstate != MULTI_STOP_EXIT);
> > > > ------------------------------------------------------------------
> > > > These functions (and the functions that they call) must be marked
> > > > notrace to prevent them from being updated while they are executing.
> > > > The consequences of failing to mark these functions can be severe:
> > > > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > > > rcu: 1-...!: (0 ticks this GP) idle=14f/1/0x4000000000000000 softirq=3397/3397 fqs=0
> > > > rcu: 3-...!: (0 ticks this GP) idle=ee9/1/0x4000000000000000 softirq=5168/5168 fqs=0
> > > > (detected by 0, t=8137 jiffies, g=5889, q=2 ncpus=4)
> > > > Task dump for CPU 1:
> > > > task:migration/1 state:R running task stack: 0 pid: 19 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > > Task dump for CPU 3:
> > > > task:migration/3 state:R running task stack: 0 pid: 29 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > > rcu: rcu_preempt kthread timer wakeup didn't happen for 8136 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
> > > > rcu: Possible timer handling issue on cpu=2 timer-softirq=594
> > > > rcu: rcu_preempt kthread starved for 8137 jiffies! g5889 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
> > > > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
> > > > rcu: RCU grace-period kthread stack dump:
> > > > task:rcu_preempt state:I stack: 0 pid: 14 ppid: 2 flags:0x00000000
> > > > Call Trace:
> > > > schedule+0x56/0xc2
> > > > schedule_timeout+0x82/0x184
> > > > rcu_gp_fqs_loop+0x19a/0x318
> > > > rcu_gp_kthread+0x11a/0x140
> > > > kthread+0xee/0x118
> > > > ret_from_exception+0x0/0x14
> > > > rcu: Stack dump where RCU GP kthread last ran:
> > > > Task dump for CPU 2:
> > > > task:migration/2 state:R running task stack: 0 pid: 24 ppid: 2 flags:0x00000000
> > > > Stopper: multi_cpu_stop+0x0/0x18c <- stop_machine_cpuslocked+0x128/0x174
> > > > Call Trace:
> > > > This commit therefore marks these functions notrace:
> > > > rcu_preempt_deferred_qs()
> > > > rcu_preempt_need_deferred_qs()
> > > > rcu_preempt_deferred_qs_irqrestore()
> > > > [ paulmck: Apply feedback from Neeraj Upadhyay. ]
> > > > Signed-off-by: Patrick Wang <[email protected]>
> > > > Acked-by: Steven Rostedt (Google) <[email protected]>
> > > > Signed-off-by: Paul E. McKenney <[email protected]>
> > > >
> > > > diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> > > > index c8ba0fe17267c..7a07f2ca153e2 100644
> > > > --- a/kernel/rcu/tree_plugin.h
> > > > +++ b/kernel/rcu/tree_plugin.h
> > > > @@ -460,7 +460,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> > > > * be quite short, for example, in the case of the call from
> > > > * rcu_read_unlock_special().
> > > > */
> > > > -static void
> > > > +static notrace void
> > > > rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> > > > {
> > > > bool empty_exp;
> > > > @@ -581,7 +581,7 @@ rcu_preempt_deferred_qs_irqrestore(struct task_struct *t, unsigned long flags)
> > > > * is disabled. This function cannot be expected to understand these
> > > > * nuances, so the caller must handle them.
> > > > */
> > > > -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > {
> > > > return (__this_cpu_read(rcu_data.cpu_no_qs.b.exp) ||
> > > > READ_ONCE(t->rcu_read_unlock_special.s)) &&
> > > > @@ -595,7 +595,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > * evaluate safety in terms of interrupt, softirq, and preemption
> > > > * disabling.
> > > > */
> > > > -static void rcu_preempt_deferred_qs(struct task_struct *t)
> > > > +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> > > > {
> > > > unsigned long flags;
> > > > @@ -926,7 +926,7 @@ static bool rcu_preempt_has_tasks(struct rcu_node *rnp)
> > > > * Because there is no preemptible RCU, there can be no deferred quiescent
> > > > * states.
> > > > */
> > > > -static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > +static notrace bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > {
> > > > return false;
> > > > }
> > > > @@ -935,7 +935,7 @@ static bool rcu_preempt_need_deferred_qs(struct task_struct *t)
> > > > // period for a quiescent state from this CPU. Note that requests from
> > > > // tasks are handled when removing the task from the blocked-tasks list
> > > > // below.
> > > > -static void rcu_preempt_deferred_qs(struct task_struct *t)
> > > > +static notrace void rcu_preempt_deferred_qs(struct task_struct *t)
> > > > {
> > > > struct rcu_data *rdp = this_cpu_ptr(&rcu_data);