diff mbox series

[bpf-next] selftests/bpf: consolidate common code in run_one_test function

Message ID 20220414050509.750209-1-mykolal@fb.com (mailing list archive)
State Changes Requested
Delegated to: BPF
Headers show
Series [bpf-next] selftests/bpf: consolidate common code in run_one_test function | expand

Checks

Context Check Description
netdev/tree_selection success Clearly marked for bpf-next
netdev/fixes_present success Fixes tag not required for -next series
netdev/subject_prefix success Link
netdev/cover_letter success Single patches do not need cover letters
netdev/patch_count success Link
netdev/header_inline success No static functions without inline keyword in header files
netdev/build_32bit success Errors and warnings before: 0 this patch: 0
netdev/cc_maintainers warning 8 maintainers not CCed: songliubraving@fb.com shuah@kernel.org netdev@vger.kernel.org kafai@fb.com linux-kselftest@vger.kernel.org yhs@fb.com john.fastabend@gmail.com kpsingh@kernel.org
netdev/build_clang success Errors and warnings before: 0 this patch: 0
netdev/module_param success Was 0 now: 0
netdev/verify_signedoff success Signed-off-by tag matches author and committer
netdev/verify_fixes success No Fixes tag
netdev/build_allmodconfig_warn success Errors and warnings before: 0 this patch: 0
netdev/checkpatch warning WARNING: added, moved or deleted file(s), does MAINTAINERS need updating? WARNING: line length of 81 exceeds 80 columns WARNING: line length of 82 exceeds 80 columns WARNING: line length of 84 exceeds 80 columns WARNING: line length of 88 exceeds 80 columns WARNING: line length of 90 exceeds 80 columns WARNING: line length of 92 exceeds 80 columns WARNING: line length of 99 exceeds 80 columns
netdev/kdoc success Errors and warnings before: 0 this patch: 0
netdev/source_inline success Was 0 now: 0
bpf/vmtest-bpf-next-VM_Test-1 success Logs for Kernel LATEST on ubuntu-latest + selftests
bpf/vmtest-bpf-next-PR success PR summary
bpf/vmtest-bpf-next-VM_Test-2 success Logs for Kernel LATEST on z15 + selftests

Commit Message

Mykola Lysenko April 14, 2022, 5:05 a.m. UTC 
This is a pre-req to add separate logging for each subtest.

Move all the mutable test data to the test_result struct.
Move per-test init/de-init into the run_one_test function.
Consolidate data aggregation and final log output in
calculate_and_print_summary function.
As a side effect, this patch fixes double counting of errors
for subtests and possible duplicate output of subtest log
on failures.

Also, add prog_tests_framework.c test to verify some of the
counting logic.

As part of verification, confirmed that number of reported
tests is the same before and after the change for both parallel
and sequential test execution.

Signed-off-by: Mykola Lysenko <mykolal@fb.com>
---
 .../bpf/prog_tests/prog_tests_framework.c     |  55 ++++
 tools/testing/selftests/bpf/test_progs.c      | 301 +++++++-----------
 tools/testing/selftests/bpf/test_progs.h      |  32 +-
 3 files changed, 195 insertions(+), 193 deletions(-)
 create mode 100644 tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c

Comments

Andrii Nakryiko April 14, 2022, 10:49 p.m. UTC | #1 
On Wed, Apr 13, 2022 at 10:05 PM Mykola Lysenko <mykolal@fb.com> wrote:
>
> This is a pre-req to add separate logging for each subtest.
>
> Move all the mutable test data to the test_result struct.
> Move per-test init/de-init into the run_one_test function.
> Consolidate data aggregation and final log output in
> calculate_and_print_summary function.
> As a side effect, this patch fixes double counting of errors
> for subtests and possible duplicate output of subtest log
> on failures.
>
> Also, add prog_tests_framework.c test to verify some of the
> counting logic.
>
> As part of verification, confirmed that number of reported
> tests is the same before and after the change for both parallel
> and sequential test execution.
>
> Signed-off-by: Mykola Lysenko <mykolal@fb.com>
> ---

