Browse Source

Add an offline tool to display the activity of the workers during the
execution. The fxt_tool utility now generates a file named "activity.data"
which can be processed by the activity.sh script that generates a picture named
activity.eps using gnuplot.

Typical usage:
./fxt_tool -i /tmp/prof_file_foo
./activity.sh activity.data

Cédric Augonnet 15 years ago
parent
commit
28f327b9d2
4 changed files with 194 additions and 9 deletions
  1. 16 5
      src/common/fxt.h
  2. 5 0
      src/core/workers.c
  3. 78 0
      tools/activity.sh
  4. 95 4
      tools/fxt_tool.c

+ 16 - 5
src/common/fxt.h

@@ -61,6 +61,9 @@
 #define STARPU_FUT_WORKER_DEINIT_START	0x5135
 #define STARPU_FUT_WORKER_DEINIT_END	0x5136
 
+#define STARPU_FUT_WORKER_SLEEP_START	0x5139
+#define STARPU_FUT_WORKER_SLEEP_END	0x5140
+
 #define STARPU_FUT_USER_DEFINED_START	0x5116
 #define STARPU_FUT_USER_DEFINED_END	0x5117
 
@@ -241,6 +244,12 @@ do {										\
 #define STARPU_TRACE_WORKER_DEINIT_END(workerkind)		\
 	FUT_DO_PROBE2(STARPU_FUT_WORKER_DEINIT_END, workerkind, syscall(SYS_gettid));
 
+#define STARPU_TRACE_WORKER_SLEEP_START	\
+	FUT_DO_PROBE1(STARPU_FUT_WORKER_SLEEP_START, syscall(SYS_gettid));
+
+#define STARPU_TRACE_WORKER_SLEEP_END	\
+	FUT_DO_PROBE1(STARPU_FUT_WORKER_SLEEP_END, syscall(SYS_gettid));
+
 #define STARPU_TRACE_USER_DEFINED_START	\
 	FUT_DO_PROBE1(STARPU_FUT_USER_DEFINED_START, syscall(SYS_gettid));
 
@@ -277,7 +286,7 @@ do {										\
 #else // !STARPU_USE_FXT
 
 #define STARPU_TRACE_NEW_MEM_NODE(nodeid)	do {} while(0);
-#define TRACE_NEW_WORKER(a,b)		do {} while(0);
+#define TRACE_NEW_WORKER(a,b)			do {} while(0);
 #define STARPU_TRACE_WORKER_INIT_START(a,b)	do {} while(0);
 #define STARPU_TRACE_WORKER_INIT_END		do {} while(0);
 #define STARPU_TRACE_START_CODELET_BODY(job)	do {} while(0);
@@ -295,18 +304,20 @@ do {										\
 #define STARPU_TRACE_TASK_DEPS(a, b)		do {} while(0);
 #define STARPU_TRACE_TASK_DONE(a)		do {} while(0);
 #define STARPU_TRACE_TAG_DONE(a)		do {} while(0);
-#define STARPU_TRACE_DATA_COPY(a, b, c)	do {} while(0);
+#define STARPU_TRACE_DATA_COPY(a, b, c)		do {} while(0);
 #define STARPU_TRACE_START_DRIVER_COPY(a,b,c,d)	do {} while(0);
 #define STARPU_TRACE_END_DRIVER_COPY(a,b,c,d)	do {} while(0);
 #define STARPU_TRACE_WORK_STEALING(a, b)	do {} while(0);
 #define STARPU_TRACE_WORKER_DEINIT_START	do {} while(0);
 #define STARPU_TRACE_WORKER_DEINIT_END(a)	do {} while(0);
-#define STARPU_TRACE_USER_DEFINED_START	do {} while(0);
+#define STARPU_TRACE_WORKER_SLEEP_START		do {} while(0);
+#define STARPU_TRACE_WORKER_SLEEP_END		do {} while(0);
+#define STARPU_TRACE_USER_DEFINED_START		do {} while(0);
 #define STARPU_TRACE_USER_DEFINED_END		do {} while(0);
 #define STARPU_TRACE_START_ALLOC(memnode)	do {} while(0);
-#define STARPU_TRACE_END_ALLOC(memnode)	do {} while(0);
+#define STARPU_TRACE_END_ALLOC(memnode)		do {} while(0);
 #define STARPU_TRACE_START_ALLOC_REUSE(a)	do {} while(0);
-#define STARPU_TRACE_END_ALLOC_REUSE(a)	do {} while(0);
+#define STARPU_TRACE_END_ALLOC_REUSE(a)		do {} while(0);
 #define STARPU_TRACE_START_MEMRECLAIM(memnode)	do {} while(0);
 #define STARPU_TRACE_END_MEMRECLAIM(memnode)	do {} while(0);
 #define STARPU_TRACE_START_PROGRESS(memnode)	do {} while(0);

+ 5 - 0
src/core/workers.c

@@ -620,9 +620,14 @@ void _starpu_block_worker(int workerid, pthread_cond_t *cond, pthread_mutex_t *m
 
 	int64_t start_time, end_time;
 	start_time = (int64_t)_starpu_timing_now();
+
+	STARPU_TRACE_WORKER_SLEEP_START
+
 	PTHREAD_COND_WAIT(cond, mutex);
 	end_time = (int64_t)_starpu_timing_now();
 
+	STARPU_TRACE_WORKER_SLEEP_END
+
 	if (profiling)
 		_starpu_worker_update_profiling_info(workerid, 0, end_time - start_time, 0);
 }

+ 78 - 0
tools/activity.sh

@@ -0,0 +1,78 @@
+#!/bin/bash
+
+#
+# StarPU
+# Copyright (C) INRIA 2008-2010 (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.
+#
+
+# The input file must be generated by the fxt_tool command
+inputfile=$1
+
+# TODO display help if -h is passed
+
+# Count the number of workers in the trace
+workers=`cut -f1 $inputfile | sort -n | uniq`
+nworkers=`cut -f1 $inputfile | sort -n | uniq|wc -l`
+
+# size of the entire graph
+width=2.5
+heigth=$(echo "0.5 * $nworkers"|bc -l)
+
+# In case 3 arguments are provided, the 2nd (resp. 3rd) indicates the start
+# (resp. the end) of the interval to be displayed.
+if [ $# -ge 3 ]; then
+starttime=$2
+endtime=$3
+else
+starttime=$(cut -f 2 $inputfile |sort -n|head -1)
+endtime=$(cut -f 2 $inputfile |sort -n|tail -1)
+fi
+
+# Gnuplot header
+cat > gnuplotcmd << EOF
+set term postscript eps enhanced color
+set output "activity.eps"
+set xrange [$starttime:$endtime]
+set size $width,$heigth
+set multiplot;
+EOF
+
+cnt=0
+for worker in $workers
+do
+	grep "^$worker" $inputfile > .tmp.$worker
+
+	starty=$(echo "0.5 * $cnt"|bc -l)
+
+cat >> gnuplotcmd << EOF
+
+set origin 0.0,$starty;
+set size $width,0.5;
+
+set key off
+
+plot ".tmp.$worker" using 2:(100) with filledcurves y1=0.0 lt rgb "#000000" notitle,\
+	 ".tmp.$worker" using 2:((100*(\$4+\$5))/\$3) with filledcurves y1=0.0 lt rgb "#ff0000" notitle,\
+	 ".tmp.$worker" using 2:((100*\$4)/\$3) with filledcurves y1=0.0 lt rgb "#00ff00" notitle
+EOF
+
+	cnt=$(($cnt+1))	
+done
+
+
+cat >> gnuplotcmd << EOF
+unset multiplot
+EOF
+
+gnuplot < gnuplotcmd

+ 95 - 4
tools/fxt_tool.c

@@ -44,6 +44,19 @@ static int nworkers = 0;
 unsigned ninputfiles = 0;
 static char *filenames[64];
 
+static uint64_t last_codelet_hash[MAXWORKERS];
+static double last_codelet_start[MAXWORKERS];
+static char last_codelet_symbol[128][MAXWORKERS];
+
+/* If more than a period of time has elapsed, we flush the profiling info,
+ * otherwise they are accumulated everytime there is a new relevant event. */
+#define ACTIVITY_PERIOD	125.0
+static double last_activity_flush_timestamp[MAXWORKERS];
+static double accumulated_sleep_time[MAXWORKERS];
+static double accumulated_exec_time[MAXWORKERS];
+
+
+
 LIST_TYPE(symbol_name,
 	char *name;
 );
@@ -69,6 +82,9 @@ static FILE *out_paje_file;
 static char *distrib_time_path = "distrib.data";
 static FILE *distrib_time;
 
+static char *activity_path = "activity.data";
+static FILE *activity_file;
+
 static void paje_output_file_init(void)
 {
 	/* create a new file */
@@ -99,6 +115,7 @@ static void paje_output_file_init(void)
 	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       Sl       S      Sleeping         \".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 \
@@ -162,6 +179,25 @@ static int find_worker_id(unsigned long tid)
 	return id;
 }
 
+static void update_accumulated_time(int worker, double sleep_time, double exec_time, double current_timestamp, int forceflush)
+{
+	accumulated_sleep_time[worker] += sleep_time;
+	accumulated_exec_time[worker] += exec_time;
+
+	/* If sufficient time has elapsed since the last flush, we have a new
+	 * point in our graph */
+	double elapsed = current_timestamp - last_activity_flush_timestamp[worker];
+	if (forceflush || (elapsed > ACTIVITY_PERIOD))
+	{		
+		fprintf(activity_file, "%d\t%lf\t%lf\t%lf\t%lf\n", worker, current_timestamp, elapsed, accumulated_exec_time[worker], accumulated_sleep_time[worker]);
+
+		/* reset the accumulated times */
+		last_activity_flush_timestamp[worker] = current_timestamp;
+		accumulated_sleep_time[worker] = 0.0;
+		accumulated_exec_time[worker] = 0.0;
+	}
+}
+
 /*
  *	Initialization
  */
@@ -206,12 +242,20 @@ static void handle_worker_init_start(void)
 	/* start initialization */
 	fprintf(out_paje_file, "10       %f     S      %s%"PRIu64"      I\n",
 			get_event_time_stamp(), prefix, ev.param[2]);
+
+
 }
 
 static void handle_worker_init_end(void)
 {
 	fprintf(out_paje_file, "10       %f     S      %s%"PRIu64"      B\n",
 			get_event_time_stamp(), prefix, ev.param[0]);
+
+	/* Initilize the accumulated time counters */
+	int worker = find_worker_id(ev.param[0]);
+	last_activity_flush_timestamp[worker] = get_event_time_stamp();
+	accumulated_sleep_time[worker] = 0.0;
+	accumulated_exec_time[worker] = 0.0;
 }
 
 static void handle_worker_deinit_start(void)
@@ -264,9 +308,6 @@ static void create_paje_state_if_not_found(char *name)
 	fprintf(out_paje_file, "6       %s       S       %s \"%f %f %f\" \n", name, name, red, green, blue);
 }
 
-static double last_codelet_start[MAXWORKERS];
-static uint64_t last_codelet_hash[MAXWORKERS];
-static char last_codelet_symbol[128][MAXWORKERS];
 
 static void handle_start_codelet_body(void)
 {
@@ -310,6 +351,8 @@ static void handle_end_codelet_body(void)
 	fprintf(out_paje_file, "10       %f	S      %s%"PRIu64"      B\n", end_codelet_time, prefix, ev.param[1]);
 
 	float codelet_length = (end_codelet_time - last_codelet_start[worker]);
+
+	update_accumulated_time(worker, 0.0, codelet_length, end_codelet_time, 0);
 	
 	if (generate_distrib)
 	fprintf(distrib_time, "%s\t%s%d\t%"PRIx64"\t%f\n", last_codelet_symbol[worker],
@@ -363,6 +406,43 @@ static void handle_worker_status(const char *newstatus)
 	end_time = STARPU_MAX(end_time, ev.time);
 }
 
+static double last_sleep_start[MAXWORKERS];
+
+static void handle_start_sleep(void)
+{
+	int worker;
+	worker = find_worker_id(ev.param[0]);
+	if (worker < 0) return;
+
+	float start_sleep_time = get_event_time_stamp();
+	last_sleep_start[worker] = start_sleep_time;
+
+	fprintf(out_paje_file, "10       %f	S      %s%"PRIu64"      Sl\n",
+				get_event_time_stamp(), prefix, ev.param[0]);
+
+	end_time = STARPU_MAX(end_time, ev.time);
+}
+
+static void handle_end_sleep(void)
+{
+	int worker;
+	worker = find_worker_id(ev.param[0]);
+	if (worker < 0) return;
+
+	float end_sleep_timestamp = get_event_time_stamp();
+
+	fprintf(out_paje_file, "10       %f	S      %s%"PRIu64"      B\n",
+				end_sleep_timestamp, prefix, ev.param[0]);
+
+	double sleep_length = end_sleep_timestamp - last_sleep_start[worker];
+
+	update_accumulated_time(worker, sleep_length, 0.0, end_sleep_timestamp, 0);
+
+	end_time = STARPU_MAX(end_time, ev.time);
+}
+
+
+
 static void handle_data_copy(void)
 {
 }
@@ -694,7 +774,6 @@ void parse_new_file(char *filename_in, char *file_prefix, uint64_t file_offset)
 		{
 			first_event = 0;
 			start_time = ev.time;
-
 		}
 
 		switch (ev.code) {
@@ -754,6 +833,14 @@ void parse_new_file(char *filename_in, char *file_prefix, uint64_t file_offset)
 				handle_worker_status("B");
 				break;
 
+			case STARPU_FUT_WORKER_SLEEP_START:
+				handle_start_sleep();
+				break;
+
+			case STARPU_FUT_WORKER_SLEEP_END:
+				handle_end_sleep();
+				break;
+
 			case STARPU_FUT_CODELET_TAG:
 				/* XXX */
 				break;
@@ -869,6 +956,8 @@ int main(int argc, char **argv)
 	if (generate_distrib)
 		distrib_time = fopen(distrib_time_path, "w+");
 
+	activity_file = fopen(activity_path, "w+");
+
 	paje_output_file_init();
 
 	if (ninputfiles == 1)
@@ -985,6 +1074,8 @@ int main(int argc, char **argv)
 
 	/* close the different files */
 	fclose(out_paje_file);
+	
+	fclose(activity_file);
 
 	if (generate_distrib)
 		fclose(distrib_time);