starpu-max/tools/fxt-tool.c

/*
 * StarPU
 * Copyright (C) INRIA 2008-2009 (see AUTHORS file)
 *
 * This program is free software; you can redistribute it and/or modify
 * it under the terms of the GNU Lesser General Public License as published by
 * the Free Software Foundation; either version 2.1 of the License, or (at
 * your option) any later version.
 *
 * This program is distributed in the hope that it will be useful, but
 * WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
 *
 * See the GNU Lesser General Public License in COPYING.LGPL for more details.
 */

#include "fxt-tool.h"

event_list_t events[MAXWORKERS];
workq_list_t taskq;
char *worker_name[MAXWORKERS];

static char *cpus_worker_colors[MAXWORKERS] = {"/greens9/7", "/greens9/6", "/greens9/5", "/greens9/4",  "/greens9/9", "/greens9/3",  "/greens9/2",  "/greens9/1"  };
static char *cuda_worker_colors[MAXWORKERS] = {"/ylorrd9/9", "/ylorrd9/6", "/ylorrd9/3", "/ylorrd9/1", "/ylorrd9/8", "/ylorrd9/7", "/ylorrd9/4", "/ylorrd9/2",  "/ylorrd9/1"};
static char *other_worker_colors[MAXWORKERS] = {"/greys9/9", "/greys9/8", "/greys9/7", "/greys9/6"};
static char *worker_colors[MAXWORKERS];

static fxt_t fut;
struct fxt_ev_64 ev;

unsigned first_event = 1;
uint64_t start_time = 0;
uint64_t end_time = 0;

unsigned nworkers = 0;

char *filename = NULL;
unsigned per_task_colour = 0;


LIST_TYPE(symbol_name,
	char *name;
);

symbol_name_list_t symbol_list;



/*
 * Paje trace file tools
 */

static char *out_paje_path = "paje.trace";
static FILE *out_paje_file;

void paje_output_file_init(void)
{
	/* create a new file */
	out_paje_file = fopen(out_paje_path, "w+");
	
	write_paje_header(out_paje_file);

	fprintf(out_paje_file, "                                        \n \
	1       P      0       \"Program\"                      	\n \
	1       Mn      P       \"Memory Node\"                         \n \
	1       T      Mn       \"Worker\"                               \n \
	1       Sc       P       \"Scheduler State\"                        \n \
	2       event   T       \"event type\"				\n \
	3       S       T       \"Thread State\"                        \n \
	3       MS       Mn       \"Memory Node State\"                        \n \
	4       ntask    Sc       \"Number of tasks\"                        \n \
	6       I       S      Initializing       \"0.0 .7 1.0\"            \n \
	6       D       S      Deinitializing       \"0.0 .1 .7\"            \n \
	6       Fi       S      FetchingInput       \"1.0 .1 1.0\"            \n \
	6       Po       S      PushingOutput       \"0.1 1.0 1.0\"            \n \
	6       E       S       Executing       \".0 .6 .4\"            \n \
	6       C       S       Callback       \".0 .3 .8\"            \n \
	6       B       S       Blocked         \".9 .1 .0\"		\n \
	6       P       S       Progressing         \".4 .1 .6\"		\n \
	6       A       MS      Allocating         \".4 .1 .0\"		\n \
	6       Ar       MS      AllocatingReuse       \".1 .1 .8\"		\n \
	6       R       MS      Reclaiming         \".0 .1 .4\"		\n \
	6       Co       MS     DriverCopy         \".3 .5 .1\"		\n \
	6       No       MS     Nothing         \".0 .0 .0\"		\n \
	5       L       P	Mn	Mn      L\n");
}

void paje_output_file_terminate(void)
{

	/* close the file */
	fclose(out_paje_file);
}


/*
 * Generic tools
 */


void handle_new_mem_node(void)
{
	char *memnodestr = malloc(16*sizeof(char));
	sprintf(memnodestr, "%ld", ev.param[0]);
	
	fprintf(out_paje_file, "7       %f	%s      Mn      p	MEMNODE%s\n", (float)((ev.time-start_time)/1000000.0), memnodestr, memnodestr);
}

