Re: profiling the kernel

Andi Kleen (andi@mlm.extern.lrz-muenchen.de)
22 Apr 1997 21:21:35 +0200


"John Brosnan" <johnbros@iol.ie> writes:

> Hi,
>
> I'm looking for any tools/ideas to help profile the Linux TCP/UDP stacks,
> where
> the time is spent, etc. I'm guess I'm looking for a 'kernel' gprof.

Linux has a kernel profiler build-in. Just boot with profile=2 on the
command line and then use the appended program to show the profile data.
You should do a echo >/proc/profile before your actual profile to clear
the profile counters and get useful data.

Program by Linus Torvalds:

/*
* Original by Ramon Garcia Fernandez <ramon@juguete.quim.ucm.es>
* Hacked by linus
*/
#include <unistd.h>
#include <stdlib.h>
#include <stdio.h>
#include <sys/fcntl.h>
#include <linux/autoconf.h>

#define prof_func "verify_area"

#define BUFSIZE 1024

#ifndef CONFIG_PROFILE_SHIFT
#define CONFIG_PROFILE_SHIFT 2
#endif

struct entry {
struct entry * next;
unsigned long time;
unsigned long address;
char name[1];
};

struct entry * list = NULL;

void do_symbol(int time, unsigned long address, char * name)
{
struct entry * entry = malloc(sizeof(struct entry) + strlen(name));
struct entry ** tmp;

entry->time = time;
entry->address = address;
strcpy(entry->name, name + (*name == '_'));
tmp = &list;
while (*tmp) {
if ((*tmp)->time > entry->time)
break;
tmp = &(*tmp)->next;
}
entry->next = *tmp;
*tmp = entry;
}

void show_symbols(unsigned long total)
{
struct entry * entry = list;

while (entry) {
printf("%10u %5d.%02d%% %08x %s\n" ,
entry->time,
(entry->time*10000/total) / 100,
(entry->time*10000/total) % 100,
entry->address, entry->name);
entry = entry->next;
}
}

/* If you do not speak Spanish:
* valor_simbolo_actual: current_symbol_value
* valor_simbolo_siguiente: next_symbol_value
* simbolo_actual: current_symbol
* next_symbol: next_symbol
* leidos: read (past participle)
* total: total
*/

int main(void)
{
int fp;
FILE *kmap;
int current_symbol_value , next_symbol_value;
char current_symbol[80] , next_symbol[80];
int has_read , total = 0, j;

fp = open("/proc/profile", O_RDONLY);
if (fp < 0) {
perror("/proc/profile");
exit(1);
}
kmap = fopen("/System.map","r");
if (!kmap) {
kmap = fopen("/usr/src/linux/System.map","r");
if (!kmap) {
perror("System.map");
exit(1);
}
}
fscanf(kmap , "%x %*s %s\n" , &current_symbol_value , current_symbol );
fscanf(kmap , "%x %*s %s\n" , &next_symbol_value , next_symbol );
puts(prof_func);

for (;;) {
unsigned int buffer[(next_symbol_value - current_symbol_value) >> CONFIG_PROFILE_SHIFT];
unsigned int tiempo = 0;

if (next_symbol_value == current_symbol_value) {
strcpy(current_symbol, next_symbol);
fscanf(kmap, "%x %*s %s\n", &next_symbol_value, next_symbol);
continue;
}
lseek (fp , sizeof(unsigned int)+current_symbol_value-0x100000 , SEEK_SET);
has_read = read (fp , buffer , sizeof(buffer) );
for ( j = 0 ; j < has_read/sizeof(unsigned int) ; j++) {
if (!strcmp(prof_func, current_symbol))
printf("%08x %d\n", j*4+current_symbol_value, buffer[j]);
tiempo += buffer[j];
}
if (tiempo != 0) {
do_symbol(tiempo, current_symbol_value, current_symbol);
total += tiempo;
}
if (has_read < (next_symbol_value -current_symbol_value)
>> CONFIG_PROFILE_SHIFT * sizeof(unsigned long) ||
next_symbol_value == current_symbol_value )
break;
strcpy ( current_symbol , next_symbol );
current_symbol_value = next_symbol_value;
fscanf(kmap , "%x %*s %s\n" , &next_symbol_value , next_symbol );
}
do_symbol(total, 0, "total");
show_symbols(total);
return(0);
}