[ltt-dev] [patch] add tracepoints to trace activate/deactivate task

[Jason Baron]

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