perf sched: Add trace event for sched wait.

From: Dongsheng <[email protected]>

Signed-off-by Dongsheng <[email protected]>

---
 include/trace/events/sched.h | 20 ++++++++++++++++++++
 1 file changed, 20 insertions(+)

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

index 67e1bbf..7aa7d43a 100644
@@ -51,6 +51,26 @@ TRACE_EVENT(sched_kthread_stop_ret,
 );
 
 /*
+ * Tracepoint for wait:
+ */
+TRACE_EVENT(sched_wait,
+
+	TP_PROTO(struct task_struct *p),
+
+	TP_ARGS(p),
+
+	TP_STRUCT__entry(
+		__field(	pid_t,	pid	)
+	),
+
+	TP_fast_assign(
+		__entry->pid	= p->pid;
+	),
+
+	TP_printk("pid=%d", __entry->pid)
+);
+
+/*
  * Tracepoint for waking up a task:
  */
 DECLARE_EVENT_CLASS(sched_wakeup_template,

Signature · 1 line

1.8.2.1

Quoted 2 lines · Dongsheng Yang

From: Dongsheng <[email protected]>

No changelog, and the tracepoint seems useless to me.

From: Dongsheng <[email protected]>

There is already a function in include/linux/wait.h to cover the 'exclusive' usage. So we can use it in sched/wait.c to replace the opened implementation of it.

Signed-off-by Dongsheng <[email protected]>

---
 kernel/sched/wait.c | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

kernel/sched/wait.c +1 -2

index 283750e..b04827e 100644
@@ -38,9 +38,8 @@ void add_wait_queue_exclusive(wait_queue_head_t *q, wait_queue_t *wait)
 	unsigned long flags;
 
 	trace_sched_wait(current);
-	wait->flags |= WQ_FLAG_EXCLUSIVE;
 	spin_lock_irqsave(&q->lock, flags);
-	__add_wait_queue_tail(q, wait);
+	__add_wait_queue_tail_exclusive(q, wait);
 	spin_unlock_irqrestore(&q->lock, flags);
 }
 EXPORT_SYMBOL(add_wait_queue_exclusive);

Quoted 29 lines · Dongsheng Yang

From: Dongsheng <[email protected]>

There is already a function in include/linux/wait.h to cover the 'exclusive' usage. So we can use it in sched/wait.c to replace the opened implementation of it.

Signed-off-by Dongsheng <[email protected]>

---
  kernel/sched/wait.c | 6 ++----
  1 file changed, 2 insertions(+), 4 deletions(-)

kernel/sched/wait.c +1 -2

index 283750e..b04827e 100644
@@ -38,9 +38,8 @@ void add_wait_queue_exclusive(wait_queue_head_t *q, wait_queue_t *wait)
  	unsigned long flags;
 
  	trace_sched_wait(current);
-	wait->flags |= WQ_FLAG_EXCLUSIVE;
  	spin_lock_irqsave(&q->lock, flags);
-	__add_wait_queue_tail(q, wait);
+	__add_wait_queue_tail_exclusive(q, wait);
  	spin_unlock_irqrestore(&q->lock, flags);
  }
  EXPORT_SYMBOL(add_wait_queue_exclusive);

@@ -192,10 +191,9 @@ prepare_to_wait_exclusive(wait_queue_head_t *q, wait_queue_t *wait, int state)
  	unsigned long flags;
 

kernel/sched/wait.c prepare_to_wait_exclusive(wait_queue_head_t *q, wait_queue_t *wait, int state) · line 198

Quoted 8 lines

kernel/sched/wait.c +1 -2

  	trace_sched_wait(current);
-	wait->flags |= WQ_FLAG_EXCLUSIVE;
  	spin_lock_irqsave(&q->lock, flags);
  	if (list_empty(&wait->task_list))
-		__add_wait_queue_tail(q, wait);
+		__add_wait_queue_tail_exclusive(q, wait);
  	set_current_state(state);
  	spin_unlock_irqrestore(&q->lock, flags);

That is not a no-op, if !list_empty() we loose the WQ_flag

.

From: Dongsheng <[email protected]>

It is pointless to wake up a running task. Currently, we can see it in perf sched latency.

Signed-off-by Dongsheng <[email protected]>