The consolidation of the per-test logic in one place is great, thanks
for tackling this! But I tried this locally and understood what you
were mentioning as completely buffered output. It really sucks and is
a big step back, I think :(

Running sudo ./test_progs -j I see no output for a long while and only
then get entire output at the end:

#239 xdp_noinline:OK
#240 xdp_perf:OK
#241 xdpwall:OK

All error logs:

#58 fexit_sleep:FAIL
test_fexit_sleep:PASS:fexit_skel_load 0 nsec
test_fexit_sleep:PASS:fexit_attach 0 nsec
test_fexit_sleep:PASS:clone 0 nsec
test_fexit_sleep:PASS:fexit_cnt 0 nsec
test_fexit_sleep:PASS:waitpid 0 nsec
test_fexit_sleep:PASS:exitstatus 0 nsec
test_fexit_sleep:FAIL:fexit_cnt 2
Summary: 240/1156 PASSED, 34 SKIPPED, 1 FAILED


First, just not seeing the progress made me wonder for a good minute
or more whether something is just stuck and deadlock. Which is anxiety
inducing and I'd rather avoid this :)

Second, as you can see, fexit_sleep actually failed (it does sometimes
in parallel mode). But I saw this only at the very end, while normally
I'd notice it as soon as it completes. In this case I know fexit_sleep
can fail and I'd ignore, but if there was some subtest that suddenly
breaks, I don't wait for all the tests to finish, I ctrl-C and go
investigate. Now I can't do that.

How much of a problem is it to preserve old behavior of streaming
results of tests as they come, but consolidate duplicate logic in one
place?

>  .../bpf/prog_tests/prog_tests_framework.c     |  55 ++++
>  tools/testing/selftests/bpf/test_progs.c      | 301 +++++++-----------
>  tools/testing/selftests/bpf/test_progs.h      |  32 +-
>  3 files changed, 195 insertions(+), 193 deletions(-)
>  create mode 100644 tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
> new file mode 100644
> index 000000000000..7a5be06653f7
> --- /dev/null
> +++ b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
> @@ -0,0 +1,55 @@
> +// SPDX-License-Identifier: (LGPL-2.1 OR BSD-2-Clause)
> +
> +#include "test_progs.h"
> +#include "testing_helpers.h"
> +
> +static void clear_test_result(struct test_result *result)
> +{
> +       result->error_cnt = 0;
> +       result->sub_succ_cnt = 0;
> +       result->skip_cnt = 0;
> +}
> +
> +void test_prog_tests_framework(void)
> +{
> +       struct test_result *result = env.test_result;
> +
> +       // in all the ASSERT calls below we need to return on the first
> +       // error due to the fact that we are cleaning the test state after
> +       // each dummy subtest
> +
> +       // test we properly count skipped tests with subtests

C++ comments, please use /* */


> +       if (test__start_subtest("test_good_subtest"))
> +               test__end_subtest();
> +       if (!ASSERT_EQ(result->skip_cnt, 0, "skip_cnt_check"))
> +               return;
> +       if (!ASSERT_EQ(result->error_cnt, 0, "error_cnt_check"))
> +               return;
> +       if (!ASSERT_EQ(result->subtest_num, 1, "subtest_num_check"))
> +               return;
> +       clear_test_result(result);
> +

[...]
Mykola Lysenko April 14, 2022, 11:40 p.m. UTC | #2 
> On Apr 14, 2022, at 3:49 PM, Andrii Nakryiko <andrii.nakryiko@gmail.com> wrote:
> 
> On Wed, Apr 13, 2022 at 10:05 PM Mykola Lysenko <mykolal@fb.com> wrote:
>> 
>> This is a pre-req to add separate logging for each subtest.
>> 
>> Move all the mutable test data to the test_result struct.
>> Move per-test init/de-init into the run_one_test function.
>> Consolidate data aggregation and final log output in
>> calculate_and_print_summary function.
>> As a side effect, this patch fixes double counting of errors
>> for subtests and possible duplicate output of subtest log
>> on failures.
>> 
>> Also, add prog_tests_framework.c test to verify some of the
>> counting logic.
>> 
>> As part of verification, confirmed that number of reported
>> tests is the same before and after the change for both parallel
>> and sequential test execution.
>> 
>> Signed-off-by: Mykola Lysenko <mykolal@fb.com>
>> ---
> 
> The consolidation of the per-test logic in one place is great, thanks
> for tackling this! But I tried this locally and understood what you
> were mentioning as completely buffered output. It really sucks and is
> a big step back, I think :(

Thanks Andrii! Your points make sense, in the next revision I will keep
this behavior untouched.

> 
> Running sudo ./test_progs -j I see no output for a long while and only
> then get entire output at the end:
> 
> #239 xdp_noinline:OK
> #240 xdp_perf:OK
> #241 xdpwall:OK
> 
> All error logs:
> 
> #58 fexit_sleep:FAIL
> test_fexit_sleep:PASS:fexit_skel_load 0 nsec
> test_fexit_sleep:PASS:fexit_attach 0 nsec
> test_fexit_sleep:PASS:clone 0 nsec
> test_fexit_sleep:PASS:fexit_cnt 0 nsec
> test_fexit_sleep:PASS:waitpid 0 nsec
> test_fexit_sleep:PASS:exitstatus 0 nsec
> test_fexit_sleep:FAIL:fexit_cnt 2
> Summary: 240/1156 PASSED, 34 SKIPPED, 1 FAILED
> 
> 
> First, just not seeing the progress made me wonder for a good minute
> or more whether something is just stuck and deadlock. Which is anxiety
> inducing and I'd rather avoid this :)
> 
> Second, as you can see, fexit_sleep actually failed (it does sometimes
> in parallel mode). But I saw this only at the very end, while normally
> I'd notice it as soon as it completes. In this case I know fexit_sleep
> can fail and I'd ignore, but if there was some subtest that suddenly
> breaks, I don't wait for all the tests to finish, I ctrl-C and go
> investigate. Now I can't do that.
> 
> How much of a problem is it to preserve old behavior of streaming
> results of tests as they come, but consolidate duplicate logic in one
> place?
> 
>> .../bpf/prog_tests/prog_tests_framework.c | 55 ++++
>> tools/testing/selftests/bpf/test_progs.c | 301 +++++++-----------
>> tools/testing/selftests/bpf/test_progs.h | 32 +-
>> 3 files changed, 195 insertions(+), 193 deletions(-)
>> create mode 100644 tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
>> 
>> diff --git a/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
>> new file mode 100644
>> index 000000000000..7a5be06653f7
>> --- /dev/null
>> +++ b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
>> @@ -0,0 +1,55 @@
>> +// SPDX-License-Identifier: (LGPL-2.1 OR BSD-2-Clause)
>> +
>> +#include "test_progs.h"
>> +#include "testing_helpers.h"
>> +
>> +static void clear_test_result(struct test_result *result)
>> +{
>> + result->error_cnt = 0;
>> + result->sub_succ_cnt = 0;
>> + result->skip_cnt = 0;
>> +}
>> +
>> +void test_prog_tests_framework(void)
>> +{
>> + struct test_result *result = env.test_result;
>> +
>> + // in all the ASSERT calls below we need to return on the first
>> + // error due to the fact that we are cleaning the test state after
>> + // each dummy subtest
>> +
>> + // test we properly count skipped tests with subtests
> 
> C++ comments, please use /* */

Will fix.

> 
> 
>> + if (test__start_subtest("test_good_subtest"))
>> + test__end_subtest();
>> + if (!ASSERT_EQ(result->skip_cnt, 0, "skip_cnt_check"))
>> + return;
>> + if (!ASSERT_EQ(result->error_cnt, 0, "error_cnt_check"))
>> + return;
>> + if (!ASSERT_EQ(result->subtest_num, 1, "subtest_num_check"))
>> + return;
>> + clear_test_result(result);
>> +
> 
> [...]
diff mbox series

Patch

diff --git a/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
new file mode 100644
index 000000000000..7a5be06653f7
--- /dev/null
+++ b/tools/testing/selftests/bpf/prog_tests/prog_tests_framework.c
@@ -0,0 +1,55 @@ 
+// SPDX-License-Identifier: (LGPL-2.1 OR BSD-2-Clause)
+
+#include "test_progs.h"
+#include "testing_helpers.h"
+
+static void clear_test_result(struct test_result *result)
+{
+	result->error_cnt = 0;
+	result->sub_succ_cnt = 0;
+	result->skip_cnt = 0;
+}
+
+void test_prog_tests_framework(void)
+{
+	struct test_result *result = env.test_result;
+
+	// in all the ASSERT calls below we need to return on the first
+	// error due to the fact that we are cleaning the test state after
+	// each dummy subtest
+
+	// test we properly count skipped tests with subtests
+	if (test__start_subtest("test_good_subtest"))
+		test__end_subtest();
+	if (!ASSERT_EQ(result->skip_cnt, 0, "skip_cnt_check"))
+		return;
+	if (!ASSERT_EQ(result->error_cnt, 0, "error_cnt_check"))
+		return;
+	if (!ASSERT_EQ(result->subtest_num, 1, "subtest_num_check"))
+		return;
+	clear_test_result(result);
+
+	if (test__start_subtest("test_skip_subtest")) {
+		test__skip();
+		test__end_subtest();
+	}
+	if (test__start_subtest("test_skip_subtest")) {
+		test__skip();
+		test__end_subtest();
+	}
+	if (!ASSERT_EQ(result->skip_cnt, 2, "skip_cnt_check"))
+		return;
+	if (!ASSERT_EQ(result->subtest_num, 3, "subtest_num_check"))
+		return;
+	clear_test_result(result);
+
+	if (test__start_subtest("test_fail_subtest")) {
+		test__fail();
+		test__end_subtest();
+	}
+	if (!ASSERT_EQ(result->error_cnt, 1, "error_cnt_check"))
+		return;
+	if (!ASSERT_EQ(result->subtest_num, 4, "subtest_num_check"))
+		return;
+	clear_test_result(result);
+}
diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
index dcad9871f556..b3881d4fd99d 100644
--- a/tools/testing/selftests/bpf/test_progs.c
+++ b/tools/testing/selftests/bpf/test_progs.c
@@ -52,18 +52,8 @@  struct prog_test_def {
 	void (*run_test)(void);
 	void (*run_serial_test)(void);
 	bool force_log;
-	int error_cnt;
-	int skip_cnt;
-	int sub_succ_cnt;
 	bool should_run;
-	bool tested;
 	bool need_cgroup_cleanup;
-
-	char *subtest_name;
-	int subtest_num;
-
-	/* store counts before subtest started */
-	int old_error_cnt;
 };
 
 /* Override C runtime library's usleep() implementation to ensure nanosleep()
@@ -162,14 +152,6 @@  static void dump_test_log(const struct prog_test_def *test, bool failed)
 	}
 }
 
-static void skip_account(void)
-{
-	if (env.test->skip_cnt) {
-		env.skip_cnt++;
-		env.test->skip_cnt = 0;
-	}
-}
-
 static void stdio_restore(void);
 
 /* A bunch of tests set custom affinity per-thread and/or per-process. Reset
@@ -219,55 +201,59 @@  static void restore_netns(void)
 void test__end_subtest(void)
 {
 	struct prog_test_def *test = env.test;
-	int sub_error_cnt = test->error_cnt - test->old_error_cnt;
+	struct test_result *result = env.test_result;
 
-	dump_test_log(test, sub_error_cnt);
+	int sub_error_cnt = result->error_cnt - result->old_error_cnt;
 
 	fprintf(stdout, "#%d/%d %s/%s:%s\n",
-	       test->test_num, test->subtest_num, test->test_name, test->subtest_name,
-	       sub_error_cnt ? "FAIL" : (test->skip_cnt ? "SKIP" : "OK"));
+	       test->test_num, result->subtest_num, test->test_name, result->subtest_name,
+	       sub_error_cnt ? "FAIL" : (result->subtest_skip_cnt ? "SKIP" : "OK"));
 
-	if (sub_error_cnt)
-		test->error_cnt++;
-	else if (test->skip_cnt == 0)
-		test->sub_succ_cnt++;
-	skip_account();
+	if (!sub_error_cnt) {
+		if (result->subtest_skip_cnt == 0) {
+			result->sub_succ_cnt++;
+		} else {
+			result->subtest_skip_cnt = 0;
+			result->skip_cnt++;
+		}
+	}
 
-	free(test->subtest_name);
-	test->subtest_name = NULL;
+	free(result->subtest_name);
+	result->subtest_name = NULL;
 }
 
 bool test__start_subtest(const char *subtest_name)
 {
 	struct prog_test_def *test = env.test;
+	struct test_result *result = env.test_result;
 
-	if (test->subtest_name)
+	if (result->subtest_name)
 		test__end_subtest();
 
-	test->subtest_num++;
+	result->subtest_num++;
 
 	if (!subtest_name || !subtest_name[0]) {
 		fprintf(env.stderr,
 			"Subtest #%d didn't provide sub-test name!\n",
-			test->subtest_num);
+			result->subtest_num);
 		return false;
 	}
 
 	if (!should_run_subtest(&env.test_selector,
 				&env.subtest_selector,
-				test->subtest_num,
+				result->subtest_num,
 				test->test_name,
 				subtest_name))
 		return false;
 
-	test->subtest_name = strdup(subtest_name);
-	if (!test->subtest_name) {
+	result->subtest_name = strdup(subtest_name);
+	if (!result->subtest_name) {
 		fprintf(env.stderr,
 			"Subtest #%d: failed to copy subtest name!\n",
-			test->subtest_num);
+			result->subtest_num);
 		return false;
 	}
-	env.test->old_error_cnt = env.test->error_cnt;
+	result->old_error_cnt = result->error_cnt;
 
 	return true;
 }
@@ -279,12 +265,15 @@  void test__force_log(void)
 
 void test__skip(void)
 {
-	env.test->skip_cnt++;
+	if (env.test_result->subtest_name)
+		env.test_result->subtest_skip_cnt++;
+	else
+		env.test_result->skip_cnt++;
 }
 
 void test__fail(void)
 {
-	env.test->error_cnt++;
+	env.test_result->error_cnt++;
 }
 
 int test__join_cgroup(const char *path)
@@ -517,8 +506,11 @@  static struct prog_test_def prog_test_defs[] = {
 #include <prog_tests/tests.h>
 #undef DEFINE_TEST
 };
+
 static const int prog_test_cnt = ARRAY_SIZE(prog_test_defs);
 
+static struct test_result test_results[ARRAY_SIZE(prog_test_defs)];
+
 const char *argp_program_version = "test_progs 0.1";
 const char *argp_program_bug_address = "<bpf@vger.kernel.org>";
 static const char argp_program_doc[] = "BPF selftests test runner";
@@ -838,18 +830,6 @@  static void sigint_handler(int signum)
 
 static int current_test_idx;
 static pthread_mutex_t current_test_lock;
-static pthread_mutex_t stdout_output_lock;
-
-struct test_result {
-	int error_cnt;
-	int skip_cnt;
-	int sub_succ_cnt;
-
-	size_t log_cnt;
-	char *log_buf;
-};
-
-static struct test_result test_results[ARRAY_SIZE(prog_test_defs)];
 
 static inline const char *str_msg(const struct msg *msg, char *buf)
 {
@@ -904,8 +884,12 @@  static int recv_message(int sock, struct msg *msg)
 static void run_one_test(int test_num)
 {
 	struct prog_test_def *test = &prog_test_defs[test_num];
+	struct test_result *result = &test_results[test_num];
+
+	stdio_hijack();
 
 	env.test = test;
+	env.test_result = result;
 
 	if (test->run_test)
 		test->run_test();
@@ -913,17 +897,26 @@  static void run_one_test(int test_num)
 		test->run_serial_test();
 
 	/* ensure last sub-test is finalized properly */
-	if (test->subtest_name)
+	if (result->subtest_name)
 		test__end_subtest();
 
-	test->tested = true;
-
-	dump_test_log(test, test->error_cnt);
+	result->tested = true;
 
 	reset_affinity();
 	restore_netns();
 	if (test->need_cgroup_cleanup)
 		cleanup_cgroup_environment();
+
+	stdio_restore();
+
+	if (env.log_buf) {
+		result->log_buf = strdup(env.log_buf);
+		result->log_cnt = env.log_cnt;
+
+		free(env.log_buf);
+		env.log_buf = NULL;
+		env.log_cnt = 0;
+	}
 }
 
 struct dispatch_data {
@@ -989,9 +982,8 @@  static void *dispatch_thread(void *ctx)
 			if (test_to_run != msg_test_done.test_done.test_num)
 				goto error;
 
-			test->tested = true;
 			result = &test_results[test_to_run];
-
+			result->tested = true;
 			result->error_cnt = msg_test_done.test_done.error_cnt;
 			result->skip_cnt = msg_test_done.test_done.skip_cnt;
 			result->sub_succ_cnt = msg_test_done.test_done.sub_succ_cnt;
@@ -1017,24 +1009,6 @@  static void *dispatch_thread(void *ctx)
 				fclose(log_fp);
 				log_fp = NULL;
 			}
-			/* output log */
-			{
-				pthread_mutex_lock(&stdout_output_lock);
-
-				if (result->log_cnt) {
-					result->log_buf[result->log_cnt] = '\0';
-					fprintf(stdout, "%s", result->log_buf);
-					if (result->log_buf[result->log_cnt - 1] != '\n')
-						fprintf(stdout, "\n");
-				}
-
-				fprintf(stdout, "#%d %s:%s\n",
-					test->test_num, test->test_name,
-					result->error_cnt ? "FAIL" : (result->skip_cnt ? "SKIP" : "OK"));
-
-				pthread_mutex_unlock(&stdout_output_lock);
-			}
-
 		} /* wait for test done */
 	} /* while (true) */
 error:
@@ -1057,38 +1031,72 @@  static void *dispatch_thread(void *ctx)
 	return NULL;
 }
 
