[PATCH 0/3] kselftest/vDSO: Output formatting cleanups for vdso_test_abi

[PATCH 0/3] kselftest/vDSO: Output formatting cleanups for vdso_test_abi

[Mark Brown]

These patches update the output of the vdso_test_abi test program to
bring it into line with expected KTAP usage, the main one being the
first patch which ensures we log distinct test names for each reported
result making it much easier for automated systems to track the status
of the tests.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
Mark Brown (3):
      kselftest/vDSO: Make test name reporting for vdso_abi_test tooling friendly
      kselftest/vDSO: Fix message formatting for clock_id logging
      kselftest/vDSO: Use ksft_print_msg() rather than printf in vdso_test_abi

 tools/testing/selftests/vDSO/vdso_test_abi.c | 72 +++++++++++++++-------------
 1 file changed, 39 insertions(+), 33 deletions(-)
---
base-commit: 98b1cc82c4affc16f5598d4fa14b1858671b2263
change-id: 20231122-kselftest-vdso-test-name-44fcc7e16a38

Best regards,
-- 
Mark Brown <broonie@kernel.org>

[PATCH 1/3] kselftest/vDSO: Make test name reporting for vdso_abi_test tooling friendly

[Mark Brown]

The test results from vdso_abi_test are all formatted using a series of
macros:

  #define VDSO_TEST_PASS_MSG()	"\n%s(): PASS\n", __func__
  #define VDSO_TEST_FAIL_MSG(x)	"\n%s(): %s FAIL\n", __func__, x
  #define VDSO_TEST_SKIP_MSG(x)	"\n%s(): SKIP: Could not find %s\n", __func__, x

which don't play nicely with automated KTAP parsers since the actual KTAP
lines are in the form

   ok 1

with no test name and we get an additional log line such as

  vdso_test_gettimeofday(): PASS

with no preceeding # as KTAP requires. The lack of a test name means that
many automation systems will have a hard time distinguishing between the
different tests or correlating results between runs, the lack of # is less
severe but could potentially cause confusion.

Fix these issues by rewriting all the result reporting to include both the
vDSO function name being tested and (where there is one) the name of the
clock being tested in the main KTAP line. Since we have tests both with and
without a specific clock we abandon the helper macros and just put the
format strings used directly in the ksft_ API calls. When we fail to look
up the relevant vDSO symbol we add a separate print statement explaining
why the skip is being done. This gives output such as:

  ok 1 __vdso_gettimeofday
  # clock_id: CLOCK_REALTIME
  # The time is 1700673118.58091596
  ok 2 __vdso_clock_gettime CLOCK_REALTIME

which is much easier for test automation to work with.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
 tools/testing/selftests/vDSO/vdso_test_abi.c | 66 +++++++++++++++-------------
 1 file changed, 36 insertions(+), 30 deletions(-)

diff --git a/tools/testing/selftests/vDSO/vdso_test_abi.c b/tools/testing/selftests/vDSO/vdso_test_abi.c
index 883ca85424bc..b304abae6e8f 100644
--- a/tools/testing/selftests/vDSO/vdso_test_abi.c
+++ b/tools/testing/selftests/vDSO/vdso_test_abi.c
@@ -33,9 +33,20 @@ typedef long (*vdso_clock_gettime_t)(clockid_t clk_id, struct timespec *ts);
 typedef long (*vdso_clock_getres_t)(clockid_t clk_id, struct timespec *ts);
 typedef time_t (*vdso_time_t)(time_t *t);
 
-#define VDSO_TEST_PASS_MSG()	"\n%s(): PASS\n", __func__
-#define VDSO_TEST_FAIL_MSG(x)	"\n%s(): %s FAIL\n", __func__, x
-#define VDSO_TEST_SKIP_MSG(x)	"\n%s(): SKIP: Could not find %s\n", __func__, x
+const char *vdso_clock_name[12] = {
+	"CLOCK_REALTIME",
+	"CLOCK_MONOTONIC",
+	"CLOCK_PROCESS_CPUTIME_ID",
+	"CLOCK_THREAD_CPUTIME_ID",
+	"CLOCK_MONOTONIC_RAW",
+	"CLOCK_REALTIME_COARSE",
+	"CLOCK_MONOTONIC_COARSE",
+	"CLOCK_BOOTTIME",
+	"CLOCK_REALTIME_ALARM",
+	"CLOCK_BOOTTIME_ALARM",
+	"CLOCK_SGI_CYCLE",
+	"CLOCK_TAI",
+};
 
 static void vdso_test_gettimeofday(void)
 {
@@ -44,7 +55,8 @@ static void vdso_test_gettimeofday(void)
 		(vdso_gettimeofday_t)vdso_sym(version, name[0]);
 
 	if (!vdso_gettimeofday) {
-		ksft_test_result_skip(VDSO_TEST_SKIP_MSG(name[0]));
+		ksft_print_msg("Couldn't find %s\n", name[0]);
+		ksft_test_result_skip("%s\n", name[0]);
 		return;
 	}
 
@@ -54,9 +66,9 @@ static void vdso_test_gettimeofday(void)
 	if (ret == 0) {
 		ksft_print_msg("The time is %lld.%06lld\n",
 			       (long long)tv.tv_sec, (long long)tv.tv_usec);
-		ksft_test_result_pass(VDSO_TEST_PASS_MSG());
+		ksft_test_result_pass("%s\n", name[0]);
 	} else {
-		ksft_test_result_fail(VDSO_TEST_FAIL_MSG(name[0]));
+		ksft_test_result_fail("%s\n", name[0]);
 	}
 }
 
