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

Neeraj Upadhyay
2022-06-22T15:50:04Z

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 <patrick.wang.shcn@gmail.com>
>>>>>
>>>>> 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 <quic_neeraju@quicinc.com>

Thanks
Neeraj

> Thanx, Paul
>
>> Thanks
>> Neeraj
>>
>>> Thanx, Paul
>>>
>>> ------------------------------------------------------------------------
>>>
>>> commit 06cfe0c675c93884c3ffc75ec24ece7d0acd7a32
>>> Author: Patrick Wang <patrick.wang.shcn@gmail.com>
>>> 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 <patrick.wang.shcn@gmail.com>
>>> Acked-by: Steven Rostedt (Google) <rostedt@goodmis.org>
>>> Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
>>>
>>> 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);