Re: [RESEND][PATCH v2] sched: Add trace_sched_waking() tracepoint to sched_ttwu_pending()

[Vishal Chourasia]

Hi,
On Mon, Mar 18, 2024 at 12:28:33PM -0700, John Stultz wrote:
> Zimuzo reported seeing occasional cases in perfetto traces where
> tasks went from sleeping directly to trace_sched_wakeup()
> without always seeing a trace_sched_waking().
> 
> Looking at the code, trace_sched_wakeup() is only called in
> ttwu_do_wakeup()
> 
> The call paths that get you to ttwu_do_wakeup() are:
> try_to_wake_up() -> ttwu_do_wakeup()
> try_to_wake_up() -> ttwu_runnable() -> ttwu_do_wakeup()
> try_to_wake_up() -> ttwu_queue() -> ttwu_do_activate() -> ttwu_do_wakeup()
> sched_ttwu_pending() -> ttwu_do_activate() -> ttwu_do_wakeup()
Notably, sched_ttwu_pending() is invoked for remote wakeups.

Given this, I anticipate a scenario similar to the following 
occurred: When a process (P) is to be awakened on a remote CPU, 
the scheduler adds P to the remote CPU's wakelist,a per-CPU queue,
and sends an IPI to the remote CPU. This action triggers 
sched_ttwu_pending() on the remote CPU, which then processes the
wakelist and wakes up the queued processes.

In this scenario, the "waking trace" of P, signifying the initiation
of the wake-up, is recorded on the CPU where try_to_wake_up was executed.
Meanwhile, the "wakeup trace," denoting the completion of the wake-up,
is observed on the remote CPU where sched_ttwu_pending() is executed.

Is there a possibility that something other than the above occurred
in your case?
>
> where trace_sched_waking() is currently called only in
> try_to_wake_up().
> 
> So add a trace_sched_waking() call to sched_ttwu_pending(), so
> we see the same state machine transitions.
> 
> With this change, the number of unexpected state transitions in
> perfetto was greatly reduced.
> 
> Cc: Ingo Molnar <mingo@xxxxxxxxxx>
> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> Cc: Juri Lelli <juri.lelli@xxxxxxxxxx>
> Cc: Vincent Guittot <vincent.guittot@xxxxxxxxxx>
> Cc: Dietmar Eggemann <dietmar.eggemann@xxxxxxx>
> Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
> Cc: Ben Segall <bsegall@xxxxxxxxxx>
> Cc: Mel Gorman <mgorman@xxxxxxx>
> Cc: Daniel Bristot de Oliveira <bristot@xxxxxxxxxx>
> Cc: Phil Auld <pauld@xxxxxxxxxx>
> Cc: Valentin Schneider <vschneid@xxxxxxxxxx>
> Cc: kernel-team@xxxxxxxxxxx
> Reviewed-by: Phil Auld <pauld@xxxxxxxxxx>
> Reported-by: Zimuzo Ezeozue <zezeozue@xxxxxxxxxx>
> Signed-off-by: John Stultz <jstultz@xxxxxxxxxx>
> ---
> v2:
> * Minor commit message fix suggested by Phil Auld
> ---
>  kernel/sched/core.c | 1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index 9116bcc90346..233f06360d6a 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -3894,6 +3894,7 @@ void sched_ttwu_pending(void *arg)
>  		if (WARN_ON_ONCE(task_cpu(p) != cpu_of(rq)))
>  			set_task_cpu(p, cpu_of(rq));
>  
> +		trace_sched_waking(p);
>  		ttwu_do_activate(rq, p, p->sched_remote_wakeup ? WF_MIGRATED : 0, &rf);
>  	}
>  
> -- 
> 2.44.0.291.gc1ea87d7ee-goog
>