@@ -67,7 +79,9 @@ static void vdso_test_clock_gettime(clockid_t clk_id)
 		(vdso_clock_gettime_t)vdso_sym(version, name[1]);
 
 	if (!vdso_clock_gettime) {
-		ksft_test_result_skip(VDSO_TEST_SKIP_MSG(name[1]));
+		ksft_print_msg("Couldn't find %s\n", name[1]);
+		ksft_test_result_skip("%s %s\n", name[1],
+				      vdso_clock_name[clk_id]);
 		return;
 	}
 
@@ -77,9 +91,11 @@ static void vdso_test_clock_gettime(clockid_t clk_id)
 	if (ret == 0) {
 		ksft_print_msg("The time is %lld.%06lld\n",
 			       (long long)ts.tv_sec, (long long)ts.tv_nsec);
-		ksft_test_result_pass(VDSO_TEST_PASS_MSG());
+		ksft_test_result_pass("%s %s\n", name[1],
+				      vdso_clock_name[clk_id]);
 	} else {
-		ksft_test_result_fail(VDSO_TEST_FAIL_MSG(name[1]));
+		ksft_test_result_fail("%s %s\n", name[1],
+				      vdso_clock_name[clk_id]);
 	}
 }
 
@@ -90,7 +106,8 @@ static void vdso_test_time(void)
 		(vdso_time_t)vdso_sym(version, name[2]);
 
 	if (!vdso_time) {
-		ksft_test_result_skip(VDSO_TEST_SKIP_MSG(name[2]));
+		ksft_print_msg("Couldn't find %s\n", name[2]);
+		ksft_test_result_skip("%s\n", name[2]);
 		return;
 	}
 
@@ -99,9 +116,9 @@ static void vdso_test_time(void)
 	if (ret > 0) {
 		ksft_print_msg("The time in hours since January 1, 1970 is %lld\n",
 				(long long)(ret / 3600));
-		ksft_test_result_pass(VDSO_TEST_PASS_MSG());
+		ksft_test_result_pass("%s\n", name[2]);
 	} else {
-		ksft_test_result_fail(VDSO_TEST_FAIL_MSG(name[2]));
+		ksft_test_result_fail("%s\n", name[2]);
 	}
 }
 
@@ -114,7 +131,9 @@ static void vdso_test_clock_getres(clockid_t clk_id)
 		(vdso_clock_getres_t)vdso_sym(version, name[3]);
 
 	if (!vdso_clock_getres) {
-		ksft_test_result_skip(VDSO_TEST_SKIP_MSG(name[3]));
+		ksft_print_msg("Couldn't find %s\n", name[3]);
+		ksft_test_result_skip("%s %s\n", name[3],
+				      vdso_clock_name[clk_id]);
 		return;
 	}
 
@@ -137,27 +156,14 @@ static void vdso_test_clock_getres(clockid_t clk_id)
 		clock_getres_fail++;
 
 	if (clock_getres_fail > 0) {
-		ksft_test_result_fail(VDSO_TEST_FAIL_MSG(name[3]));
+		ksft_test_result_fail("%s %s\n", name[3],
+				      vdso_clock_name[clk_id]);
 	} else {
-		ksft_test_result_pass(VDSO_TEST_PASS_MSG());
+		ksft_test_result_pass("%s %s\n", name[3],
+				      vdso_clock_name[clk_id]);
 	}
 }
 
