That's a _really_ useless number, I wonder why that was used?
I'm including my personal profil.c here, which also allows you to profile
a single function if you want to (the profile data is _very_ raw, but
it's useful together with a "disassemble fn_name" with "gdb vmlinux" to
find out where int he function the time is spent).
This will also give you the numbers in percentage of time spent in the
kernel. That is at least a somewhat useful metric (good for comparing
different runs of the same thing under different kernels).
(Oh, this assumes a profile shift of "2", so use a kernel command line of
"profile=2" when you use this. It could read the profile shift
dynamically, but I never bothered to do that as I always use 2 myself).
Oh, if you profile single functions, I'd suggest using "gdb vmlinux" to
find the actual addresses (which show up in the profile output), and in a
parallell window you'd look at the actual assembly code as generated by
gcc, as that's a lot more readable than the stuff gdb shows.
Linus
-----
/*
* Original by Ramon Garcia Fernandez <ramon@juguete.quim.ucm.es>
* Hacked to death by linus
*/
#include <unistd.h>
#include <stdlib.h>
#include <stdio.h>
#include <sys/fcntl.h>
#include <linux/autoconf.h>
#define prof_func "do_no_page"
#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(int argc, char ** argv)
{
int fp;
char * func = prof_func;
FILE *kmap;
int current_symbol_value , next_symbol_value;
char current_symbol[80] , next_symbol[80];
int has_read , total = 0, j;
if (argc == 2)
func = argv[1];
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" , ¤t_symbol_value , current_symbol );
fscanf(kmap , "%x %*s %s\n" , &next_symbol_value , next_symbol );
puts(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(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);
}