* [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio
@ 2019-08-02 17:17 Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream Stanislav Fomichev
` (3 more replies)
0 siblings, 4 replies; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 17:17 UTC (permalink / raw)
To: netdev, bpf; +Cc: davem, ast, daniel, Stanislav Fomichev, Andrii Nakryiko
I was looking into converting test_sockops* to test_progs framework
and that requires using cgroup_helpers.c which rely on stdio/stderr.
Let's use open_memstream to override stdout into buffer during
subtests instead of custom test_{v,}printf wrappers. That lets
us continue to use stdio in the subtests and dump it on failure
if required.
That would also fix bpf_find_map which currently uses printf to
signal failure (missed during test_printf conversion).
Cc: Andrii Nakryiko <andriin@fb.com>
Stanislav Fomichev (3):
selftests/bpf: test_progs: switch to open_memstream
selftests/bpf: test_progs: test__printf -> printf
selftests/bpf: test_progs: drop extra trailing tab
.../bpf/prog_tests/bpf_verif_scale.c | 4 +-
.../selftests/bpf/prog_tests/l4lb_all.c | 2 +-
.../selftests/bpf/prog_tests/map_lock.c | 10 +-
.../selftests/bpf/prog_tests/send_signal.c | 4 +-
.../selftests/bpf/prog_tests/spinlock.c | 2 +-
.../bpf/prog_tests/stacktrace_build_id.c | 4 +-
.../bpf/prog_tests/stacktrace_build_id_nmi.c | 4 +-
.../selftests/bpf/prog_tests/xdp_noinline.c | 4 +-
tools/testing/selftests/bpf/test_progs.c | 116 +++++++-----------
tools/testing/selftests/bpf/test_progs.h | 12 +-
10 files changed, 68 insertions(+), 94 deletions(-)
--
2.22.0.770.g0f2c4a37fd-goog
^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream
2019-08-02 17:17 [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Stanislav Fomichev
@ 2019-08-02 17:17 ` Stanislav Fomichev
2019-08-02 19:57 ` Andrii Nakryiko
2019-08-02 17:17 ` [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf Stanislav Fomichev
` (2 subsequent siblings)
3 siblings, 1 reply; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 17:17 UTC (permalink / raw)
To: netdev, bpf; +Cc: davem, ast, daniel, Stanislav Fomichev, Andrii Nakryiko
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.
test_{v,}printf are now simple wrappers around stdout and will be
removed in the next patch.
Cc: Andrii Nakryiko <andriin@fb.com>
Signed-off-by: Stanislav Fomichev <sdf@google.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);
+
+ 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); /* 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);
+}
+
+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();
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;
int succ_cnt; /* successful tests */
--
2.22.0.770.g0f2c4a37fd-goog
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf
2019-08-02 17:17 [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream Stanislav Fomichev
@ 2019-08-02 17:17 ` Stanislav Fomichev
2019-08-02 19:59 ` Andrii Nakryiko
2019-08-02 17:17 ` [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab Stanislav Fomichev
2019-08-02 20:00 ` [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Andrii Nakryiko
3 siblings, 1 reply; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 17:17 UTC (permalink / raw)
To: netdev, bpf; +Cc: davem, ast, daniel, Stanislav Fomichev, Andrii Nakryiko
Now that test__printf is a simple wraper around printf, let's drop it
(and test__vprintf as well).
Cc: Andrii Nakryiko <andriin@fb.com>
Signed-off-by: Stanislav Fomichev <sdf@google.com>
---
.../selftests/bpf/prog_tests/bpf_verif_scale.c | 4 ++--
.../testing/selftests/bpf/prog_tests/l4lb_all.c | 2 +-
.../testing/selftests/bpf/prog_tests/map_lock.c | 10 +++++-----
.../selftests/bpf/prog_tests/send_signal.c | 4 ++--
.../testing/selftests/bpf/prog_tests/spinlock.c | 2 +-
.../bpf/prog_tests/stacktrace_build_id.c | 4 ++--
.../bpf/prog_tests/stacktrace_build_id_nmi.c | 4 ++--
.../selftests/bpf/prog_tests/xdp_noinline.c | 4 ++--
tools/testing/selftests/bpf/test_progs.c | 16 +---------------
tools/testing/selftests/bpf/test_progs.h | 10 ++++------
10 files changed, 22 insertions(+), 38 deletions(-)
diff --git a/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c b/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
index b4be96162ff4..3548ba2f24a8 100644
--- a/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
+++ b/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
@@ -5,13 +5,13 @@ static int libbpf_debug_print(enum libbpf_print_level level,
const char *format, va_list args)
{
if (level != LIBBPF_DEBUG) {
- test__vprintf(format, args);
+ vprintf(format, args);
return 0;
}
if (!strstr(format, "verifier log"))
return 0;
- test__vprintf("%s", args);
+ vprintf("%s", args);
return 0;
}
diff --git a/tools/testing/selftests/bpf/prog_tests/l4lb_all.c b/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
index 5ce572c03a5f..20ddca830e68 100644
--- a/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
+++ b/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
@@ -74,7 +74,7 @@ static void test_l4lb(const char *file)
}
if (bytes != MAGIC_BYTES * NUM_ITER * 2 || pkts != NUM_ITER * 2) {
error_cnt++;
- test__printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
+ printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
}
out:
bpf_object__close(obj);
diff --git a/tools/testing/selftests/bpf/prog_tests/map_lock.c b/tools/testing/selftests/bpf/prog_tests/map_lock.c
index 2e78217ed3fd..ee99368c595c 100644
--- a/tools/testing/selftests/bpf/prog_tests/map_lock.c
+++ b/tools/testing/selftests/bpf/prog_tests/map_lock.c
@@ -9,12 +9,12 @@ static void *parallel_map_access(void *arg)
for (i = 0; i < 10000; i++) {
err = bpf_map_lookup_elem_flags(map_fd, &key, vars, BPF_F_LOCK);
if (err) {
- test__printf("lookup failed\n");
+ printf("lookup failed\n");
error_cnt++;
goto out;
}
if (vars[0] != 0) {
- test__printf("lookup #%d var[0]=%d\n", i, vars[0]);
+ printf("lookup #%d var[0]=%d\n", i, vars[0]);
error_cnt++;
goto out;
}
@@ -22,8 +22,8 @@ static void *parallel_map_access(void *arg)
for (j = 2; j < 17; j++) {
if (vars[j] == rnd)
continue;
- test__printf("lookup #%d var[1]=%d var[%d]=%d\n",
- i, rnd, j, vars[j]);
+ printf("lookup #%d var[1]=%d var[%d]=%d\n",
+ i, rnd, j, vars[j]);
error_cnt++;
goto out;
}
@@ -43,7 +43,7 @@ void test_map_lock(void)
err = bpf_prog_load(file, BPF_PROG_TYPE_CGROUP_SKB, &obj, &prog_fd);
if (err) {
- test__printf("test_map_lock:bpf_prog_load errno %d\n", errno);
+ printf("test_map_lock:bpf_prog_load errno %d\n", errno);
goto close_prog;
}
map_fd[0] = bpf_find_map(__func__, obj, "hash_map");
diff --git a/tools/testing/selftests/bpf/prog_tests/send_signal.c b/tools/testing/selftests/bpf/prog_tests/send_signal.c
index 461b423d0584..1575f0a1f586 100644
--- a/tools/testing/selftests/bpf/prog_tests/send_signal.c
+++ b/tools/testing/selftests/bpf/prog_tests/send_signal.c
@@ -202,8 +202,8 @@ static int test_send_signal_nmi(void)
-1 /* cpu */, -1 /* group_fd */, 0 /* flags */);
if (pmu_fd == -1) {
if (errno == ENOENT) {
- test__printf("%s:SKIP:no PERF_COUNT_HW_CPU_CYCLES\n",
- __func__);
+ printf("%s:SKIP:no PERF_COUNT_HW_CPU_CYCLES\n",
+ __func__);
return 0;
}
/* Let the test fail with a more informative message */
diff --git a/tools/testing/selftests/bpf/prog_tests/spinlock.c b/tools/testing/selftests/bpf/prog_tests/spinlock.c
index deb2db5b85b0..114ebe6a438e 100644
--- a/tools/testing/selftests/bpf/prog_tests/spinlock.c
+++ b/tools/testing/selftests/bpf/prog_tests/spinlock.c
@@ -12,7 +12,7 @@ void test_spinlock(void)
err = bpf_prog_load(file, BPF_PROG_TYPE_CGROUP_SKB, &obj, &prog_fd);
if (err) {
- test__printf("test_spin_lock:bpf_prog_load errno %d\n", errno);
+ printf("test_spin_lock:bpf_prog_load errno %d\n", errno);
goto close_prog;
}
for (i = 0; i < 4; i++)
diff --git a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
index 356d2c017a9c..ac44fda84833 100644
--- a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
+++ b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
@@ -109,8 +109,8 @@ void test_stacktrace_build_id(void)
if (build_id_matches < 1 && retry--) {
bpf_link__destroy(link);
bpf_object__close(obj);
- test__printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
- __func__);
+ printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
+ __func__);
goto retry;
}
diff --git a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
index f44f2c159714..9557b7dfb782 100644
--- a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
+++ b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
@@ -140,8 +140,8 @@ void test_stacktrace_build_id_nmi(void)
if (build_id_matches < 1 && retry--) {
bpf_link__destroy(link);
bpf_object__close(obj);
- test__printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
- __func__);
+ printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
+ __func__);
goto retry;
}
diff --git a/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c b/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
index b5404494b8aa..15f7c272edb0 100644
--- a/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
+++ b/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
@@ -75,8 +75,8 @@ void test_xdp_noinline(void)
}
if (bytes != MAGIC_BYTES * NUM_ITER * 2 || pkts != NUM_ITER * 2) {
error_cnt++;
- test__printf("test_xdp_noinline:FAIL:stats %lld %lld\n",
- bytes, pkts);
+ printf("test_xdp_noinline:FAIL:stats %lld %lld\n",
+ bytes, pkts);
}
out:
bpf_object__close(obj);
diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
index 00d1565d01a3..71c717162ac8 100644
--- a/tools/testing/selftests/bpf/test_progs.c
+++ b/tools/testing/selftests/bpf/test_progs.c
@@ -106,20 +106,6 @@ void test__force_log() {
env.test->force_log = true;
}
-void test__vprintf(const char *fmt, va_list args)
-{
- vprintf(fmt, args);
-}
-
-void test__printf(const char *fmt, ...)
-{
- va_list args;
-
- va_start(args, fmt);
- test__vprintf(fmt, args);
- va_end(args);
-}
-
struct ipv4_packet pkt_v4 = {
.eth.h_proto = __bpf_constant_htons(ETH_P_IP),
.iph.ihl = 5,
@@ -311,7 +297,7 @@ static int libbpf_print_fn(enum libbpf_print_level level,
{
if (!env.very_verbose && level == LIBBPF_DEBUG)
return 0;
- test__vprintf(format, args);
+ vprintf(format, args);
return 0;
}
diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
index 9fd89078494f..cf0486dbb9b4 100644
--- a/tools/testing/selftests/bpf/test_progs.h
+++ b/tools/testing/selftests/bpf/test_progs.h
@@ -69,8 +69,6 @@ extern int error_cnt;
extern int pass_cnt;
extern struct test_env env;
-extern void test__printf(const char *fmt, ...);
-extern void test__vprintf(const char *fmt, va_list args);
extern void test__force_log();
extern bool test__start_subtest(const char *name);
@@ -96,12 +94,12 @@ extern struct ipv6_packet pkt_v6;
int __ret = !!(condition); \
if (__ret) { \
error_cnt++; \
- test__printf("%s:FAIL:%s ", __func__, tag); \
- test__printf(format); \
+ printf("%s:FAIL:%s ", __func__, tag); \
+ printf(format); \
} else { \
pass_cnt++; \
- test__printf("%s:PASS:%s %d nsec\n", \
- __func__, tag, duration); \
+ printf("%s:PASS:%s %d nsec\n", \
+ __func__, tag, duration); \
} \
__ret; \
})
--
2.22.0.770.g0f2c4a37fd-goog
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab
2019-08-02 17:17 [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf Stanislav Fomichev
@ 2019-08-02 17:17 ` Stanislav Fomichev
2019-08-02 19:59 ` Andrii Nakryiko
2019-08-02 20:00 ` [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Andrii Nakryiko
3 siblings, 1 reply; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 17:17 UTC (permalink / raw)
To: netdev, bpf; +Cc: davem, ast, daniel, Stanislav Fomichev, Andrii Nakryiko
Small (un)related cleanup.
Cc: Andrii Nakryiko <andriin@fb.com>
Signed-off-by: Stanislav Fomichev <sdf@google.com>
---
tools/testing/selftests/bpf/test_progs.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
index 71c717162ac8..477539d0adeb 100644
--- a/tools/testing/selftests/bpf/test_progs.c
+++ b/tools/testing/selftests/bpf/test_progs.c
@@ -279,7 +279,7 @@ enum ARG_KEYS {
ARG_VERIFIER_STATS = 's',
ARG_VERBOSE = 'v',
};
-
+
static const struct argp_option opts[] = {
{ "num", ARG_TEST_NUM, "NUM", 0,
"Run test number NUM only " },
--
2.22.0.770.g0f2c4a37fd-goog
^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream
2019-08-02 17:17 ` [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream Stanislav Fomichev
@ 2019-08-02 19:57 ` Andrii Nakryiko
2019-08-02 20:14 ` Stanislav Fomichev
0 siblings, 1 reply; 12+ messages in thread
From: Andrii Nakryiko @ 2019-08-02 19:57 UTC (permalink / raw)
To: Stanislav Fomichev, netdev, bpf; +Cc: davem, ast, daniel, andrii.nakryiko
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@fb.com>
> Signed-off-by: Stanislav Fomichev <sdf@google.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 */
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf
2019-08-02 17:17 ` [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf Stanislav Fomichev
@ 2019-08-02 19:59 ` Andrii Nakryiko
0 siblings, 0 replies; 12+ messages in thread
From: Andrii Nakryiko @ 2019-08-02 19:59 UTC (permalink / raw)
To: Stanislav Fomichev, netdev, bpf; +Cc: davem, ast, daniel, andrii.nakryiko
On 8/2/19 10:17 AM, Stanislav Fomichev wrote:
> Now that test__printf is a simple wraper around printf, let's drop it
> (and test__vprintf as well).
>
> Cc: Andrii Nakryiko <andriin@fb.com>
> Signed-off-by: Stanislav Fomichev <sdf@google.com>
> ---
Acked-by: Andrii Nakryiko <andriin@fb.com>
> .../selftests/bpf/prog_tests/bpf_verif_scale.c | 4 ++--
> .../testing/selftests/bpf/prog_tests/l4lb_all.c | 2 +-
> .../testing/selftests/bpf/prog_tests/map_lock.c | 10 +++++-----
> .../selftests/bpf/prog_tests/send_signal.c | 4 ++--
> .../testing/selftests/bpf/prog_tests/spinlock.c | 2 +-
> .../bpf/prog_tests/stacktrace_build_id.c | 4 ++--
> .../bpf/prog_tests/stacktrace_build_id_nmi.c | 4 ++--
> .../selftests/bpf/prog_tests/xdp_noinline.c | 4 ++--
> tools/testing/selftests/bpf/test_progs.c | 16 +---------------
> tools/testing/selftests/bpf/test_progs.h | 10 ++++------
> 10 files changed, 22 insertions(+), 38 deletions(-)
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c b/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
> index b4be96162ff4..3548ba2f24a8 100644
> --- a/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
> +++ b/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
> @@ -5,13 +5,13 @@ static int libbpf_debug_print(enum libbpf_print_level level,
> const char *format, va_list args)
> {
> if (level != LIBBPF_DEBUG) {
> - test__vprintf(format, args);
> + vprintf(format, args);
> return 0;
> }
>
> if (!strstr(format, "verifier log"))
> return 0;
> - test__vprintf("%s", args);
> + vprintf("%s", args);
> return 0;
> }
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/l4lb_all.c b/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
> index 5ce572c03a5f..20ddca830e68 100644
> --- a/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
> +++ b/tools/testing/selftests/bpf/prog_tests/l4lb_all.c
> @@ -74,7 +74,7 @@ static void test_l4lb(const char *file)
> }
> if (bytes != MAGIC_BYTES * NUM_ITER * 2 || pkts != NUM_ITER * 2) {
> error_cnt++;
> - test__printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
> + printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
> }
> out:
> bpf_object__close(obj);
> diff --git a/tools/testing/selftests/bpf/prog_tests/map_lock.c b/tools/testing/selftests/bpf/prog_tests/map_lock.c
> index 2e78217ed3fd..ee99368c595c 100644
> --- a/tools/testing/selftests/bpf/prog_tests/map_lock.c
> +++ b/tools/testing/selftests/bpf/prog_tests/map_lock.c
> @@ -9,12 +9,12 @@ static void *parallel_map_access(void *arg)
> for (i = 0; i < 10000; i++) {
> err = bpf_map_lookup_elem_flags(map_fd, &key, vars, BPF_F_LOCK);
> if (err) {
> - test__printf("lookup failed\n");
> + printf("lookup failed\n");
> error_cnt++;
> goto out;
> }
> if (vars[0] != 0) {
> - test__printf("lookup #%d var[0]=%d\n", i, vars[0]);
> + printf("lookup #%d var[0]=%d\n", i, vars[0]);
> error_cnt++;
> goto out;
> }
> @@ -22,8 +22,8 @@ static void *parallel_map_access(void *arg)
> for (j = 2; j < 17; j++) {
> if (vars[j] == rnd)
> continue;
> - test__printf("lookup #%d var[1]=%d var[%d]=%d\n",
> - i, rnd, j, vars[j]);
> + printf("lookup #%d var[1]=%d var[%d]=%d\n",
> + i, rnd, j, vars[j]);
> error_cnt++;
> goto out;
> }
> @@ -43,7 +43,7 @@ void test_map_lock(void)
>
> err = bpf_prog_load(file, BPF_PROG_TYPE_CGROUP_SKB, &obj, &prog_fd);
> if (err) {
> - test__printf("test_map_lock:bpf_prog_load errno %d\n", errno);
> + printf("test_map_lock:bpf_prog_load errno %d\n", errno);
> goto close_prog;
> }
> map_fd[0] = bpf_find_map(__func__, obj, "hash_map");
> diff --git a/tools/testing/selftests/bpf/prog_tests/send_signal.c b/tools/testing/selftests/bpf/prog_tests/send_signal.c
> index 461b423d0584..1575f0a1f586 100644
> --- a/tools/testing/selftests/bpf/prog_tests/send_signal.c
> +++ b/tools/testing/selftests/bpf/prog_tests/send_signal.c
> @@ -202,8 +202,8 @@ static int test_send_signal_nmi(void)
> -1 /* cpu */, -1 /* group_fd */, 0 /* flags */);
> if (pmu_fd == -1) {
> if (errno == ENOENT) {
> - test__printf("%s:SKIP:no PERF_COUNT_HW_CPU_CYCLES\n",
> - __func__);
> + printf("%s:SKIP:no PERF_COUNT_HW_CPU_CYCLES\n",
> + __func__);
> return 0;
> }
> /* Let the test fail with a more informative message */
> diff --git a/tools/testing/selftests/bpf/prog_tests/spinlock.c b/tools/testing/selftests/bpf/prog_tests/spinlock.c
> index deb2db5b85b0..114ebe6a438e 100644
> --- a/tools/testing/selftests/bpf/prog_tests/spinlock.c
> +++ b/tools/testing/selftests/bpf/prog_tests/spinlock.c
> @@ -12,7 +12,7 @@ void test_spinlock(void)
>
> err = bpf_prog_load(file, BPF_PROG_TYPE_CGROUP_SKB, &obj, &prog_fd);
> if (err) {
> - test__printf("test_spin_lock:bpf_prog_load errno %d\n", errno);
> + printf("test_spin_lock:bpf_prog_load errno %d\n", errno);
> goto close_prog;
> }
> for (i = 0; i < 4; i++)
> diff --git a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
> index 356d2c017a9c..ac44fda84833 100644
> --- a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
> +++ b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id.c
> @@ -109,8 +109,8 @@ void test_stacktrace_build_id(void)
> if (build_id_matches < 1 && retry--) {
> bpf_link__destroy(link);
> bpf_object__close(obj);
> - test__printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
> - __func__);
> + printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
> + __func__);
> goto retry;
> }
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
> index f44f2c159714..9557b7dfb782 100644
> --- a/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
> +++ b/tools/testing/selftests/bpf/prog_tests/stacktrace_build_id_nmi.c
> @@ -140,8 +140,8 @@ void test_stacktrace_build_id_nmi(void)
> if (build_id_matches < 1 && retry--) {
> bpf_link__destroy(link);
> bpf_object__close(obj);
> - test__printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
> - __func__);
> + printf("%s:WARN:Didn't find expected build ID from the map, retrying\n",
> + __func__);
> goto retry;
> }
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c b/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
> index b5404494b8aa..15f7c272edb0 100644
> --- a/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
> +++ b/tools/testing/selftests/bpf/prog_tests/xdp_noinline.c
> @@ -75,8 +75,8 @@ void test_xdp_noinline(void)
> }
> if (bytes != MAGIC_BYTES * NUM_ITER * 2 || pkts != NUM_ITER * 2) {
> error_cnt++;
> - test__printf("test_xdp_noinline:FAIL:stats %lld %lld\n",
> - bytes, pkts);
> + printf("test_xdp_noinline:FAIL:stats %lld %lld\n",
> + bytes, pkts);
> }
> out:
> bpf_object__close(obj);
> diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
> index 00d1565d01a3..71c717162ac8 100644
> --- a/tools/testing/selftests/bpf/test_progs.c
> +++ b/tools/testing/selftests/bpf/test_progs.c
> @@ -106,20 +106,6 @@ void test__force_log() {
> env.test->force_log = true;
> }
>
> -void test__vprintf(const char *fmt, va_list args)
> -{
> - vprintf(fmt, args);
> -}
> -
> -void test__printf(const char *fmt, ...)
> -{
> - va_list args;
> -
> - va_start(args, fmt);
> - test__vprintf(fmt, args);
> - va_end(args);
> -}
> -
> struct ipv4_packet pkt_v4 = {
> .eth.h_proto = __bpf_constant_htons(ETH_P_IP),
> .iph.ihl = 5,
> @@ -311,7 +297,7 @@ static int libbpf_print_fn(enum libbpf_print_level level,
> {
> if (!env.very_verbose && level == LIBBPF_DEBUG)
> return 0;
> - test__vprintf(format, args);
> + vprintf(format, args);
> return 0;
> }
>
> diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
> index 9fd89078494f..cf0486dbb9b4 100644
> --- a/tools/testing/selftests/bpf/test_progs.h
> +++ b/tools/testing/selftests/bpf/test_progs.h
> @@ -69,8 +69,6 @@ extern int error_cnt;
> extern int pass_cnt;
> extern struct test_env env;
>
> -extern void test__printf(const char *fmt, ...);
> -extern void test__vprintf(const char *fmt, va_list args);
> extern void test__force_log();
> extern bool test__start_subtest(const char *name);
>
> @@ -96,12 +94,12 @@ extern struct ipv6_packet pkt_v6;
> int __ret = !!(condition); \
> if (__ret) { \
> error_cnt++; \
> - test__printf("%s:FAIL:%s ", __func__, tag); \
> - test__printf(format); \
> + printf("%s:FAIL:%s ", __func__, tag); \
> + printf(format); \
> } else { \
> pass_cnt++; \
> - test__printf("%s:PASS:%s %d nsec\n", \
> - __func__, tag, duration); \
> + printf("%s:PASS:%s %d nsec\n", \
> + __func__, tag, duration); \
> } \
> __ret; \
> })
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab
2019-08-02 17:17 ` [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab Stanislav Fomichev
@ 2019-08-02 19:59 ` Andrii Nakryiko
0 siblings, 0 replies; 12+ messages in thread
From: Andrii Nakryiko @ 2019-08-02 19:59 UTC (permalink / raw)
To: Stanislav Fomichev, netdev, bpf; +Cc: davem, ast, daniel
On 8/2/19 10:17 AM, Stanislav Fomichev wrote:
> Small (un)related cleanup.
>
> Cc: Andrii Nakryiko <andriin@fb.com>
> Signed-off-by: Stanislav Fomichev <sdf@google.com>
> ---
Acked-by: Andrii Nakryiko <andriin@fb.com>
> tools/testing/selftests/bpf/test_progs.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
> index 71c717162ac8..477539d0adeb 100644
> --- a/tools/testing/selftests/bpf/test_progs.c
> +++ b/tools/testing/selftests/bpf/test_progs.c
> @@ -279,7 +279,7 @@ enum ARG_KEYS {
> ARG_VERIFIER_STATS = 's',
> ARG_VERBOSE = 'v',
> };
> -
> +
> static const struct argp_option opts[] = {
> { "num", ARG_TEST_NUM, "NUM", 0,
> "Run test number NUM only " },
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio
2019-08-02 17:17 [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Stanislav Fomichev
` (2 preceding siblings ...)
2019-08-02 17:17 ` [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab Stanislav Fomichev
@ 2019-08-02 20:00 ` Andrii Nakryiko
2019-08-02 20:16 ` Stanislav Fomichev
3 siblings, 1 reply; 12+ messages in thread
From: Andrii Nakryiko @ 2019-08-02 20:00 UTC (permalink / raw)
To: Stanislav Fomichev, netdev, bpf; +Cc: davem, ast, daniel, andrii.nakryiko
On 8/2/19 10:17 AM, Stanislav Fomichev wrote:
> I was looking into converting test_sockops* to test_progs framework
> and that requires using cgroup_helpers.c which rely on stdio/stderr.
> Let's use open_memstream to override stdout into buffer during
> subtests instead of custom test_{v,}printf wrappers. That lets
> us continue to use stdio in the subtests and dump it on failure
> if required.
>
> That would also fix bpf_find_map which currently uses printf to
> signal failure (missed during test_printf conversion).
I wonder if we should hijack stderr as well?
>
> Cc: Andrii Nakryiko <andriin@fb.com>
>
> Stanislav Fomichev (3):
> selftests/bpf: test_progs: switch to open_memstream
> selftests/bpf: test_progs: test__printf -> printf
> selftests/bpf: test_progs: drop extra trailing tab
>
> .../bpf/prog_tests/bpf_verif_scale.c | 4 +-
> .../selftests/bpf/prog_tests/l4lb_all.c | 2 +-
> .../selftests/bpf/prog_tests/map_lock.c | 10 +-
> .../selftests/bpf/prog_tests/send_signal.c | 4 +-
> .../selftests/bpf/prog_tests/spinlock.c | 2 +-
> .../bpf/prog_tests/stacktrace_build_id.c | 4 +-
> .../bpf/prog_tests/stacktrace_build_id_nmi.c | 4 +-
> .../selftests/bpf/prog_tests/xdp_noinline.c | 4 +-
> tools/testing/selftests/bpf/test_progs.c | 116 +++++++-----------
> tools/testing/selftests/bpf/test_progs.h | 12 +-
> 10 files changed, 68 insertions(+), 94 deletions(-)
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream
2019-08-02 19:57 ` Andrii Nakryiko
@ 2019-08-02 20:14 ` Stanislav Fomichev
2019-08-03 6:00 ` Andrii Nakryiko
0 siblings, 1 reply; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 20:14 UTC (permalink / raw)
To: Andrii Nakryiko
Cc: Stanislav Fomichev, netdev, bpf, davem, ast, daniel, andrii.nakryiko
On 08/02, Andrii Nakryiko wrote:
> 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!
One possible downside of using open_memstream is that it's glibc
specific. I probably need to wrap it in #ifdef __GLIBC__ to make
it work with other libcs and just print everything as it was before :-(.
I'm not sure we care though.
> > test_{v,}printf are now simple wrappers around stdout and will be
> > removed in the next patch.
> >
> > Cc: Andrii Nakryiko <andriin@fb.com>
> > Signed-off-by: Stanislav Fomichev <sdf@google.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.
I'll rename it to log_size to match open_memstream args.
We probably still need to do strlen because open_memstream can allocate
bigger buffer to hold the data.
> > +
> > + 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.
SG, will move to where we currently clear log_cnt, thanks!
> > /* 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).
Good point, will do.
> > +}
> > +
> > +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?
We can do that, my thinking was to limit the area of hijacking :-)
But that would work as well, less allocations per test, I guess. Will
do.
> > 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.
Ack. See above, will rename to log_size, let me know if you disagree.
> > int succ_cnt; /* successful tests */
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio
2019-08-02 20:00 ` [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Andrii Nakryiko
@ 2019-08-02 20:16 ` Stanislav Fomichev
0 siblings, 0 replies; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-02 20:16 UTC (permalink / raw)
To: Andrii Nakryiko
Cc: Stanislav Fomichev, netdev, bpf, davem, ast, daniel, andrii.nakryiko
On 08/02, Andrii Nakryiko wrote:
>
> On 8/2/19 10:17 AM, Stanislav Fomichev wrote:
> > I was looking into converting test_sockops* to test_progs framework
> > and that requires using cgroup_helpers.c which rely on stdio/stderr.
> > Let's use open_memstream to override stdout into buffer during
> > subtests instead of custom test_{v,}printf wrappers. That lets
> > us continue to use stdio in the subtests and dump it on failure
> > if required.
> >
> > That would also fix bpf_find_map which currently uses printf to
> > signal failure (missed during test_printf conversion).
> I wonder if we should hijack stderr as well?
I was planning to do it when I add cgroup_helpers support because they
log to stderr. Wanted to keep the changes minimal. But let's do
them all in this series while we are it.
> > Cc: Andrii Nakryiko <andriin@fb.com>
> >
> > Stanislav Fomichev (3):
> > selftests/bpf: test_progs: switch to open_memstream
> > selftests/bpf: test_progs: test__printf -> printf
> > selftests/bpf: test_progs: drop extra trailing tab
> >
> > .../bpf/prog_tests/bpf_verif_scale.c | 4 +-
> > .../selftests/bpf/prog_tests/l4lb_all.c | 2 +-
> > .../selftests/bpf/prog_tests/map_lock.c | 10 +-
> > .../selftests/bpf/prog_tests/send_signal.c | 4 +-
> > .../selftests/bpf/prog_tests/spinlock.c | 2 +-
> > .../bpf/prog_tests/stacktrace_build_id.c | 4 +-
> > .../bpf/prog_tests/stacktrace_build_id_nmi.c | 4 +-
> > .../selftests/bpf/prog_tests/xdp_noinline.c | 4 +-
> > tools/testing/selftests/bpf/test_progs.c | 116 +++++++-----------
> > tools/testing/selftests/bpf/test_progs.h | 12 +-
> > 10 files changed, 68 insertions(+), 94 deletions(-)
> >
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream
2019-08-02 20:14 ` Stanislav Fomichev
@ 2019-08-03 6:00 ` Andrii Nakryiko
2019-08-05 15:12 ` Stanislav Fomichev
0 siblings, 1 reply; 12+ messages in thread
From: Andrii Nakryiko @ 2019-08-03 6:00 UTC (permalink / raw)
To: Stanislav Fomichev
Cc: Andrii Nakryiko, Stanislav Fomichev, netdev, bpf, davem, ast, daniel
On Fri, Aug 2, 2019 at 1:14 PM Stanislav Fomichev <sdf@fomichev.me> wrote:
>
> On 08/02, Andrii Nakryiko wrote:
> > 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!
> One possible downside of using open_memstream is that it's glibc
> specific. I probably need to wrap it in #ifdef __GLIBC__ to make
> it work with other libcs and just print everything as it was before :-(.
> I'm not sure we care though.
Given this is selftests/bpf, it is probably OK.
>
> > > test_{v,}printf are now simple wrappers around stdout and will be
> > > removed in the next patch.
> > >
> > > Cc: Andrii Nakryiko <andriin@fb.com>
> > > Signed-off-by: Stanislav Fomichev <sdf@google.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.
> I'll rename it to log_size to match open_memstream args.
> We probably still need to do strlen because open_memstream can allocate
> bigger buffer to hold the data.
If I read man page correctly, env.log_cnt will be exactly the value
that strlen will return - number of actual bytes written (omitting
terminal zero), not number of pre-allocated bytes, thus I'm saying
that strlen is redundant. Please take a look again.
>
> > > +
> > > + 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.
> SG, will move to where we currently clear log_cnt, thanks!
>
> > > /* 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).
> Good point, will do.
>
> > > +}
> > > +
> > > +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?
> We can do that, my thinking was to limit the area of hijacking :-)
But why? We actually want to hijack stdout/stderr for entire duration
of all the tests. If test_progs needs some "infrastructural" mandatory
output, we have env.stdout/env.stderr for that.
> But that would work as well, less allocations per test, I guess. Will
> do.
>
> > > 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.
> Ack. See above, will rename to log_size, let me know if you disagree.
>
> > > int succ_cnt; /* successful tests */
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream
2019-08-03 6:00 ` Andrii Nakryiko
@ 2019-08-05 15:12 ` Stanislav Fomichev
0 siblings, 0 replies; 12+ messages in thread
From: Stanislav Fomichev @ 2019-08-05 15:12 UTC (permalink / raw)
To: Andrii Nakryiko
Cc: Andrii Nakryiko, Stanislav Fomichev, netdev, bpf, davem, ast, daniel
On 08/02, Andrii Nakryiko wrote:
> On Fri, Aug 2, 2019 at 1:14 PM Stanislav Fomichev <sdf@fomichev.me> wrote:
> >
> > On 08/02, Andrii Nakryiko wrote:
> > > 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!
> > One possible downside of using open_memstream is that it's glibc
> > specific. I probably need to wrap it in #ifdef __GLIBC__ to make
> > it work with other libcs and just print everything as it was before :-(.
> > I'm not sure we care though.
>
> Given this is selftests/bpf, it is probably OK.
>
> >
> > > > test_{v,}printf are now simple wrappers around stdout and will be
> > > > removed in the next patch.
> > > >
> > > > Cc: Andrii Nakryiko <andriin@fb.com>
> > > > Signed-off-by: Stanislav Fomichev <sdf@google.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.
> > I'll rename it to log_size to match open_memstream args.
> > We probably still need to do strlen because open_memstream can allocate
> > bigger buffer to hold the data.
>
> If I read man page correctly, env.log_cnt will be exactly the value
> that strlen will return - number of actual bytes written (omitting
> terminal zero), not number of pre-allocated bytes, thus I'm saying
> that strlen is redundant. Please take a look again.
Yeah, you're right, I've played with it a bit and it does return the
length of the data, not the (possibly bigger) size of the buffer.
Will fix in a v3 and use 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.
> > SG, will move to where we currently clear log_cnt, thanks!
> >
> > > > /* 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).
> > Good point, will do.
> >
> > > > +}
> > > > +
> > > > +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?
> > We can do that, my thinking was to limit the area of hijacking :-)
>
> But why? We actually want to hijack stdout/stderr for entire duration
> of all the tests. If test_progs needs some "infrastructural" mandatory
> output, we have env.stdout/env.stderr for that.
Oh, I agree, I've done just that for v2 that's already out.
I was just trying to justify my initial thinking :-)
> > But that would work as well, less allocations per test, I guess. Will
> > do.
> >
> > > > 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.
> > Ack. See above, will rename to log_size, let me know if you disagree.
> >
> > > > int succ_cnt; /* successful tests */
^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2019-08-05 15:12 UTC | newest]
Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-08-02 17:17 [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 1/3] selftests/bpf: test_progs: switch to open_memstream Stanislav Fomichev
2019-08-02 19:57 ` Andrii Nakryiko
2019-08-02 20:14 ` Stanislav Fomichev
2019-08-03 6:00 ` Andrii Nakryiko
2019-08-05 15:12 ` Stanislav Fomichev
2019-08-02 17:17 ` [PATCH bpf-next 2/3] selftests/bpf: test_progs: test__printf -> printf Stanislav Fomichev
2019-08-02 19:59 ` Andrii Nakryiko
2019-08-02 17:17 ` [PATCH bpf-next 3/3] selftests/bpf: test_progs: drop extra trailing tab Stanislav Fomichev
2019-08-02 19:59 ` Andrii Nakryiko
2019-08-02 20:00 ` [PATCH bpf-next 0/3] selftests/bpf: switch test_progs back to stdio Andrii Nakryiko
2019-08-02 20:16 ` Stanislav Fomichev
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).