-const char *vdso_clock_name[12] = {
-	"CLOCK_REALTIME",
-	"CLOCK_MONOTONIC",
-	"CLOCK_PROCESS_CPUTIME_ID",
-	"CLOCK_THREAD_CPUTIME_ID",
-	"CLOCK_MONOTONIC_RAW",
-	"CLOCK_REALTIME_COARSE",
-	"CLOCK_MONOTONIC_COARSE",
-	"CLOCK_BOOTTIME",
-	"CLOCK_REALTIME_ALARM",
-	"CLOCK_BOOTTIME_ALARM",
-	"CLOCK_SGI_CYCLE",
-	"CLOCK_TAI",
-};
-
 /*
  * This function calls vdso_test_clock_gettime and vdso_test_clock_getres
  * with different values for clock_id.

-- 
2.39.2

[PATCH 2/3] kselftest/vDSO: Fix message formatting for clock_id logging

[Mark Brown]

When logging the ID of the currently tested clock vdso_test_clock() puts a
spurious newline at the start of the format string resulting in output
such as

  #
  clock_id: CLOCK_BOOTTIME

which is a valid but empty KTAP informational message followed by a non
conferment output line. Remove the initial newline to create a more KTAP
friendly

  # clock_id: CLOCK_BOOTTIME

Signed-off-by: Mark Brown <broonie@kernel.org>
---
 tools/testing/selftests/vDSO/vdso_test_abi.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/testing/selftests/vDSO/vdso_test_abi.c b/tools/testing/selftests/vDSO/vdso_test_abi.c
index b304abae6e8f..d0e247cca58a 100644
--- a/tools/testing/selftests/vDSO/vdso_test_abi.c
+++ b/tools/testing/selftests/vDSO/vdso_test_abi.c
@@ -170,7 +170,7 @@ static void vdso_test_clock_getres(clockid_t clk_id)
  */
 static inline void vdso_test_clock(clockid_t clock_id)
 {
-	ksft_print_msg("\nclock_id: %s\n", vdso_clock_name[clock_id]);
+	ksft_print_msg("clock_id: %s\n", vdso_clock_name[clock_id]);
 
 	vdso_test_clock_gettime(clock_id);
 

-- 
2.39.2

[PATCH 3/3] kselftest/vDSO: Use ksft_print_msg() rather than printf in vdso_test_abi

[Mark Brown]

There are a couple of raw printf() calls in vdso_test_abi which result in
non KTAP conforment output such as

   [vDSO kselftest] VDSO_VERSION: LINUX_2.6

Convert them to use ksft_print_msg() so that they don't cause confusion for
parsers.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
 tools/testing/selftests/vDSO/vdso_test_abi.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tools/testing/selftests/vDSO/vdso_test_abi.c b/tools/testing/selftests/vDSO/vdso_test_abi.c
index d0e247cca58a..96d32fd65b42 100644
--- a/tools/testing/selftests/vDSO/vdso_test_abi.c
+++ b/tools/testing/selftests/vDSO/vdso_test_abi.c
@@ -187,14 +187,14 @@ int main(int argc, char **argv)
 	ksft_set_plan(VDSO_TEST_PLAN);
 
 	if (!sysinfo_ehdr) {
-		printf("AT_SYSINFO_EHDR is not present!\n");
+		ksft_print_msg("AT_SYSINFO_EHDR is not present!\n");
 		return KSFT_SKIP;
 	}
 
 	version = versions[VDSO_VERSION];
 	name = (const char **)&names[VDSO_NAMES];
 
-	printf("[vDSO kselftest] VDSO_VERSION: %s\n", version);
+	ksft_print_msg("[vDSO kselftest] VDSO_VERSION: %s\n", version);
 
 	vdso_init_from_sysinfo_ehdr(getauxval(AT_SYSINFO_EHDR));
 

-- 
2.39.2

Re: [PATCH 0/3] kselftest/vDSO: Output formatting cleanups for vdso_test_abi

[Shuah Khan]

On 11/23/23 03:45, Mark Brown wrote:
> These patches update the output of the vdso_test_abi test program to
> bring it into line with expected KTAP usage, the main one being the
> first patch which ensures we log distinct test names for each reported
> result making it much easier for automated systems to track the status
> of the tests.
> 
> Signed-off-by: Mark Brown <broonie@kernel.org>
> ---
> Mark Brown (3):
>        kselftest/vDSO: Make test name reporting for vdso_abi_test tooling friendly
>        kselftest/vDSO: Fix message formatting for clock_id logging
>        kselftest/vDSO: Use ksft_print_msg() rather than printf in vdso_test_abi
> 
>   tools/testing/selftests/vDSO/vdso_test_abi.c | 72 +++++++++++++++-------------
>   1 file changed, 39 insertions(+), 33 deletions(-)
> ---
> base-commit: 98b1cc82c4affc16f5598d4fa14b1858671b2263
> change-id: 20231122-kselftest-vdso-test-name-44fcc7e16a38
> 
> Best regards,

Thank you. Applied to linux-kselftest next for Linux 6.8-rc1

thanks,
-- Shuah