-static void print_all_error_logs(void)
+static void calculate_and_print_summary(struct test_env *env)
 {
 	int i;
+	int succ_cnt = 0, fail_cnt = 0, sub_succ_cnt = 0, skip_cnt = 0;
+
+	for (i = 0; i < prog_test_cnt; i++) {
+		struct prog_test_def *test = &prog_test_defs[i];
+		struct test_result *result = &test_results[i];
+
+		if (!result->tested)
+			continue;
+
+		sub_succ_cnt += result->sub_succ_cnt;
+		skip_cnt += result->skip_cnt;
+
+		if (result->error_cnt)
+			fail_cnt++;
+		else
+			succ_cnt++;
+
+		printf("#%d %s:%s\n",
+		       test->test_num, test->test_name,
+		       result->error_cnt ? "FAIL" : (result->skip_cnt ? "SKIP" : "OK"));
+
+		if (env->verbosity > VERBOSE_NONE || test->force_log || result->error_cnt) {
+			if (result->log_cnt) {
+				result->log_buf[result->log_cnt] = '\0';
+				printf("%s", result->log_buf);
+				if (result->log_buf[result->log_cnt - 1] != '\n')
+					printf("\n");
+			}
+		}
+	}
 
-	if (env.fail_cnt)
-		fprintf(stdout, "\nAll error logs:\n");
+	if (fail_cnt)
+		printf("\nAll error logs:\n");
 
 	/* print error logs again */
 	for (i = 0; i < prog_test_cnt; i++) {
-		struct prog_test_def *test;
-		struct test_result *result;
-
-		test = &prog_test_defs[i];
-		result = &test_results[i];
+		struct prog_test_def *test = &prog_test_defs[i];
+		struct test_result *result = &test_results[i];
 
-		if (!test->tested || !result->error_cnt)
+		if (!result->tested || !result->error_cnt)
 			continue;
 
-		fprintf(stdout, "\n#%d %s:%s\n",
-			test->test_num, test->test_name,
-			result->error_cnt ? "FAIL" : (result->skip_cnt ? "SKIP" : "OK"));
+		printf("\n#%d %s:%s\n",
+		       test->test_num, test->test_name, "FAIL");
 
 		if (result->log_cnt) {
 			result->log_buf[result->log_cnt] = '\0';
-			fprintf(stdout, "%s", result->log_buf);
+			printf("%s", result->log_buf);
 			if (result->log_buf[result->log_cnt - 1] != '\n')
-				fprintf(stdout, "\n");
+				printf("\n");
 		}
 	}
+
+	printf("Summary: %d/%d PASSED, %d SKIPPED, %d FAILED\n",
+	       succ_cnt, sub_succ_cnt, skip_cnt, fail_cnt);
+
+	env->succ_cnt = succ_cnt;
+	env->sub_succ_cnt = sub_succ_cnt;
+	env->fail_cnt = fail_cnt;
+	env->skip_cnt = skip_cnt;
 }
 