static unsigned cuda_index = 0;
static unsigned cpus_index = 0;
static unsigned other_index = 0;

void handle_worker_init_start(void)
{
	/* 
	   arg0 : type of worker (cuda, core ..)
	   arg1 : memory node
	   arg2 : thread id 
	*/
	char *str = malloc(20*sizeof(char));
	char *color = NULL;
	
	strcpy(str, "unknown");

	switch (ev.param[0]) {
		case FUT_APPS_KEY:
			str = "apps";
			color = other_worker_colors[other_index++];
			break;
		case FUT_CORE_KEY:
			str = "core";
			color = cpus_worker_colors[cpus_index++];
			break;
		case FUT_CUDA_KEY:
			str = "cuda";
			color = cuda_worker_colors[cuda_index++];
			break;
	}

//	fprintf(stderr, "new %s worker (tid = %d)\n", str, ev.param[1]);
	char *memnodestr = malloc(16*sizeof(char));
	sprintf(memnodestr, "%ld", ev.param[1]);
	
	char *tidstr = malloc(16*sizeof(char));
	sprintf(tidstr, "%ld", ev.param[2]);

	fprintf(out_paje_file, "7       %f	%s      T      MEMNODE%s       %s \n", (float)((ev.time-start_time)/1000000.0), tidstr, memnodestr, tidstr);

	/* create a new key in the htable */
	uint64_t workerid = nworkers++;
	ENTRY item;
		item.key = tidstr;
		item.data = (void *)workerid;

	worker_colors[workerid] = color;

	ENTRY *res;
	res = hsearch(item, FIND);

	worker_name[workerid] = str;

	/* only register a thread once */
	STARPU_ASSERT(res == NULL);

	res = hsearch(item, ENTER);
	STARPU_ASSERT(res);

	events[workerid] = event_list_new();

	/* start initialization */
	fprintf(out_paje_file, "10       %f     S      %ld      I\n", (float)((ev.time-start_time)/1000000.0), ev.param[2]);
}

