ANDROID: sched: Add trace events for proxy execution

Add sched_[start, finish]_task_selection trace events to measure the
latency of proxy execution patches in task selection.

Moreover, introduce trace events for interesting events in proxy
execution:
1. sched_pe_enqueue_sleeping_task: a task gets enqueued on wait queue of
   a sleeping task (mutex owner).
2. sched_pe_activate_blocked_entity: When owner is woken and we activate
   tasks enqueued on the owner' blocked entities list.
3. sched_pe_migration: dependency chain crosses remote CPU.
4. sched_pe_return_migration: returning a previously proxy-migrated task
   to it's originating cpu.
5. sched_pe_owner_is_migrating: mutex owner task is mid-migration.
New trace events can be tested via this command:
$ perf trace -e sched:sched_start_task_selection \
  -e sched:sched_finish_task_selection \
  -e sched:sched_pe_enqueue_sleeping_task \
  -e sched:sched_pe_activate_blocked_entity \
  -e sched:sched_pe_migration \
  -e sched:sched_pe_return_migration \
  -e sched:sched_pe_owner_is_migrating

Note: These trace events are not intended to merge upstream. Instead,
they are only for making PE tests easier and will be converted to trace
points once Proxy Execution patches hit upstream.

CC: John Stultz <jstultz@google.com>
CC: Joel Fernandes <joelaf@google.com>
Cc: Qais Yousef <qyousef@layalina.io>
CC: Ingo Molnar <mingo@redhat.com>
CC: Peter Zijlstra <peterz@infradead.org>
CC: Juri Lelli <juri.lelli@redhat.com>
CC: Vincent Guittot <vincent.guittot@linaro.org>
CC: Dietmar Eggemann <dietmar.eggemann@arm.com>
CC: Valentin Schneider <vschneid@redhat.com>
CC: Steven Rostedt <rostedt@goodmis.org>
CC: Masami Hiramatsu <mhiramat@kernel.org>
CC: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
CC: Ben Segall <bsegall@google.com>
CC: Zimuzo Ezeozue <zezeozue@google.com>
CC: Mel Gorman <mgorman@suse.de>
CC: Will Deacon <will@kernel.org>
CC: Waiman Long <longman@redhat.com>
CC: Boqun Feng <boqun.feng@gmail.com>
CC: "Paul E. McKenney" <paulmck@kernel.org>
CC: Xuewen Yan <xuewen.yan94@gmail.com>
CC: K Prateek Nayak <kprateek.nayak@amd.com>
CC: Thomas Gleixner <tglx@linutronix.de>
CC: Daniel Lezcano <daniel.lezcano@linaro.org>
CC: kernel-team@android.com
CC: linux-trace-kernel@vger.kernel.org
Change-Id: Iec008efa1f954c0f0d43714fdd32cf96fc0dd561
Signed-off-by: Metin Kaya <metin.kaya@arm.com>
[jstultz: Add more details to the traceevents for validating
 proxy behavior]
Signed-off-by: John Stultz <jstultz@google.com>
Bug: 306081722
---
v10:
* Add more details to the traceevents (owner task for proxy
  migrations, and  prev, selected and next for task selection)
  so its easier to understand the proxy behavior.
v11:
* Rename sched_pe_owner_is_migrating and include owner & waiter
  in the trace_event
