From eae7fd30d2436e4956608401ee58378c9812b97e Mon Sep 17 00:00:00 2001
From: Luis Gerhorst <privat@luisgerhorst.de>
Date: Wed, 21 Apr 2021 11:50:53 +0200
Subject: [PATCH] mbtex_count: Print every lock iteration

---
 samples/mbtex_count/prj.conf            |   4 -
 samples/mbtex_count/src/main.c          | 138 +++++++++++++-----------
 tests/benchmarks/footprints/src/main.c  |   2 -
 tests/benchmarks/footprints/src/mbtex.c |  61 -----------
 4 files changed, 77 insertions(+), 128 deletions(-)
 delete mode 100644 tests/benchmarks/footprints/src/mbtex.c

diff --git a/samples/mbtex_count/prj.conf b/samples/mbtex_count/prj.conf
index 80ea65b866c..a34ade452c5 100644
--- a/samples/mbtex_count/prj.conf
+++ b/samples/mbtex_count/prj.conf
@@ -1,7 +1,3 @@
 CONFIG_STDOUT_CONSOLE=y
 CONFIG_THREAD_NAME=y
 CONFIG_TIMING_FUNCTIONS=y
-
-# Enable migration-based synchronization
-CONFIG_MBS=n
-CONFIG_MBS_NUM_CPUS=0
diff --git a/samples/mbtex_count/src/main.c b/samples/mbtex_count/src/main.c
index a9e6be30aa8..93e7b00fcfc 100644
--- a/samples/mbtex_count/src/main.c
+++ b/samples/mbtex_count/src/main.c
@@ -10,12 +10,7 @@
 #include <sys/printk.h>
 #include <timing/timing.h>
 
-/* size of stack area used by each thread */
-#define STACKSIZE (1024*8)
-/* scheduling priority used by each thread */
-#define PRIORITY 7
-
-#define ITER (1000)
+#define ITER (128)
 
 #ifdef CONFIG_MBS
 #define K_MXTEX_DEFINE K_MBTEX_DEFINE
@@ -46,7 +41,6 @@ K_MXTEX_DEFINE(mxtex);
 static volatile uint64_t data[SIZE] = {};
 
 static int workload(int acc) {
-#pragma clang loop unroll(64)
 	for (int j = 0; j < SIZE; j += STEP) {
 		acc += data[j]++;
 	}
@@ -68,57 +62,52 @@ static int other_workload(int acc) {
 	return acc;
 }
 
+static int rep;
+
 void time_mxtex(void)
 {
-	timing_init();
-	timing_start();
+	int acc = 0;
 
-	for (int rep = 0; true; rep++) {
-		timing_t start_time = timing_counter_get();
-		uint32_t lock_total = 0;
-		uint32_t buff_total = 0;
-		uint32_t buff_max = 0;
-		uint32_t buff_min = UINT32_MAX;
+	timing_t lock_cycles[ITER];
+	timing_t workload_cycles[ITER];
 
-		unsigned int acc = 0;
+	timing_t rep_start_time = timing_counter_get();
+	for (int i = 0; i < ITER; i++) {
+		timing_t lock_start_time = timing_counter_get();
+		k_mxtex_lock(&mxtex, K_FOREVER);
+		timing_t lock_end_time = timing_counter_get();
 
-		for (int i = 0; i < ITER; i++) {
-			timing_t lock_start_time = timing_counter_get();
-			k_mxtex_lock(&mxtex, K_FOREVER);
-			timing_t lock_end_time = timing_counter_get();
+		timing_t workload_start_time = timing_counter_get();
+		acc += workload(acc);
+		timing_t workload_end_time = timing_counter_get();
 
-			timing_t buffstart_time = timing_counter_get();
-			acc = workload(acc);
-			timing_t buffend_time = timing_counter_get();
+		/* TODO: count on which cpu this was executed and how
+		 * often it is different from the previous one */
 
-			/* TODO: count on which cpu this was executed and how
-			 * often it is different from the previous one */
+		k_mxtex_unlock(&mxtex);
 
-			k_mxtex_unlock(&mxtex);
+		lock_cycles[i] = timing_cycles_get(&lock_start_time, &lock_end_time);
+		workload_cycles[i] = timing_cycles_get(&workload_start_time, &workload_end_time);
 
-			uint32_t lock_time = timing_cycles_get(&lock_start_time, &lock_end_time);
-			lock_total += lock_time;
+		/* Flush the caches. */
+		acc += other_workload(acc);
+	}
+	timing_t rep_end_time = timing_counter_get();
+
+	uint64_t rep_cycles = timing_cycles_get(&rep_start_time, &rep_end_time);
+	for (int i = 0; i < ITER; i++) {
+		printk("%p\t" "%d\t" "%d\t"
+		       "%llu\t" "%llu\t"
+		       "%llu\t" "%llu\t"
+		       "%llu\t" "%llu\n",
+		       _current, rep, i,
+		       rep_cycles, timing_cycles_to_ns(rep_cycles),
+		       lock_cycles[i], timing_cycles_to_ns(lock_cycles[i]),
+		       workload_cycles[i], timing_cycles_to_ns(workload_cycles[i]));
+	}
 
-			uint32_t buff = timing_cycles_get(&buffstart_time, &buffend_time);
-			buff_total += buff;
-			buff_max = buff > buff_max ? buff : buff_max;
-			buff_min = buff < buff_min ? buff : buff_min;
+	printk("# acc=%d\n", acc);
 
-			acc += other_workload(acc);
-		}
-		timing_t end_time = timing_counter_get();
-
-		uint32_t total = timing_cycles_get(&start_time, &end_time);
-		printk("%s, rep %d, iter %d, "
-		       "total %6u, "
-		       "lock %6u "
-		       "buff %6u - %6u - %6u, acc %u\n",
-		       _current->name, rep, ITER,
-		       total / ITER,
-		       lock_total / ITER,
-		       buff_min, buff_total / ITER, buff_max,
-		       acc);
-	}
 }
 
 void thread(void *dummy1, void *dummy2, void *dummy3)
@@ -130,17 +119,44 @@ void thread(void *dummy1, void *dummy2, void *dummy3)
 	time_mxtex();
 }
 
