Re: [Evolution-hackers] profiling patch

[Not Zed <notzed ximian com>]

FWIW i've committed an updated version of this to cvs.  It might need a new tool to analyse it, i've written some stuff in c, but it's still work in progress - i've attached it anyway.

On Wed, 2005-04-27 at 16:28 +0530, Not Zed wrote:
>     
>     
>     Initial work-in-progress on a profiling patch for evolution.  Profiling events are emitted to a plugin, which can process them, or in this case, just dump them to stdout.  Disabling the plugin just disables the event logging; so it is easy to turn it off, and it can be compiled out completely when it isn't needed (or will be able to when i've finished it).
>     
>     It shows that I was wrong about the folder loading, although it isn't that slow still.  And it shows that e-tree is the main slowness when changing messages, although the sample points aren't correct yet for the rendering stage.
>     
>     The doprofile.pl script just scans the output dumped and presents each event in a more readable form.
>     
>     Michael
>     


#include <stdio.h>

#include <glib.h>

static int
scanline(char *p, long unsigned int *secp, long unsigned int *usecp, char **item, char **sub, char **uid)
{
	long unsigned int sec, usec;

	sec = 0;
	usec = 0;
	while (isdigit(*p)) {
		sec = sec*10 + *p-'0';
		p++;
	}
	if (*p++ != '.')
		return 0;
	while (isdigit(*p)) {
		usec = usec*10 + *p-'0';
		p++;
	}
	*secp = sec;
	*usecp = usec;
	if (*p++ != ':')
		return 0;
	if (*p++ != ' ')
		return 0;
	*item = p;
	while (*p && *p != '.')
		p++;
	if (*p != '.')
		return 0;
	*p++ = 0;
	*sub = p;
	while (*p && *p != ',')
		p++;
	if (*p != ',')
		return 0;
	*p++ = 0;
	*uid = p;
	while (*p && *p != '\n')
		p++;
	*p = 0;

	return 1;
}

struct _subtask {
	struct _subtask *next;
	char *sub;
	double time;
};

struct _task {
	struct _task *next;

	char *key;
	char *task;
	struct _subtask *subtask;
	struct _subtask *subtaskend;
};

GHashTable *tasks;
GHashTable *donetasks;
GHashTable *sentinals;
double timezero;

static char *sentinal_data[] = {
	"folder.opened",
	"list.regenerated",
	"format.done",
	"format.empty",
	"goto.done",
	"goto.empty",
};

static void
dump_task(void *key, void *val, void *data)
{
	struct _task *task = val;
	struct _subtask *item, *fitem, *litem;
	double diff;
	double total = 0.0;
	int count = 0;
	char *name;
	FILE *fp;

	name = g_strdup_printf("%s.csv", task->task);
	fp = fopen(name, "w");
	g_free(name);

	printf("Task: %s\n", task->task);

	for (;task;task = task->next) {
		item = task->subtask;
		if (item == NULL)
			continue;
		printf("run: %d\n", count);
		fitem = litem = item;
		item = item->next;
		while (item) {
			diff = item->time - litem->time;
			printf(" %4.4f: %s\n", diff, litem->sub);
			litem = item;
			item = item->next;
		}
		diff = litem->time - fitem->time;
		printf("Total: %4.4f\n", diff);
		fprintf(fp, "%4.4f %4.4f", (litem->time-timezero), diff);
		litem = item = task->subtask;
		item = item->next;
		while (item) {
			diff = item->time - litem->time;
			fprintf(fp, " %4.4f", diff);
			litem = item;
			item = item->next;
		}
		fprintf(fp, "\n");
		total += diff;
		count++;
	}
	fclose(fp);

	printf("Average: %4.4f\n", total/count);

}

int main(int argc, char **argv)
{
	char buf[1024];
	char key[1024];
	long unsigned int sec, usec;
	char *type, *sub, *uid;
	int i;

	tasks = g_hash_table_new(g_str_hash, g_str_equal);
	donetasks = g_hash_table_new(g_str_hash, g_str_equal);
	sentinals = g_hash_table_new(g_str_hash, g_str_equal);

	for (i=0;i<sizeof(sentinal_data)/sizeof(sentinal_data[0]);i++)
		g_hash_table_insert(sentinals, sentinal_data[i], sentinal_data[i]);

	while (fgets(buf, sizeof(buf), stdin)) {
		struct _task *task, *oldtask;
		struct _subtask *item;

		if (!scanline(buf, &sec, &usec, &type, &sub, &uid))
			continue;

		sprintf(key, "%s.%s", type, "");

		task = g_hash_table_lookup(tasks, key);
		if (task == NULL) {
			task = g_malloc0(sizeof(*task));
			task->subtaskend = (struct _subtask *)&task->subtask;
			task->key = g_strdup(key);
			task->task = g_strdup(type);
			g_hash_table_insert(tasks, task->key, task);
		}

		item = g_malloc0(sizeof(*item));
		item->time = sec + usec/1000000.0;
		item->sub = g_strdup(sub);

		if (timezero == 0.0)
			timezero = item->time;

		/*printf("adding item %s to %s %f %ld.%ld %f\n", item->sub, task->key, item->time, sec, usec, sec+usec/1000000.0);*/

		task->subtaskend->next = item;
		task->subtaskend = item;

		sprintf(key, "%s.%s", type, sub);
		if (g_hash_table_lookup(sentinals, key)) {
			g_hash_table_remove(tasks, task->key);
			oldtask = g_hash_table_lookup(donetasks, task->key);
			if (oldtask)
				task->next = oldtask;
			g_hash_table_insert(donetasks, task->key, task);
		}
	}

	g_hash_table_foreach(donetasks, dump_task, NULL);
}