-static int server_main(void)
+static void server_main(void)
 {
 	pthread_t *dispatcher_threads;
 	struct dispatch_data *data;
@@ -1144,60 +1152,18 @@  static int server_main(void)
 
 	for (int i = 0; i < prog_test_cnt; i++) {
 		struct prog_test_def *test = &prog_test_defs[i];
-		struct test_result *result = &test_results[i];
 
 		if (!test->should_run || !test->run_serial_test)
 			continue;
 
-		stdio_hijack();
-
 		run_one_test(i);
-
-		stdio_restore();
-		if (env.log_buf) {
-			result->log_cnt = env.log_cnt;
-			result->log_buf = strdup(env.log_buf);
-
-			free(env.log_buf);
-			env.log_buf = NULL;
-			env.log_cnt = 0;
-		}
-		restore_netns();
-
-		fprintf(stdout, "#%d %s:%s\n",
-			test->test_num, test->test_name,
-			test->error_cnt ? "FAIL" : (test->skip_cnt ? "SKIP" : "OK"));
-
-		result->error_cnt = test->error_cnt;
-		result->skip_cnt = test->skip_cnt;
-		result->sub_succ_cnt = test->sub_succ_cnt;
 	}
 
 	/* generate summary */
 	fflush(stderr);
 	fflush(stdout);
 
-	for (i = 0; i < prog_test_cnt; i++) {
-		struct prog_test_def *current_test;
-		struct test_result *result;
-
-		current_test = &prog_test_defs[i];
-		result = &test_results[i];
-
-		if (!current_test->tested)
-			continue;
-
-		env.succ_cnt += result->error_cnt ? 0 : 1;
-		env.skip_cnt += result->skip_cnt;
-		if (result->error_cnt)
-			env.fail_cnt++;
-		env.sub_succ_cnt += result->sub_succ_cnt;
-	}
-
-	print_all_error_logs();
-
-	fprintf(stdout, "Summary: %d/%d PASSED, %d SKIPPED, %d FAILED\n",
-		env.succ_cnt, env.sub_succ_cnt, env.skip_cnt, env.fail_cnt);
+	calculate_and_print_summary(&env);
 
 	/* reap all workers */
 	for (i = 0; i < env.workers; i++) {
@@ -1207,8 +1173,6 @@  static int server_main(void)
 		if (pid != env.worker_pids[i])
 			perror("Unable to reap worker");
 	}
-
-	return 0;
 }
 
 static int worker_main(int sock)
