Selftest output reporting was happening before the TAP headers and plan had been emitted. Move the first test reports later.

Acked-by: Christian Brauner christian.brauner@ubuntu.com Signed-off-by: Kees Cook keescook@chromium.org --- tools/testing/selftests/clone3/clone3.c | 2 +- tools/testing/selftests/clone3/clone3_clear_sighand.c | 3 +-- tools/testing/selftests/clone3/clone3_set_tid.c | 2 +- 3 files changed, 3 insertions(+), 4 deletions(-)

diff --git a/tools/testing/selftests/clone3/clone3.c b/tools/testing/selftests/clone3/clone3.c index f14c269a5a18..b7e6dec36173 100644 --- a/tools/testing/selftests/clone3/clone3.c +++ b/tools/testing/selftests/clone3/clone3.c @@ -131,9 +131,9 @@ int main(int argc, char *argv[])

uid_t uid = getuid();

- test_clone3_supported(); ksft_print_header(); ksft_set_plan(17); + test_clone3_supported();

/* Just a simple clone3() should return 0.*/ test_clone3(0, 0, 0, CLONE3_ARGS_NO_TEST); diff --git a/tools/testing/selftests/clone3/clone3_clear_sighand.c b/tools/testing/selftests/clone3/clone3_clear_sighand.c index 9e1af8aa7698..db5fc9c5edcf 100644 --- a/tools/testing/selftests/clone3/clone3_clear_sighand.c +++ b/tools/testing/selftests/clone3/clone3_clear_sighand.c @@ -119,9 +119,8 @@ static void test_clone3_clear_sighand(void) int main(int argc, char **argv) { ksft_print_header(); - test_clone3_supported(); - ksft_set_plan(1); + test_clone3_supported();

test_clone3_clear_sighand();

diff --git a/tools/testing/selftests/clone3/clone3_set_tid.c b/tools/testing/selftests/clone3/clone3_set_tid.c index 25beb22f35b5..5831c1082d6d 100644 --- a/tools/testing/selftests/clone3/clone3_set_tid.c +++ b/tools/testing/selftests/clone3/clone3_set_tid.c @@ -157,8 +157,8 @@ int main(int argc, char *argv[]) pid_t set_tid[MAX_PID_NS_LEVEL * 2];

ksft_print_header(); - test_clone3_supported(); ksft_set_plan(29); + test_clone3_supported();

if (pipe(pipe_1) < 0 || pipe(pipe_2) < 0) ksft_exit_fail_msg("pipe() failed\n");

The binderfs test mixed the full harness API and the selftest API. Adjust to use only the harness API so that the harness API can switch to using the selftest API internally in future patches.

Acked-by: Christian Brauner christian.brauner@ubuntu.com Signed-off-by: Kees Cook keescook@chromium.org --- .../filesystems/binderfs/binderfs_test.c | 284 +++++++++--------- 1 file changed, 146 insertions(+), 138 deletions(-)

diff --git a/tools/testing/selftests/filesystems/binderfs/binderfs_test.c b/tools/testing/selftests/filesystems/binderfs/binderfs_test.c index 8a6b507e34a8..1d27f52c61e6 100644 --- a/tools/testing/selftests/filesystems/binderfs/binderfs_test.c +++ b/tools/testing/selftests/filesystems/binderfs/binderfs_test.c @@ -21,7 +21,6 @@ #include <linux/android/binder.h> #include <linux/android/binderfs.h>

-#include "../../kselftest.h" #include "../../kselftest_harness.h"

#define DEFAULT_THREADS 4 @@ -37,37 +36,26 @@ fd = -EBADF; \ }

-#define log_exit(format, ...) \ - ({ \ - fprintf(stderr, format "\n", ##__VA_ARGS__); \ - exit(EXIT_FAILURE); \ - }) - -static void change_mountns(void) +static void change_mountns(struct __test_metadata *_metadata) { int ret;

ret = unshare(CLONE_NEWNS); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to unshare mount namespace\n", - strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to unshare mount namespace", + strerror(errno)); + }

ret = mount(NULL, "/", NULL, MS_REC | MS_PRIVATE, 0); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to mount / as private\n", - strerror(errno)); -} - -static void rmdir_protect_errno(const char *dir) -{ - int saved_errno = errno; - (void)rmdir(dir); - errno = saved_errno; + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to mount / as private", + strerror(errno)); + } }