-K_THREAD_DEFINE(thread_a, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_b, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_c, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_d, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_e, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_f, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
-K_THREAD_DEFINE(thread_g, STACKSIZE, thread, NULL, NULL, NULL,
-		PRIORITY, 0, 0);
+/* size of stack area used by each thread */
+#define STACK_SIZE (1024*8)
+/* scheduling priority used by each thread */
+#define PRIORITY 7
+
+#define NR_THREADS 5
+
+struct k_thread tdata[NR_THREADS];
+static K_KERNEL_STACK_ARRAY_DEFINE(tstack, NR_THREADS, STACK_SIZE);
+
+void main(void)
+{
+	k_tid_t tid[NR_THREADS];
+
+	printk("PROJECT EXECUTION START\n"
+	       "thread\t" "rep\t" "iter\t"
+	       "rep_cycles\t" "rep_ns\t"
+	       "lock_cycles\t" "lock_ns\t"
+	       "workload_cycles\t" "workload_ns\n");
+
+	timing_init();
+	timing_start();
+
+	for (int r = 0; r < 3; r++) {
+		rep = r;
+		for (size_t i = 0; i < NR_THREADS; i++) {
+			tid[i] = k_thread_create(&tdata[i], tstack[i], STACK_SIZE,
+						 thread,
+						 NULL, NULL, NULL,
+						 PRIORITY,
+						 0, K_NO_WAIT);
+
+		}
+
+		for (size_t i = 0; i < NR_THREADS; i++) {
+			k_thread_join(tid[i], K_FOREVER);
+		}
+	}
+
+	printk("PROJECT EXECUTION SUCCESSFUL\n");
+}
diff --git a/tests/benchmarks/footprints/src/main.c b/tests/benchmarks/footprints/src/main.c
index 3f72b794901..1894be911b2 100644
--- a/tests/benchmarks/footprints/src/main.c
+++ b/tests/benchmarks/footprints/src/main.c
@@ -58,8 +58,6 @@ void main(void)
 
 	run_mutex();
 
-	run_mbtex();
-
 	run_timer();
 
 	run_libc();
diff --git a/tests/benchmarks/footprints/src/mbtex.c b/tests/benchmarks/footprints/src/mbtex.c
deleted file mode 100644
index 80192a0031c..00000000000
--- a/tests/benchmarks/footprints/src/mbtex.c
+++ /dev/null
@@ -1,61 +0,0 @@
-/*
- * Copyright (c) 2020 Intel Corporation.
- *
- * SPDX-License-Identifier: Apache-2.0
- */
-
-#include <kernel.h>
-#include <zephyr.h>
-
-#include "footprint.h"
-
-#define STACK_SIZE	512
-
-K_MBTEX_DEFINE(user_mbtex);
-
-#ifdef CONFIG_USERSPACE
-static void user_thread_fn(void *arg1, void *arg2, void *arg3)
-{
-	ARG_UNUSED(arg1);
-	ARG_UNUSED(arg2);
-	ARG_UNUSED(arg3);
-
-	k_mbtex_lock(&user_mbtex, K_FOREVER);
-
-	k_mbtex_unlock(&user_mbtex);
-}
-
-static void run_user_mbtex(void)
-{
-	k_tid_t tid;
-
-	/* Exercise simple workqueue */
-	tid = k_thread_create(&my_thread, my_stack_area, STACK_SIZE,
-			      user_thread_fn, NULL, NULL, NULL,
-			      0, K_USER, K_FOREVER);
-	k_object_access_grant(&user_mbtex, tid);
-
-	k_thread_start(tid);
-	k_thread_join(tid, K_FOREVER);
-}
-#endif /* CONFIG_USERSPACE */
-
-static void run_system_mbtex(void)
-{
-	struct k_mbtex sys_mbtex;
-
-	k_mbtex_init(&sys_mbtex);
-
-	k_mbtex_lock(&sys_mbtex, K_FOREVER);
-
-	k_mbtex_unlock(&sys_mbtex);
-}
-
-void run_mbtex(void)
-{
-	run_system_mbtex();
-
-#ifdef CONFIG_USERSPACE
-	run_user_mbtex();
-#endif
-}
-- 
GitLab