test: Keep track of suite duration

Show the time taken by each test suite with 'ut all' and the total time
for all suites.

Take care to remove any sandbox time-offset from the values.

Fix the comment-format on timer_test_add_offset() while we are here.

Signed-off-by: Simon Glass <sjg@chromium.org>

5 files changed, 48 insertions, 2 deletions

diff --git a/drivers/timer/sandbox_timer.c b/drivers/timer/sandbox_timer.c
index e8b54a02965..c1baf3c69ec 100644
--- a/drivers/timer/sandbox_timer.c
+++ b/drivers/timer/sandbox_timer.c
@@ -18,6 +18,11 @@ void timer_test_add_offset(unsigned long offset)
 	sandbox_timer_offset += offset;
 }
 
+ulong timer_test_get_offset(void)
+{
+	return sandbox_timer_offset;
+};
+
 u64 notrace timer_early_get_count(void)
 {
 	return os_get_nsec() / 1000 + sandbox_timer_offset * 1000;
diff --git a/include/test/test.h b/include/test/test.h
index bac43c81d63..25c7712d160 100644
--- a/include/test/test.h
+++ b/include/test/test.h
@@ -16,11 +16,15 @@
  * @skip_count: Number of tests that were skipped
  * @test_count: Number of tests run. If a test is run muiltiple times, only one
  *	is counted
+ * @start: Timer value when test started
+ * @duration_ms: Suite duration in milliseconds
  */
 struct ut_stats {
 	int fail_count;
 	int skip_count;
 	int test_count;
+	ulong start;
+	ulong duration_ms;
 };
 
 /*
diff --git a/include/time.h b/include/time.h
index 3b2ba091247..f5b86bf70fe 100644
--- a/include/time.h
+++ b/include/time.h
@@ -28,7 +28,7 @@ uint64_t get_timer_us(uint64_t base);
  */
 unsigned long get_timer_us_long(unsigned long base);
 
-/*
+/**
  * timer_test_add_offset()
  *
  * Allow tests to add to the time reported through lib/time.c functions
@@ -36,6 +36,19 @@ unsigned long get_timer_us_long(unsigned long base);
  */
 void timer_test_add_offset(unsigned long offset);
 
+#ifdef CONFIG_SANDBOX
+/**
+ * timer_test_get_offset()
+ *
+ * Get the total offset currently being added the time
+ *
+ * Return:: number of milliseconds the system time has been advanced
+ */
+ulong timer_test_get_offset(void);
+#else
+static inline ulong timer_test_get_offset(void) { return 0; }
+#endif
+
 /**
  * usec_to_tick() - convert microseconds to clock ticks
  *
diff --git a/test/Kconfig b/test/Kconfig
index 558a9cd49b4..1c8e3d16300 100644
--- a/test/Kconfig
+++ b/test/Kconfig
@@ -20,6 +20,15 @@ config SPL_UNIT_TEST
 	  of-platdata and SPL handover. To run these tests with the sandbox_spl
 	  board, use the -u (unit test) option.
 
+config UNIT_TEST_DURATION
+	bool "Report unit-test duration"
+	depends on UNIT_TEST
+	default y
+	help
+	  Enable this short the time taken by each test suite. This is reported
+	  after the suite runs, alongside the pass/fail results. In addition,
+	  an overall total is reported if multiple suites are run.
+
 config UT_LIB
 	bool "Unit tests for library functions"
 	depends on UNIT_TEST
diff --git a/test/test-main.c b/test/test-main.c
index 815f54bebd5..1d821a3fe72 100644
--- a/test/test-main.c
+++ b/test/test-main.c
@@ -14,6 +14,7 @@
 #include <net.h>
 #include <of_live.h>
 #include <os.h>
+#include <spl.h>
 #include <usb.h>
 #include <dm/ofnode.h>
 #include <dm/root.h>
@@ -680,6 +681,8 @@ void ut_report(struct ut_stats *stats, int run_count)
 	else
 		printf("Tests");
 	printf(" run: %d, ", stats->test_count);
+	if (stats)
+		printf("%ld ms, ", stats->duration_ms);
 	if (stats->skip_count)
 		printf("skipped: %d, ", stats->skip_count);
 	printf("failures: %d\n", stats->fail_count);
@@ -692,9 +695,15 @@ int ut_run_list(struct unit_test_state *uts, const char *category,
 {
 	;
 	bool has_dm_tests = false;
+	ulong start_offset = 0;
+	ulong test_offset = 0;
 	int ret;
 
 	memset(&uts->cur, '\0', sizeof(struct ut_stats));
+	if (CONFIG_IS_ENABLED(UNIT_TEST_DURATION)) {
+		uts->cur.start = get_timer(0);
+		start_offset = timer_test_get_offset();
+	}
 
 	if (!CONFIG_IS_ENABLED(OF_PLATDATA) &&
 	    ut_list_has_dm_tests(tests, count, prefix, select_name)) {
@@ -732,13 +741,19 @@ int ut_run_list(struct unit_test_state *uts, const char *category,
 	if (has_dm_tests)
 		dm_test_restore(uts->of_root);
 
-	ut_report(&uts->cur, 1);
 	if (ret == -ENOENT)
 		printf("Test '%s' not found\n", select_name);
+	if (CONFIG_IS_ENABLED(UNIT_TEST_DURATION)) {
+		test_offset = timer_test_get_offset() - start_offset;
+
+		uts->cur.duration_ms = get_timer(uts->cur.start) - test_offset;
+	}
+	ut_report(&uts->cur, 1);
 
 	uts->total.skip_count += uts->cur.skip_count;
 	uts->total.fail_count += uts->cur.fail_count;
 	uts->total.test_count += uts->cur.test_count;
+	uts->total.duration_ms += uts->cur.duration_ms;
 	uts->run_count++;
 
 	return ret;