X-Git-Url: http://rtime.felk.cvut.cz/gitweb/can-benchmark.git/blobdiff_plain/02ace553c6f4b790696fce6b560e0b3a59f929e4..0050e301dae44fac57f8b30a22f07ec870618c2d:/latester/latester.c

diff --git a/latester/latester.c b/latester/latester.c
index 67e1dcb..ff627dc 100644
--- a/latester/latester.c
+++ b/latester/latester.c
@@ -166,7 +166,7 @@ int timespec_subtract (struct timespec *result, struct timespec *x, struct times
 
 void msg_info_print(FILE *f, struct msg_info *mi)
 {
-	struct timespec diff;
+	struct timespec diff, routing_delay, tx_time;
 	void *local = talloc_new (NULL);
 	static long num = 0;
 	char sent[64], received[64];
@@ -189,7 +189,12 @@ void msg_info_print(FILE *f, struct msg_info *mi)
 			mi->tx_time_us);
 		break;
 	case 3:
-		fprintf(f, "%ld: %s %s -> %s (%s) -> %s (%s) %s = %s (%s), %s (%s) %d\n",
+		tx_time.tv_sec = 0;
+		tx_time.tv_nsec = mi->tx_time_us*1000;
+		timespec_subtract(&routing_delay, &mi->ts_rx_final_kern, &mi->ts_rx_onwire_kern);
+		timespec_subtract(&routing_delay, &routing_delay, &tx_time);
+
+		fprintf(f, "%ld: %s %s -> %s (%s) -> %s (%s) %s = %s (%s), %s (%s) %d %s\n",
 			num, S(mi->ts_sent), sent,
 			S(mi->ts_rx_onwire_kern), S(mi->ts_rx_onwire),
 			S(mi->ts_rx_final_kern), S(mi->ts_rx_final), received,
@@ -197,7 +202,8 @@ void msg_info_print(FILE *f, struct msg_info *mi)
 			DIFF(mi->ts_sent, mi->ts_rx_onwire),
 			DIFF(mi->ts_rx_onwire_kern, mi->ts_rx_final_kern),
 			DIFF(mi->ts_rx_onwire, mi->ts_rx_final),
-			mi->tx_time_us);
+			mi->tx_time_us,
+			S(routing_delay));
 		break;
 	}
 #undef S
@@ -421,26 +427,34 @@ static inline void send_and_check(int s)
 	}
 }
 
-static inline void get_next_timeout(struct timespec *timeout)
+static inline void get_next_timeout(struct timespec *timeout, bool advance)
 {
 	struct timespec now;
 	static struct timespec last = {-1, 0 };
 
 	clock_gettime(CLOCK_MONOTONIC, &now);
 
-	if (last.tv_sec == -1)
+	if (last.tv_sec == -1) {
 		last = now;
+		last.tv_nsec = last.tv_nsec/1000000*1000000;
+	}
 	if (opt.period_us != 0) {
-		last.tv_sec += opt.period_us/1000000;
-		last.tv_nsec += (opt.period_us%1000000)*1000;
-		while (last.tv_nsec >= 1000000000) {
-			last.tv_nsec -= 1000000000;
-			last.tv_sec++;
+		if (advance) {
+			last.tv_sec += opt.period_us/1000000;
+			last.tv_nsec += (opt.period_us%1000000)*1000;
+			while (last.tv_nsec >= 1000000000) {
+				last.tv_nsec -= 1000000000;
+				last.tv_sec++;
+			}
 		}
 		if (timespec_subtract(timeout, &last, &now) /* is negative */) {
 			stats.overrun++;
 			memset(timeout, 0, sizeof(*timeout));
 		}
+/* 		printf("next %ld.%06ld  now %ld.%06ld  --> timeout %ld.%06ld\n", */
+/* 		       last.tv_sec, last.tv_nsec/1000, */
+/* 		       now.tv_sec, now.tv_nsec/1000, */
+/* 		       timeout->tv_sec, timeout->tv_nsec/1000); */
 	} else if (opt.timeout_ms != 0) {
 		timeout->tv_sec = opt.timeout_ms/1000;
 		timeout->tv_nsec = (opt.timeout_ms%1000)*1000000;
@@ -590,11 +604,12 @@ void *measure_thread(void *arg)
 		SEND();
 
 	get_tstamp(&stats.tic);
-
+	ret = 0;
 	while (!finish_flag &&
 	       (opt.count == 0 || count < opt.count || msg_in_progress != 0)) {
 
-		get_next_timeout(&timeout);
+		get_next_timeout(&timeout, ret == 0);
+		//printf("timeout %ld.%06ld\n", timeout.tv_sec, timeout.tv_nsec/1000);
 		//printf("ppoll"); fflush(stdout);
 		ret = ppoll(pfd, num_interfaces, &timeout, NULL);
 		//printf("=%d\n", ret);
@@ -850,6 +865,7 @@ int main(int argc, const char *argv[])
 		fclose(opt.f_msgs);
 
 	if (opt.f_stat) {
+		struct histogram_stats hs;
 		fprintf(opt.f_stat, "cmdline='");
 		for (i=0; i<argc; i++)
 			fprintf(opt.f_stat, "%s%s", argv[i], i < argc-1 ? " " : "");
@@ -857,7 +873,7 @@ int main(int argc, const char *argv[])
 
 		timespec_subtract(&diff, &stats.tac, &stats.tic);
 		fprintf(opt.f_stat, "duration=%s # seconds\n", tstamp_str(NULL, &diff));
-	
+
 		fprintf(opt.f_stat, "sent=%d\n", count);
 		fprintf(opt.f_stat, "overrun=%d\n", stats.overrun);
 		if (stats.overrun && !opt.quiet)
@@ -875,6 +891,12 @@ int main(int argc, const char *argv[])
 		if (stats.timeouts && !opt.quiet)
 			printf("invalid_frame=%d\n", stats.timeouts);
 
+		histogram_stats(&histogram_gw, &hs);
+		double avg = hs.count ? (double)hs.sum/hs.count : 0;
+		fprintf(opt.f_stat, "avg=%g\n", avg);
+		for (i = 0; i <= 20; i++)
+			fprintf(opt.f_stat, "percentile%d=%d\n", i*5, hs.percentile[i*5]);
+
 		fclose(opt.f_stat);
 	}