* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
@ 2008-12-08 19:49 Jason Baron
2008-12-08 19:54 ` Peter Zijlstra
0 siblings, 1 reply; 15+ messages in thread
From: Jason Baron @ 2008-12-08 19:49 UTC (permalink / raw)
hi,
I thought it would be useful to track when a task is
'activated/deactivated'. This case is different from wakeup/wait, in that
task can be activated and deactivated, when the scheduler re-balances
tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
patches I can more precisely figure out when a task becomes runnable and
why.
Patch to add these tracepoints to the lttng tree is below. I'm also including a
systemtap script, originally written by Oracle, but which I've modified to work
with these new tracepoints.
thanks,
-Jason
Signed-off-by: Jason Baron <jbaron at redhat.com>
diff --git a/include/trace/sched.h b/include/trace/sched.h
index fe4767d..d1fd8a3 100644
--- a/include/trace/sched.h
+++ b/include/trace/sched.h
@@ -4,6 +4,8 @@
#include <linux/sched.h>
#include <linux/tracepoint.h>
+struct rq;
+
DECLARE_TRACE(sched_kthread_stop,
TPPROTO(struct task_struct *t),
TPARGS(t));
@@ -44,5 +46,13 @@ DECLARE_TRACE(sched_signal_send,
DECLARE_TRACE(sched_kthread_create,
TPPROTO(void *fn, int pid),
TPARGS(fn, pid));
+DECLARE_TRACE(sched_activate_task,
+ TPPROTO(struct task_struct *p, struct rq *rq),
+ TPARGS(p, rq));
+DECLARE_TRACE(sched_deactivate_task,
+ TPPROTO(struct task_struct *p, struct rq *rq),
+ TPARGS(p, rq));
+
+
#endif
diff --git a/kernel/sched.c b/kernel/sched.c
index cc7f048..7b707cf 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -122,6 +122,8 @@ DEFINE_TRACE(sched_wakeup);
DEFINE_TRACE(sched_wakeup_new);
DEFINE_TRACE(sched_switch);
DEFINE_TRACE(sched_migrate_task);
+DEFINE_TRACE(sched_activate_task);
+DEFINE_TRACE(sched_deactivate_task);
#ifdef CONFIG_SMP
/*
@@ -1716,6 +1718,7 @@ static int effective_prio(struct task_struct *p)
*/
static void activate_task(struct rq *rq, struct task_struct *p, int wakeup)
{
+ trace_sched_activate_task(p, rq);
if (task_contributes_to_load(p))
rq->nr_uninterruptible--;
@@ -1728,6 +1731,7 @@ static void activate_task(struct rq *rq, struct task_struct *p, int wakeup)
*/
static void deactivate_task(struct rq *rq, struct task_struct *p, int sleep)
{
+ trace_sched_deactivate_task(p, rq);
if (task_contributes_to_load(p))
rq->nr_uninterruptible++;
@@ -2420,6 +2424,7 @@ void wake_up_new_task(struct task_struct *p, unsigned long clone_flags)
* Let the scheduling class do new task startup
* management (if any):
*/
+ trace_sched_activate_task(p, rq);
p->sched_class->task_new(rq, p);
inc_nr_running(rq);
}
diff --git a/ltt/probes/kernel-trace.c b/ltt/probes/kernel-trace.c
index e241499..c27e671 100644
--- a/ltt/probes/kernel-trace.c
+++ b/ltt/probes/kernel-trace.c
@@ -372,6 +372,19 @@ void probe_kernel_vprintk(unsigned long retaddr, char *buf, int len)
}
}
+void probe_activate_task(struct task_struct *p, struct rq *rq)
+{
+ trace_mark_tp(kernel_activate_task, sched_activate_task, probe_activate_task,
+ "pid %d state %ld cpu_id %u", p->pid, p->state, task_cpu(p));
+}
+
+void probe_deactivate_task(struct task_struct *p, struct rq *rq)
+{
+ trace_mark_tp(kernel_deactivate_task, sched_deactivate_task,
+ probe_deactivate_task, "pid %d state %ld cpu_id %u",
+ p->pid, p->state, task_cpu(p));
+}
+
#ifdef CONFIG_MODULES
void probe_kernel_module_free(struct module *mod)
{
#!/usr/bin/env stap
#
# Copyright (C) 2007 Oracle Corp.
#
# Trace state transition of one specified process
#
# GNU General Public License (GPL); either version 2, or (at your option) any
# later version.
#
# Parameter 1: specified process id
#
# Usage:
# ./proc_transition_by_pid.stp -gx 1234
#
# Output:
# Process 1234: TASK_RUNNING -> TASK_INTERRUPTIBLE
# Process 1234: TASK_RUNNING -> TASK_STOP
# ...
#
# Note: timestamp may be not exactly point to transition moment. Fix me!
global id_state
global traced_pid
global task_name
/*return task name according to process id*/
function __get_task_name: string (pid:long) %{
struct task_struct *p;
pid_t pid;
pid = (pid_t)(long)THIS->pid;
rcu_read_lock();
p = find_task_by_vpid(pid);
rcu_read_unlock();
if (p==NULL)
strlcpy(THIS->__retvalue,"Unknown",MAXSTRINGLEN);
else {
strlcpy(THIS->__retvalue,p->comm,MAXSTRINGLEN);
}
CATCH_DEREF_FAULT();
%}
function __get_task_struct: long (pid:long) %{
struct task_struct *p;
pid_t pid;
pid = (pid_t)(long)THIS->pid;
rcu_read_lock();
p = find_task_by_vpid(pid);
rcu_read_unlock();
if (p==NULL)
THIS->__retvalue=(long)NULL;
else {
THIS->__retvalue=(long)p;
}
CATCH_DEREF_FAULT();
%}
/* process added into runqueue : really running or well prepared */
probe kernel.mark("kernel_activate_task"){
if ($arg1==traced_pid)
printf("[%d] %s(%d): %s --> TASK_RUNNING\n",get_cycles(),task_name,traced_pid,id_state[$arg2]);
}
/* process removed from runqueue : in wait queue or other state */
probe kernel.mark("kernel_deactivate_task") {
if ($arg1==traced_pid)
printf("[%d] %s(%d): TASK_RUNNING --> %s\n", get_cycles(),task_name,traced_pid, id_state[$arg2]);
}
/* process clean up */
probe kernel.mark("kernel_process_exit") {
if ($arg1==traced_pid){
printf("[%d] %s(%d): %s --> Cleaned \n", get_cycles(),task_execname(__get_task_struct($arg1)),traced_pid,id_state[task_state(__get_task_struct($arg1))]);
exit()
}
}
/* accept one parameter as process id
* if not in correct format, step1 parse reports error*/
probe begin {
/*from sched.h*/
id_state[0] = "TASK_RUNNING"
id_state[1] = "TASK_INTERRUPTIBLE"
id_state[2] = "TASK_UNINTERRUPTIBLE"
id_state[4] = "TASK_STOPPED"
id_state[8] = "TASK_TRACED"
/* exit_state
id_state[16] = "EXIT_ZOMBIE"
id_state[32] = "EXIT_DEAD"
*/
id_state[64] = "TASK_NONINTERACTIVE"
id_state[128] = "TASK_DEAD"
traced_pid = target();
task_name = __get_task_name(traced_pid);
if (task_name!="Unknown") {
printf("Now scanning the process...%s %d\n\n", task_name, traced_pid);
}
else {
printf("No such process!\n");
exit();
}
}
probe end{
delete id_state;
delete traced_pid;
delete task_name;
}
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-08 19:49 [ltt-dev] [patch] add tracepoints to trace activate/deactivate task Jason Baron
@ 2008-12-08 19:54 ` Peter Zijlstra
2008-12-08 22:38 ` Jason Baron
0 siblings, 1 reply; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-08 19:54 UTC (permalink / raw)
On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> hi,
>
> I thought it would be useful to track when a task is
> 'activated/deactivated'. This case is different from wakeup/wait, in that
> task can be activated and deactivated, when the scheduler re-balances
> tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> patches I can more precisely figure out when a task becomes runnable and
> why.
Then I still not agree with it because it does not expose the event that
did the change.
If you want the cpu allowed mask, put a tracepoint there. If you want
migrate information (didn't we have that?) then put one there, etc.
> -Jason
>
> Signed-off-by: Jason Baron <jbaron at redhat.com>
>
>
> diff --git a/include/trace/sched.h b/include/trace/sched.h
> index fe4767d..d1fd8a3 100644
> --- a/include/trace/sched.h
> +++ b/include/trace/sched.h
> @@ -4,6 +4,8 @@
> #include <linux/sched.h>
> #include <linux/tracepoint.h>
>
> +struct rq;
> +
> DECLARE_TRACE(sched_kthread_stop,
> TPPROTO(struct task_struct *t),
> TPARGS(t));
> @@ -44,5 +46,13 @@ DECLARE_TRACE(sched_signal_send,
> DECLARE_TRACE(sched_kthread_create,
> TPPROTO(void *fn, int pid),
> TPARGS(fn, pid));
> +DECLARE_TRACE(sched_activate_task,
> + TPPROTO(struct task_struct *p, struct rq *rq),
> + TPARGS(p, rq));
> +DECLARE_TRACE(sched_deactivate_task,
> + TPPROTO(struct task_struct *p, struct rq *rq),
> + TPARGS(p, rq));
> +
> +
>
> #endif
> diff --git a/kernel/sched.c b/kernel/sched.c
> index cc7f048..7b707cf 100644
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -122,6 +122,8 @@ DEFINE_TRACE(sched_wakeup);
> DEFINE_TRACE(sched_wakeup_new);
> DEFINE_TRACE(sched_switch);
> DEFINE_TRACE(sched_migrate_task);
> +DEFINE_TRACE(sched_activate_task);
> +DEFINE_TRACE(sched_deactivate_task);
>
> #ifdef CONFIG_SMP
> /*
> @@ -1716,6 +1718,7 @@ static int effective_prio(struct task_struct *p)
> */
> static void activate_task(struct rq *rq, struct task_struct *p, int wakeup)
> {
> + trace_sched_activate_task(p, rq);
> if (task_contributes_to_load(p))
> rq->nr_uninterruptible--;
>
> @@ -1728,6 +1731,7 @@ static void activate_task(struct rq *rq, struct task_struct *p, int wakeup)
> */
> static void deactivate_task(struct rq *rq, struct task_struct *p, int sleep)
> {
> + trace_sched_deactivate_task(p, rq);
> if (task_contributes_to_load(p))
> rq->nr_uninterruptible++;
>
> @@ -2420,6 +2424,7 @@ void wake_up_new_task(struct task_struct *p, unsigned long clone_flags)
> * Let the scheduling class do new task startup
> * management (if any):
> */
> + trace_sched_activate_task(p, rq);
> p->sched_class->task_new(rq, p);
> inc_nr_running(rq);
> }
> diff --git a/ltt/probes/kernel-trace.c b/ltt/probes/kernel-trace.c
> index e241499..c27e671 100644
> --- a/ltt/probes/kernel-trace.c
> +++ b/ltt/probes/kernel-trace.c
> @@ -372,6 +372,19 @@ void probe_kernel_vprintk(unsigned long retaddr, char *buf, int len)
> }
> }
>
> +void probe_activate_task(struct task_struct *p, struct rq *rq)
> +{
> + trace_mark_tp(kernel_activate_task, sched_activate_task, probe_activate_task,
> + "pid %d state %ld cpu_id %u", p->pid, p->state, task_cpu(p));
> +}
> +
> +void probe_deactivate_task(struct task_struct *p, struct rq *rq)
> +{
> + trace_mark_tp(kernel_deactivate_task, sched_deactivate_task,
> + probe_deactivate_task, "pid %d state %ld cpu_id %u",
> + p->pid, p->state, task_cpu(p));
> +}
> +
> #ifdef CONFIG_MODULES
> void probe_kernel_module_free(struct module *mod)
> {
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-08 19:54 ` Peter Zijlstra
@ 2008-12-08 22:38 ` Jason Baron
2008-12-08 22:42 ` Peter Zijlstra
0 siblings, 1 reply; 15+ messages in thread
From: Jason Baron @ 2008-12-08 22:38 UTC (permalink / raw)
On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > hi,
> >
> > I thought it would be useful to track when a task is
> > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > task can be activated and deactivated, when the scheduler re-balances
> > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > patches I can more precisely figure out when a task becomes runnable and
> > why.
>
> Then I still not agree with it because it does not expose the event that
> did the change.
>
> If you want the cpu allowed mask, put a tracepoint there. If you want
> migrate information (didn't we have that?) then put one there, etc.
>
well, with stap backtrace I can figure out the event, otherwise i'm
sprinkling 14 more trace events in the scheduler...I can go down that
patch if people think its better?
thanks,
-Jason
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-08 22:38 ` Jason Baron
@ 2008-12-08 22:42 ` Peter Zijlstra
2008-12-09 21:00 ` Jason Baron
0 siblings, 1 reply; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-08 22:42 UTC (permalink / raw)
On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > hi,
> > >
> > > I thought it would be useful to track when a task is
> > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > task can be activated and deactivated, when the scheduler re-balances
> > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > patches I can more precisely figure out when a task becomes runnable and
> > > why.
> >
> > Then I still not agree with it because it does not expose the event that
> > did the change.
> >
> > If you want the cpu allowed mask, put a tracepoint there. If you want
> > migrate information (didn't we have that?) then put one there, etc.
> >
>
> well, with stap backtrace I can figure out the event, otherwise i'm
> sprinkling 14 more trace events in the scheduler...I can go down that
> patch if people think its better?
what events are you interested in? some of them are just straight
syscall things like nice.
But yes, I'd rather you'd do the events - that's what tracepoints are
all about, marking indivudual events, not some fugly hook for stap.
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-08 22:42 ` Peter Zijlstra
@ 2008-12-09 21:00 ` Jason Baron
2008-12-09 21:29 ` Jason Baron
2008-12-09 22:10 ` Mathieu Desnoyers
0 siblings, 2 replies; 15+ messages in thread
From: Jason Baron @ 2008-12-09 21:00 UTC (permalink / raw)
On Mon, Dec 08, 2008 at 11:42:49PM +0100, Peter Zijlstra wrote:
> On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > hi,
> > > >
> > > > I thought it would be useful to track when a task is
> > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > task can be activated and deactivated, when the scheduler re-balances
> > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > patches I can more precisely figure out when a task becomes runnable and
> > > > why.
> > >
> > > Then I still not agree with it because it does not expose the event that
> > > did the change.
> > >
> > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > migrate information (didn't we have that?) then put one there, etc.
> > >
> >
> > well, with stap backtrace I can figure out the event, otherwise i'm
> > sprinkling 14 more trace events in the scheduler...I can go down that
> > patch if people think its better?
>
> what events are you interested in? some of them are just straight
> syscall things like nice.
>
> But yes, I'd rather you'd do the events - that's what tracepoints are
> all about, marking indivudual events, not some fugly hook for stap.
well, i think that the activate/deactivate combination gives you a lot
of interesting statistics. You could figure out how long tasks wait on
the runqueue, when and how tasks are migrated between runqueues, queue
lengths, average queue lengths, large queues lengths. These statistics
could help diagnose performance problems.
For example, i just wrote the systemtap script below which outputs the
distribution of queue lengths per-cpu on my system. I'm sure Frank could
improve the stap code, but below is the script and the output.
thanks,
-Jason
sample output (during a kernel compile). Each line is the cpu number the
"length" of the queue, and the "number" of times that length happened.
You'll notice that queue lengths are mostly between 0-3 but there are
definitely some larger lengths including a length of 13.
cpu: 0 length: -1 number: 5979
cpu: 0 length: 0 number: 12462
cpu: 0 length: 1 number: 13139
cpu: 0 length: 2 number: 12744
cpu: 0 length: 3 number: 9047
cpu: 0 length: 4 number: 3965
cpu: 0 length: 5 number: 1278
cpu: 0 length: 6 number: 378
cpu: 0 length: 7 number: 156
cpu: 0 length: 8 number: 80
cpu: 0 length: 9 number: 42
cpu: 0 length: 10 number: 15
cpu: 0 length: 11 number: 4
cpu: 0 length: 12 number: 1
cpu: 1 length: 1 number: 9260
cpu: 1 length: 0 number: 4162
cpu: 1 length: 2 number: 10652
cpu: 1 length: 3 number: 10288
cpu: 1 length: 4 number: 6645
cpu: 1 length: 5 number: 2472
cpu: 1 length: 6 number: 710
cpu: 1 length: 7 number: 192
cpu: 1 length: 8 number: 56
cpu: 1 length: 9 number: 18
cpu: 1 length: 10 number: 6
cpu: 1 length: 11 number: 3
cpu: 1 length: 12 number: 2
cpu: 1 length: 13 number: 1
cpu: 2 length: 1 number: 8897
cpu: 2 length: 0 number: 4104
cpu: 2 length: 2 number: 10322
cpu: 2 length: 3 number: 9984
cpu: 2 length: 4 number: 6256
cpu: 2 length: 5 number: 2293
cpu: 2 length: 6 number: 656
cpu: 2 length: 7 number: 213
cpu: 2 length: 8 number: 77
cpu: 2 length: 9 number: 40
cpu: 2 length: 10 number: 17
cpu: 2 length: 11 number: 6
cpu: 2 length: 12 number: 1
cpu: 3 length: 1 number: 9023
cpu: 3 length: 0 number: 4089
cpu: 3 length: 2 number: 10605
cpu: 3 length: 3 number: 10125
cpu: 3 length: 4 number: 6196
cpu: 3 length: 5 number: 2298
cpu: 3 length: 6 number: 746
cpu: 3 length: 7 number: 271
cpu: 3 length: 8 number: 117
cpu: 3 length: 9 number: 53
cpu: 3 length: 10 number: 22
cpu: 3 length: 11 number: 7
cpu: 3 length: 12 number: 2
#!/usr/bin/env stap
#
global cpu_queue_distribution
global current_queue_length
/* process added into runqueue : really running or well prepared */
probe kernel.mark("kernel_activate_task"){
current_queue_length[$arg3]++;
cpu_queue_distribution[$arg3,current_queue_length[$arg3]]++
}
/* process removed from runqueue : in wait queue or other state */
probe kernel.mark("kernel_deactivate_task") {
current_queue_length[$arg3]--;
cpu_queue_distribution[$arg3,current_queue_length[$arg3]]++
}
probe end{
foreach ([cpu+, length] in cpu_queue_distribution) {
printf("cpu: %d length: %d number: %d\n", cpu, length, cpu_queue_distribution[cpu,length]);
}
}
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-09 21:00 ` Jason Baron
@ 2008-12-09 21:29 ` Jason Baron
2008-12-09 22:10 ` Mathieu Desnoyers
1 sibling, 0 replies; 15+ messages in thread
From: Jason Baron @ 2008-12-09 21:29 UTC (permalink / raw)
On Tue, Dec 09, 2008 at 04:00:48PM -0500, Jason Baron wrote:
> > On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > > hi,
> > > > >
> > > > > I thought it would be useful to track when a task is
> > > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > > task can be activated and deactivated, when the scheduler re-balances
> > > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > > patches I can more precisely figure out when a task becomes runnable and
> > > > > why.
> > > >
> > > > Then I still not agree with it because it does not expose the event that
> > > > did the change.
> > > >
> > > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > > migrate information (didn't we have that?) then put one there, etc.
> > > >
> > >
> > > well, with stap backtrace I can figure out the event, otherwise i'm
> > > sprinkling 14 more trace events in the scheduler...I can go down that
> > > patch if people think its better?
> >
> > what events are you interested in? some of them are just straight
> > syscall things like nice.
> >
> > But yes, I'd rather you'd do the events - that's what tracepoints are
> > all about, marking indivudual events, not some fugly hook for stap.
>
> well, i think that the activate/deactivate combination gives you a lot
> of interesting statistics. You could figure out how long tasks wait on
> the runqueue, when and how tasks are migrated between runqueues, queue
> lengths, average queue lengths, large queues lengths. These statistics
> could help diagnose performance problems.
>
> For example, i just wrote the systemtap script below which outputs the
> distribution of queue lengths per-cpu on my system. I'm sure Frank could
> improve the stap code, but below is the script and the output.
ok, a couple suggestions from Frank I now get:
cpu: 0
value |-------------------------------------------------- count
0 |@@@@@@@@ 8460
1 |@@@@@@@@@@@@@@@@@@@@ 19346
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 47466
4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 26154
8 | 357
16 | 0
32 | 0
cpu: 2
value |-------------------------------------------------- count
0 |@@@@@@@ 6101
1 |@@@@@@@@@@@@@@@@@@ 14782
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 39206
4 |@@@@@@@@@@@@@@@@@@@@@@@@ 18968
8 | 369
16 | 0
32 | 0
cpu: 1
value |-------------------------------------------------- count
0 |@@@@@@@ 6488
1 |@@@@@@@@@@@@@@@@@@@ 16540
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 43027
4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 23262
8 | 337
16 | 0
32 | 0
cpu: 3
value |-------------------------------------------------- count
0 |@@@@@@@ 5991
1 |@@@@@@@@@@@@@@@@@@@ 14808
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 38258
4 |@@@@@@@@@@@@@@@@@@@@@@@@@ 19172
8 | 323
16 | 0
32 | 0
script:
#!/usr/bin/env stap
#
global cpu_queue_distribution
global current_queue_length
/* process added into runqueue : really running or well prepared */
probe kernel.mark("kernel_activate_task"){
cpu_queue_distribution[$arg3] <<<
(++current_queue_length[$arg3]);
}
/* process removed from runqueue : in wait queue or other state */
probe kernel.mark("kernel_deactivate_task") {
if(current_queue_length[$arg3])
cpu_queue_distribution[$arg3] <<<
(--current_queue_length[$arg3]);
}
probe end{
foreach (cpu in cpu_queue_distribution) {
printf("cpu: %d\n", cpu);
print(@hist_log(cpu_queue_distribution[cpu]));
}
}
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-09 21:00 ` Jason Baron
2008-12-09 21:29 ` Jason Baron
@ 2008-12-09 22:10 ` Mathieu Desnoyers
2008-12-10 7:08 ` Peter Zijlstra
1 sibling, 1 reply; 15+ messages in thread
From: Mathieu Desnoyers @ 2008-12-09 22:10 UTC (permalink / raw)
* Jason Baron (jbaron at redhat.com) wrote:
> On Mon, Dec 08, 2008 at 11:42:49PM +0100, Peter Zijlstra wrote:
> > On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > > hi,
> > > > >
> > > > > I thought it would be useful to track when a task is
> > > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > > task can be activated and deactivated, when the scheduler re-balances
> > > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > > patches I can more precisely figure out when a task becomes runnable and
> > > > > why.
> > > >
> > > > Then I still not agree with it because it does not expose the event that
> > > > did the change.
> > > >
> > > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > > migrate information (didn't we have that?) then put one there, etc.
> > > >
> > >
> > > well, with stap backtrace I can figure out the event, otherwise i'm
> > > sprinkling 14 more trace events in the scheduler...I can go down that
> > > patch if people think its better?
> >
> > what events are you interested in? some of them are just straight
> > syscall things like nice.
> >
> > But yes, I'd rather you'd do the events - that's what tracepoints are
> > all about, marking indivudual events, not some fugly hook for stap.
>
> well, i think that the activate/deactivate combination gives you a lot
> of interesting statistics. You could figure out how long tasks wait on
> the runqueue, when and how tasks are migrated between runqueues, queue
> lengths, average queue lengths, large queues lengths. These statistics
> could help diagnose performance problems.
>
> For example, i just wrote the systemtap script below which outputs the
> distribution of queue lengths per-cpu on my system. I'm sure Frank could
> improve the stap code, but below is the script and the output.
>
Quoting yourself in this thread :
"I thought it would be useful to track when a task is
'activated/deactivated'. This case is different from wakeup/wait, in
that task can be activated and deactivated, when the scheduler
re-balances tasks, the allowable cpuset changes, or cpu hotplug occurs.
Using these patches I can more precisely figure out when a task becomes
runnable and why."
Peter Zijlstra objected that the key events we would like to see traced
are more detailed than just "activate/deactivate" state, e.g. an event
for wakeup, one for wait, one for re-balance, one for cpuset change, one
for hotplug. Doing this will allow other tracers to do other useful
stuff with the information.
So trying to argue that "activate/deactivate" is "good" is missing the
point here. Yes, we need that information, but in fact we need _more
precise_ information, which is a superset of those "activate/deactivate"
events.
Peter, am I understanding your point correctly ?
Mathieu
> thanks,
>
> -Jason
>
> sample output (during a kernel compile). Each line is the cpu number the
> "length" of the queue, and the "number" of times that length happened.
> You'll notice that queue lengths are mostly between 0-3 but there are
> definitely some larger lengths including a length of 13.
>
> cpu: 0 length: -1 number: 5979
> cpu: 0 length: 0 number: 12462
> cpu: 0 length: 1 number: 13139
> cpu: 0 length: 2 number: 12744
> cpu: 0 length: 3 number: 9047
> cpu: 0 length: 4 number: 3965
> cpu: 0 length: 5 number: 1278
> cpu: 0 length: 6 number: 378
> cpu: 0 length: 7 number: 156
> cpu: 0 length: 8 number: 80
> cpu: 0 length: 9 number: 42
> cpu: 0 length: 10 number: 15
> cpu: 0 length: 11 number: 4
> cpu: 0 length: 12 number: 1
> cpu: 1 length: 1 number: 9260
> cpu: 1 length: 0 number: 4162
> cpu: 1 length: 2 number: 10652
> cpu: 1 length: 3 number: 10288
> cpu: 1 length: 4 number: 6645
> cpu: 1 length: 5 number: 2472
> cpu: 1 length: 6 number: 710
> cpu: 1 length: 7 number: 192
> cpu: 1 length: 8 number: 56
> cpu: 1 length: 9 number: 18
> cpu: 1 length: 10 number: 6
> cpu: 1 length: 11 number: 3
> cpu: 1 length: 12 number: 2
> cpu: 1 length: 13 number: 1
> cpu: 2 length: 1 number: 8897
> cpu: 2 length: 0 number: 4104
> cpu: 2 length: 2 number: 10322
> cpu: 2 length: 3 number: 9984
> cpu: 2 length: 4 number: 6256
> cpu: 2 length: 5 number: 2293
> cpu: 2 length: 6 number: 656
> cpu: 2 length: 7 number: 213
> cpu: 2 length: 8 number: 77
> cpu: 2 length: 9 number: 40
> cpu: 2 length: 10 number: 17
> cpu: 2 length: 11 number: 6
> cpu: 2 length: 12 number: 1
> cpu: 3 length: 1 number: 9023
> cpu: 3 length: 0 number: 4089
> cpu: 3 length: 2 number: 10605
> cpu: 3 length: 3 number: 10125
> cpu: 3 length: 4 number: 6196
> cpu: 3 length: 5 number: 2298
> cpu: 3 length: 6 number: 746
> cpu: 3 length: 7 number: 271
> cpu: 3 length: 8 number: 117
> cpu: 3 length: 9 number: 53
> cpu: 3 length: 10 number: 22
> cpu: 3 length: 11 number: 7
> cpu: 3 length: 12 number: 2
>
>
>
> #!/usr/bin/env stap
> #
>
> global cpu_queue_distribution
> global current_queue_length
>
> /* process added into runqueue : really running or well prepared */
> probe kernel.mark("kernel_activate_task"){
> current_queue_length[$arg3]++;
> cpu_queue_distribution[$arg3,current_queue_length[$arg3]]++
> }
>
> /* process removed from runqueue : in wait queue or other state */
> probe kernel.mark("kernel_deactivate_task") {
> current_queue_length[$arg3]--;
> cpu_queue_distribution[$arg3,current_queue_length[$arg3]]++
> }
>
>
> probe end{
> foreach ([cpu+, length] in cpu_queue_distribution) {
> printf("cpu: %d length: %d number: %d\n", cpu, length, cpu_queue_distribution[cpu,length]);
> }
> }
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> _______________________________________________
> ltt-dev mailing list
> ltt-dev at lists.casi.polymtl.ca
> http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
>
--
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-09 22:10 ` Mathieu Desnoyers
@ 2008-12-10 7:08 ` Peter Zijlstra
2008-12-10 12:27 ` Mathieu Desnoyers
2008-12-10 12:34 ` Mathieu Desnoyers
0 siblings, 2 replies; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-10 7:08 UTC (permalink / raw)
On Tue, 2008-12-09 at 17:10 -0500, Mathieu Desnoyers wrote:
> * Jason Baron (jbaron at redhat.com) wrote:
> > On Mon, Dec 08, 2008 at 11:42:49PM +0100, Peter Zijlstra wrote:
> > > On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > > > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > > > hi,
> > > > > >
> > > > > > I thought it would be useful to track when a task is
> > > > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > > > task can be activated and deactivated, when the scheduler re-balances
> > > > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > > > patches I can more precisely figure out when a task becomes runnable and
> > > > > > why.
> > > > >
> > > > > Then I still not agree with it because it does not expose the event that
> > > > > did the change.
> > > > >
> > > > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > > > migrate information (didn't we have that?) then put one there, etc.
> > > > >
> > > >
> > > > well, with stap backtrace I can figure out the event, otherwise i'm
> > > > sprinkling 14 more trace events in the scheduler...I can go down that
> > > > patch if people think its better?
> > >
> > > what events are you interested in? some of them are just straight
> > > syscall things like nice.
> > >
> > > But yes, I'd rather you'd do the events - that's what tracepoints are
> > > all about, marking indivudual events, not some fugly hook for stap.
> >
> > well, i think that the activate/deactivate combination gives you a lot
> > of interesting statistics. You could figure out how long tasks wait on
> > the runqueue, when and how tasks are migrated between runqueues, queue
> > lengths, average queue lengths, large queues lengths. These statistics
> > could help diagnose performance problems.
> >
> > For example, i just wrote the systemtap script below which outputs the
> > distribution of queue lengths per-cpu on my system. I'm sure Frank could
> > improve the stap code, but below is the script and the output.
> >
>
> Quoting yourself in this thread :
>
> "I thought it would be useful to track when a task is
> 'activated/deactivated'. This case is different from wakeup/wait, in
> that task can be activated and deactivated, when the scheduler
> re-balances tasks, the allowable cpuset changes, or cpu hotplug occurs.
> Using these patches I can more precisely figure out when a task becomes
> runnable and why."
>
> Peter Zijlstra objected that the key events we would like to see traced
> are more detailed than just "activate/deactivate" state, e.g. an event
> for wakeup, one for wait, one for re-balance, one for cpuset change, one
> for hotplug. Doing this will allow other tracers to do other useful
> stuff with the information.
>
> So trying to argue that "activate/deactivate" is "good" is missing the
> point here. Yes, we need that information, but in fact we need _more
> precise_ information, which is a superset of those "activate/deactivate"
> events.
>
> Peter, am I understanding your point correctly ?
Quite so.
The point is that for some operations the tasks never conceptually leave
the rq, like renice - its never not runnable, we just need to pull it
off and re-insert it in order to make the weight change, but its for all
intents and purposes an 'atomic' operation.
So if you want that information, you want a trace_sched_setscheduler()
hook that will tell you about the old scheduler/prio and the new
scheduler/prio for a task - because that is the information that is
native to that event, deactivate/activate not so, one could conceivably
implement renice without using them.
Same thing with migration, its conceptually an atomic op, we just need
to lift a task from one cpu to another, it doesn't conceptually become
unrunnable during that move.
So looking at activate/deactivate is wrong.
---
Subject: trace: fixup task migration trace point
The trace point only caught one of many places where a task changes cpu,
put it in the right place to we get all of them.
Change the signature while we're at it.
Signed-off-by: Peter Zijlstra <a.p.zijlstra at chello.nl>
---
include/trace/sched.h | 4 ++--
kernel/sched.c | 3 ++-
2 files changed, 4 insertions(+), 3 deletions(-)
diff --git a/include/trace/sched.h b/include/trace/sched.h
index 9b2854a..f4549d5 100644
--- a/include/trace/sched.h
+++ b/include/trace/sched.h
@@ -30,8 +30,8 @@ DECLARE_TRACE(sched_switch,
TPARGS(rq, prev, next));
DECLARE_TRACE(sched_migrate_task,
- TPPROTO(struct rq *rq, struct task_struct *p, int dest_cpu),
- TPARGS(rq, p, dest_cpu));
+ TPPROTO(struct task_struct *p, int orig_cpu, int dest_cpu),
+ TPARGS(p, orig_cpu, dest_cpu));
DECLARE_TRACE(sched_process_free,
TPPROTO(struct task_struct *p),
diff --git a/kernel/sched.c b/kernel/sched.c
index 0eff15b..3dc54cd 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -1861,6 +1861,8 @@ void set_task_cpu(struct task_struct *p, unsigned int new_cpu)
clock_offset = old_rq->clock - new_rq->clock;
+ trace_sched_migrate_task(p, task_cpu(p), new_cpu);
+
#ifdef CONFIG_SCHEDSTATS
if (p->se.wait_start)
p->se.wait_start -= clock_offset;
@@ -2841,7 +2843,6 @@ static void sched_migrate_task(struct task_struct *p, int dest_cpu)
|| unlikely(!cpu_active(dest_cpu)))
goto out;
- trace_sched_migrate_task(rq, p, dest_cpu);
/* force the process onto the specified CPU */
if (migrate_task(p, dest_cpu, &req)) {
/* Need to wait for migration thread (might exit: take ref). */
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 7:08 ` Peter Zijlstra
@ 2008-12-10 12:27 ` Mathieu Desnoyers
2008-12-10 13:15 ` Peter Zijlstra
2008-12-10 12:34 ` Mathieu Desnoyers
1 sibling, 1 reply; 15+ messages in thread
From: Mathieu Desnoyers @ 2008-12-10 12:27 UTC (permalink / raw)
* Peter Zijlstra (peterz at infradead.org) wrote:
> On Tue, 2008-12-09 at 17:10 -0500, Mathieu Desnoyers wrote:
> > * Jason Baron (jbaron at redhat.com) wrote:
> > > On Mon, Dec 08, 2008 at 11:42:49PM +0100, Peter Zijlstra wrote:
> > > > On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > > > > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > > > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > > > > hi,
> > > > > > >
> > > > > > > I thought it would be useful to track when a task is
> > > > > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > > > > task can be activated and deactivated, when the scheduler re-balances
> > > > > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > > > > patches I can more precisely figure out when a task becomes runnable and
> > > > > > > why.
> > > > > >
> > > > > > Then I still not agree with it because it does not expose the event that
> > > > > > did the change.
> > > > > >
> > > > > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > > > > migrate information (didn't we have that?) then put one there, etc.
> > > > > >
> > > > >
> > > > > well, with stap backtrace I can figure out the event, otherwise i'm
> > > > > sprinkling 14 more trace events in the scheduler...I can go down that
> > > > > patch if people think its better?
> > > >
> > > > what events are you interested in? some of them are just straight
> > > > syscall things like nice.
> > > >
> > > > But yes, I'd rather you'd do the events - that's what tracepoints are
> > > > all about, marking indivudual events, not some fugly hook for stap.
> > >
> > > well, i think that the activate/deactivate combination gives you a lot
> > > of interesting statistics. You could figure out how long tasks wait on
> > > the runqueue, when and how tasks are migrated between runqueues, queue
> > > lengths, average queue lengths, large queues lengths. These statistics
> > > could help diagnose performance problems.
> > >
> > > For example, i just wrote the systemtap script below which outputs the
> > > distribution of queue lengths per-cpu on my system. I'm sure Frank could
> > > improve the stap code, but below is the script and the output.
> > >
> >
> > Quoting yourself in this thread :
> >
> > "I thought it would be useful to track when a task is
> > 'activated/deactivated'. This case is different from wakeup/wait, in
> > that task can be activated and deactivated, when the scheduler
> > re-balances tasks, the allowable cpuset changes, or cpu hotplug occurs.
> > Using these patches I can more precisely figure out when a task becomes
> > runnable and why."
> >
> > Peter Zijlstra objected that the key events we would like to see traced
> > are more detailed than just "activate/deactivate" state, e.g. an event
> > for wakeup, one for wait, one for re-balance, one for cpuset change, one
> > for hotplug. Doing this will allow other tracers to do other useful
> > stuff with the information.
> >
> > So trying to argue that "activate/deactivate" is "good" is missing the
> > point here. Yes, we need that information, but in fact we need _more
> > precise_ information, which is a superset of those "activate/deactivate"
> > events.
> >
> > Peter, am I understanding your point correctly ?
>
> Quite so.
>
> The point is that for some operations the tasks never conceptually leave
> the rq, like renice - its never not runnable, we just need to pull it
> off and re-insert it in order to make the weight change, but its for all
> intents and purposes an 'atomic' operation.
>
> So if you want that information, you want a trace_sched_setscheduler()
> hook that will tell you about the old scheduler/prio and the new
> scheduler/prio for a task - because that is the information that is
> native to that event, deactivate/activate not so, one could conceivably
> implement renice without using them.
>
> Same thing with migration, its conceptually an atomic op, we just need
> to lift a task from one cpu to another, it doesn't conceptually become
> unrunnable during that move.
>
> So looking at activate/deactivate is wrong.
>
Thanks Peter, I'm pulling your patch into the LTTng tree.
Do you think there would be other events that Jason would need to
identify every time a task gets de/activated, or he is able to
reconstruct this from the current tracepoints ?
Mathieu
> ---
> Subject: trace: fixup task migration trace point
>
> The trace point only caught one of many places where a task changes cpu,
> put it in the right place to we get all of them.
>
> Change the signature while we're at it.
>
> Signed-off-by: Peter Zijlstra <a.p.zijlstra at chello.nl>
> ---
> include/trace/sched.h | 4 ++--
> kernel/sched.c | 3 ++-
> 2 files changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/include/trace/sched.h b/include/trace/sched.h
> index 9b2854a..f4549d5 100644
> --- a/include/trace/sched.h
> +++ b/include/trace/sched.h
> @@ -30,8 +30,8 @@ DECLARE_TRACE(sched_switch,
> TPARGS(rq, prev, next));
>
> DECLARE_TRACE(sched_migrate_task,
> - TPPROTO(struct rq *rq, struct task_struct *p, int dest_cpu),
> - TPARGS(rq, p, dest_cpu));
> + TPPROTO(struct task_struct *p, int orig_cpu, int dest_cpu),
> + TPARGS(p, orig_cpu, dest_cpu));
>
> DECLARE_TRACE(sched_process_free,
> TPPROTO(struct task_struct *p),
> diff --git a/kernel/sched.c b/kernel/sched.c
> index 0eff15b..3dc54cd 100644
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -1861,6 +1861,8 @@ void set_task_cpu(struct task_struct *p, unsigned int new_cpu)
>
> clock_offset = old_rq->clock - new_rq->clock;
>
> + trace_sched_migrate_task(p, task_cpu(p), new_cpu);
> +
> #ifdef CONFIG_SCHEDSTATS
> if (p->se.wait_start)
> p->se.wait_start -= clock_offset;
> @@ -2841,7 +2843,6 @@ static void sched_migrate_task(struct task_struct *p, int dest_cpu)
> || unlikely(!cpu_active(dest_cpu)))
> goto out;
>
> - trace_sched_migrate_task(rq, p, dest_cpu);
> /* force the process onto the specified CPU */
> if (migrate_task(p, dest_cpu, &req)) {
> /* Need to wait for migration thread (might exit: take ref). */
>
--
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 12:27 ` Mathieu Desnoyers
@ 2008-12-10 13:15 ` Peter Zijlstra
2008-12-10 17:14 ` Jason Baron
0 siblings, 1 reply; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-10 13:15 UTC (permalink / raw)
On Wed, 2008-12-10 at 07:27 -0500, Mathieu Desnoyers wrote:
>
> Do you think there would be other events that Jason would need to
> identify every time a task gets de/activated, or he is able to
> reconstruct this from the current tracepoints ?
I don't know what events Jason wants, some of the things he mentioned
map directly to syscalls, so I'm not sure if we'd want to catch it at a
generic syscall layer, or a tracepoint per syscall guts.
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 13:15 ` Peter Zijlstra
@ 2008-12-10 17:14 ` Jason Baron
2008-12-10 17:52 ` Mathieu Desnoyers
0 siblings, 1 reply; 15+ messages in thread
From: Jason Baron @ 2008-12-10 17:14 UTC (permalink / raw)
On Wed, Dec 10, 2008 at 02:15:41PM +0100, Peter Zijlstra wrote:
> On Wed, 2008-12-10 at 07:27 -0500, Mathieu Desnoyers wrote:
> >
> > Do you think there would be other events that Jason would need to
> > identify every time a task gets de/activated, or he is able to
> > reconstruct this from the current tracepoints ?
>
> I don't know what events Jason wants, some of the things he mentioned
> map directly to syscalls, so I'm not sure if we'd want to catch it at a
> generic syscall layer, or a tracepoint per syscall guts.
>
>
My goal is to instrument the scheduler at the most "interesting" points.
Activate and Deactivate allow me to directly figure out queue length (posted in
my previous mail), how long a process wait on a queue, and when a
process moves between queues. Yes, I might be able to figure these out
from insturmentation calls from schedule(), try_to_wake_up(),
wake_up_new_task(), pull_task(), migrate_task(), etc. But its going to
be awfully complex. Activate/deactivate task seem like very core basic
scheduler primitives.
Adding a tracepoint to set_task_cpu() is good but it doesn't tell me
about whether or not a task is on queue. It simply tells me when a task
is assigned a different cpu (which activate/deactivate can do as well).
I understand and appreciate what you guys are saying about do not
instrument the code too generally, but IMHO activate/deactivate are core
scheduler primitives, which are difficult to piece together otherwise. I
can up with more scripts that show their utility.
thanks,
-Jason
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 17:14 ` Jason Baron
@ 2008-12-10 17:52 ` Mathieu Desnoyers
2008-12-10 19:28 ` Peter Zijlstra
0 siblings, 1 reply; 15+ messages in thread
From: Mathieu Desnoyers @ 2008-12-10 17:52 UTC (permalink / raw)
* Jason Baron (jbaron at redhat.com) wrote:
> On Wed, Dec 10, 2008 at 02:15:41PM +0100, Peter Zijlstra wrote:
> > On Wed, 2008-12-10 at 07:27 -0500, Mathieu Desnoyers wrote:
> > >
> > > Do you think there would be other events that Jason would need to
> > > identify every time a task gets de/activated, or he is able to
> > > reconstruct this from the current tracepoints ?
> >
> > I don't know what events Jason wants, some of the things he mentioned
> > map directly to syscalls, so I'm not sure if we'd want to catch it at a
> > generic syscall layer, or a tracepoint per syscall guts.
> >
> >
>
> My goal is to instrument the scheduler at the most "interesting" points.
> Activate and Deactivate allow me to directly figure out queue length (posted in
> my previous mail), how long a process wait on a queue, and when a
> process moves between queues. Yes, I might be able to figure these out
> from insturmentation calls from schedule(), try_to_wake_up(),
> wake_up_new_task(), pull_task(), migrate_task(), etc. But its going to
> be awfully complex. Activate/deactivate task seem like very core basic
> scheduler primitives.
>
> Adding a tracepoint to set_task_cpu() is good but it doesn't tell me
> about whether or not a task is on queue. It simply tells me when a task
> is assigned a different cpu (which activate/deactivate can do as well).
>
> I understand and appreciate what you guys are saying about do not
> instrument the code too generally, but IMHO activate/deactivate are core
> scheduler primitives, which are difficult to piece together otherwise. I
> can up with more scripts that show their utility.
>
Would it be possible to simply use
p->se.on_rq
in the events already instrumenting the scheduler to keep track of the
activation state and manage to get the same result ?
And also, adding duplicate instrumentation to simplify tracer analysis
is imho the wrong approach.
Mathieu
>
> thanks,
>
> -Jason
>
>
>
--
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 17:52 ` Mathieu Desnoyers
@ 2008-12-10 19:28 ` Peter Zijlstra
0 siblings, 0 replies; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-10 19:28 UTC (permalink / raw)
On Wed, 2008-12-10 at 12:52 -0500, Mathieu Desnoyers wrote:
> > I understand and appreciate what you guys are saying about do not
> > instrument the code too generally, but IMHO activate/deactivate are core
> > scheduler primitives, which are difficult to piece together otherwise.
That's simply not true - its mostly a scheduler implementation detail.
Re-read my previous email.
^ permalink raw reply [flat|nested] 15+ messages in thread
* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 7:08 ` Peter Zijlstra
2008-12-10 12:27 ` Mathieu Desnoyers
@ 2008-12-10 12:34 ` Mathieu Desnoyers
2008-12-10 13:14 ` Peter Zijlstra
1 sibling, 1 reply; 15+ messages in thread
From: Mathieu Desnoyers @ 2008-12-10 12:34 UTC (permalink / raw)
* Peter Zijlstra (peterz at infradead.org) wrote:
> On Tue, 2008-12-09 at 17:10 -0500, Mathieu Desnoyers wrote:
> > * Jason Baron (jbaron at redhat.com) wrote:
> > > On Mon, Dec 08, 2008 at 11:42:49PM +0100, Peter Zijlstra wrote:
> > > > On Mon, 2008-12-08 at 17:38 -0500, Jason Baron wrote:
> > > > > On Mon, Dec 08, 2008 at 08:54:10PM +0100, Peter Zijlstra wrote:
> > > > > > On Mon, 2008-12-08 at 14:49 -0500, Jason Baron wrote:
> > > > > > > hi,
> > > > > > >
> > > > > > > I thought it would be useful to track when a task is
> > > > > > > 'activated/deactivated'. This case is different from wakeup/wait, in that
> > > > > > > task can be activated and deactivated, when the scheduler re-balances
> > > > > > > tasks, the allowable cpuset changes, or cpu hotplug occurs. Using these
> > > > > > > patches I can more precisely figure out when a task becomes runnable and
> > > > > > > why.
> > > > > >
> > > > > > Then I still not agree with it because it does not expose the event that
> > > > > > did the change.
> > > > > >
> > > > > > If you want the cpu allowed mask, put a tracepoint there. If you want
> > > > > > migrate information (didn't we have that?) then put one there, etc.
> > > > > >
> > > > >
> > > > > well, with stap backtrace I can figure out the event, otherwise i'm
> > > > > sprinkling 14 more trace events in the scheduler...I can go down that
> > > > > patch if people think its better?
> > > >
> > > > what events are you interested in? some of them are just straight
> > > > syscall things like nice.
> > > >
> > > > But yes, I'd rather you'd do the events - that's what tracepoints are
> > > > all about, marking indivudual events, not some fugly hook for stap.
> > >
> > > well, i think that the activate/deactivate combination gives you a lot
> > > of interesting statistics. You could figure out how long tasks wait on
> > > the runqueue, when and how tasks are migrated between runqueues, queue
> > > lengths, average queue lengths, large queues lengths. These statistics
> > > could help diagnose performance problems.
> > >
> > > For example, i just wrote the systemtap script below which outputs the
> > > distribution of queue lengths per-cpu on my system. I'm sure Frank could
> > > improve the stap code, but below is the script and the output.
> > >
> >
> > Quoting yourself in this thread :
> >
> > "I thought it would be useful to track when a task is
> > 'activated/deactivated'. This case is different from wakeup/wait, in
> > that task can be activated and deactivated, when the scheduler
> > re-balances tasks, the allowable cpuset changes, or cpu hotplug occurs.
> > Using these patches I can more precisely figure out when a task becomes
> > runnable and why."
> >
> > Peter Zijlstra objected that the key events we would like to see traced
> > are more detailed than just "activate/deactivate" state, e.g. an event
> > for wakeup, one for wait, one for re-balance, one for cpuset change, one
> > for hotplug. Doing this will allow other tracers to do other useful
> > stuff with the information.
> >
> > So trying to argue that "activate/deactivate" is "good" is missing the
> > point here. Yes, we need that information, but in fact we need _more
> > precise_ information, which is a superset of those "activate/deactivate"
> > events.
> >
> > Peter, am I understanding your point correctly ?
>
> Quite so.
>
> The point is that for some operations the tasks never conceptually leave
> the rq, like renice - its never not runnable, we just need to pull it
> off and re-insert it in order to make the weight change, but its for all
> intents and purposes an 'atomic' operation.
>
> So if you want that information, you want a trace_sched_setscheduler()
> hook that will tell you about the old scheduler/prio and the new
> scheduler/prio for a task - because that is the information that is
> native to that event, deactivate/activate not so, one could conceivably
> implement renice without using them.
>
> Same thing with migration, its conceptually an atomic op, we just need
> to lift a task from one cpu to another, it doesn't conceptually become
> unrunnable during that move.
>
> So looking at activate/deactivate is wrong.
>
> ---
> Subject: trace: fixup task migration trace point
>
> The trace point only caught one of many places where a task changes cpu,
> put it in the right place to we get all of them.
>
> Change the signature while we're at it.
>
> Signed-off-by: Peter Zijlstra <a.p.zijlstra at chello.nl>
> ---
> include/trace/sched.h | 4 ++--
> kernel/sched.c | 3 ++-
> 2 files changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/include/trace/sched.h b/include/trace/sched.h
> index 9b2854a..f4549d5 100644
> --- a/include/trace/sched.h
> +++ b/include/trace/sched.h
> @@ -30,8 +30,8 @@ DECLARE_TRACE(sched_switch,
> TPARGS(rq, prev, next));
>
> DECLARE_TRACE(sched_migrate_task,
> - TPPROTO(struct rq *rq, struct task_struct *p, int dest_cpu),
> - TPARGS(rq, p, dest_cpu));
> + TPPROTO(struct task_struct *p, int orig_cpu, int dest_cpu),
> + TPARGS(p, orig_cpu, dest_cpu));
>
> DECLARE_TRACE(sched_process_free,
> TPPROTO(struct task_struct *p),
> diff --git a/kernel/sched.c b/kernel/sched.c
> index 0eff15b..3dc54cd 100644
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -1861,6 +1861,8 @@ void set_task_cpu(struct task_struct *p, unsigned int new_cpu)
>
> clock_offset = old_rq->clock - new_rq->clock;
>
> + trace_sched_migrate_task(p, task_cpu(p), new_cpu);
Hrm, looking at it, I think that :
- task_cpu(p) will add some code output outside of the conditional
branch, which I think we would like to avoid.
- We can easily get the "from" cpu within the tracepoint probe.
Therefore, I don't see why we would extract this information
explicitly ?
Mathieu
> +
> #ifdef CONFIG_SCHEDSTATS
> if (p->se.wait_start)
> p->se.wait_start -= clock_offset;
> @@ -2841,7 +2843,6 @@ static void sched_migrate_task(struct task_struct *p, int dest_cpu)
> || unlikely(!cpu_active(dest_cpu)))
> goto out;
>
> - trace_sched_migrate_task(rq, p, dest_cpu);
> /* force the process onto the specified CPU */
> if (migrate_task(p, dest_cpu, &req)) {
> /* Need to wait for migration thread (might exit: take ref). */
>
--
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
^ permalink raw reply [flat|nested] 15+ messages in thread* [ltt-dev] [patch] add tracepoints to trace activate/deactivate task
2008-12-10 12:34 ` Mathieu Desnoyers
@ 2008-12-10 13:14 ` Peter Zijlstra
0 siblings, 0 replies; 15+ messages in thread
From: Peter Zijlstra @ 2008-12-10 13:14 UTC (permalink / raw)
On Wed, 2008-12-10 at 07:34 -0500, Mathieu Desnoyers wrote:
> > include/trace/sched.h | 4 ++--
> > kernel/sched.c | 3 ++-
> > 2 files changed, 4 insertions(+), 3 deletions(-)
> >
> > diff --git a/include/trace/sched.h b/include/trace/sched.h
> > index 9b2854a..f4549d5 100644
> > --- a/include/trace/sched.h
> > +++ b/include/trace/sched.h
> > @@ -30,8 +30,8 @@ DECLARE_TRACE(sched_switch,
> > TPARGS(rq, prev, next));
> >
> > DECLARE_TRACE(sched_migrate_task,
> > - TPPROTO(struct rq *rq, struct task_struct *p, int dest_cpu),
> > - TPARGS(rq, p, dest_cpu));
> > + TPPROTO(struct task_struct *p, int orig_cpu, int dest_cpu),
> > + TPARGS(p, orig_cpu, dest_cpu));
> >
> > DECLARE_TRACE(sched_process_free,
> > TPPROTO(struct task_struct *p),
> > diff --git a/kernel/sched.c b/kernel/sched.c
> > index 0eff15b..3dc54cd 100644
> > --- a/kernel/sched.c
> > +++ b/kernel/sched.c
> > @@ -1861,6 +1861,8 @@ void set_task_cpu(struct task_struct *p, unsigned int new_cpu)
> >
> > clock_offset = old_rq->clock - new_rq->clock;
> >
> > + trace_sched_migrate_task(p, task_cpu(p), new_cpu);
>
> Hrm, looking at it, I think that :
>
> - task_cpu(p) will add some code output outside of the conditional
> branch, which I think we would like to avoid.
> - We can easily get the "from" cpu within the tracepoint probe.
> Therefore, I don't see why we would extract this information
> explicitly ?
Right, just nuke it - thanks!
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2008-12-10 19:28 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2008-12-08 19:49 [ltt-dev] [patch] add tracepoints to trace activate/deactivate task Jason Baron
2008-12-08 19:54 ` Peter Zijlstra
2008-12-08 22:38 ` Jason Baron
2008-12-08 22:42 ` Peter Zijlstra
2008-12-09 21:00 ` Jason Baron
2008-12-09 21:29 ` Jason Baron
2008-12-09 22:10 ` Mathieu Desnoyers
2008-12-10 7:08 ` Peter Zijlstra
2008-12-10 12:27 ` Mathieu Desnoyers
2008-12-10 13:15 ` Peter Zijlstra
2008-12-10 17:14 ` Jason Baron
2008-12-10 17:52 ` Mathieu Desnoyers
2008-12-10 19:28 ` Peter Zijlstra
2008-12-10 12:34 ` Mathieu Desnoyers
2008-12-10 13:14 ` Peter Zijlstra
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox