From mboxrd@z Thu Jan  1 00:00:00 1970
From: jbaron@redhat.com (Jason Baron)
Date: Tue, 9 Dec 2008 16:00:48 -0500
Subject: [ltt-dev] [patch] add tracepoints to trace activate/deactivate
	task
In-Reply-To: <1228776169.12729.2.camel@twins>
References: <20081208194948.GC27166@redhat.com> <1228766050.6939.7.camel@twins>
	<20081208223840.GA30314@redhat.com>
	<1228776169.12729.2.camel@twins>
Message-ID: <20081209210048.GA4440@redhat.com>

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]);
	}
}