Re: [PATCH v3] rcu: ftrace: avoid tracing a few functions executed in stop machine

[Steven Rostedt]

On Tue, 26 Apr 2022 18:55:11 +0800
Patrick Wang <patrick.wang.shcn@xxxxxxxxx> wrote:

> Because of the change of stop machine implementation, there are functions
> being called while waiting currently:
> 
> ----------------------------------------------------------------
> 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 (including the calls inside) should be marked notrace to avoid
> their codes being updated when they are being called. The calls inside
> rcu_momentary_dyntick_idle() still remain traced, and will cause crash:
> 
>   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:
> 
> Mark the calls inside rcu_momentary_dyntick_idle():
>  rcu_preempt_deferred_qs()
>  rcu_preempt_need_deferred_qs()
>  rcu_preempt_deferred_qs_irqrestore()
> as notrace to prevent this.
> 
> Signed-off-by: Patrick Wang <patrick.wang.shcn@xxxxxxxxx>
> ---
> v1->v2:
>  - Modify log message.

Acked-by: Steven Rostedt (Google) <rostedt@xxxxxxxxxxx>

-- Steve