Display the name of the worker in the "activity" output.

src/common/fxt.h

@@ -94,6 +94,8 @@
 
 #define STARPU_FUT_USER_EVENT		0x5132
 
+#define STARPU_FUT_SET_PROFILING	0x5142
+
 #ifdef STARPU_USE_FXT
 #include <sys/syscall.h> /* pour les définitions de SYS_xxx */
 #include <fxt/fxt.h>
@@ -140,8 +142,8 @@ do {									\
 #define STARPU_TRACE_NEW_MEM_NODE(nodeid)			\
 	FUT_DO_PROBE2(STARPU_FUT_NEW_MEM_NODE, nodeid, syscall(SYS_gettid));
 
-#define STARPU_TRACE_WORKER_INIT_START(workerkind,memnode)	\
-	FUT_DO_PROBE3(STARPU_FUT_WORKER_INIT_START, workerkind, memnode, syscall(SYS_gettid));
+#define STARPU_TRACE_WORKER_INIT_START(workerkind, devid, memnode)	\
+	FUT_DO_PROBE4(STARPU_FUT_WORKER_INIT_START, workerkind, devid, memnode, syscall(SYS_gettid));
 
 #define STARPU_TRACE_WORKER_INIT_END				\
 	FUT_DO_PROBE1(STARPU_FUT_WORKER_INIT_END, syscall(SYS_gettid));
@@ -288,11 +290,14 @@ do {										\
 #define STARPU_TRACE_USER_EVENT(code)			\
 	FUT_DO_PROBE2(STARPU_FUT_USER_EVENT, code, syscall(SYS_gettid));
 
+#define STARPU_TRACE_SET_PROFILING(status)		\
+	FUT_DO_PROBE2(STARPU_FUT_SET_PROFILING, status, syscall(SYS_gettid));
+
 #else // !STARPU_USE_FXT
 
 #define STARPU_TRACE_NEW_MEM_NODE(nodeid)	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_START(a,b,c)	do {} while(0);
 #define STARPU_TRACE_WORKER_INIT_END		do {} while(0);
 #define STARPU_TRACE_START_CODELET_BODY(job)	do {} while(0);
 #define STARPU_TRACE_END_CODELET_BODY(job)	do {} while(0);
@@ -329,6 +334,7 @@ do {										\
 #define STARPU_TRACE_START_PROGRESS(memnode)	do {} while(0);
 #define STARPU_TRACE_END_PROGRESS(memnode)	do {} while(0);
 #define STARPU_TRACE_USER_EVENT(code)		do {} while(0);
+#define STARPU_TRACE_SET_PROFILING(status)	do {} while(0);
 
 #endif // STARPU_USE_FXT
 

src/drivers/cpu/driver_cpu.c

@@ -128,16 +128,17 @@ void *_starpu_cpu_worker(void *arg)
 	struct starpu_jobq_s *jobq = cpu_arg->jobq;
 	unsigned memnode = cpu_arg->memory_node;
 	int workerid = cpu_arg->workerid;
+	int devid = cpu_arg->devid;
 
 #ifdef STARPU_USE_FXT
 	_starpu_fxt_register_thread(cpu_arg->bindid);
 #endif
-	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_CPU_KEY, memnode);
+	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_CPU_KEY, devid, memnode);
 
 	_starpu_bind_thread_on_cpu(cpu_arg->config, cpu_arg->bindid);
 
 #ifdef STARPU_VERBOSE
-        fprintf(stderr, "cpu worker %d is ready on logical cpu %d\n", cpu_arg->devid, cpu_arg->bindid);
+        fprintf(stderr, "cpu worker %d is ready on logical cpu %d\n", devid, cpu_arg->bindid);
 #endif
 
 	_starpu_set_local_memory_node_key(&memnode);
@@ -146,7 +147,7 @@ void *_starpu_cpu_worker(void *arg)
 
 	_starpu_set_local_worker_key(cpu_arg);
 
-	snprintf(cpu_arg->name, 32, "CPU %d", cpu_arg->devid);
+	snprintf(cpu_arg->name, 32, "CPU %d", devid);
 
 	cpu_arg->status = STATUS_UNKNOWN;
 
@@ -228,7 +229,7 @@ void *_starpu_cpu_worker(void *arg)
 	_starpu_free_all_automatically_allocated_buffers(memnode);
 
 #ifdef STARPU_DATA_STATS
-	fprintf(stderr, "CPU #%d computation %le comm %le (%lf \%%)\n", cpu_arg->devid, jobq->total_computation_time, jobq->total_communication_time,  jobq->total_communication_time*100.0/jobq->total_computation_time);
+	fprintf(stderr, "CPU #%d computation %le comm %le (%lf \%%)\n", devid, jobq->total_computation_time, jobq->total_communication_time,  jobq->total_communication_time*100.0/jobq->total_computation_time);
 #endif
 
 #ifdef STARPU_VERBOSE
@@ -238,7 +239,7 @@ void *_starpu_cpu_worker(void *arg)
 		ratio = jobq->total_computation_time_error/jobq->total_computation_time;
 	}
 
