test: Show the average time per test

Show the average duration of a test, so we can keep track of how it is
trending. Report the suite with the longest average test to encourage
people to improve it.

Add a function to update the stats based on the results from a single
suite and another to show the summary information.

Make this optional, since sandbox's SPL tests do not have a timer driver
and people may want to print results without times.

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

diff --git a/include/test/test.h b/include/test/test.h
index 25c7712..877fda8 100644 (file)
--- a/include/test/test.h
+++ b/include/test/test.h
@@ -33,6 +33,8 @@ struct ut_stats {
  * @cur: Statistics for the current run
  * @total: Statistics for all test runs
  * @run_count: Number of times ut_run_list() has been called
+ * @worst: Sute which had the first per-text run time
+ * @worst_ms: Time taken by that test
  * @start: Store the starting mallinfo when doing leak test
  * @of_live: true to use livetree if available, false to use flattree
  * @of_root: Record of the livetree root node (used for setting up tests)
@@ -56,6 +58,8 @@ struct unit_test_state {
        struct ut_stats cur;
        struct ut_stats total;
        int run_count;
+       const struct suite *worst;
+       int worst_ms;
        struct mallinfo start;
        struct device_node *of_root;
        bool of_live;

diff --git a/test/cmd_ut.c b/test/cmd_ut.c
index cc30c51..c96277d 100644 (file)
--- a/test/cmd_ut.c
+++ b/test/cmd_ut.c
@@ -192,6 +192,36 @@ static int run_suite(struct unit_test_state *uts, struct suite *ste,
        return ret;
 }
 
+static void show_stats(struct unit_test_state *uts)
+{
+       if (uts->run_count < 2)
+               return;
+
+       ut_report(&uts->total, uts->run_count);
+       if (CONFIG_IS_ENABLED(UNIT_TEST_DURATION) &&
+           uts->total.test_count && uts->worst) {
+               ulong avg = uts->total.duration_ms / uts->total.test_count;
+
+               printf("Average test time: %ld ms, worst case '%s' took %d ms\n",
+                      avg, uts->worst->name, uts->worst_ms);
+       }
+}
+
+static void update_stats(struct unit_test_state *uts, const struct suite *ste)
+{
+       if (CONFIG_IS_ENABLED(UNIT_TEST_DURATION) && uts->cur.test_count) {
+               ulong avg;
+
+               avg = uts->cur.duration_ms ?
+                       uts->cur.duration_ms /
+                       uts->cur.test_count : 0;
+               if (avg > uts->worst_ms) {
+                       uts->worst_ms = avg;
+                       uts->worst = ste;
+               }
+       }
+}
+
 static int do_ut_all(struct unit_test_state *uts, struct cmd_tbl *cmdtp,
                     int flag, int argc, char *const argv[])
 {
@@ -208,6 +238,7 @@ static int do_ut_all(struct unit_test_state *uts, struct cmd_tbl *cmdtp,
                        retval = run_suite(uts, ste, cmdtp, flag, 1, argv);
                        if (!any_fail)
                                any_fail = retval;
+                       update_stats(uts, ste);
                }
        }
        ut_report(&uts->total, uts->run_count);
@@ -306,6 +337,7 @@ static int do_ut(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[])
 
                ret = run_suite(&uts, ste, cmdtp, flag, argc, argv);
        }
+       show_stats(&uts);
        if (ret)
                return ret;
        ut_uninit_state(&uts);

diff --git a/test/test-main.c b/test/test-main.c
index 1d821a3..597afa2 100644 (file)
--- a/test/test-main.c
+++ b/test/test-main.c
@@ -677,12 +677,16 @@ static int ut_run_tests(struct unit_test_state *uts, const char *prefix,
 void ut_report(struct ut_stats *stats, int run_count)
 {
        if (run_count > 1)
-               printf("Suites run: %d, total tests", run_count);
+               printf("Total tests");
        else
                printf("Tests");
        printf(" run: %d, ", stats->test_count);
-       if (stats)
-               printf("%ld ms, ", stats->duration_ms);
+       if (stats && stats->test_count) {
+               ulong dur = stats->duration_ms;
+
+               printf("%ld ms, average: %ld ms, ", dur,
+                      dur ? dur / stats->test_count : 0);
+       }
        if (stats->skip_count)
                printf("skipped: %d, ", stats->skip_count);
        printf("failures: %d\n", stats->fail_count);