drivers: flash: shell: Use timing functions for speed tests

Use the timing functions to increase the accuracy of the flash speed
measurements.

Signed-off-by: Pieter De Gendt <pieter.degendt@basalte.be>

Author: pdgendt

drivers/flash/Kconfig

@@ -108,6 +108,7 @@ if FLASH_SHELL
 config FLASH_SHELL_TEST_COMMANDS
 	bool "Flash read/write/erase test commands"
 	select CBPRINTF_FP_SUPPORT
+	select TIMING_FUNCTIONS
 	help
 	  Enable additional flash shell commands for performing
 	  read/write/erase tests with speed output.

drivers/flash/flash_shell.c

@@ -17,6 +17,10 @@
 #include <zephyr/shell/shell.h>
 #include <zephyr/sys/util.h>
 
+#ifdef CONFIG_FLASH_SHELL_TEST_COMMANDS
+#include <zephyr/timing/timing.h>
+#endif
+
 /* Buffer is only needed for bytes that follow command and offset */
 #define BUF_ARRAY_CNT (CONFIG_SHELL_ARGC_MAX - 2)
 
@@ -354,23 +358,25 @@ static int read_write_erase_validate(const struct shell *sh, size_t argc, char *
 	return 0;
 }
 
-static void speed_output(const struct shell *sh, uint64_t total_time, double loops, double size)
+static void speed_output(const struct shell *sh, uint64_t total_time, uint32_t loops, uint32_t size)
 {
-	double time_per_loop = (double)total_time / loops;
+	uint64_t time_per_loop = timing_cycles_to_ns_avg(total_time, loops);
 	double throughput = size;
 	uint8_t speed_index = 0;
 
 	if (time_per_loop > 0) {
-		throughput /= (time_per_loop / 1000.0);
+		throughput *= NSEC_PER_SEC;
+		throughput /= time_per_loop;
 	}
 
 	while (throughput >= (double)speed_divisor && speed_index < ARRAY_SIZE(speed_types)) {
 		throughput /= (double)speed_divisor;
 		++speed_index;
 	}
 
-	shell_print(sh, "Total: %llums, Per loop: ~%.0fms, Speed: ~%.1f%sps",
-		    total_time, time_per_loop, throughput, speed_types[speed_index]);
+	shell_print(sh, "Total: %llu ns, Per loop: %llu ns, Speed: ~%.1f%sps",
+		    timing_cycles_to_ns(total_time), time_per_loop, throughput,
+		    speed_types[speed_index]);
 }
 
 static int cmd_read_test(const struct shell *sh, size_t argc, char *argv[])
@@ -381,7 +387,7 @@ static int cmd_read_test(const struct shell *sh, size_t argc, char *argv[])
 	int result;
 	uint32_t addr;
 	uint32_t size;
-	uint64_t start_time;
+	timing_t start_time, stop_time;
 	uint64_t loop_time;
 	uint64_t total_time = 0;
 	uint32_t loops = 0;
@@ -396,10 +402,14 @@ static int cmd_read_test(const struct shell *sh, size_t argc, char *argv[])
 		return result;
 	}
 
+	timing_init();
+	timing_start();
+
 	while (repeat--) {
-		start_time = k_uptime_get();
+		start_time = timing_counter_get();
 		result = flash_read(flash_dev, addr, test_arr, size);
-		loop_time = k_uptime_delta(&start_time);
+		stop_time = timing_counter_get();
+		loop_time = timing_cycles_get(&start_time, &stop_time);
 
 		if (result) {
 			shell_error(sh, "Read failed: %d", result);
@@ -408,13 +418,15 @@ static int cmd_read_test(const struct shell *sh, size_t argc, char *argv[])
 
 		++loops;
 		total_time += loop_time;
-		shell_print(sh, "Loop #%u done in %llums.", loops, loop_time);
+		shell_print(sh, "Loop #%u done in %llu ns.", loops, timing_cycles_to_ns(loop_time));
 	}
 
 	if (result == 0) {
-		speed_output(sh, total_time, (double)loops, (double)size);
+		speed_output(sh, total_time, loops, size);
 	}
 
+	timing_stop();
+
 	return result;
 }
 
@@ -425,7 +437,7 @@ static int cmd_write_test(const struct shell *sh, size_t argc, char *argv[])
 	int result;
 	uint32_t addr;
 	uint32_t size;
-	uint64_t start_time;
+	timing_t start_time, stop_time;
 	uint64_t loop_time;
 	uint64_t total_time = 0;
 	uint32_t loops = 0;