-	_starpu_print_to_logfile("MODEL ERROR: CPU %d ERROR %lf EXEC %lf RATIO %lf NTASKS %d\n", cpu_arg->devid, jobq->total_computation_time_error, jobq->total_computation_time, ratio, jobq->total_job_performed);
+	_starpu_print_to_logfile("MODEL ERROR: CPU %d ERROR %lf EXEC %lf RATIO %lf NTASKS %d\n", devid, jobq->total_computation_time_error, jobq->total_computation_time, ratio, jobq->total_job_performed);
 #endif
 
 	STARPU_TRACE_WORKER_DEINIT_END(STARPU_FUT_CPU_KEY);

src/drivers/cuda/driver_cuda.c

@@ -206,7 +206,7 @@ void *_starpu_cuda_worker(void *arg)
 #ifdef STARPU_USE_FXT
 	_starpu_fxt_register_thread(args->bindid);
 #endif
-	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_CUDA_KEY, memnode);
+	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_CUDA_KEY, devid, memnode);
 
 	_starpu_bind_thread_on_cpu(args->config, args->bindid);
 

src/drivers/opencl/driver_opencl.c

@@ -197,7 +197,7 @@ void *_starpu_opencl_worker(void *arg)
 #endif
 
 	unsigned memnode = args->memory_node;
-	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_OPENCL_KEY, memnode);
+	STARPU_TRACE_WORKER_INIT_START(STARPU_FUT_OPENCL_KEY, devid, memnode);
 
 	_starpu_bind_thread_on_cpu(args->config, args->bindid);
 

src/profiling/profiling.c

@@ -20,6 +20,7 @@
 #include <common/config.h>
 #include <common/utils.h>
 #include <common/timing.h>
+#include <common/fxt.h>
 #include <errno.h>
 
 static struct starpu_worker_profiling_info worker_info[STARPU_NMAXWORKERS];
@@ -37,6 +38,8 @@ int starpu_profiling_status_set(int status)
 	int prev_value = profiling;
 	profiling = status;
 
