rt-app, rt-app_parse_config: add task pipeline latency metric

End-to-end latency of a pipeline of tasks is a useful metric to evaluate
synthetic mobile-like workloads (e.g., audio/video decoding pipeline).

Add such feature by piggybacking barrier_like events.

Signed-off-by: Juri Lelli <[email protected]>

Author: Juri Lelli

src/rt-app.c

@@ -286,18 +286,29 @@ static int run_event(event_data_t *event, int dry_run,
 		pthread_cond_signal(&(rdata->res.cond.obj));
 		break;
 	case rtapp_barrier:
-		log_debug("barrier %s ", rdata->name);
-		pthread_mutex_lock(&(rdata->res.barrier.m_obj));
-		if (rdata->res.barrier.waiting == 0) {
-			/* everyone is already waiting, signal */
-			pthread_cond_broadcast(&(rdata->res.barrier.c_obj));
-		} else {
-			/* not everyone is waiting, mark then wait */
-			rdata->res.barrier.waiting -= 1;
-			pthread_cond_wait(&(rdata->res.barrier.c_obj), &(rdata->res.barrier.m_obj));
-			rdata->res.barrier.waiting += 1;
+		{
+			struct timespec t_delta;
+			log_debug("barrier %s ", rdata->name);
+			pthread_mutex_lock(&(rdata->res.barrier.m_obj));
+			if (rdata->res.barrier.waiting == 0) {
+				/* everyone is already waiting, signal */
+				pthread_cond_broadcast(&(rdata->res.barrier.c_obj));
+				clock_gettime(CLOCK_MONOTONIC, &t_delta);
+				t_delta = timespec_sub(&t_delta, &rdata->res.barrier.t_ref);
+				ldata->pipe_latency = timespec_to_usec(&t_delta);
+				log_debug("pipeline duration %lu ", ldata->pipe_latency);
+			} else {
+				/* not everyone is waiting, mark then wait */
+				rdata->res.barrier.waiting -= 1;
+				pthread_cond_wait(&(rdata->res.barrier.c_obj), &(rdata->res.barrier.m_obj));
+				rdata->res.barrier.waiting += 1;
+			}
+			pthread_mutex_unlock(&(rdata->res.barrier.m_obj));
 		}
-		pthread_mutex_unlock(&(rdata->res.barrier.m_obj));
+		break;
+	case rtapp_bref:
+		log_debug("bref %s ", rdata->name);
+		clock_gettime(CLOCK_MONOTONIC, &rdata->res.barrier.t_ref);
 		break;
 	case rtapp_sig_and_wait:
 		log_debug("signal and wait %s", rdata->name);
@@ -762,10 +773,11 @@ void *thread_body(void *arg)
 
 	log_notice("[%d] starting thread ...\n", data->ind);
 
-	fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s %10s %10s\n",
+	fprintf(data->log_handler, "%s %8s %8s %8s %15s %15s %15s %10s %10s %10s %10s %10s\n",
 				   "#idx", "perf", "run", "period",
 				   "start", "end", "rel_st", "slack",
-				   "c_duration", "c_period", "wu_lat");
+				   "c_duration", "c_period", "wu_lat",
+				   "pipe_lat");
 
 	if (opts.ftrace)
 		log_ftrace(ft_data.marker_fd, "[%d] starts", data->ind);
@@ -836,6 +848,7 @@ void *thread_body(void *arg)
 		curr_timing->duration = ldata.duration;
 		curr_timing->perf = ldata.perf;
 		curr_timing->wu_latency = ldata.wu_latency;
+		curr_timing->pipe_latency = ldata.pipe_latency;
 		curr_timing->slack = ldata.slack;
 		curr_timing->c_period = ldata.c_period;
 		curr_timing->c_duration = ldata.c_duration;

src/rt-app_parse_config.c

@@ -236,6 +236,7 @@ static void init_barrier_resource(rtapp_resource_t *data, const rtapp_options_t
 			&data->res.barrier.m_attr);
 
 	pthread_cond_init(&data->res.barrier.c_obj, NULL);
+	data->res.barrier.t_ref = usec_to_timespec(0UL);
 }
 
 static void
@@ -517,6 +518,23 @@ parse_thread_event_data(char *name, struct json_object *obj,
 		return;
 	}
 
+    if (!strncmp(name, "bref", strlen("bref"))) {
+
+		if (!json_object_is_type(obj, json_type_string))
+			goto unknown_event;
+
+		data->type = rtapp_bref;
+
+		ref = json_object_get_string(obj);
+		i = get_resource_index(ref, rtapp_barrier, opts);
+
+		data->res = i;
+		rdata = &(opts->resources[data->res]);
+
+		log_info(PIN2 "type %d target %s [%d]", data->type, rdata->name, rdata->index);
+		return;
+	}
+
 	if (!strncmp(name, "timer", strlen("timer"))) {
 
 		tmp = get_string_value_from(obj, "ref", TRUE, "unknown");
@@ -631,6 +649,7 @@ static char *events[] = {
 	"iorun",
 	"yield",
 	"barrier",
+	"bref",
 	NULL
 };
 

src/rt-app_types.h

@@ -72,7 +72,8 @@ typedef enum resource_t
 	rtapp_iorun,
 	rtapp_runtime,
 	rtapp_yield,
-	rtapp_barrier
+	rtapp_barrier,
+	rtapp_bref
 } resource_t;
 
 struct _rtapp_mutex {
@@ -97,6 +98,8 @@ struct _rtapp_barrier_like {
 	int waiting;
 	/* condvar to wait/signal on */
 	pthread_cond_t c_obj;
+	/* time reference for tasks pipeline */
+	struct timespec t_ref;
 };
 
 struct _rtapp_signal {
@@ -200,6 +203,7 @@ typedef struct _log_data_t {
 	unsigned long perf;
 	unsigned long duration;
 	unsigned long wu_latency;
+	unsigned long pipe_latency;
 	unsigned long c_duration;
 	unsigned long c_period;
 	long slack;
@@ -241,6 +245,7 @@ typedef struct _timing_point_t {
 	unsigned long c_duration;
 	unsigned long c_period;
 	unsigned long wu_latency;
+	unsigned long pipe_latency;
 	long slack;
 	__u64 start_time;
 	__u64 end_time;

src/rt-app_utils.c

@@ -145,7 +145,7 @@ void
 log_timing(FILE *handler, timing_point_t *t)
 {
 	fprintf(handler,
-		"%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %10lu %10lu %10lu",
+		"%4d %8lu %8lu %8lu %15llu %15llu %15llu %10ld %10lu %10lu %10lu %10lu",
 		t->ind,
 		t->perf,
 		t->duration,
@@ -156,7 +156,8 @@ log_timing(FILE *handler, timing_point_t *t)
 		t->slack,
 		t->c_duration,
 		t->c_period,
-		t->wu_latency
+		t->wu_latency,
+		t->pipe_latency
 	);
 	fprintf(handler, "\n");
 }