void handle_worker_init_end(void)
{
	fprintf(out_paje_file, "10       %f     S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[0]);
	
}

void handle_worker_deinit_start(void)
{
	fprintf(out_paje_file, "10       %f     S      %ld      D\n", (float)((ev.time-start_time)/1000000.0), ev.param[0]);
}


void handle_worker_deinit_end(void)
{
	fprintf(out_paje_file, "8       %f	%ld	T\n", (float)((ev.time-start_time)/1000000.0), ev.param[1]);
}


int find_workder_id(unsigned long tid)
{
	char tidstr[16];
	sprintf(tidstr, "%ld", tid);

	ENTRY item;
		item.key = tidstr;
		item.data = NULL;
	ENTRY *res;
	res = hsearch(item, FIND);
	//STARPU_ASSERT(res);
	if (!res)
		return -1;

	int id = (uintptr_t)(res->data);

	return id;
}

static void create_paje_state_if_not_found(char *name)
{
	symbol_name_itor_t itor;
	for (itor = symbol_name_list_begin(symbol_list);
		itor != symbol_name_list_end(symbol_list);
		itor = symbol_name_list_next(itor))
	{
		if (!strcmp(name, itor->name))
		{
			/* we found an entry */
			return;
		}
	}

	/* it's the first time ... */
	symbol_name_t entry = symbol_name_new();
		entry->name = malloc(strlen(name));
		strcpy(entry->name, name);

	symbol_name_list_push_front(symbol_list, entry);
	
	/* choose some colour ... that's disguting yes */
	uint32_t hash_symbol = crc32_string(name, 0);

	unsigned hash_symbol_red = (unsigned)crc32_string("red", hash_symbol) % 1024;
	unsigned hash_symbol_green = (unsigned)crc32_string("green", hash_symbol) % 1024;
	unsigned hash_symbol_blue = (unsigned)crc32_string("blue", hash_symbol) % 1024;

	fprintf(stderr, "name %s hash red %d green %d blue %d \n", name, hash_symbol_red, hash_symbol_green, hash_symbol_blue);

	uint32_t hash_sum = hash_symbol_red + hash_symbol_green + hash_symbol_blue;

	float red = (1.0f * hash_symbol_red) / hash_sum;
	float green = (1.0f * hash_symbol_green) / hash_sum;
	float blue = (1.0f * hash_symbol_blue) / hash_sum;

	/* create the Paje state */
	fprintf(out_paje_file, "6       %s       S       %s \"%f %f %f\" \n", name, red, green, blue, name);
}

void handle_start_codelet_body(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);

	if (worker < 0) return;

	if (per_task_colour)
	{
		unsigned long has_name = ev.param[2];
		char *name = has_name?(char *)&ev.param[3]:"unknown";

		create_paje_state_if_not_found(name);

		fprintf(out_paje_file, "101       %f	S      %ld      E	%s\n", (float)((ev.time-start_time)/1000000.0), ev.param[1], name);
	}
	else {
		fprintf(out_paje_file, "10       %f	S      %ld      E\n", (float)((ev.time-start_time)/1000000.0), ev.param[1]);
	}

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = WORKING;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_end_codelet_body(void)
{
	//fprintf(stderr, "end codelet %p on tid %d\n", (void *)ev.param[0], ev.param[1]);

	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;
//	printf("<- worker %d\n", worker);
	fprintf(out_paje_file, "10       %f	S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = IDLE;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_user_event(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;

	unsigned code;
	code = ev.param[2];	

	fprintf(out_paje_file, "9       %f     event      %ld      %d\n", (float)((ev.time-start_time)/1000000.0), ev.param[1], code);
}

void handle_start_callback(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;
	fprintf(out_paje_file, "10       %f	S      %ld      C\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );
}

void handle_end_callback(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;
	fprintf(out_paje_file, "10       %f	S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );
}


void handle_start_fetch_input(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;

	fprintf(out_paje_file, "10       %f	S      %ld      Fi\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = FETCHING;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_end_fetch_input(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;

	fprintf(out_paje_file, "10       %f	S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = IDLE;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_start_push_output(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;

	fprintf(out_paje_file, "10       %f	S      %ld      Po\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = PUSHING;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_end_push_output(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;
	
	fprintf(out_paje_file, "10       %f	S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = IDLE;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_start_progress(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;

	fprintf(out_paje_file, "10       %f	S      %ld      P\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = PUSHING;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}

void handle_end_progress(void)
{
	int worker;
	worker = find_workder_id(ev.param[1]);
	if (worker < 0) return;
	
	fprintf(out_paje_file, "10       %f	S      %ld      B\n", (float)((ev.time-start_time)/1000000.0), ev.param[1] );

	event_t e = event_new();
	e->time =  ev.time;
	e->mode = IDLE;
	event_list_push_back(events[worker], e);

	end_time = STARPU_MAX(end_time, ev.time);
}


void handle_data_copy(void)
{
}

void handle_start_driver_copy(void)
{
	unsigned src = ev.param[0];
	unsigned dst = ev.param[1];
	unsigned size = ev.param[2];
	unsigned comid = ev.param[3];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      Co\n", (float)((ev.time-start_time)/1000000.0), dst);
	fprintf(out_paje_file, "18       %f	L      p	%d	MEMNODE%d	com_%d\n", (float)((ev.time-start_time)/1000000.0), size, src, comid);

}

void handle_end_driver_copy(void)
{
	unsigned dst = ev.param[1];
	unsigned size = ev.param[2];
	unsigned comid = ev.param[3];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      No\n", (float)((ev.time-start_time)/1000000.0), dst);
	fprintf(out_paje_file, "19       %f	L      p	%d	MEMNODE%d	com_%d\n", (float)((ev.time-start_time)/1000000.0), size, dst, comid);
}

void handle_start_alloc(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      A\n", (float)((ev.time-start_time)/1000000.0), memnode);
}

void handle_end_alloc(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      No\n", (float)((ev.time-start_time)/1000000.0), memnode);
}


void handle_start_alloc_reuse(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      Ar\n", (float)((ev.time-start_time)/1000000.0), memnode);
}

void handle_end_alloc_reuse(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      No\n", (float)((ev.time-start_time)/1000000.0), memnode);
}


void handle_start_memreclaim(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      R\n", (float)((ev.time-start_time)/1000000.0), memnode);
}

void handle_end_memreclaim(void)
{
	unsigned memnode = ev.param[0];

	fprintf(out_paje_file, "10       %f     MS      MEMNODE%d      No\n", (float)((ev.time-start_time)/1000000.0), memnode);
}

int maxq_size = 0;
int curq_size = 0;

void handle_job_push(void)
{
	curq_size++;

	maxq_size = STARPU_MAX(maxq_size, curq_size);

	workq_t e = workq_new();
	e->time =  ev.time;
	e->diff =  +1;
	e->current_size = curq_size;

	fprintf(out_paje_file, "13       %f ntask sched %f\n", (float)((ev.time-start_time)/1000000.0), (float)curq_size);

	workq_list_push_back(taskq, e);
}

void handle_job_pop(void)
{
	curq_size--;

	workq_t e = workq_new();
	e->time =  ev.time;
	e->diff =  -1;
	e->current_size = curq_size;

	fprintf(out_paje_file, "13       %f ntask sched %f\n", (float)((ev.time-start_time)/1000000.0), (float)curq_size);

	workq_list_push_back(taskq, e);
}

void handle_codelet_tag_deps(void)
{
	uint64_t child;
	uint64_t father;

	child = ev.param[0]; 
	father = ev.param[1]; 

	add_deps(child, father);
}

void handle_task_done(void)
{
	uint64_t tag_id;
	tag_id = ev.param[0];

        int worker;
        worker = find_workder_id(ev.param[1]);

	dot_set_tag_done(tag_id, worker_colors[worker]);
}

void generate_svg_output(void)
{
	svg_engine_generate_output(events, taskq, worker_name, nworkers, maxq_size, start_time, end_time, "toto.svg");
}

void generate_gnuplot_output(void)
{
	FILE *output;
	output = fopen("data", "w+");
	STARPU_ASSERT(output);
	
	unsigned linesize;
	unsigned maxline = 0;

	unsigned worker;
	for (worker = 0; worker < nworkers; worker++)
	{
		linesize = 0;

		event_itor_t i;
		for (i = event_list_begin(events[worker]);
		     i != event_list_end(events[worker]);
		     i = event_list_next(i))
		{
			linesize++;
		}
		maxline = STARPU_MAX(maxline, linesize);
	}

	for (worker = 0; worker < nworkers; worker++)
	{
		unsigned long prev = start_time;

		fprintf(output, "%d\t", 0);

		event_itor_t i;
		for (i = event_list_begin(events[worker]);
		     i != event_list_end(events[worker]);
		     i = event_list_next(i))
		{
			fprintf(output, "%lu\t", (i->time - prev)/FACTOR);
			prev = i->time;
		}
		fprintf(output, "\n");
	}

	fclose(output);
}

static void parse_args(int argc, char **argv)
{
	int i;
	for (i = 1; i < argc; i++) {
		if (strcmp(argv[i], "-c") == 0) {
			per_task_colour = 1;
		}

		if (strcmp(argv[i], "-o") == 0) {
			out_paje_path = argv[++i];
		}

		if (strcmp(argv[i], "-i") == 0) {
			filename = argv[++i];
		}

		if (strcmp(argv[i], "-h") == 0) {
		        fprintf(stderr, "Usage : %s [-c] [-i input_filename] [-o output_filename]\n", argv[0]);
			fprintf(stderr, "\t-c: use a different colour for every type of task.\n");
		        exit(-1);
		}
	}
}

/*
 * This program should be used to parse the log generated by FxT 
 */
int main(int argc, char **argv)
{
	int ret;
	int fd_in, fd_out;

	int use_stdout = 1;

	init_dag_dot();

	parse_args(argc, argv);

	fd_in = open(filename, O_RDONLY);
	if (fd_in < 0) {
	        perror("open failed :");
	        exit(-1);
	}

	fut = fxt_fdopen(fd_in);
	if (!fut) {
	        perror("fxt_fdopen :");
	        exit(-1);
	}
	
	fxt_blockev_t block;
	block = fxt_blockev_enter(fut);

	/* create a htable to identify each worker(tid) */
	hcreate(MAXWORKERS);

	symbol_list = symbol_name_list_new(); 

	paje_output_file_init();

	taskq = workq_list_new();

	while(1) {
		ret = fxt_next_ev(block, FXT_EV_TYPE_64, (struct fxt_ev *)&ev);
		if (ret != FXT_EV_OK) {
			fprintf(stderr, "no more block ...\n");
			break;
		}

		__attribute__ ((unused)) int nbparam = ev.nb_params;

		if (first_event)
		{
			first_event = 0;
			start_time = ev.time;

			/* create the "program" container */
			fprintf(out_paje_file, "7       %f p      P      0       program \n", (float)(start_time-start_time));
			/* create a variable with the number of tasks */
			fprintf(out_paje_file, "7       %f sched      Sc      p       scheduler \n", (float)(start_time-start_time));
			fprintf(out_paje_file, "13       %f ntask sched 0.0\n", (float)(start_time-start_time));
		}

		switch (ev.code) {
			case FUT_WORKER_INIT_START:
				handle_worker_init_start();
				break;

			case FUT_WORKER_INIT_END:
				handle_worker_init_end();
				break;

			case FUT_NEW_MEM_NODE:
				handle_new_mem_node();
				break;

			/* detect when the workers were idling or not */
			case FUT_START_CODELET_BODY:
				handle_start_codelet_body();
				break;
			case FUT_END_CODELET_BODY:
				handle_end_codelet_body();
				break;

			case FUT_START_CALLBACK:
				handle_start_callback();
				break;
			case FUT_END_CALLBACK:
				handle_end_callback();
				break;


			/* monitor stack size */
			case FUT_JOB_PUSH:
				handle_job_push();
				break;
			case FUT_JOB_POP:
				handle_job_pop();
				break;

			/* check the memory transfer overhead */
			case FUT_START_FETCH_INPUT:
				handle_start_fetch_input();
				break;
			case FUT_END_FETCH_INPUT:
				handle_end_fetch_input();
				break;
			case FUT_START_PUSH_OUTPUT:
				handle_start_push_output();
				break;
			case FUT_END_PUSH_OUTPUT:
				handle_end_push_output();
				break;

			case FUT_START_PROGRESS:
				handle_start_progress();
				break;
			case FUT_END_PROGRESS:
				handle_end_progress();
				break;


			case FUT_CODELET_TAG:
				//handle_codelet_tag();
				break;

			case FUT_CODELET_TAG_DEPS:
				handle_codelet_tag_deps();
				break;

			case FUT_TASK_DONE:
				handle_task_done();
				break;

			case FUT_DATA_COPY:
				handle_data_copy();
				break;

			case FUT_START_DRIVER_COPY:
				handle_start_driver_copy();
				break;

			case FUT_END_DRIVER_COPY:
				handle_end_driver_copy();
				break;

			case FUT_WORK_STEALING:
				/* XXX */
				break;

			case FUT_WORKER_DEINIT_START:
				handle_worker_deinit_start();
				break;

			case FUT_WORKER_DEINIT_END:
				handle_worker_deinit_end();
				break;

			case FUT_START_ALLOC:
				handle_start_alloc();
				break;

			case FUT_END_ALLOC:
				handle_end_alloc();
				break;

			case FUT_START_ALLOC_REUSE:
				handle_start_alloc_reuse();
				break;

			case FUT_END_ALLOC_REUSE:
				handle_end_alloc_reuse();
				break;


			case FUT_START_MEMRECLAIM:
				handle_start_memreclaim();
				break;

			case FUT_END_MEMRECLAIM:
				handle_end_memreclaim();
				break;

			case FUT_USER_EVENT:
				handle_user_event();
				break;

			default:
				fprintf(stderr, "unknown event.. %x at time %llx\n", (unsigned)ev.code, (long long unsigned)ev.time);
				break;
		}
	}

	generate_gnuplot_output();
	generate_svg_output();
	paje_output_file_terminate();

	terminate_dat_dot();

	return 0;
}