lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <80957794-de90-b09b-89ef-6094d6357d9e@fb.com>
Date:   Fri, 2 Aug 2019 19:57:40 +0000
From:   Andrii Nakryiko <andriin@...com>
To:     Stanislav Fomichev <sdf@...gle.com>,
        "netdev@...r.kernel.org" <netdev@...r.kernel.org>,
        "bpf@...r.kernel.org" <bpf@...r.kernel.org>
CC:     "davem@...emloft.net" <davem@...emloft.net>,
        "ast@...nel.org" <ast@...nel.org>,
        "daniel@...earbox.net" <daniel@...earbox.net>,
        "andrii.nakryiko@...il.com" <andrii.nakryiko@...il.com>
Subject: Re: [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to
 open_memstream

On 8/2/19 10:17 AM, Stanislav Fomichev wrote:
> Use open_memstream to override stdout during test execution.
> The copy of the original stdout is held in env.stdout and used
> to print subtest info and dump failed log.

I really like the idea. I didn't know about open_memstream, it's awesome. Thanks!

>
> test_{v,}printf are now simple wrappers around stdout and will be
> removed in the next patch.
>
> Cc: Andrii Nakryiko <andriin@...com>
> Signed-off-by: Stanislav Fomichev <sdf@...gle.com>
> ---
>  tools/testing/selftests/bpf/test_progs.c | 100 ++++++++++-------------
>  tools/testing/selftests/bpf/test_progs.h |   2 +-
>  2 files changed, 46 insertions(+), 56 deletions(-)
>
> diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
> index db00196c8315..00d1565d01a3 100644
> --- a/tools/testing/selftests/bpf/test_progs.c
> +++ b/tools/testing/selftests/bpf/test_progs.c
> @@ -40,14 +40,22 @@ static bool should_run(struct test_selector *sel, int num, const char *name)
>  
>  static void dump_test_log(const struct prog_test_def *test, bool failed)
>  {
> -	if (env.verbose || test->force_log || failed) {
> -		if (env.log_cnt) {
> -			fprintf(stdout, "%s", env.log_buf);
> -			if (env.log_buf[env.log_cnt - 1] != '\n')
> -				fprintf(stdout, "\n");
> +	if (stdout == env.stdout)
> +		return;
> +
> +	fflush(stdout); /* exports env.log_buf & env.log_cap */
> +
> +	if (env.log_cap && (env.verbose || test->force_log || failed)) {
> +		int len = strlen(env.log_buf);

env.log_cap is not really a capacity, it's actual number of bytes (without terminating zero), so there is no need to do strlen and it's probably better to rename env.log_cap into env.log_cnt.


> +
> +		if (len) {
> +			fprintf(env.stdout, "%s", env.log_buf);
> +			if (env.log_buf[len - 1] != '\n')
> +				fprintf(env.stdout, "\n");
> +
> +			fseeko(stdout, 0, SEEK_SET);
Same bug as I already fixed with env.log_cnt = 0 being inside this if. You want to do seek always, not just when you print output log.
>  /* rewind */
>  		}
>  	}
> -	env.log_cnt = 0;
>  }
>  
>  void test__end_subtest()
> @@ -62,7 +70,7 @@ void test__end_subtest()
>  
>  	dump_test_log(test, sub_error_cnt);
>  
> -	printf("#%d/%d %s:%s\n",
> +	fprintf(env.stdout, "#%d/%d %s:%s\n",
>  	       test->test_num, test->subtest_num,
>  	       test->subtest_name, sub_error_cnt ? "FAIL" : "OK");
>  }
> @@ -100,53 +108,7 @@ void test__force_log() {
>  
>  void test__vprintf(const char *fmt, va_list args)
>  {
> -	size_t rem_sz;
> -	int ret = 0;
> -
> -	if (env.verbose || (env.test && env.test->force_log)) {
> -		vfprintf(stderr, fmt, args);
> -		return;
> -	}
> -
> -try_again:
> -	rem_sz = env.log_cap - env.log_cnt;
> -	if (rem_sz) {
> -		va_list ap;
> -
> -		va_copy(ap, args);
> -		/* we reserved extra byte for \0 at the end */
> -		ret = vsnprintf(env.log_buf + env.log_cnt, rem_sz + 1, fmt, ap);
> -		va_end(ap);
> -
> -		if (ret < 0) {
> -			env.log_buf[env.log_cnt] = '\0';
> -			fprintf(stderr, "failed to log w/ fmt '%s'\n", fmt);
> -			return;
> -		}
> -	}
> -
> -	if (!rem_sz || ret > rem_sz) {
> -		size_t new_sz = env.log_cap * 3 / 2;
> -		char *new_buf;
> -
> -		if (new_sz < 4096)
> -			new_sz = 4096;
> -		if (new_sz < ret + env.log_cnt)
> -			new_sz = ret + env.log_cnt;
> -
> -		/* +1 for guaranteed space for terminating \0 */
> -		new_buf = realloc(env.log_buf, new_sz + 1);
> -		if (!new_buf) {
> -			fprintf(stderr, "failed to realloc log buffer: %d\n",
> -				errno);
> -			return;
> -		}
> -		env.log_buf = new_buf;
> -		env.log_cap = new_sz;
> -		goto try_again;
> -	}
> -
> -	env.log_cnt += ret;
> +	vprintf(fmt, args);
>  }
>  
>  void test__printf(const char *fmt, ...)
> @@ -477,6 +439,32 @@ static error_t parse_arg(int key, char *arg, struct argp_state *state)
>  	return 0;
>  }
>  
> +static void stdout_hijack(void)
> +{
> +	if (env.verbose || (env.test && env.test->force_log)) {
> +		/* nothing to do, output to stdout by default */
> +		return;
> +	}
> +
> +	/* stdout -> buffer */
> +	fflush(stdout);
> +	stdout = open_memstream(&env.log_buf, &env.log_cap);
Check errors and restore original stdout if something went wrong? (And emit some warning to stderr).
> +}
> +
> +static void stdout_restore(void)
> +{
> +	if (stdout == env.stdout)
> +		return;
> +
> +	fclose(stdout);
> +	free(env.log_buf);
> +
> +	env.log_buf = NULL;
> +	env.log_cap = 0;
> +
> +	stdout = env.stdout;
> +}
> +
>  int main(int argc, char **argv)
>  {
>  	static const struct argp argp = {
> @@ -495,6 +483,7 @@ int main(int argc, char **argv)
>  	srand(time(NULL));
>  
>  	env.jit_enabled = is_jit_enabled();
> +	env.stdout = stdout;
>  
>  	for (i = 0; i < prog_test_cnt; i++) {
>  		struct prog_test_def *test = &prog_test_defs[i];
> @@ -508,6 +497,7 @@ int main(int argc, char **argv)
>  				test->test_num, test->test_name))
>  			continue;
>  
> +		stdout_hijack();
Why do you do this for every test? Just do once before all the tests and restore after?
>  		test->run_test();
>  		/* ensure last sub-test is finalized properly */
>  		if (test->subtest_name)
> @@ -522,6 +512,7 @@ int main(int argc, char **argv)
>  			env.succ_cnt++;
>  
>  		dump_test_log(test, test->error_cnt);
> +		stdout_restore();
>  
>  		printf("#%d %s:%s\n", test->test_num, test->test_name,
>  		       test->error_cnt ? "FAIL" : "OK");
> @@ -529,7 +520,6 @@ int main(int argc, char **argv)
>  	printf("Summary: %d/%d PASSED, %d FAILED\n",
>  	       env.succ_cnt, env.sub_succ_cnt, env.fail_cnt);
>  
> -	free(env.log_buf);
>  	free(env.test_selector.num_set);
>  	free(env.subtest_selector.num_set);
>  
> diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
> index afd14962456f..9fd89078494f 100644
> --- a/tools/testing/selftests/bpf/test_progs.h
> +++ b/tools/testing/selftests/bpf/test_progs.h
> @@ -56,8 +56,8 @@ struct test_env {
>  	bool jit_enabled;
>  
>  	struct prog_test_def *test;
> +	FILE *stdout;
>  	char *log_buf;
> -	size_t log_cnt;
>  	size_t log_cap;
So it's actually log_cnt that's assigned on fflush for memstream, according to man page, so probably keep log_cnt, delete log_cap.
>  
>  	int succ_cnt; /* successful tests */

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