From 91a432721c2b16aa6610bd9c89bbee7763552f77 Mon Sep 17 00:00:00 2001 From: Chris Wilson Date: Sat, 6 Sep 2014 08:40:04 +0100 Subject: [PATCH] core: Display subtest walltime Signed-off-by: Chris Wilson --- lib/igt_core.c | 22 +++++++++++++++++++--- 1 file changed, 19 insertions(+), 3 deletions(-) diff --git a/lib/igt_core.c b/lib/igt_core.c index 5cd7d8f8..5d414683 100644 --- a/lib/igt_core.c +++ b/lib/igt_core.c @@ -49,6 +49,7 @@ #include #include #include +#include #include "drmtest.h" #include "intel_chipset.h" @@ -206,6 +207,7 @@ static bool list_subtests = false; static char *run_single_subtest = NULL; static bool run_single_subtest_found = false; static const char *in_subtest = NULL; +static struct timespec subtest_time; static bool in_fixture = false; static bool test_with_subtests = false; static enum { @@ -250,6 +252,14 @@ static void kmsg(const char *format, ...) fclose(file); } +static void gettime(struct timespec *ts) +{ + memset(ts, 0, sizeof(*ts)); + + if (clock_gettime(CLOCK_MONOTONIC_COARSE, ts)) + clock_gettime(CLOCK_MONOTONIC, ts); +} + bool __igt_fixture(void) { assert(!in_fixture); @@ -593,8 +603,6 @@ bool __igt_run_subtest(const char *subtest_name) run_single_subtest_found = true; } - - if (skip_subtests_henceforth) { printf("Subtest %s: %s\n", subtest_name, skip_subtests_henceforth == SKIP ? @@ -604,6 +612,7 @@ bool __igt_run_subtest(const char *subtest_name) kmsg(KERN_INFO "%s: starting subtest %s\n", command_str, subtest_name); + gettime(&subtest_time); return (in_subtest = subtest_name); } @@ -637,7 +646,14 @@ static int igt_exitcode; static void exit_subtest(const char *) __attribute__((noreturn)); static void exit_subtest(const char *result) { - printf("Subtest %s: %s\n", in_subtest, result); + struct timespec now; + double elapsed; + + gettime(&now); + elapsed = now.tv_sec - subtest_time.tv_sec; + elapsed += (now.tv_nsec - subtest_time.tv_nsec) * 1e-9; + + printf("Subtest %s: %s (%.3fs)\n", in_subtest, result, elapsed); in_subtest = NULL; longjmp(igt_subtest_jmpbuf, 1); }