---
 kernel/sched/core.c | 3 +++
 1 file changed, 3 insertions(+)

kernel/sched/core.c +0 -0

index 268a45e..fc6b644 100644

On Tue, Apr 15, 2014 at 09:32:53PM +0900, Dongsheng Yang wrote:

How can you get there with ->state == RUNNING? try_to_wake_up*() bail when !(->state & state).

.

Quoted 4 lines · Peter Zijlstra

On Tue, Apr 15, 2014 at 09:32:53PM +0900, Dongsheng Yang wrote:

How can you get there with ->state == RUNNING? try_to_wake_up*() bail when !(->state & state).

Yes, try_to_wake_up() did this check. But other callers would miss it.

With the following code ,I can get the actual message of waking up a running task

kernel/sched/core.c +0 -0

index 9f63275..1369cae 100644
@@ -1418,8 +1418,10 @@ static void ttwu_activate(struct rq *rq, struct 

task_stru
static void
ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags) {

kernel/sched/core.c +3 -1

-       if (p->state == TASK_RUNNING)
+       if (p->state == TASK_RUNNING) {
+               printk("Wakeup a running task.");
                return;
+       }
 
        check_preempt_curr(rq, p, wake_flags);
        trace_sched_wakeup(p, true);

# grep "Wakeup" /var/log/messages
Apr 15 20:16:21 localhost kernel: [    5.436505] Wakeup a running task.
Apr 15 20:16:21 localhost kernel: [    7.776042] Wakeup a running task.
Apr 15 20:16:21 localhost kernel: [    9.324274] Wakeup a running task.

So, I think there are some caller of ttwu_do_wakeup() is attempt to wake up a running task.

Quoted 2 lines

.

Signature · 5 lines

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/
.

Quoted 29 lines · Dongsheng Yang

Quoted 4 lines · Peter Zijlstra

On Tue, Apr 15, 2014 at 09:32:53PM +0900, Dongsheng Yang wrote:

How can you get there with ->state == RUNNING? try_to_wake_up*() bail when !(->state & state).

Yes, try_to_wake_up() did this check. But other callers would miss it.

With the following code ,I can get the actual message of waking up a running task

kernel/sched/core.c +0 -0

index 9f63275..1369cae 100644
@@ -1418,8 +1418,10 @@ static void ttwu_activate(struct rq *rq, struct

task_stru
static void
ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags) {

kernel/sched/core.c +3 -1

-       if (p->state == TASK_RUNNING)
+       if (p->state == TASK_RUNNING) {
+               printk("Wakeup a running task.");
                return;
+       }
 
        check_preempt_curr(rq, p, wake_flags);
        trace_sched_wakeup(p, true);

Quoted 4 lines

# grep "Wakeup" /var/log/messages
Apr 15 20:16:21 localhost kernel: [    5.436505] Wakeup a running task.
Apr 15 20:16:21 localhost kernel: [    7.776042] Wakeup a running task.
Apr 15 20:16:21 localhost kernel: [    9.324274] Wakeup a running task.

Hi Peter, after some more investigation, I think I got the problem, which is that
some other task set p->state to TASK_RUNNING without holding p->pi_lock.

Scenario as attached graph shown, if some other task set p->state to TASK_RUNNING after the check if (! (p->state & state)), then we are wasting time to wake up a running task in try_to_wake_up().

If the analyse is right, I think there are two methods to solve this problem:
* Skip in ttwu_do_wakeup() when p->state is running, as what my patch
did.
* Add a locking when we set p->state, lots of work to do and I am afraid
it will hurt the performance of kernel.

This is all expected behavior, and the somewhat less than useful trace events are expected. A task setting p->state to TASK_RUNNING without locks is fine if and only p == current. The standard deschedule loop is

basically:

while (1) {
set_current_state(TASK_(UN)INTERRUPTIBLE);

if (should_still_sleep)

    schedule();
}

set_current_state(TASK_RUNNING);

Which can produce this in a race.

The only problem this causes is a wasted check_preempt_curr call in the racing case, and a somewhat inaccurate sched:sched_wakeup trace event. Note that even if you did recheck in ttwu_do_wakeup you could still race and get an "inaccurate" trace event. Heck, even if the ttwu is _necessary_ because p is currently trying to take rq->lock to deschedule, you won't get a matching sched_switch event, because the ttwu is running before schedule is.

You could sorta fix this I guess by tracking every write to p->state with trace events, but that would be a somewhat different change, and might be considered too expensive for all I know (and the trace events could /still/ be resolved in a different order across cpus compared to p->state's memory).

This is all expected behavior, and the somewhat less than useful trace events are expected. A task setting p->state to TASK_RUNNING without locks is fine if and only p == current. The standard deschedule loop is basically:

while (1) {
set_current_state(TASK_(UN)INTERRUPTIBLE);
if (should_still_sleep)

    schedule();
}

set_current_state(TASK_RUNNING);

Which can produce this in a race.

The only problem this causes is a wasted check_preempt_curr call in the racing case, and a somewhat inaccurate sched:sched_wakeup trace event. Note that even if you did recheck in ttwu_do_wakeup you could still race and get an "inaccurate" trace event. Heck, even if the ttwu is _necessary_ because p is currently trying to take rq->lock to deschedule, you won't get a matching sched_switch event, because the ttwu is running before schedule is.

You could sorta fix this I guess by tracking every write to p->state with trace events, but that would be a somewhat different change, and might be considered too expensive for all I know (and the trace events could /still/ be resolved in a different order across cpus compared to p->state's memory).

Quoted 12 lines · On Tue, Apr 22, 2014 at 10:10:52AM -0700, [email protected] wrote:

This is all expected behavior, and the somewhat less than useful trace events are expected. A task setting p->state to TASK_RUNNING without locks is fine if and only p == current. The standard deschedule loop is basically:

while (1) {
   set_current_state(TASK_(UN)INTERRUPTIBLE);
   if (should_still_sleep)
     schedule();
}

set_current_state(TASK_RUNNING);

Quoted 6 lines

Which can produce this in a race.

The only problem this causes is a wasted check_preempt_curr call in the racing case, and a somewhat inaccurate sched:sched_wakeup trace event. Note that even if you did recheck in ttwu_do_wakeup you could still race and get an "inaccurate" trace event.

Quoted 10 lines

Heck, even if the ttwu is
_necessary_ because p is currently trying to take rq->lock to deschedule, you won't get a matching sched_switch event, because the ttwu is running before schedule is.

You could sorta fix this I guess by tracking every write to p->state with trace events, but that would be a somewhat different change, and might be considered too expensive for all I know (and the trace events could /still/ be resolved in a different order across cpus compared to p->state's memory).

Ah, you're saying that a second task could try a spurious wakeup between set_current_state() and schedule(). Yes, that'll trigger this indeed.

.

The original design of sched:sched_wakeup is to trace the event inserting a task into run queue. It means we can know that the state of this task is changed from "sleeping" to "waiting_cpu". Then we can calculate the delay time from this task on_rq = 1 to running on cpu in perf sched latency.

But currently, sched:sched_wakeup event is tracing ttwu_do_wakeup() and this function only set the p->state to TASK_RUNNING. This trace point can tell user very little. When get a event of sched:sched_wakeup, user know that kernel call ttwu_do_wakeup() once, but we can not say that task start to wait cpu from now on. Maybe it did not dequeue at all, in this case we will get a wrong latency time calculated by "sched_in_time - wakeup_time".

Anyway, current sched:sched_wakeup event can tell user very little. When we get a sched:sched_wakeup:
* We can not say a task is inserted into run queue, it is also used for task which is on_rq and only change the task->state to TASK_RUNNING.
* We can not say the task->state is changed from {UN}INTERRUPTABLE to RUNNING, sometimes task->state is already changed to RUNNING by other cpu.

As explained above, this patch move the trace point of sched:sched_wakeup from ttwu_do_wakeup() to ttwu_activate(), then when we get an event of sched_wakeup, we can say that a task enqueued and started waiting cpu to run.

Signed-off-by Dongsheng Yang <[email protected]>

---
 kernel/sched/core.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

kernel/sched/core.c +1 -1

index 9074c6d..0cae994 100644
@@ -1420,6 +1420,7 @@ static void ttwu_activate(struct rq *rq, struct task_struct *p, int en_flags)
 {
 	activate_task(rq, p, en_flags);
 	p->on_rq = 1;
+	trace_sched_wakeup(p, true);
 
 	/* if a worker is waking up, notify workqueue */
 	if (p->flags & PF_WQ_WORKER)

@@ -1433,7 +1434,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

Quoted 19 lines · On Mon, 5 May 2014 15:34:07 +0900 Dongsheng Yang <[email protected]>…

The original design of sched:sched_wakeup is to trace the event inserting a task into run queue. It means we can know that the state of this task is changed from "sleeping" to "waiting_cpu". Then we can calculate the delay time from this task on_rq = 1 to running on cpu in perf sched latency.

But currently, sched:sched_wakeup event is tracing ttwu_do_wakeup() and this function only set the p->state to TASK_RUNNING. This trace point can tell user very little. When get a event of sched:sched_wakeup, user know that kernel call ttwu_do_wakeup() once, but we can not say that task start to wait cpu from now on. Maybe it did not dequeue at all, in this case we will get a wrong latency time calculated by "sched_in_time - wakeup_time".

Anyway, current sched:sched_wakeup event can tell user very little. When we get a sched:sched_wakeup:
* We can not say a task is inserted into run queue, it is also used for task which is on_rq and only change the task->state to TASK_RUNNING.
* We can not say the task->state is changed from {UN}INTERRUPTABLE to RUNNING, sometimes task->state is already changed to RUNNING by other cpu.

Quoted 4 lines

As explained above, this patch move the trace point of sched:sched_wakeup from ttwu_do_wakeup() to ttwu_activate(), then when we get an event of sched_wakeup, we can say that a task enqueued and started waiting cpu to run.

tldr;

ttwu_do_wakeup() is called when the task's state is switched back to TASK_RUNNING, whether or not the task actually scheduled out. Tracing the wakeup event when the task never scheduled out is quite confusing. It should only trace the task wake up if the task actually did go to sleep. Move the tracepoint from ttwu_do_wakeup() to ttwu_activate() where it is called only if the task is really woken up and not just have its state changed.

-- Steve

Quoted 18 lines

Signed-off-by Dongsheng Yang <[email protected]>

---
  kernel/sched/core.c | 2 +-
  1 file changed, 1 insertion(+), 1 deletion(-)

kernel/sched/core.c +1 -0

index 9074c6d..0cae994 100644
@@ -1420,6 +1420,7 @@ static void ttwu_activate(struct rq *rq, struct task_struct *p, int en_flags)
  {
  	activate_task(rq, p, en_flags);
  	p->on_rq = 1;
+	trace_sched_wakeup(p, true);
 
  	/* if a worker is waking up, notify workqueue */
  	if (p->flags & PF_WQ_WORKER)

kernel/sched/core.c static void · line 1439

Quoted 7 lines

kernel/sched/core.c +0 -1

@@ -1433,7 +1434,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

.

Quoted 1 line

tldr;

Yes, it is really loooong, sorry for my terrible expression in english. :(

Quoted 8 lines

ttwu_do_wakeup() is called when the task's state is switched back to TASK_RUNNING, whether or not the task actually scheduled out. Tracing the wakeup event when the task never scheduled out is quite confusing. It should only trace the task wake up if the task actually did go to sleep. Move the tracepoint from ttwu_do_wakeup() to ttwu_activate() where it is called only if the task is really woken up and not just have its state changed.

Thanx for your kind comment here, it looks shorter and more clear to me. I will update my commit message with your suggestion.

Thank you very much! :)

On Tue, 6 May 2014 09:19:51 +0900 Dongsheng Yang <[email protected]> wrote:

I wonder if we should have the event, or way to distinguish the difference. Hmm, there's that "success" parameter in the tracepoint. Could we possible be able to trace events where the success is true only if it was actually waking the event, and false otherwise?

Having the sched_wakeup trace event show you when something woke the task up may still be useful information. For example, you add yourself to a wait queue and want to see the "wakeup". If we only show it for tasks that really woke up then we wont see it for those that added itself to a waitqueue but was "woken" before it could schedule out.

The original sched_wakeup did this, but with the ttwu rewrite, it was lost.

Something like below?

-- Steve

kernel/sched/core.c +1 -1

index 268a45e..e583989 100644
@@ -1404,6 +1404,7 @@ static void ttwu_activate(struct rq *rq, struct task_struct *p, int en_flags)
  {
  	activate_task(rq, p, en_flags);
  	p->on_rq = 1;
+	trace_sched_wakeup(p, true);
 
  	/* if a worker is waking up, notify workqueue */
  	if (p->flags & PF_WQ_WORKER)

@@ -1417,7 +1418,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

kernel/sched/core.c +0 -1

--

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
.

ttwu_do_wakeup() is called when the task's state is switched back to TASK_RUNNING, whether or not the task actually scheduled out. Tracing the wakeup event when the task never scheduled out is quite confusing.

This patch take the use of 'success' parameter in sched_wakeup tracepoint, to indicate that the task we are waking up did schedule out or just change its state to TASK_RUNNING.

success is true:
task was out of run queue and sleeping, we are really wake it up.
success is false:
taks was on run queue all the time and we just change its state to TASK_RUNNING.

Signed-off-by Dongsheng Yang <[email protected]>

---
  kernel/sched/core.c | 5 ++++-
  1 file changed, 4 insertions(+), 1 deletion(-)

kernel/sched/core.c +4 -1

index 9074c6d..14b9fe4 100644
@@ -1420,6 +1420,7 @@ static void ttwu_activate(struct rq *rq, struct task_struct *p, int en_flags)
  {
  	activate_task(rq, p, en_flags);
  	p->on_rq = 1;
+	trace_sched_wakeup(p, true);
 
  	/* if a worker is waking up, notify workqueue */
  	if (p->flags & PF_WQ_WORKER)

@@ -1433,7 +1434,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

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

@@ -1675,6 +1676,8 @@ static void try_to_wake_up_local(struct task_struct *p)
 
  	if (!p->on_rq)
  		ttwu_activate(rq, p, ENQUEUE_WAKEUP);
+	else
+		trace_sched_wakeup(p, false);
 
  	ttwu_do_wakeup(rq, p, 0);
  	ttwu_stat(p, smp_processor_id(), 0);

Hi steven, does this version look good to you?

ttwu_do_wakeup() is called when the task's state is switched back to TASK_RUNNING, whether or not the task actually scheduled out. Tracing the wakeup event when the task never scheduled out is quite confusing.

This patch take the use of 'success' parameter in sched_wakeup tracepoint, to indicate that the task we are waking up did schedule out or just change its state to TASK_RUNNING.

success is true:
task was out of run queue and sleeping, we are really wake it up.
success is false:
taks was on run queue all the time and we just change its state to TASK_RUNNING.

Quoted 9 lines · Dongsheng Yang

ttwu_do_wakeup() is called when the task's state is switched back to TASK_RUNNING, whether or not the task actually scheduled out. Tracing the wakeup event when the task never scheduled out is quite confusing.

This patch take the use of 'success' parameter in sched_wakeup tracepoint, to indicate that the task we are waking up did schedule out or just change its state to TASK_RUNNING.

Quoted 5 lines

success is true:
task was out of run queue and sleeping, we are really wake it up.
success is false:
taks was on run queue all the time and we just change its state to TASK_RUNNING.

No, I think this patch is crap and doesn't actually change anything much, at best it simply reduces the size of the race window.

I also think you're trying to solve something that cannot be solved.

So the fundamental wait loop is:

   for (;;) {
        set_current_state(TASK_UNINTERRUPTIBLE);
        if (cond)
                break;
        schedule();
   }
   __set_task_state(TASK_RUNNING);

And the fundamental wakeup is:

   cond = true;
   wake_up_process(TASK_NORMAL);

And this is very much on purpose a lock-free but strictly ordered scenario. It is a variation of:

   X = Y = 0

   (wait)       (wake)
   [w] X = 1    [w] Y = 1
   MB           MB
   [r] Y                [r] X

[ where: X := state, Y := cond ]

And we all 'know' that the only provided guarantee is that:

   X==0 && Y==0

is impossible -- but only that, all 3 other states are observable.

This guarantee means that its impossible to both miss the condition and the wakeup; iow. it guarantees fwd progress.

OTOH its fundamentally racy, nothing guarantees we will not 'observe' both the condition and the wakeup.

The setting of .success=false when ->on_rq is actively wrong, suppose the waiter has already observed cond==false but has not yet gotten to schedule(), at that point the wakeup happens and sees ->on_rq==1. The wakeup is still very much a real wakeup.

If it were not for that wakeup the waiter would have gone to sleep and missed the update of condition.

So no.. not going to happen. And certainly not with such a crappy Changelog.

And a frozen seafood of choice lobbed at Steven for not seeing this :-)

Actually, this patch does not attempt to solve the race condition. It only want to avoid sched:sched_wakeup with success==true in a fake wakeup, as explained below.

Quoted 34 lines

So the fundamental wait loop is:

   for (;;) {
        set_current_state(TASK_UNINTERRUPTIBLE);
        if (cond)
                break;
        schedule();
   }
   __set_task_state(TASK_RUNNING);

And the fundamental wakeup is:

   cond = true;
   wake_up_process(TASK_NORMAL);

And this is very much on purpose a lock-free but strictly ordered scenario. It is a variation of:

   X = Y = 0

   (wait)       (wake)
   [w] X = 1    [w] Y = 1
   MB           MB
   [r] Y                [r] X

[ where: X := state, Y := cond ]

And we all 'know' that the only provided guarantee is that:

   X==0 && Y==0

is impossible -- but only that, all 3 other states are observable.

This guarantee means that its impossible to both miss the condition and the wakeup; iow. it guarantees fwd progress.

Quoted 7 lines

OTOH its fundamentally racy, nothing guarantees we will not 'observe' both the condition and the wakeup.

The setting of .success=false when ->on_rq is actively wrong, suppose the waiter has already observed cond==false but has not yet gotten to schedule(), at that point the wakeup happens and sees ->on_rq==1. The wakeup is still very much a real wakeup.

Yes, if a wakeup happens before schedule(), wakeup sees ->on_rq==1. Then we can get an event with .success==false. But I think it is not a real wakeup. :(

Yes, at this moment, maybe the task is already out of run queue. But *this* wakeup did not move it back to run queue, it only change the state of it to TASK_RUNNING. I believe the next wakeup for this task will do the real wake up moving it back to run queue.

And if scheduler really wake it up, we can get an event with success==true.

Anyway, what I want with this patch is to make scheduler raise accurate events when waking up a task.

If a wakeup only change the state of task, raise a event with success==false. If a wakeup move a task back to runqueue, .success==true.

It means, we do not need to care about the task is on_rq or not currently, the value of .success is decided by the behavior we did in the function of try_to_wake_up().

Wish I explain myself clearly.

So if the wait side has already observed cond==false, then without the wakeup, which still potentially has ->on_rq == true, it would block. Therefore the wakeup is a _real_ wakeup.

We fundamentally cannot know, on the wake side, if the wait side has or has not observed cond, and therefore the distinction you're trying to make is a false one.

Quoted 7 lines · On Sun, 11 May 2014 18:35:31 +0200 Peter Zijlstra <[email protected]> wrote:

So if the wait side has already observed cond==false, then without the wakeup, which still potentially has ->on_rq == true, it would block. Therefore the wakeup is a _real_ wakeup.

We fundamentally cannot know, on the wake side, if the wait side has or has not observed cond, and therefore the distinction you're trying to make is a false one.

I believe you may be misunderstanding Dongsheng. It has nothing to do with the wake condition. But the "success" is basically saying, "did I move the task on to the run queue?". That's a relevant piece of information that the wake up event isn't currently showing.

Let me ask you this; with Donsheng's patch, will there ever be a sched_switch event when the wakeup event sees 'false' and the sched_switch event see the task with a state other than "R"? And if so, how did the task doing the wakeup event, wake up that task?

Quoted 7 lines · Steven Rostedt

On Sun, 11 May 2014 18:35:31 +0200
Peter Zijlstra <[email protected]> wrote:
I believe you may be misunderstanding Dongsheng. It has nothing to do with the wake condition. But the "success" is basically saying, "did I move the task on to the run queue?". That's a relevant piece of information that the wake up event isn't currently showing.

Quoted 4 lines

Let me ask you this; with Donsheng's patch, will there ever be a sched_switch event when the wakeup event sees 'false' and the sched_switch event see the task with a state other than "R"? And if so, how did the task doing the wakeup event, wake up that task?

But that has nothing what so fucking ever to do with 'success'. Reusing that trace argument for something entirely different is just retarded.

But that has nothing what so fucking ever to do with 'success'. Reusing that trace argument for something entirely different is just retarded.

Quoted 2 lines · On Mon, 12 May 2014 08:47:30 +0200 Peter Zijlstra <[email protected]> wrote:

But that has nothing what so fucking ever to do with 'success'. Reusing that trace argument for something entirely different is just retarded.

And having a "success" field that his hard coded to "true" is also retarded. At least this change is fucking useful.

How about this. Add a new field called 'rq_added' or something. We can ever shrink the size of the "success" field and hard code it to true in the trace. That will never change. Then the caller of the tracepoint will send in a "true" or "false" to "rq_added" and we can add that tracepoint as well.

What I mean by shrink the size of the success field is that it is currently 4 bytes in size. We can make it two (or one) and then add another field for the 'rq_added' and have that be two bytes as well. This shouldn't break any tools that use this.

Point being, this is useful information, why not pass it to userspace?

Quoted 1 line

Point being, this is useful information, why not pass it to userspace?

Because it adds code to one of the hottest code paths in the kernel and so far nobody had a sane explanation of WTF they were doing.

Quoted 5 lines · On Mon, 12 May 2014 17:09:50 +0200 Peter Zijlstra <[email protected]> wrote:

Quoted 1 line

Point being, this is useful information, why not pass it to userspace?

Because it adds code to one of the hottest code paths in the kernel and so far nobody had a sane explanation of WTF they were doing.

Is there a measurable difference with these extra tracepoints?

Quoted 5 lines · Peter Zijlstra

Quoted 4 lines · Dongsheng Yang

How can you get there with ->state == RUNNING? try_to_wake_up*() bail when !(->state & state).

Hi Peter, after some more investigation, I think I got the problem, which is that
some other task set p->state to TASK_RUNNING without holding p->pi_lock.

Hi all:

	This is to solve the bug message shown in perf sched latency.

	# perf sched latency|tail
	  ksoftirqd/0:3         |      0.597 ms |       57 | avg:    0.004 ms | max:    0.054 ms | max at: 19681.546204 s
	  ksoftirqd/1:14        |      0.637 ms |       58 | avg:    0.004 ms | max:    0.066 ms | max at: 19674.687734 s
	  irqbalance:349        |      0.429 ms |        1 | avg:    0.004 ms | max:    0.004 ms | max at: 19675.791528 s
	  ksoftirqd/3:24        |      0.527 ms |       67 | avg:    0.003 ms | max:    0.011 ms | max at: 19673.285019 s
	  migration/3:23        |      0.000 ms |        1 | avg:    0.002 ms | max:    0.002 ms | max at: 19672.055354 s
	 -----------------------------------------------------------------------------------------
	  TOTAL:                |   4384.616 ms |    36879 |
	 ---------------------------------------------------
	  INFO: 0.030% state machine bugs (11 out of 36684)

	After some investigation, there are two reasons cause this problem.

	(1). Sometimes, scheduler will wake up a running task, it is not necessary,
	     then I skip the wakeup if task->state is TASK_RUNNING. [4/8]

	(2). No tracing for sched wait.
	This is a simple graph for task state changing.

	----------------		1		----------------
	| TASK_RUNNING | ------------------------------>| TASK_RUNNING |
	|   (running)  |<------------------------------ |  (wait cpu)  |
	----------------		2		----------------
		^						|
		|4	-------------------------	3	|
		|-------|TASK_{UN}INTERRUPTABLE	|<--------------|
			|	in wait_rq	|
			-------------------------

	As the graph shown above, there are four event in scheduling, and

we currently are tracing 3 of them.

1 & 2: sched:sched_switch
4: sched:sched_wakeup|sched:sched_wakeup_new

But about 3, we have no trace event for it.

Quoted 1 line · Dongsheng Yang

But about 3, we have no trace event for it.

We do, sched_switch() includes the previous task state. Also there's tons more than a waitqueue you can get stuck in.

.