-static int __do_binderfs_test(void) +static int __do_binderfs_test(struct __test_metadata *_metadata) { - int fd, ret, saved_errno; + int fd, ret, saved_errno, result = 1; size_t len; ssize_t wret; struct binderfs_device device = { 0 }; @@ -75,113 +63,107 @@ static int __do_binderfs_test(void) char binderfs_mntpt[] = P_tmpdir "/binderfs_XXXXXX", device_path[sizeof(P_tmpdir "/binderfs_XXXXXX/") + BINDERFS_MAX_NAME];

- change_mountns(); + change_mountns(_metadata);

- if (!mkdtemp(binderfs_mntpt)) - ksft_exit_fail_msg( - "%s - Failed to create binderfs mountpoint\n", + EXPECT_NE(mkdtemp(binderfs_mntpt), NULL) { + TH_LOG("%s - Failed to create binderfs mountpoint", strerror(errno)); + goto out; + }

ret = mount(NULL, binderfs_mntpt, "binder", 0, 0); - if (ret < 0) { - if (errno != ENODEV) - ksft_exit_fail_msg("%s - Failed to mount binderfs\n", - strerror(errno)); - - rmdir_protect_errno(binderfs_mntpt); - return 1; + EXPECT_EQ(ret, 0) { + if (errno == ENODEV) + XFAIL(goto out, "binderfs missing"); + TH_LOG("%s - Failed to mount binderfs", strerror(errno)); + goto rmdir; }

- /* binderfs mount test passed */ - ksft_inc_pass_cnt(); + /* success: binderfs mounted */

memcpy(device.name, "my-binder", strlen("my-binder"));

snprintf(device_path, sizeof(device_path), "%s/binder-control", binderfs_mntpt); fd = open(device_path, O_RDONLY | O_CLOEXEC); - if (fd < 0) - ksft_exit_fail_msg( - "%s - Failed to open binder-control device\n", + EXPECT_GE(fd, 0) { + TH_LOG("%s - Failed to open binder-control device", strerror(errno)); + goto umount; + }

ret = ioctl(fd, BINDER_CTL_ADD, &device); saved_errno = errno; close(fd); errno = saved_errno; - if (ret < 0) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg( - "%s - Failed to allocate new binder device\n", + EXPECT_GE(ret, 0) { + TH_LOG("%s - Failed to allocate new binder device", strerror(errno)); + goto umount; }

- ksft_print_msg( - "Allocated new binder device with major %d, minor %d, and name %s\n", + TH_LOG("Allocated new binder device with major %d, minor %d, and name %s", device.major, device.minor, device.name);

- /* binder device allocation test passed */ - ksft_inc_pass_cnt(); + /* success: binder device allocation */

snprintf(device_path, sizeof(device_path), "%s/my-binder", binderfs_mntpt); fd = open(device_path, O_CLOEXEC | O_RDONLY); - if (fd < 0) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg("%s - Failed to open my-binder device\n", - strerror(errno)); + EXPECT_GE(fd, 0) { + TH_LOG("%s - Failed to open my-binder device", + strerror(errno)); + goto umount; }

ret = ioctl(fd, BINDER_VERSION, &version); saved_errno = errno; close(fd); errno = saved_errno; - if (ret < 0) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg( - "%s - Failed to open perform BINDER_VERSION request\n", + EXPECT_GE(ret, 0) { + TH_LOG("%s - Failed to open perform BINDER_VERSION request", strerror(errno)); + goto umount; }

- ksft_print_msg("Detected binder version: %d\n", - version.protocol_version); + TH_LOG("Detected binder version: %d", version.protocol_version);

- /* binder transaction with binderfs binder device passed */ - ksft_inc_pass_cnt(); + /* success: binder transaction with binderfs binder device */

ret = unlink(device_path); - if (ret < 0) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg("%s - Failed to delete binder device\n", - strerror(errno)); + EXPECT_EQ(ret, 0) { + TH_LOG("%s - Failed to delete binder device", + strerror(errno)); + goto umount; }

- /* binder device removal passed */ - ksft_inc_pass_cnt(); + /* success: binder device removal */

snprintf(device_path, sizeof(device_path), "%s/binder-control", binderfs_mntpt); ret = unlink(device_path); - if (!ret) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg("Managed to delete binder-control device\n"); - } else if (errno != EPERM) { - rmdir_protect_errno(binderfs_mntpt); - ksft_exit_fail_msg( - "%s - Failed to delete binder-control device but exited with unexpected error code\n", + EXPECT_NE(ret, 0) { + TH_LOG("Managed to delete binder-control device"); + goto umount; + } + EXPECT_EQ(errno, EPERM) { + TH_LOG("%s - Failed to delete binder-control device but exited with unexpected error code", strerror(errno)); + goto umount; }

- /* binder-control device removal failed as expected */ - ksft_inc_xfail_cnt(); + /* success: binder-control device removal failed as expected */ + result = 0;

-on_error: +umount: ret = umount2(binderfs_mntpt, MNT_DETACH); - rmdir_protect_errno(binderfs_mntpt); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to unmount binderfs\n", - strerror(errno)); - - /* binderfs unmount test passed */ - ksft_inc_pass_cnt(); - return 0; + EXPECT_EQ(ret, 0) { + TH_LOG("%s - Failed to unmount binderfs", strerror(errno)); + } +rmdir: + ret = rmdir(binderfs_mntpt); + EXPECT_EQ(ret, 0) { + TH_LOG("%s - Failed to rmdir binderfs mount", strerror(errno)); + } +out: + return result; }

static int wait_for_pid(pid_t pid) @@ -291,7 +273,7 @@ static int write_id_mapping(enum idmap_type type, pid_t pid, const char *buf, return 0; }

-static void change_userns(int syncfds[2]) +static void change_userns(struct __test_metadata *_metadata, int syncfds[2]) { int ret; char buf; @@ -299,25 +281,29 @@ static void change_userns(int syncfds[2]) close_prot_errno_disarm(syncfds[1]);

ret = unshare(CLONE_NEWUSER); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to unshare user namespace\n", - strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to unshare user namespace", + strerror(errno)); + }

ret = write_nointr(syncfds[0], "1", 1); - if (ret != 1) - ksft_exit_fail_msg("write_nointr() failed\n"); + ASSERT_EQ(ret, 1) { + TH_LOG("write_nointr() failed"); + }

ret = read_nointr(syncfds[0], &buf, 1); - if (ret != 1) - ksft_exit_fail_msg("read_nointr() failed\n"); + ASSERT_EQ(ret, 1) { + TH_LOG("read_nointr() failed"); + }

close_prot_errno_disarm(syncfds[0]);

- if (setid_userns_root()) - ksft_exit_fail_msg("setid_userns_root() failed"); + ASSERT_EQ(setid_userns_root(), 0) { + TH_LOG("setid_userns_root() failed"); + } }

-static void change_idmaps(int syncfds[2], pid_t pid) +static void change_idmaps(struct __test_metadata *_metadata, int syncfds[2], pid_t pid) { int ret; char buf; @@ -326,35 +312,42 @@ static void change_idmaps(int syncfds[2], pid_t pid) close_prot_errno_disarm(syncfds[0]);

ret = read_nointr(syncfds[1], &buf, 1); - if (ret != 1) - ksft_exit_fail_msg("read_nointr() failed\n"); + ASSERT_EQ(ret, 1) { + TH_LOG("read_nointr() failed"); + }

snprintf(id_map, sizeof(id_map), "0 %d 1\n", getuid()); ret = write_id_mapping(UID_MAP, pid, id_map, strlen(id_map)); - if (ret) - ksft_exit_fail_msg("write_id_mapping(UID_MAP) failed"); + ASSERT_EQ(ret, 0) { + TH_LOG("write_id_mapping(UID_MAP) failed"); + }

snprintf(id_map, sizeof(id_map), "0 %d 1\n", getgid()); ret = write_id_mapping(GID_MAP, pid, id_map, strlen(id_map)); - if (ret) - ksft_exit_fail_msg("write_id_mapping(GID_MAP) failed"); + ASSERT_EQ(ret, 0) { + TH_LOG("write_id_mapping(GID_MAP) failed"); + }

ret = write_nointr(syncfds[1], "1", 1); - if (ret != 1) - ksft_exit_fail_msg("write_nointr() failed"); + ASSERT_EQ(ret, 1) { + TH_LOG("write_nointr() failed"); + }

close_prot_errno_disarm(syncfds[1]); }

+struct __test_metadata *_thread_metadata; static void *binder_version_thread(void *data) { + struct __test_metadata *_metadata = _thread_metadata; int fd = PTR_TO_INT(data); struct binder_version version = { 0 }; int ret;

ret = ioctl(fd, BINDER_VERSION, &version); if (ret < 0) - ksft_print_msg("%s - Failed to open perform BINDER_VERSION request\n", strerror(errno)); + TH_LOG("%s - Failed to open perform BINDER_VERSION request\n", + strerror(errno));

pthread_exit(data); } @@ -377,68 +370,79 @@ TEST(binderfs_stress) device_path[sizeof(P_tmpdir "/binderfs_XXXXXX/") + BINDERFS_MAX_NAME];

ret = socketpair(PF_LOCAL, SOCK_STREAM | SOCK_CLOEXEC, 0, syncfds); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to create socket pair", strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to create socket pair", strerror(errno)); + }

pid = fork(); - if (pid < 0) { + ASSERT_GE(pid, 0) { + TH_LOG("%s - Failed to fork", strerror(errno)); close_prot_errno_disarm(syncfds[0]); close_prot_errno_disarm(syncfds[1]); - ksft_exit_fail_msg("%s - Failed to fork", strerror(errno)); }

if (pid == 0) { int i, j, k, nthreads; pthread_attr_t attr; pthread_t threads[DEFAULT_THREADS]; - change_userns(syncfds); - change_mountns(); + change_userns(_metadata, syncfds); + change_mountns(_metadata);

- if (!mkdtemp(binderfs_mntpt)) - log_exit("%s - Failed to create binderfs mountpoint\n", - strerror(errno)); + ASSERT_NE(mkdtemp(binderfs_mntpt), NULL) { + TH_LOG("%s - Failed to create binderfs mountpoint", + strerror(errno)); + }

ret = mount(NULL, binderfs_mntpt, "binder", 0, 0); - if (ret < 0) - log_exit("%s - Failed to mount binderfs\n", strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to mount binderfs", strerror(errno)); + }

for (int i = 0; i < ARRAY_SIZE(fds); i++) {

snprintf(device_path, sizeof(device_path), "%s/binder-control", binderfs_mntpt); fd = open(device_path, O_RDONLY | O_CLOEXEC); - if (fd < 0) - log_exit("%s - Failed to open binder-control device\n", strerror(errno)); + ASSERT_GE(fd, 0) { + TH_LOG("%s - Failed to open binder-control device", + strerror(errno)); + }

memset(&device, 0, sizeof(device)); snprintf(device.name, sizeof(device.name), "%d", i); ret = ioctl(fd, BINDER_CTL_ADD, &device); close_prot_errno_disarm(fd); - if (ret < 0) - log_exit("%s - Failed to allocate new binder device\n", strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to allocate new binder device", + strerror(errno)); + }

snprintf(device_path, sizeof(device_path), "%s/%d", binderfs_mntpt, i); fds[i] = open(device_path, O_RDONLY | O_CLOEXEC); - if (fds[i] < 0) - log_exit("%s - Failed to open binder device\n", strerror(errno)); + ASSERT_GE(fds[i], 0) { + TH_LOG("%s - Failed to open binder device", strerror(errno)); + } }

ret = umount2(binderfs_mntpt, MNT_DETACH); - rmdir_protect_errno(binderfs_mntpt); - if (ret < 0) - log_exit("%s - Failed to unmount binderfs\n", strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to unmount binderfs", strerror(errno)); + rmdir(binderfs_mntpt); + }

nthreads = get_nprocs_conf(); if (nthreads > DEFAULT_THREADS) nthreads = DEFAULT_THREADS;

+ _thread_metadata = _metadata; pthread_attr_init(&attr); for (k = 0; k < ARRAY_SIZE(fds); k++) { for (i = 0; i < nthreads; i++) { ret = pthread_create(&threads[i], &attr, binder_version_thread, INT_TO_PTR(fds[k])); if (ret) { - ksft_print_msg("%s - Failed to create thread %d\n", strerror(errno), i); + TH_LOG("%s - Failed to create thread %d", + strerror(errno), i); break; } } @@ -448,7 +452,8 @@ TEST(binderfs_stress)

ret = pthread_join(threads[j], &fdptr); if (ret) - ksft_print_msg("%s - Failed to join thread %d for fd %d\n", strerror(errno), j, PTR_TO_INT(fdptr)); + TH_LOG("%s - Failed to join thread %d for fd %d", + strerror(errno), j, PTR_TO_INT(fdptr)); } } pthread_attr_destroy(&attr); @@ -459,11 +464,12 @@ TEST(binderfs_stress) exit(EXIT_SUCCESS); }

- change_idmaps(syncfds, pid); + change_idmaps(_metadata, syncfds, pid);

ret = wait_for_pid(pid); - if (ret) - ksft_exit_fail_msg("wait_for_pid() failed"); + ASSERT_EQ(ret, 0) { + TH_LOG("wait_for_pid() failed"); + } }

TEST(binderfs_test_privileged) @@ -471,7 +477,7 @@ TEST(binderfs_test_privileged) if (geteuid() != 0) XFAIL(return, "Tests are not run as root. Skipping privileged tests");

- if (__do_binderfs_test() == 1) + if (__do_binderfs_test(_metadata)) XFAIL(return, "The Android binderfs filesystem is not available"); }

@@ -482,31 +488,33 @@ TEST(binderfs_test_unprivileged) pid_t pid;

ret = socketpair(PF_LOCAL, SOCK_STREAM | SOCK_CLOEXEC, 0, syncfds); - if (ret < 0) - ksft_exit_fail_msg("%s - Failed to create socket pair", strerror(errno)); + ASSERT_EQ(ret, 0) { + TH_LOG("%s - Failed to create socket pair", strerror(errno)); + }

pid = fork(); - if (pid < 0) { + ASSERT_GE(pid, 0) { close_prot_errno_disarm(syncfds[0]); close_prot_errno_disarm(syncfds[1]); - ksft_exit_fail_msg("%s - Failed to fork", strerror(errno)); + TH_LOG("%s - Failed to fork", strerror(errno)); }

if (pid == 0) { - change_userns(syncfds); - if (__do_binderfs_test() == 1) + change_userns(_metadata, syncfds); + if (__do_binderfs_test(_metadata)) exit(2); exit(EXIT_SUCCESS); }

- change_idmaps(syncfds, pid); + change_idmaps(_metadata, syncfds, pid);

ret = wait_for_pid(pid); if (ret) { if (ret == 2) XFAIL(return, "The Android binderfs filesystem is not available"); - else - ksft_exit_fail_msg("wait_for_pid() failed"); + ASSERT_EQ(ret, 0) { + TH_LOG("wait_for_pid() failed"); + } } }

Using the kselftest_harness.h would result in non-TAP test reporting, which didn't make much sense given that all the requirements for using the low-level API were met. Switch to using ksft_*() helpers while retaining as much of a human-readability as possible.

Signed-off-by: Kees Cook keescook@chromium.org --- tools/testing/selftests/kselftest.h | 5 +- tools/testing/selftests/kselftest_harness.h | 52 ++++++++++++--------- 2 files changed, 33 insertions(+), 24 deletions(-)

diff --git a/tools/testing/selftests/kselftest.h b/tools/testing/selftests/kselftest.h index 2cd5eefed4d2..9b4efdbb07f6 100644 --- a/tools/testing/selftests/kselftest.h +++ b/tools/testing/selftests/kselftest.h @@ -1,7 +1,8 @@ /* SPDX-License-Identifier: GPL-2.0 */ /* - * kselftest.h: kselftest framework return codes to include from - * selftests. + * kselftest.h: low-level kselftest framework to include from + * selftest programs. When possible, please use + * kselftest_harness.h instead. * * Copyright (c) 2014 Shuah Khan shuahkh@osg.samsung.com * Copyright (c) 2014 Samsung Electronics Co., Ltd. diff --git a/tools/testing/selftests/kselftest_harness.h b/tools/testing/selftests/kselftest_harness.h index c9f03ef93338..f8f7e47c739a 100644 --- a/tools/testing/selftests/kselftest_harness.h +++ b/tools/testing/selftests/kselftest_harness.h @@ -50,7 +50,9 @@ #ifndef __KSELFTEST_HARNESS_H #define __KSELFTEST_HARNESS_H

+#ifndef _GNU_SOURCE #define _GNU_SOURCE +#endif #include <asm/types.h> #include <errno.h> #include <stdbool.h> @@ -62,6 +64,8 @@ #include <sys/wait.h> #include <unistd.h>

+#include "kselftest.h" + #define TEST_TIMEOUT_DEFAULT 30

/* Utilities exposed to the test definitions */ @@ -104,7 +108,7 @@

/* Unconditional logger for internal use. */ #define __TH_LOG(fmt, ...) \ - fprintf(TH_LOG_STREAM, "%s:%d:%s:" fmt "\n", \ + fprintf(TH_LOG_STREAM, "# %s:%d:%s:" fmt "\n", \ __FILE__, __LINE__, _metadata->name, ##__VA_ARGS__)

/** @@ -119,7 +123,7 @@ */ #define XFAIL(statement, fmt, ...) do { \ if (TH_LOG_ENABLED) { \ - fprintf(TH_LOG_STREAM, "[ XFAIL! ] " fmt "\n", \ + fprintf(TH_LOG_STREAM, "# XFAIL " fmt "\n", \ ##__VA_ARGS__); \ } \ /* TODO: find a way to pass xfail to test runner process. */ \ @@ -813,12 +817,12 @@ static void __timeout_handler(int sig, siginfo_t *info, void *ucontext) /* Sanity check handler execution environment. */ if (!t) { fprintf(TH_LOG_STREAM, - "no active test in SIGALRM handler!?\n"); + "# no active test in SIGALRM handler!?\n"); abort(); } if (sig != SIGALRM || sig != info->si_signo) { fprintf(TH_LOG_STREAM, - "%s: SIGALRM handler caught signal %d!?\n", + "# %s: SIGALRM handler caught signal %d!?\n", t->name, sig != SIGALRM ? sig : info->si_signo); abort(); } @@ -839,7 +843,7 @@ void __wait_for_test(struct __test_metadata *t) if (sigaction(SIGALRM, &action, &saved_action)) { t->passed = 0; fprintf(TH_LOG_STREAM, - "%s: unable to install SIGALRM handler\n", + "# %s: unable to install SIGALRM handler\n", t->name); return; } @@ -851,7 +855,7 @@ void __wait_for_test(struct __test_metadata *t) if (sigaction(SIGALRM, &saved_action, NULL)) { t->passed = 0; fprintf(TH_LOG_STREAM, - "%s: unable to uninstall SIGALRM handler\n", + "# %s: unable to uninstall SIGALRM handler\n", t->name); return; } @@ -860,18 +864,17 @@ void __wait_for_test(struct __test_metadata *t) if (t->timed_out) { t->passed = 0; fprintf(TH_LOG_STREAM, - "%s: Test terminated by timeout\n", t->name); + "# %s: Test terminated by timeout\n", t->name); } else if (WIFEXITED(status)) { t->passed = t->termsig == -1 ? !WEXITSTATUS(status) : 0; if (t->termsig != -1) { fprintf(TH_LOG_STREAM, - "%s: Test exited normally " - "instead of by signal (code: %d)\n", + "# %s: Test exited normally instead of by signal (code: %d)\n", t->name, WEXITSTATUS(status)); } else if (!t->passed) { fprintf(TH_LOG_STREAM, - "%s: Test failed at step #%d\n", + "# %s: Test failed at step #%d\n", t->name, WEXITSTATUS(status)); } @@ -879,20 +882,19 @@ void __wait_for_test(struct __test_metadata *t) t->passed = 0; if (WTERMSIG(status) == SIGABRT) { fprintf(TH_LOG_STREAM, - "%s: Test terminated by assertion\n", + "# %s: Test terminated by assertion\n", t->name); } else if (WTERMSIG(status) == t->termsig) { t->passed = 1; } else { fprintf(TH_LOG_STREAM, - "%s: Test terminated unexpectedly " - "by signal %d\n", + "# %s: Test terminated unexpectedly by signal %d\n", t->name, WTERMSIG(status)); } } else { fprintf(TH_LOG_STREAM, - "%s: Test ended in some other way [%u]\n", + "# %s: Test ended in some other way [%u]\n", t->name, status); } @@ -908,11 +910,11 @@ void __run_test(struct __fixture_metadata *f, t->step = 0; t->no_print = 0;

- printf("[ RUN ] %s%s%s.%s\n", + ksft_print_msg(" RUN %s%s%s.%s ...\n", f->name, variant->name[0] ? "." : "", variant->name, t->name); t->pid = fork(); if (t->pid < 0) { - printf("ERROR SPAWNING TEST CHILD\n"); + ksft_print_msg("ERROR SPAWNING TEST CHILD\n"); t->passed = 0; } else if (t->pid == 0) { t->fn(t, variant); @@ -921,7 +923,9 @@ void __run_test(struct __fixture_metadata *f, } else { __wait_for_test(t); } - printf("[ %4s ] %s%s%s.%s\n", (t->passed ? "OK" : "FAIL"), + ksft_print_msg(" %4s %s%s%s.%s\n", t->passed ? "OK" : "FAIL", + f->name, variant->name[0] ? "." : "", variant->name, t->name); + ksft_test_result(t->passed, "%s%s%s.%s\n", f->name, variant->name[0] ? "." : "", variant->name, t->name); }

@@ -945,8 +949,9 @@ static int test_harness_run(int __attribute__((unused)) argc, } }

- /* TODO(wad) add optional arguments similar to gtest. */ - printf("[==========] Running %u tests from %u test cases.\n", + ksft_print_header(); + ksft_set_plan(test_count); + ksft_print_msg("Starting %u tests from %u test cases.\n", test_count, case_count); for (f = __fixture_list; f; f = f->next) { for (v = f->variant ?: &no_variant; v; v = v->next) { @@ -960,9 +965,12 @@ static int test_harness_run(int __attribute__((unused)) argc, } } } - printf("[==========] %u / %u tests passed.\n", pass_count, count); - printf("[ %s ]\n", (ret ? "FAILED" : "PASSED")); - return ret; + ksft_print_msg("%s: %u / %u tests passed.\n", ret ? "FAILED" : "PASSED", + pass_count, count); + ksft_exit(ret == 0); + + /* unreachable */ + return KSFT_FAIL; }

static void __attribute__((constructor)) __constructor_order_first(void)

Since forever the harness output for signed value tests have reported unsigned values to avoid casting. Instead, actually test the variable types and perform the correct casts and choose the correct format specifiers.

Signed-off-by: Kees Cook keescook@chromium.org --- tools/testing/selftests/kselftest_harness.h | 42 ++++++++++++++++++--- 1 file changed, 37 insertions(+), 5 deletions(-)

diff --git a/tools/testing/selftests/kselftest_harness.h b/tools/testing/selftests/kselftest_harness.h index b519765904a6..ae51b762d120 100644 --- a/tools/testing/selftests/kselftest_harness.h +++ b/tools/testing/selftests/kselftest_harness.h @@ -679,17 +679,49 @@ if (_metadata->passed && _metadata->step < 255) \ _metadata->step++;

+#define is_signed_type(var) (!!(((__typeof__(var))(-1)) < (__typeof__(var))1)) + #define __EXPECT(_expected, _expected_str, _seen, _seen_str, _t, _assert) do { \ /* Avoid multiple evaluation of the cases */ \ __typeof__(_expected) __exp = (_expected); \ __typeof__(_seen) __seen = (_seen); \ if (_assert) __INC_STEP(_metadata); \ if (!(__exp _t __seen)) { \ - unsigned long long __exp_print = (uintptr_t)__exp; \ - unsigned long long __seen_print = (uintptr_t)__seen; \ - __TH_LOG("Expected %s (%llu) %s %s (%llu)", \ - _expected_str, __exp_print, #_t, \ - _seen_str, __seen_print); \ + /* Report with actual signedness to avoid weird output. */ \ + switch (is_signed_type(__exp) * 2 + is_signed_type(__seen)) { \ + case 0: { \ + unsigned long long __exp_print = (uintptr_t)__exp; \ + unsigned long long __seen_print = (uintptr_t)__seen; \ + __TH_LOG("Expected %s (%llu) %s %s (%llu)", \ + _expected_str, __exp_print, #_t, \ + _seen_str, __seen_print); \ + break; \ + } \ + case 1: { \ + unsigned long long __exp_print = (uintptr_t)__exp; \ + long long __seen_print = (intptr_t)__seen; \ + __TH_LOG("Expected %s (%llu) %s %s (%lld)", \ + _expected_str, __exp_print, #_t, \ + _seen_str, __seen_print); \ + break; \ + } \ + case 2: { \ + long long __exp_print = (intptr_t)__exp; \ + unsigned long long __seen_print = (uintptr_t)__seen; \ + __TH_LOG("Expected %s (%lld) %s %s (%llu)", \ + _expected_str, __exp_print, #_t, \ + _seen_str, __seen_print); \ + break; \ + } \ + case 3: { \ + long long __exp_print = (intptr_t)__exp; \ + long long __seen_print = (intptr_t)__seen; \ + __TH_LOG("Expected %s (%lld) %s %s (%lld)", \ + _expected_str, __exp_print, #_t, \ + _seen_str, __seen_print); \ + break; \ + } \ + } \ _metadata->passed = 0; \ /* Ensure the optional handler is triggered */ \ _metadata->trigger = 1; \

On Mon, Jul 13, 2020 at 12:08:08PM -0700, Ralph Campbell wrote:

On 6/22/20 11:16 AM, Kees Cook wrote:

...

Plumb the old XFAIL result into a TAP SKIP.

Signed-off-by: Kees Cook keescook@chromium.org

tools/testing/selftests/kselftest_harness.h | 64 ++++++++++++++----- tools/testing/selftests/seccomp/seccomp_bpf.c | 8 +-- 2 files changed, 52 insertions(+), 20 deletions(-)

diff --git a/tools/testing/selftests/kselftest_harness.h b/tools/testing/selftests/kselftest_harness.h index f8f7e47c739a..b519765904a6 100644 --- a/tools/testing/selftests/kselftest_harness.h +++ b/tools/testing/selftests/kselftest_harness.h @@ -112,22 +112,22 @@ __FILE__, __LINE__, _metadata->name, ##__VA_ARGS__) /**

• • XFAIL(statement, fmt, ...)

• • SKIP(statement, fmt, ...)

• • @statement: statement to run after reporting XFAIL

• • @statement: statement to run after reporting SKIP
  • @fmt: format string
  • @...: optional arguments

• • This forces a "pass" after reporting a failure with an XFAIL prefix,

• • This forces a "pass" after reporting why something is being skipped
  • and runs "statement", which is usually "return" or "goto skip".
  */

-#define XFAIL(statement, fmt, ...) do { \ +#define SKIP(statement, fmt, ...) do { \ if (TH_LOG_ENABLED) { \

• fprintf(TH_LOG_STREAM, "#      XFAIL     " fmt "\n", \
  

• fprintf(TH_LOG_STREAM, "#      SKIP     " fmt "\n", \
  ##__VA_ARGS__); \
  

  } \

• /* TODO: find a way to pass xfail to test runner process. */ \ _metadata->passed = 1; \

• _metadata->skip = 1; \ _metadata->trigger = 0; \ statement; \ } while (0)

@@ -777,6 +777,7 @@ struct __test_metadata { struct __fixture_metadata *fixture; int termsig; int passed;

• int skip; /* did SKIP get used? */ int trigger; /* extra handler after the evaluation */ int timeout; /* seconds to wait for test timeout */ bool timed_out; /* did this test timeout instead of exiting? */

@@ -866,17 +867,31 @@ void __wait_for_test(struct __test_metadata *t) fprintf(TH_LOG_STREAM, "# %s: Test terminated by timeout\n", t->name); } else if (WIFEXITED(status)) {

• t->passed = t->termsig == -1 ? !WEXITSTATUS(status) : 0;
  

  if (t->termsig != -1) {

• 	t->passed = 0;
  fprintf(TH_LOG_STREAM,
  	"# %s: Test exited normally instead of by signal (code: %d)\n",
  	t->name,
  	WEXITSTATUS(status));
  

• } else if (!t->passed) {
  

• 	fprintf(TH_LOG_STREAM,
  

• 		"# %s: Test failed at step #%d\n",
  

• 		t->name,
  

• 		WEXITSTATUS(status));
  

• } else {
  

• 	switch (WEXITSTATUS(status)) {
  

• 	/* Success */
  

• 	case 0:
  

• 		t->passed = 1;
  

• 		break;
  

• 	/* SKIP */
  

• 	case 255:
  

• 		t->passed = 1;
  

• 		t->skip = 1;
  

• 		break;
  

• 	/* Other failure, assume step report. */
  

• 	default:
  

• 		t->passed = 0;
  

• 		fprintf(TH_LOG_STREAM,
  

• 			"# %s: Test failed at step #%d\n",
  

• 			t->name,
  

• 			WEXITSTATUS(status));
  

• 	}
  

  } } else if (WIFSIGNALED(status)) { t->passed = 0;

@@ -906,6 +921,7 @@ void __run_test(struct __fixture_metadata *f, { /* reset test struct */ t->passed = 1;

• t->skip = 0; t->trigger = 0; t->step = 0; t->no_print = 0;

@@ -918,15 +934,31 @@ void __run_test(struct __fixture_metadata *f, t->passed = 0; } else if (t->pid == 0) { t->fn(t, variant);

• /* return the step that failed or 0 */
  

• _exit(t->passed ? 0 : t->step);
  

• /* Make sure step doesn't get lost in reporting */
  

• if (t->step >= 255) {
  

• 	ksft_print_msg("Too many test steps (%u)!?\n", t->step);
  

• 	t->step = 254;
  

• }
  

I noticed that this message is now appearing in the HMM self tests. I haven't quite tracked down why ->steps should be 255 after running the first test. I did notice that ASSERT*() calls __INC_STEP() but that doesn't explain it. Separately, maybe __INC_STEP() should check for < 254 instead of < 255?

Set CONFIG_HMM_TESTS=m, build and install kernel and modules.
cd tools/testing/selftests/vm
make
./test_hmm.sh smoke
Running smoke test. Note, this test provides basic coverage.
[  106.803476] memmap_init_zone_device initialised 65536 pages in 7ms
[  106.810141] added new 256 MB chunk (total 1 chunks, 256 MB) PFNs [0x3ffff0000 0x400000000)
[  106.823703] memmap_init_zone_device initialised 65536 pages in 4ms
[  106.829968] added new 256 MB chunk (total 1 chunks, 256 MB) PFNs [0x3fffe0000 0x3ffff0000)
[  106.838655] HMM test module loaded. This is only for testing HMM.
TAP version 13
1..20
# Starting 20 tests from 3 test cases.
#  RUN           hmm.open_close ...
#            OK  hmm.open_close
ok 1 hmm.open_close
#  RUN           hmm.anon_read ...
# Too many test steps (255)!?
#            OK  hmm.anon_read

Oooh:

#define NTIMES 256

Yes, that's a lot of steps. :)

I agree,__ INC_STEP() needs adjustment, though it should be 253. Does this work for you?

diff --git a/tools/testing/selftests/kselftest_harness.h b/tools/testing/selftests/kselftest_harness.h index 935029d4fb21..4f78e4805633 100644 --- a/tools/testing/selftests/kselftest_harness.h +++ b/tools/testing/selftests/kselftest_harness.h @@ -680,7 +680,8 @@ __bail(_assert, _metadata->no_print, _metadata->step))

#define __INC_STEP(_metadata) \ - if (_metadata->passed && _metadata->step < 255) \ + /* Keep "step" below 255 (which is used for "SKIP" reporting). */ \ + if (_metadata->passed && _metadata->step < 253) \ _metadata->step++;

#define is_signed_type(var) (!!(((__typeof__(var))(-1)) < (__typeof__(var))1)) @@ -976,12 +977,6 @@ void __run_test(struct __fixture_metadata *f, t->passed = 0; } else if (t->pid == 0) { t->fn(t, variant); - /* Make sure step doesn't get lost in reporting */ - if (t->step >= 255) { - ksft_print_msg("Too many test steps (%u)!?\n", t->step); - t->step = 254; - } - /* Use 255 for SKIP */ if (t->skip) _exit(255); /* Pass is exit 0 */