@@ -1229,35 +1193,29 @@  static int worker_main(int sock)
 					env.worker_id);
 			goto out;
 		case MSG_DO_TEST: {
-			int test_to_run;
-			struct prog_test_def *test;
+			int test_to_run = msg.do_test.test_num;
+			struct prog_test_def *test = &prog_test_defs[test_to_run];
+			struct test_result *result = &test_results[test_to_run];
 			struct msg msg_done;
 
-			test_to_run = msg.do_test.test_num;
-			test = &prog_test_defs[test_to_run];
-
 			if (env.debug)
 				fprintf(stderr, "[%d]: #%d:%s running.\n",
 					env.worker_id,
 					test_to_run + 1,
 					test->test_name);
 
-			stdio_hijack();
-
 			run_one_test(test_to_run);
 
-			stdio_restore();
-
 			memset(&msg_done, 0, sizeof(msg_done));
 			msg_done.type = MSG_TEST_DONE;
 			msg_done.test_done.test_num = test_to_run;
-			msg_done.test_done.error_cnt = test->error_cnt;
-			msg_done.test_done.skip_cnt = test->skip_cnt;
-			msg_done.test_done.sub_succ_cnt = test->sub_succ_cnt;
+			msg_done.test_done.error_cnt = result->error_cnt;
+			msg_done.test_done.skip_cnt = result->skip_cnt;
+			msg_done.test_done.sub_succ_cnt = result->sub_succ_cnt;
 			msg_done.test_done.have_log = false;
 
-			if (env.verbosity > VERBOSE_NONE || test->force_log || test->error_cnt) {
-				if (env.log_cnt)
+			if (env.verbosity > VERBOSE_NONE || test->force_log || result->error_cnt) {
+				if (result->log_cnt)
 					msg_done.test_done.have_log = true;
 			}
 			if (send_message(sock, &msg_done) < 0) {
@@ -1270,8 +1228,8 @@  static int worker_main(int sock)
 				char *src;
 				size_t slen;
 
-				src = env.log_buf;
-				slen = env.log_cnt;
+				src = result->log_buf;
+				slen = result->log_cnt;
 				while (slen) {
 					struct msg msg_log;
 					char *dest;
@@ -1291,10 +1249,10 @@  static int worker_main(int sock)
 					assert(send_message(sock, &msg_log) >= 0);
 				}
 			}
-			if (env.log_buf) {
-				free(env.log_buf);
-				env.log_buf = NULL;
-				env.log_cnt = 0;
+			if (result->log_buf) {
+				free(result->log_buf);
+				result->log_buf = NULL;
+				result->log_cnt = 0;
 			}
 			if (env.debug)
 				fprintf(stderr, "[%d]: #%d:%s done.\n",
@@ -1425,7 +1383,6 @@  int main(int argc, char **argv)
 
 	for (i = 0; i < prog_test_cnt; i++) {
 		struct prog_test_def *test = &prog_test_defs[i];
-		struct test_result *result;
 
 		if (!test->should_run)
 			continue;
@@ -1441,34 +1398,7 @@  int main(int argc, char **argv)
 			continue;
 		}
 
-		stdio_hijack();
-
 		run_one_test(i);
-
-		stdio_restore();
-
-		fprintf(env.stdout, "#%d %s:%s\n",
-			test->test_num, test->test_name,
-			test->error_cnt ? "FAIL" : (test->skip_cnt ? "SKIP" : "OK"));
-
-		result = &test_results[i];
-		result->error_cnt = test->error_cnt;
-		if (env.log_buf) {
-			result->log_buf = strdup(env.log_buf);
-			result->log_cnt = env.log_cnt;
-
-			free(env.log_buf);
-			env.log_buf = NULL;
-			env.log_cnt = 0;
-		}
-
-		if (test->error_cnt)
-			env.fail_cnt++;
-		else
-			env.succ_cnt++;
-
-		skip_account();
-		env.sub_succ_cnt += test->sub_succ_cnt;
 	}
 
 	if (env.get_test_cnt) {
@@ -1479,10 +1409,7 @@  int main(int argc, char **argv)
 	if (env.list_test_names)
 		goto out;
 
-	print_all_error_logs();
-
-	fprintf(stdout, "Summary: %d/%d PASSED, %d SKIPPED, %d FAILED\n",
-		env.succ_cnt, env.sub_succ_cnt, env.skip_cnt, env.fail_cnt);
+	calculate_and_print_summary(&env);
 
 	close(env.saved_netns_fd);
 out:
diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
index 6a8d68bb459e..0521d6348e83 100644
--- a/tools/testing/selftests/bpf/test_progs.h
+++ b/tools/testing/selftests/bpf/test_progs.h
@@ -64,6 +64,24 @@  struct test_selector {
 	int num_set_len;
 };
 
+struct test_result {
+	bool tested;
+
+	int error_cnt;
+	int skip_cnt;
+	int subtest_skip_cnt;
+	int sub_succ_cnt;
+
+	char *subtest_name;
+	int subtest_num;
+
+	/* store counts before subtest started */
+	int old_error_cnt;
+
+	size_t log_cnt;
+	char *log_buf;
+};
+
 struct test_env {
 	struct test_selector test_selector;
 	struct test_selector subtest_selector;
@@ -76,7 +94,8 @@  struct test_env {
 	bool get_test_cnt;
 	bool list_test_names;
 
-	struct prog_test_def *test; /* current running tests */
+	struct prog_test_def *test; /* current running test */
+	struct test_result *test_result; /* current running test result */
 
 	FILE *stdout;
 	FILE *stderr;
@@ -126,11 +145,12 @@  struct msg {
 
 extern struct test_env env;
 
-extern void test__force_log();
-extern bool test__start_subtest(const char *name);
-extern void test__skip(void);
-extern void test__fail(void);
-extern int test__join_cgroup(const char *path);
+void test__force_log(void);
+bool test__start_subtest(const char *name);
+void test__end_subtest(void);
+void test__skip(void);
+void test__fail(void);
+int test__join_cgroup(const char *path);
 
 #define PRINT_FAIL(format...)                                                  \
 	({                                                                     \