* Add trace-event for activation of blocked entities
* Rename sched_pe_migration
* Add sched_pe_return_migration to track return migration events
v12:
* Renaming of selected -> donor
* Nit fixup suggested by Metin
* Build fixup for !SCHED_PROXY_EXEC case
This commit is contained in:
Metin Kaya
2023-12-27 12:09:08 +00:00
committed by John Stultz
parent f86b854c98
commit 6d7a9ac0d5
2 changed files with 254 additions and 1 deletions
+241
View File
@@ -793,6 +793,247 @@ TRACE_EVENT(sched_wake_idle_without_ipi,
TP_printk("cpu=%d", __entry->cpu)
);
#ifdef CONFIG_SCHED_PROXY_EXEC
/**
* sched_pe_enqueue_sleeping_task - called when a task is enqueued on wait
* queue of a sleeping task (mutex owner).
* @mutex_owner: pointer to struct task_struct
* @blocked: pointer to struct task_struct
*/
TRACE_EVENT(sched_pe_enqueue_sleeping_task,
TP_PROTO(struct task_struct *mutex_owner, struct task_struct *blocked),
TP_ARGS(mutex_owner, blocked),
TP_STRUCT__entry(
__array(char, owner_comm, TASK_COMM_LEN )
__field(pid_t, owner_pid )
__field(int, owner_prio )
__field(int, owner_cpu )
__array(char, blocked_comm, TASK_COMM_LEN )
__field(pid_t, blocked_pid )
__field(int, blocked_prio )
__field(int, blocked_cpu )
),
TP_fast_assign(
strscpy(__entry->owner_comm, mutex_owner->comm, TASK_COMM_LEN);
__entry->owner_pid = mutex_owner->pid;
__entry->owner_prio = mutex_owner->prio; /* XXX SCHED_DEADLINE */
__entry->owner_cpu = task_cpu(mutex_owner);
strscpy(__entry->blocked_comm, blocked->comm, TASK_COMM_LEN);
__entry->blocked_pid = blocked->pid;
__entry->blocked_prio = blocked->prio; /* XXX SCHED_DEADLINE */
__entry->blocked_cpu = task_cpu(blocked);
),
TP_printk("task=%s pid=%d prio=%d cpu=%d blocked_on owner_task=%s owner_pid=%d owner_prio=%d owner_cpu=%d",
__entry->blocked_comm, __entry->blocked_pid,
__entry->blocked_prio, __entry->blocked_cpu,
__entry->owner_comm, __entry->owner_pid,
__entry->owner_prio, __entry->owner_cpu)
);
/**
* sched_pe_activate_blocked_entity - called when a blocked entity is activated
* when mutex owner wakes
* @owner: pointer to struct task_struct
* @blocked: pointer to struct task_struct
*/
TRACE_EVENT(sched_pe_activate_blocked_entity,
TP_PROTO(struct task_struct *owner, struct task_struct *blocked),
TP_ARGS(owner, blocked),
TP_STRUCT__entry(
__array(char, owner_comm, TASK_COMM_LEN )
__field(pid_t, owner_pid )
__field(int, owner_prio )
__field(int, owner_cpu )
__array(char, blocked_comm, TASK_COMM_LEN )
__field(pid_t, blocked_pid )
__field(int, blocked_prio )
__field(int, blocked_cpu )
),
TP_fast_assign(
strscpy(__entry->owner_comm, owner->comm, TASK_COMM_LEN);
__entry->owner_pid = owner->pid;
__entry->owner_prio = owner->prio; /* XXX SCHED_DEADLINE */
__entry->owner_cpu = task_cpu(owner);
strscpy(__entry->blocked_comm, blocked->comm, TASK_COMM_LEN);
__entry->blocked_pid = blocked->pid;
__entry->blocked_prio = blocked->prio; /* XXX SCHED_DEADLINE */
__entry->blocked_cpu = task_cpu(blocked);
),
TP_printk("activating task=%s pid=%d prio=%d cpu=%d, blocked_on owner=%s pid=%d prio=%d cpu=%d",
__entry->blocked_comm, __entry->blocked_pid,
__entry->blocked_prio, __entry->blocked_cpu,
__entry->owner_comm, __entry->owner_pid,
__entry->owner_prio, __entry->owner_cpu)
);
/**
* sched_pe_cross_remote_cpu - called when dependency chain crosses remote CPU
* @p: pointer to struct task_struct
*/
TRACE_EVENT(sched_pe_migration,
TP_PROTO(struct task_struct *next, struct task_struct *owner),
TP_ARGS(next, owner),
TP_STRUCT__entry(
__array(char, next_comm, TASK_COMM_LEN )
__field(pid_t, next_pid )
__field(int, next_prio )
__array(char, owner_comm, TASK_COMM_LEN )
__field(pid_t, owner_pid )
__field(int, owner_prio )
__field(int, remote_cpu )
),
TP_fast_assign(
strscpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
__entry->next_pid = next->pid;
__entry->next_prio = next->prio; /* XXX SCHED_DEADLINE */
strscpy(__entry->owner_comm, owner->comm, TASK_COMM_LEN);
__entry->owner_pid = owner->pid;
__entry->owner_prio = owner->prio; /* XXX SCHED_DEADLINE */
__entry->remote_cpu = task_cpu(owner);
),
TP_printk("next=%s pid=%d prio=%d owner=%s pid=%d prio=%d remote_cpu=%d",
__entry->next_comm, __entry->next_pid, __entry->next_prio,
__entry->owner_comm, __entry->owner_pid, __entry->owner_prio,
__entry->remote_cpu)
);
/**
* sched_pe_task_is_migrating - called when mutex owner is in migrating state
* @p: pointer to struct task_struct
*/
TRACE_EVENT(sched_pe_owner_is_migrating,
TP_PROTO(struct task_struct *owner, struct task_struct *waiter),
TP_ARGS(owner, waiter),
TP_STRUCT__entry(
__array(char, owner_comm, TASK_COMM_LEN )
__field(pid_t, owner_pid )
__field(int, owner_prio )
__array(char, waiter_comm, TASK_COMM_LEN )
__field(pid_t, waiter_pid )
__field(int, waiter_prio )
),
TP_fast_assign(
strscpy(__entry->owner_comm, owner->comm, TASK_COMM_LEN);
__entry->owner_pid = owner->pid;
__entry->owner_prio = owner->prio; /* XXX SCHED_DEADLINE */
strscpy(__entry->waiter_comm, waiter->comm, TASK_COMM_LEN);
__entry->waiter_pid = waiter->pid;
__entry->waiter_prio = waiter->prio; /* XXX SCHED_DEADLINE */
),
TP_printk("owner comm=%s pid=%d prio=%d waiter comm=%s pid=%d prio=%d",
__entry->owner_comm, __entry->owner_pid, __entry->owner_prio,
__entry->waiter_comm, __entry->waiter_pid, __entry->waiter_prio)
);
#endif /* CONFIG_SCHED_PROXY_EXEC */
/**
* sched_pe_cross_remote_cpu - called when dependency chain crosses remote CPU
* @p: pointer to struct task_struct
*/
TRACE_EVENT(sched_pe_return_migration,
TP_PROTO(struct task_struct *task, int target_cpu),
TP_ARGS(task, target_cpu),
TP_STRUCT__entry(
__array(char, comm, TASK_COMM_LEN )
__field(pid_t, pid )
__field(int, prio )
__field(int, target_cpu )
),
TP_fast_assign(
strscpy(__entry->comm, task->comm, TASK_COMM_LEN);
__entry->pid = task->pid;
__entry->prio = task->prio; /* XXX SCHED_DEADLINE */
__entry->target_cpu = target_cpu;
),
TP_printk("task=%s pid=%d prio=%d target_cpu=%d",
__entry->comm, __entry->pid, __entry->prio,
__entry->target_cpu)
);
TRACE_EVENT(sched_start_task_selection,
TP_PROTO(struct task_struct *prev, int cpu, bool is_blocked),
TP_ARGS(prev, cpu, is_blocked),
TP_STRUCT__entry(
__array(char, comm, TASK_COMM_LEN )
__field(pid_t, pid )
__field(int, prio )
__field(bool, is_blocked )
),
TP_fast_assign(
strscpy(__entry->comm, prev->comm, TASK_COMM_LEN);
__entry->pid = prev->pid;
__entry->prio = prev->prio; /* XXX SCHED_DEADLINE */
__entry->is_blocked = is_blocked;
),
TP_printk("prev=%s pid=%d prio=%d is_blocked: %i",
__entry->comm, __entry->pid, __entry->prio, __entry->is_blocked)
);
TRACE_EVENT(sched_finish_task_selection,
TP_PROTO(struct task_struct *donor, struct task_struct *next, int cpu),
TP_ARGS(donor, next, cpu),
TP_STRUCT__entry(
__array(char, donor_comm, TASK_COMM_LEN )
__field(pid_t, donor_pid )
__field(int, donor_prio )
__array(char, next_comm, TASK_COMM_LEN )
__field(pid_t, next_pid )
__field(int, next_prio )
__field(int, cpu )
),
TP_fast_assign(
strscpy(__entry->donor_comm, donor->comm, TASK_COMM_LEN);
__entry->donor_pid = donor->pid;
__entry->donor_prio = donor->prio; /* XXX SCHED_DEADLINE */
strscpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
__entry->next_pid = next->pid;
__entry->next_prio = next->prio; /* XXX SCHED_DEADLINE */
__entry->cpu = cpu;
),
TP_printk("donor=%s pid=%d prio=%d next=%s pid=%d prio=%d cpu=%d",
__entry->donor_comm, __entry->donor_pid, __entry->donor_prio,
__entry->next_comm, __entry->next_pid, __entry->next_prio,
__entry->cpu)
);
/*
* Following tracepoints are not exported in tracefs and provide hooking
* mechanisms only for testing and debugging purposes.
+13 -1
View File
@@ -3937,6 +3937,7 @@ static void activate_blocked_waiters(struct rq *target_rq,
raw_spin_unlock_irqrestore(&owner->blocked_lock, flags);
do_activate_blocked_waiter(target_rq, p, en_flags);
trace_sched_pe_activate_blocked_entity(owner, p);
raw_spin_lock_irqsave(&p->blocked_lock, flags);
if (list_empty(&p->blocked_activation_node)) {
@@ -4101,8 +4102,10 @@ static int ttwu_runnable(struct task_struct *p, int wake_flags)
*/
wakeup_preempt(rq, p, wake_flags);
}
if (proxy_needs_return(rq, p))
if (proxy_needs_return(rq, p)) {
trace_sched_pe_return_migration(p, p->wake_cpu);
goto out;
}
ttwu_do_wakeup(p);
ret = 1;
}
@@ -7093,6 +7096,7 @@ static void proxy_enqueue_on_owner(struct rq *rq, struct task_struct *owner,
* ttwu_activate() will pick them up and place them on whatever rq
* @owner will run next.
*/
trace_sched_pe_enqueue_sleeping_task(owner, p);
WARN_ON(p == owner);
WARN_ON(!p->on_rq);
WARN_ON(p->sleeping_owner);
@@ -7185,6 +7189,8 @@ find_proxy_task(struct rq *rq, struct task_struct *donor, struct rq_flags *rf)
owner_cpu = task_cpu(owner);
if (owner_cpu != this_cpu) {
trace_sched_pe_migration(donor, owner);
/*
* @owner can disappear, simply migrate to @owner_cpu and leave that CPU
* to sort things out.
@@ -7199,6 +7205,8 @@ find_proxy_task(struct rq *rq, struct task_struct *donor, struct rq_flags *rf)
}
if (task_on_rq_migrating(owner)) {
trace_sched_pe_owner_is_migrating(owner, p);
/*
* One of the chain of mutex owners is currently migrating to this
* CPU, but has not yet been enqueued because we are holding the
@@ -7336,6 +7344,7 @@ needs_return:
return proxy_resched_idle(rq);
p->blocked_on_state = BO_RUNNABLE;
trace_sched_pe_return_migration(p, p->wake_cpu);
proxy_migrate_task(rq, rf, p, p->wake_cpu);
return NULL;
@@ -7486,6 +7495,8 @@ static void __sched notrace __schedule(int sched_mode)
}
prev_not_proxied = !prev->blocked_donor;
trace_sched_start_task_selection(prev, cpu, task_is_blocked(prev));
pick_again:
next = pick_next_task(rq, rq->donor, &rf);
rq_set_donor(rq, next);
@@ -7500,6 +7511,7 @@ pick_again:
if (next == rq->idle)
preserve_need_resched = true;
}
trace_sched_finish_task_selection(rq->donor, next, cpu);
picked:
if (!preserve_need_resched)
clear_tsk_need_resched(prev);