+	STARPU_TRACE_SET_PROFILING(status);
+
 	/* If we enable profiling, we reset the counters. */
 	if (status == STARPU_PROFILING_ENABLE)
 	{

tools/activity.sh

@@ -25,20 +25,27 @@ inputfile_with_counters=$1
 inputfile=.$inputfile_with_counters.activity
 inputfile_cnt_ready=.$1.cnt_ready
 inputfile_cnt_submitted=.$1.cnt_submitted
+set_profiling_list=.$1.set_profiling_list
+names=.$1.names
 
-grep -v "^cnt" $inputfile_with_counters > $inputfile
+grep "^set_profiling" $inputfile_with_counters > $set_profiling_list
+grep "0$" $set_profiling_list | cut -f 2 | sort -n > $set_profiling_list.disable
+grep "1$" $set_profiling_list | cut -f 2 | sort -n > $set_profiling_list.enable
+
+grep "^name" $inputfile_with_counters > $names
+
+grep -v "^cnt" $inputfile_with_counters | grep -v "^set_profiling" | grep -v "^name" > $inputfile
 grep "^cnt_ready" $inputfile_with_counters > $inputfile_cnt_ready
 grep "^cnt_submitted" $inputfile_with_counters > $inputfile_cnt_submitted
 
-max_cnt_submitted=`cut -f2 $inputfile_cnt_submitted |sort -n|tail -1`
-
 # 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 + (0.5 * $nworkers)"|bc -l)
+width=1.5
+heigth=0.40
+total_heigth=$(echo "$heigth + ($heigth * $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.
@@ -46,23 +53,50 @@ if [ $# -ge 3 ]; then
 starttime=$2
 endtime=$3
 else
+#if profiling is explicitely enabled (resp. disabled) at some point, we set the
+# default start (rest. end) point when we enable (resp. disable) profiling for
+# the first time.
+profiling_enable_cnt=`wc -l $set_profiling_list.enable|sed -e "s/\(.*\) .*/\1/"`
+if [ $profiling_enable_cnt -ge 1 ]; then
+starttime=`head -1 $set_profiling_list.enable`
+else
 starttime=$(cut -f 2 $inputfile |sort -n|head -1)
+fi
+
+# TODO test if last disable > first enable
+
+profiling_disable_cnt=$(wc -l $set_profiling_list.disable|sed -e "s/\(.*\) .*/\1/")
+if [ $profiling_disable_cnt -ge 1 ]; then
+endtime=`tail -1 $set_profiling_list.disable`
+else
 endtime=$(cut -f 2 $inputfile |sort -n|tail -1)
 fi
 
+# The values in the file are in ms, we display seconds
+starttime=$(echo "$starttime * 0.001 "| bc -l)
+endtime=$(echo "$endtime * 0.001 "| bc -l)
+
+fi
+
+echo "START $starttime END $endtime"
+
 # Gnuplot header
 cat > gnuplotcmd << EOF
 set term postscript eps enhanced color
 set output "activity.eps"
 set xrange [$starttime:$endtime]
-set size $width,$heigth
+set size $width,$total_heigth
 set multiplot;
 
 set origin 0.0,0.0;
-set size $width,0.5;
+set size $width,$heigth;
+
+set logscale y
+
+plot "$inputfile_cnt_submitted" using (\$2/1000):3 with filledcurves lt rgb "#999999" title "submitted",\
+	"$inputfile_cnt_ready" using (\$2/1000):3 with filledcurves lt rgb "#000000" title "ready"
 
-plot "$inputfile_cnt_submitted" using 2:3 with filledcurves lt rgb "#999999" title "submitted",\
-	"$inputfile_cnt_ready" using 2:3 with filledcurves lt rgb "#000000" title "ready"
+set nologscale y
 
 EOF
 
@@ -71,18 +105,22 @@ for worker in $workers
 do
 	grep "^$worker" $inputfile > .tmp.$worker
 
-	starty=$(echo "0.5 + (0.5 * $cnt)"|bc -l)
+	starty=$(echo "$heigth + ($heigth * $cnt)"|bc -l)
 
 cat >> gnuplotcmd << EOF
 
 set origin 0.0,$starty;
-set size $width,0.5;
+set size $width,$heigth;
 
 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
+set yrange [0:100]
+
+set ylabel "$(cut -f2- $names |grep "^$worker" | cut -f2)"
+
+plot ".tmp.$worker" using (\$2/1000):(100) with filledcurves y1=0.0 lt rgb "#000000" notitle,\
+	 ".tmp.$worker" using (\$2/1000):((100*(\$4+\$5))/\$3) with filledcurves y1=0.0 lt rgb "#ff0000" notitle,\
+	 ".tmp.$worker" using (\$2/1000):((100*\$4)/\$3) with filledcurves y1=0.0 lt rgb "#00ff00" notitle
 EOF
 
 	cnt=$(($cnt+1))	
@@ -100,6 +138,12 @@ rm $inputfile
 rm $inputfile_cnt_ready
 rm $inputfile_cnt_submitted
 
+rm $set_profiling_list
+rm $set_profiling_list.enable
+rm $set_profiling_list.disable
+
+#rm $names
+
 for worker in $workers
 do
 	rm .tmp.$worker

tools/fxt_tool.c

@@ -50,7 +50,7 @@ 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
+#define ACTIVITY_PERIOD	75.0
 static double last_activity_flush_timestamp[MAXWORKERS];
 static double accumulated_sleep_time[MAXWORKERS];
 static double accumulated_exec_time[MAXWORKERS];
@@ -218,22 +218,29 @@ static void handle_worker_init_start(void)
 	   arg2 : thread id 
 	*/
 	fprintf(out_paje_file, "7       %f	%s%"PRIu64"      T      %sMEMNODE%"PRIu64"       %s%"PRIu64"\n",
-		get_event_time_stamp(), prefix, ev.param[2], prefix, ev.param[1], prefix, ev.param[2]);
+		get_event_time_stamp(), prefix, ev.param[3], prefix, ev.param[1], prefix, ev.param[3]);
 
-	int workerid = register_worker_id(ev.param[2]);
+	int devid = ev.param[1];
+	int workerid = register_worker_id(ev.param[3]);
+
+	char *kindstr = "";
 
 	switch (ev.param[0]) {
 		case STARPU_FUT_APPS_KEY:
 			set_next_other_worker_color(workerid);
+			kindstr = "apps";
 			break;
 		case STARPU_FUT_CPU_KEY:
 			set_next_cpu_worker_color(workerid);
+			kindstr = "cpu";
 			break;
 		case STARPU_FUT_CUDA_KEY:
 			set_next_cuda_worker_color(workerid);
+			kindstr = "cuda";
 			break;
 		case STARPU_FUT_OPENCL_KEY:
 			set_next_opencl_worker_color(workerid);
+			kindstr = "opencl";
 			break;
 		default:
 			STARPU_ABORT();
@@ -243,7 +250,7 @@ static void handle_worker_init_start(void)
 	fprintf(out_paje_file, "10       %f     S      %s%"PRIu64"      I\n",
 			get_event_time_stamp(), prefix, ev.param[2]);
 
-
+	fprintf(activity_file, "name\t%d\t%s %d\n", workerid, kindstr, devid);
 }
 
 static void handle_worker_init_end(void)
@@ -680,6 +687,13 @@ static void handle_mpi_irecv_end(void)
 	add_mpi_recv_transfer(src, rank, mpi_tag, date);
 }
 
+static void handle_set_profiling(void)
+{
+	int status = ev.param[0];
+
+	fprintf(activity_file, "set_profiling\t%lf\t%d\n", get_event_time_stamp(), status);
+}
+
 static void parse_args(int argc, char **argv)
 {
 	/* We want to support arguments such as "fxt_tool -i trace_*" */
@@ -947,6 +961,10 @@ void parse_new_file(char *filename_in, char *file_prefix, uint64_t file_offset)
 				handle_mpi_irecv_end();
 				break;
 
+			case STARPU_FUT_SET_PROFILING:
+				handle_set_profiling();
+				break;
+
 			default:
 				fprintf(stderr, "unknown event.. %x at time %llx WITH OFFSET %llx\n",
 					(unsigned)ev.code, (long long unsigned)ev.time, (long long unsigned)(ev.time-offset));