sched: Fix sched_wakeup tracepoint

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

+++ b/kernel/sched/core.c

kernel/sched/core.c +1 -1

@@ -1457,7 +1457,6 @@ static void
 ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
 {
 	check_preempt_curr(rq, p, wake_flags);
-	trace_sched_wakeup(p, true);
 
 	p->state = TASK_RUNNING;
 #ifdef CONFIG_SMP

@@ -1505,6 +1504,7 @@ static int ttwu_remote(struct task_struct *p, int wake_flags)
 	if (task_on_rq_queued(p)) {
 		/* check_preempt_curr() may use rq clock */
 		update_rq_clock(rq);
+		trace_sched_wakeup(p, true);
 		ttwu_do_wakeup(rq, p, wake_flags);
 		ret = 1;
 	}

Quoted 16 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Quoted 2 lines

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

Quoted 23 lines

+++ b/kernel/sched/core.c

kernel/sched/core.c +1 -1

@@ -1457,7 +1457,6 @@ static void
 ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
 {
 	check_preempt_curr(rq, p, wake_flags);
-	trace_sched_wakeup(p, true);
 
 	p->state = TASK_RUNNING;
 #ifdef CONFIG_SMP

@@ -1505,6 +1504,7 @@ static int ttwu_remote(struct task_struct *p, int
 wake_flags)
 	if (task_on_rq_queued(p)) {
 		/* check_preempt_curr() may use rq clock */
 		update_rq_clock(rq);
+		trace_sched_wakeup(p, true);
 		ttwu_do_wakeup(rq, p, wake_flags);
 		ret = 1;

kernel/sched/core.c +0 -0

 	}

@@ -1619,6 +1619,7 @@ static void ttwu_queue(struct task_struct *p, int cpu)
 {
 	struct rq *rq = cpu_rq(cpu);
 

kernel/sched/core.c static void ttwu_queue(struct task_struct *p, int cpu) · line 1625

Quoted 4 lines

kernel/sched/core.c +1 -0

+	trace_sched_wakeup(p, true);
 #if defined(CONFIG_SMP)
 	if (sched_feat(TTWU_QUEUE) && !cpus_share_cache(smp_processor_id(), cpu)) {
 		sched_clock_cpu(cpu); /* sync clocks x-cpu */

You only need one site in try_to_wake_up(), put it right after success=1.

Quoted 17 lines · ----- On Jun 5, 2015, at 2:09 PM, Peter Zijlstra [email protected] wrote:

Quoted 16 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Quoted 5 lines

Quoted 2 lines

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

That would be the delay between timestamp@wakeup (in the waker) to timestamp@sched_switch_in (in the wakee).

ttwu_pending is going through a lockless list populated before sending the IPI, and iterated on by the IPI handler. Therefore moving the tracepoint before the enqueue will account spend in the queue in the wakeup latency time.

Quoted 23 lines

Quoted 23 lines

+++ b/kernel/sched/core.c

kernel/sched/core.c +1 -1

@@ -1457,7 +1457,6 @@ static void
 ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
 {
 	check_preempt_curr(rq, p, wake_flags);
-	trace_sched_wakeup(p, true);
 
 	p->state = TASK_RUNNING;
 #ifdef CONFIG_SMP

@@ -1505,6 +1504,7 @@ static int ttwu_remote(struct task_struct *p, int
 wake_flags)
 	if (task_on_rq_queued(p)) {
 		/* check_preempt_curr() may use rq clock */
 		update_rq_clock(rq);
+		trace_sched_wakeup(p, true);
 		ttwu_do_wakeup(rq, p, wake_flags);
 		ret = 1;

kernel/sched/core.c +0 -0

 	}

@@ -1619,6 +1619,7 @@ static void ttwu_queue(struct task_struct *p, int cpu)
 {
 	struct rq *rq = cpu_rq(cpu);
 

Quoted 7 lines

kernel/sched/core.c static void ttwu_queue(struct task_struct *p, int cpu) · line 1625

Quoted 4 lines

kernel/sched/core.c +1 -0

+	trace_sched_wakeup(p, true);
 #if defined(CONFIG_SMP)
 	if (sched_feat(TTWU_QUEUE) && !cpus_share_cache(smp_processor_id(), cpu)) {
 		sched_clock_cpu(cpu); /* sync clocks x-cpu */

You only need one site in try_to_wake_up(), put it right after success=1.

There are code paths further down the chain that check whether the task is not fully dequeued from the runqueue (e.g. after grabbing the rq lock in ttwu_remote()) and skips sched_wakeup event in those cases. Do we care about not tracing an event in those cases, or would tracing it (as per your suggestion) be preferable ?

Also, moving the tracepoint to try_to_wake_up() would not be enough. We would also need to instrument try_to_wake_up_local().

Quoted 19 lines · Mathieu Desnoyers

Quoted 17 lines · ----- On Jun 5, 2015, at 2:09 PM, Peter Zijlstra [email protected] wrote:

Quoted 16 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Quoted 8 lines

Quoted 5 lines

Quoted 2 lines

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

That would be the delay between timestamp@wakeup (in the waker) to timestamp@sched_switch_in (in the wakee).

That's scheduling latency. Its how long it takes a runnable task to become running. Wakeup latency would be how long it takes from 'event' to the task being runnable.

The unfortunate situation here is that placing that tracepoint in the wakee -- which makes sense -- makes measuring either of the above latencies impossible because it does not capture the becoming RUNNABLE part.

Quoted 4 lines

ttwu_pending is going through a lockless list populated before sending the IPI, and iterated on by the IPI handler. Therefore moving the tracepoint before the enqueue will account spend in the queue in the wakeup latency time.

Which is wrong from all points of view latencies.

Quoted 32 lines

Quoted 31 lines

Quoted 21 lines

+++ b/kernel/sched/core.c

kernel/sched/core.c +1 -1

@@ -1457,7 +1457,6 @@ static void
 ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
 {
 	check_preempt_curr(rq, p, wake_flags);
-	trace_sched_wakeup(p, true);
 
 	p->state = TASK_RUNNING;
 #ifdef CONFIG_SMP

@@ -1505,6 +1504,7 @@ static int ttwu_remote(struct task_struct *p, int
 wake_flags)
 	if (task_on_rq_queued(p)) {
 		/* check_preempt_curr() may use rq clock */
 		update_rq_clock(rq);
+		trace_sched_wakeup(p, true);
 		ttwu_do_wakeup(rq, p, wake_flags);
 		ret = 1;

kernel/sched/core.c +0 -0

 	}

kernel/sched/core.c static void ttwu_queue(struct task_struct *p, int cpu) · line 1625

Quoted 7 lines

kernel/sched/core.c +1 -0

@@ -1619,6 +1619,7 @@ static void ttwu_queue(struct task_struct *p, int cpu)
 {
 	struct rq *rq = cpu_rq(cpu);
 
+	trace_sched_wakeup(p, true);
 #if defined(CONFIG_SMP)
 	if (sched_feat(TTWU_QUEUE) && !cpus_share_cache(smp_processor_id(), cpu)) {
 		sched_clock_cpu(cpu); /* sync clocks x-cpu */

You only need one site in try_to_wake_up(), put it right after success=1.

Quoted 5 lines

There are code paths further down the chain that check whether the task is not fully dequeued from the runqueue (e.g. after grabbing the rq lock in ttwu_remote()) and skips sched_wakeup event in those cases. Do we care about not tracing an event in those cases, or would tracing it (as per your suggestion) be preferable ?

Its an actual wakeup, we change task->state, therefore one should trace it.

Quoted 4 lines

Also, moving the tracepoint to try_to_wake_up() would not be enough. We would also need to instrument try_to_wake_up_local().

Sure, I just objected to having 2 tracepoint in the 'normal' wakeup path.

OK, so considering the definition naming feedback you provided, we may need a 3 tracepoint if we want to calculate both wakeup latency and scheduling latency (naming ofc open to discussion):

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

We can then calculate wakeup latency as

time@sched_activate - time@sched_wakeup

And scheduling latency as

time@sched_switch - time@sched_activate

In the case of critical path analysis, we don't care about this level of granularity. What we care about is is sum of the two, which we can express as:

time@sched_switch - time@sched_wakeup

Is there an officially blessed name for this ?

Quoted 7 lines · Mathieu Desnoyers

OK, so considering the definition naming feedback you provided, we may need a 3 tracepoint if we want to calculate both wakeup latency and scheduling latency (naming ofc open to discussion):

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

I would propose:

sched_waking: upon calling try_to_wake_up() as soon as we know we need
to change state; guaranteed to be called from the context doing the wakeup.

sched_woken: the wakeup is complete (task is runnable, any delay
between this and actually getting on a cpu is down to the scheduler).

sched_switch: when switching from task @prev to @next.

This means abandoning trace_sched_wakeup(); which might be a problem, which is why I bloody hate tracepoints :-(

Quoted 7 lines · Mathieu Desnoyers

OK, so considering the definition naming feedback you provided, we may need a 3 tracepoint if we want to calculate both wakeup latency and scheduling latency (naming ofc open to discussion):

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

I would propose:

sched_waking: upon calling try_to_wake_up() as soon as we know we need
to change state; guaranteed to be called from the context doing the wakeup.

sched_woken: the wakeup is complete (task is runnable, any delay
between this and actually getting on a cpu is down to the scheduler).

sched_switch: when switching from task @prev to @next.

This means abandoning trace_sched_wakeup(); which might be a problem, which is why I bloody hate tracepoints :-(

Quoted 11 lines · ----- On Jun 6, 2015, at 2:02 PM, Peter Zijlstra [email protected] wrote:

Quoted 7 lines · Mathieu Desnoyers

OK, so considering the definition naming feedback you provided, we may need a 3 tracepoint if we want to calculate both wakeup latency and scheduling latency (naming ofc open to discussion):

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

I would propose:

Quoted 8 lines

sched_waking: upon calling try_to_wake_up() as soon as we know we need
to change state; guaranteed to be called from the context doing the wakeup.

sched_woken: the wakeup is complete (task is runnable, any delay
between this and actually getting on a cpu is down to the scheduler).

sched_switch: when switching from task @prev to @next.

Agreed,

Quoted 3 lines

This means abandoning trace_sched_wakeup(); which might be a problem, which is why I bloody hate tracepoints :-(

OK. I guess it's about time we dive into that question. Should tracepoint semantic be kept cast in stone forever ? Not in my opinion, and here is why.

Most of the Linux kernel ABI exposed to userspace serves as support to runtime (system calls, virtual file systems, etc). For all that, it makes tons of sense to keep it stable, following the Documentation/ABI/README guidelines. Even there, we have provisions for obsolescence and removal of an ABI if need be, which provides userspace some time to adapt to changes.

How are tracepoints different ? Well, those are not meant to be used in runtime support, but rather for analyzing systems, which means that userspace tools using the tracepoint content do not need it to _run_, but rather as information source to perform analyses.

Even though I dislike analogies, I think we need one here. Let's consider CAN bus ports for car debugging. Even though the transport is covered by standards, it does not mandate the semantics of the data per se. I would not expect a debugging device made in 2005 to work for newest generations of car. However, I would expect that new debug devices are compatible with older cars, and that those debug devices have means to query which type of car it is debugging. Otherwise, the debugging device is simply crap, because it cannot adapt to change. What should a debug device created in 2005 do if connected to a new car ? Ideally, it should gracefully decline to interact with this car, and require a software upgrade.

OK, now back to kernel tracepoints. My opinion is that it is a fundamental requirement that trace analysis tools should be able to detect that they are unable understand tracepoint data they care about. It seems perfectly fine to me to require that analysis tool upgrades are needed to interact with a new kernel. However, a tool should be able to handle a range of older kernel versions too.

This can be done by many means, including making sure preexisting event name and fields semantic are immutable, or by versioning of tracepoints on a per-event basis.

Here, in the case of sched_wakeup: we end up noticing that it accidentally changed location in the kernel across versions, which makes it useless for many analyses unless they use kernel version information to get the right semantic associated with this event.

So here, for introducing sched_waking/sched_woken, we have a few ways forward:

1) Keep sched_wakeup as it is, and add those two new events. Analyses can then continue using the old event for a while, and if they sees that sched_waking/sched_woken are there, they can use those more precise events instead. This could allow us to do a gradual deprecation phase for the sched_wakeup tracepoint.

2) Remove sched_wakeup event, replacing it by sched_waking/sched_woken. Require immediate analysis tool upgrade to deal with this new information. Old tools should gracefully fail and ask users to upgrade. If they don't, fix them so they can handle change.

So how about we introduce the 'waking' tracepoint and leave the existing wakeup one in place and preserve its woken semantics.

Steven, can we do aliases? Where one tracepoint is known to userspace under multiple names? In that case we could rename the thing to woken and have an alias wakeup which we can phase out over time.

The patch also takes away the success parameter to the tracepoint, but does not quite go as far as actually removing it from the tracepoint itself.

We can do that in a follow up patch which we can quickly revert if it turns out people are actually still using that for something.

---
include/trace/events/sched.h | 28 ++++++++++++++++++++--------
kernel/sched/core.c | 9 ++++++---

2 files changed, 26 insertions(+), 11 deletions(-)

include/trace/events/sched.h +20 -8

index d57a575fe31f..b1608d5679e2 100644
@@ -55,7 +55,7 @@ TRACE_EVENT(sched_kthread_stop_ret,
 */
 DECLARE_EVENT_CLASS(sched_wakeup_template,
 
-	TP_PROTO(struct task_struct *p, int success),
+	TP_PROTO(struct task_struct *p),
 
 	TP_ARGS(__perf_task(p), success),
 

@@ -71,25 +71,37 @@ DECLARE_EVENT_CLASS(sched_wakeup_template,
 		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
 		__entry->pid		= p->pid;
 		__entry->prio		= p->prio;
-		__entry->success	= success;
+		__entry->success	= 1; /* rudiment, kill when possible */
 		__entry->target_cpu	= task_cpu(p);
 	),
 
-	TP_printk("comm=%s pid=%d prio=%d success=%d target_cpu=%03d",
+	TP_printk("comm=%s pid=%d prio=%d target_cpu=%03d",
 		  __entry->comm, __entry->pid, __entry->prio,
-		  __entry->success, __entry->target_cpu)
+		  __entry->target_cpu)
 );
 
+/*
+ * Tracepoint called when waking a task; this tracepoint is guaranteed to be
+ * called from the waking context.
+ */
+DEFINE_EVENT(sched_wakeup_template, sched_waking,
+	     TP_PROTO(struct task_struct *p),
+	     TP_ARGS(p));
+
+/*
+ * Tracepoint called when the task is actually woken; p->state == TASK_RUNNNG.
+ * It it not always called from the waking context.
+ */
 DEFINE_EVENT(sched_wakeup_template, sched_wakeup,
-	     TP_PROTO(struct task_struct *p, int success),
-	     TP_ARGS(p, success));
+	     TP_PROTO(struct task_struct *p),
+	     TP_ARGS(p));
 
 /*
 * Tracepoint for waking up a new task:
 */
 DEFINE_EVENT(sched_wakeup_template, sched_wakeup_new,
-	     TP_PROTO(struct task_struct *p, int success),
-	     TP_ARGS(p, success));
+	     TP_PROTO(struct task_struct *p),
+	     TP_ARGS(p));
 
 #ifdef CREATE_TRACE_POINTS
 static inline long __trace_sched_switch_state(struct task_struct *p)

kernel/sched/core.c +3 -2

index d5078c0f20e6..354e667620a9 100644
@@ -1487,9 +1487,9 @@ static void
 ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
 {
 	check_preempt_curr(rq, p, wake_flags);
-	trace_sched_wakeup(p, true);
-
 	p->state = TASK_RUNNING;
+	trace_sched_wakeup(p);
+
 #ifdef CONFIG_SMP
 	if (p->sched_class->task_woken)
 		p->sched_class->task_woken(rq, p);

@@ -1695,6 +1695,7 @@ try_to_wake_up(struct task_struct *p, unsigned int state,
 int wake_flags)
 		goto out;
 
 	success = 1; /* we're going to change ->state */
+	trace_sched_waking(p);
 	cpu = task_cpu(p);
 

	if (p->on_rq && ttwu_remote(p, wake_flags))

kernel/sched/core.c +3 -1

@@ -1761,6 +1762,8 @@ static void try_to_wake_up_local(struct task_struct *p)
 	if (!(p->state & TASK_NORMAL))
 		goto out;
 
+	trace_sched_waking(p);
+
 	if (!task_on_rq_queued(p))
 		ttwu_activate(rq, p, ENQUEUE_WAKEUP);
 

@@ -2119,7 +2122,7 @@ void wake_up_new_task(struct task_struct *p)
 	rq = __task_rq_lock(p);
 	activate_task(rq, p, 0);
 	p->on_rq = TASK_ON_RQ_QUEUED;
-	trace_sched_wakeup_new(p, true);
+	trace_sched_wakeup_new(p);
 	check_preempt_curr(rq, p, WF_FORK);
 #ifdef CONFIG_SMP
 	if (p->sched_class->task_woken)

So how about we introduce the 'waking' tracepoint and leave the existing wakeup one in place and preserve its woken semantics.

Steven, can we do aliases? Where one tracepoint is known to userspace under multiple names? In that case we could rename the thing to woken and have an alias wakeup which we can phase out over time.

The patch also takes away the success parameter to the tracepoint, but does not quite go as far as actually removing it from the tracepoint itself.

We can do that in a follow up patch which we can quickly revert if it turns out people are actually still using that for something.

Quoted 8 lines · Peter Zijlstra

So how about we introduce the 'waking' tracepoint and leave the existing wakeup one in place and preserve its woken semantics.

Steven, can we do aliases? Where one tracepoint is known to userspace under multiple names? In that case we could rename the thing to woken and have an alias wakeup which we can phase out over time.

Quoted 6 lines

The patch also takes away the success parameter to the tracepoint, but does not quite go as far as actually removing it from the tracepoint itself.

We can do that in a follow up patch which we can quickly revert if it turns out people are actually still using that for something.

+1 to this patch. How is it going?

Here at Twitter, we are analyzing scheduling latencies too, with our own tool using existing tracepoints, it would be nice to have more granularity on the scheduling latency.

And, you probably want to change perf sched to respect this new 'waking' event too. ;)

Thanks.

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

We can then calculate wakeup latency as

time@sched_activate - time@sched_wakeup

Quoted 4 lines · Mathieu Desnoyers

sched_wakeup: when try_to_wake_up{,_local} is called in the waker.
sched_activate_task: when the wakee is marked runnable.
sched_switch: when scheduling actually happens.

Quoted 3 lines

We can then calculate wakeup latency as

time@sched_activate - time@sched_wakeup

One more thing, I think I would disagree with this. I would suggest never to use the 'wakeup' (or 'waking' in my proposal) for timing. I would suggest to use your interrupt tracepoint (or whatever else causes wakeup to be called for this).

The wakeup times should be measured in tasktime -- of course, if interrupts/preemption are disabled then tasktime == walltime.

The scheduling bit OTOH always needs to be measured in walltime, and is most affected by the presence of other tasks on the system.

This too is why I'm not sure it makes sense to combine the two into a single measurement. They should be measured in different time domains.

Quoted 16 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Quoted 2 lines

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

Quoted 17 lines · Peter Zijlstra

Quoted 16 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Quoted 5 lines

Quoted 2 lines

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

Well, the point of wakeup is when the wakee calls wakeup. If the trace

point is in the IPI then you account the time between the wakeup and the actuall handling in the IPI to the wakee instead of accounting it to the time between wakeup and sched switch.

Thanks,

tglx

Quoted 20 lines · Peter Zijlstra

Quoted 18 lines · Mathieu Desnoyers

Commit 317f394160e9 "sched: Move the second half of ttwu() to the remote cpu" moves ttwu_do_wakeup() to an IPI handler context on the remote CPU for remote wakeups. This commit appeared upstream in Linux v3.0.

Unfortunately, ttwu_do_wakeup() happens to contain the "sched_wakeup" tracepoint. Analyzing wakup latencies depends on getting the wakeup chain right: which process is the waker, which is the wakee. Moving this instrumention outside of the waker context prevents trace analysis tools from getting the waker pid, either through "current" in the tracepoint probe, or by deducing it using other scheduler events based on the CPU executing the tracepoint.

Another side-effect of moving this instrumentation to the scheduler ipi is that the delay during which the wakeup is sitting in the pending queue is not accounted for when calculating wakeup latency.

Therefore, move the sched_wakeup instrumentation back to the waker context to fix those two shortcomings.

Quoted 2 lines

What do you consider wakeup-latency? I don't see how moving the tracepoint into the caller will magically account the queue time.

Well, the point of wakeup is when the wakee calls wakeup. If the trace point is in the IPI then you account the time between the wakeup and the actuall handling in the IPI to the wakee instead of accounting it to the time between wakeup and sched switch.

to the time between wakeup and sched switch.

My point exactly, wake->schedule is what we call the scheduling latency, not the wake latency, which would be from 'event' to the task being runnable.