@@ -444,10 +456,14 @@ static int cmd_write_test(const struct shell *sh, size_t argc, char *argv[])
 		test_arr[i] = (uint8_t)i;
 	}
 
+	timing_init();
+	timing_start();
+
 	while (repeat--) {
-		start_time = k_uptime_get();
+		start_time = timing_counter_get();
 		result = flash_write(flash_dev, addr, test_arr, size);
-		loop_time = k_uptime_delta(&start_time);
+		stop_time = timing_counter_get();
+		loop_time = timing_cycles_get(&start_time, &stop_time);
 
 		if (result) {
 			shell_error(sh, "Write failed: %d", result);
@@ -456,13 +472,15 @@ static int cmd_write_test(const struct shell *sh, size_t argc, char *argv[])
 
 		++loops;
 		total_time += loop_time;
-		shell_print(sh, "Loop #%u done in %llu ticks.", loops, loop_time);
+		shell_print(sh, "Loop #%u done in %llu ns.", loops, timing_cycles_to_ns(loop_time));
 	}
 
 	if (result == 0) {
-		speed_output(sh, total_time, (double)loops, (double)size);
+		speed_output(sh, total_time, loops, size);
 	}
 
+	timing_stop();
+
 	return result;
 }
 
@@ -473,7 +491,7 @@ static int cmd_erase_test(const struct shell *sh, size_t argc, char *argv[])
 	int result;
 	uint32_t addr;
 	uint32_t size;
-	uint64_t start_time;
+	timing_t start_time, stop_time;
 	uint64_t loop_time;
 	uint64_t total_time = 0;
 	uint32_t loops = 0;
@@ -492,10 +510,14 @@ static int cmd_erase_test(const struct shell *sh, size_t argc, char *argv[])
 		test_arr[i] = (uint8_t)i;
 	}
 
+	timing_init();
+	timing_start();
+
 	while (repeat--) {
-		start_time = k_uptime_get();
+		start_time = timing_counter_get();
 		result = flash_erase(flash_dev, addr, size);
-		loop_time = k_uptime_delta(&start_time);
+		stop_time = timing_counter_get();
+		loop_time = timing_cycles_get(&start_time, &stop_time);
 
 		if (result) {
 			shell_error(sh, "Erase failed: %d", result);
@@ -504,13 +526,15 @@ static int cmd_erase_test(const struct shell *sh, size_t argc, char *argv[])
 
 		++loops;
 		total_time += loop_time;
-		shell_print(sh, "Loop #%u done in %llums.", loops, loop_time);
+		shell_print(sh, "Loop #%u done in %llu ns.", loops, timing_cycles_to_ns(loop_time));
 	}
 
 	if (result == 0) {
-		speed_output(sh, total_time, (double)loops, (double)size);
+		speed_output(sh, total_time, loops, size);
 	}
 
+	timing_stop();
+
 	return result;
 }
 
@@ -522,7 +546,7 @@ static int cmd_erase_write_test(const struct shell *sh, size_t argc, char *argv[
 	int result_write = 0;
 	uint32_t addr;
 	uint32_t size;
-	uint64_t start_time;
+	timing_t start_time, stop_time;
 	uint64_t loop_time;
 	uint64_t total_time = 0;
 	uint32_t loops = 0;
@@ -541,11 +565,15 @@ static int cmd_erase_write_test(const struct shell *sh, size_t argc, char *argv[
 		test_arr[i] = (uint8_t)i;
 	}
 
+	timing_init();
+	timing_start();
+
 	while (repeat--) {
-		start_time = k_uptime_get();
+		start_time = timing_counter_get();
 		result_erase = flash_erase(flash_dev, addr, size);
 		result_write = flash_write(flash_dev, addr, test_arr, size);
-		loop_time = k_uptime_delta(&start_time);
+		stop_time = timing_counter_get();
+		loop_time = timing_cycles_get(&start_time, &stop_time);
 
 		if (result_erase) {
 			shell_error(sh, "Erase failed: %d", result_erase);
@@ -559,13 +587,15 @@ static int cmd_erase_write_test(const struct shell *sh, size_t argc, char *argv[
 
 		++loops;
 		total_time += loop_time;
-		shell_print(sh, "Loop #%u done in %llums.", loops, loop_time);
+		shell_print(sh, "Loop #%u done in %llu ns.", loops, timing_cycles_to_ns(loop_time));
 	}
 
 	if (result_erase == 0 && result_write == 0) {
-		speed_output(sh, total_time, (double)loops, (double)size);
+		speed_output(sh, total_time, loops, size);
 	}
 
+	timing_stop();
+
 	return (result_erase != 0 ? result_erase : result_write);
 }
 #endif