selftests/bpf: Integrate verbose verifier log into test_progs

Add exra level of verboseness, activated by -vvv argument. When -vv is
specified, verbose libbpf and verifier log (level 1) is output, even for
successful tests. With -vvv, verifier log goes to level 2.

This is extremely useful to debug verifier failures, as well as just see the
state and flow of verification. Before this, you'd have to go and modify
load_program()'s source code inside libbpf to specify extra log_level flags,
which is suboptimal to say the least.

Currently -vv and -vvv triggering verifier output is integrated into
test_stub's bpf_prog_load as well as bpf_verif_scale.c tests.

Signed-off-by: Andrii Nakryiko <andriin@fb.com>
Signed-off-by: Alexei Starovoitov <ast@kernel.org>
Link: https://lore.kernel.org/bpf/20191120003548.4159797-1-andriin@fb.com

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 1c01ee2600a97ce02a0b622dc51f21c30b5c3e07..9486c13af6b2cb697107de857a86d27d0809f987 100644 (file)
--- a/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
+++ b/tools/testing/selftests/bpf/prog_tests/bpf_verif_scale.c
@@ -15,6 +15,8 @@ static int libbpf_debug_print(enum libbpf_print_level level,
        return 0;
 }
 
+extern int extra_prog_load_log_flags;
+
 static int check_load(const char *file, enum bpf_prog_type type)
 {
        struct bpf_prog_load_attr attr;
@@ -24,7 +26,7 @@ static int check_load(const char *file, enum bpf_prog_type type)
        memset(&attr, 0, sizeof(struct bpf_prog_load_attr));
        attr.file = file;
        attr.prog_type = type;
-       attr.log_level = 4;
+       attr.log_level = 4 | extra_prog_load_log_flags;
        attr.prog_flags = BPF_F_TEST_RND_HI32;
        err = bpf_prog_load_xattr(&attr, &obj, &prog_fd);
        bpf_object__close(obj);

diff --git a/tools/testing/selftests/bpf/test_progs.c b/tools/testing/selftests/bpf/test_progs.c
index a05a807840c0ec2c9f2e7d809afc765940a7e7dd..7fa7d08a8104d3359124f753c5a533e7c22d3070 100644 (file)
--- a/tools/testing/selftests/bpf/test_progs.c
+++ b/tools/testing/selftests/bpf/test_progs.c
@@ -45,7 +45,7 @@ static void dump_test_log(const struct prog_test_def *test, bool failed)
 
        fflush(stdout); /* exports env.log_buf & env.log_cnt */
 
-       if (env.verbose || test->force_log || failed) {
+       if (env.verbosity > VERBOSE_NONE || test->force_log || failed) {
                if (env.log_cnt) {
                        env.log_buf[env.log_cnt] = '\0';
                        fprintf(env.stdout, "%s", env.log_buf);
@@ -346,14 +346,14 @@ static const struct argp_option opts[] = {
        { "verifier-stats", ARG_VERIFIER_STATS, NULL, 0,
          "Output verifier statistics", },
        { "verbose", ARG_VERBOSE, "LEVEL", OPTION_ARG_OPTIONAL,
-         "Verbose output (use -vv for extra verbose output)" },
+         "Verbose output (use -vv or -vvv for progressively verbose output)" },
        {},
 };
 
 static int libbpf_print_fn(enum libbpf_print_level level,
                           const char *format, va_list args)
 {
-       if (!env.very_verbose && level == LIBBPF_DEBUG)
+       if (env.verbosity < VERBOSE_VERY && level == LIBBPF_DEBUG)
                return 0;
        vprintf(format, args);
        return 0;
@@ -419,6 +419,8 @@ int parse_num_list(const char *s, struct test_selector *sel)
        return 0;
 }
 
+extern int extra_prog_load_log_flags;
+
 static error_t parse_arg(int key, char *arg, struct argp_state *state)
 {
        struct test_env *env = state->input;
@@ -460,9 +462,14 @@ static error_t parse_arg(int key, char *arg, struct argp_state *state)
                env->verifier_stats = true;
                break;
        case ARG_VERBOSE:
+               env->verbosity = VERBOSE_NORMAL;
                if (arg) {
                        if (strcmp(arg, "v") == 0) {
-                               env->very_verbose = true;
+                               env->verbosity = VERBOSE_VERY;
+                               extra_prog_load_log_flags = 1;
+                       } else if (strcmp(arg, "vv") == 0) {
+                               env->verbosity = VERBOSE_SUPER;
+                               extra_prog_load_log_flags = 2;
                        } else {
                                fprintf(stderr,
                                        "Unrecognized verbosity setting ('%s'), only -v and -vv are supported\n",
@@ -470,7 +477,6 @@ static error_t parse_arg(int key, char *arg, struct argp_state *state)
                                return -EINVAL;
                        }
                }
-               env->verbose = true;
                break;
        case ARGP_KEY_ARG:
                argp_usage(state);
@@ -489,7 +495,7 @@ static void stdio_hijack(void)
        env.stdout = stdout;
        env.stderr = stderr;
 
-       if (env.verbose) {
+       if (env.verbosity > VERBOSE_NONE) {
                /* nothing to do, output to stdout by default */
                return;
        }

diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
index 0c48f64f732b2cd2934693807d3977cfeb913af5..8477df8359793802f2ee14e8f035b0773ba35953 100644 (file)
--- a/tools/testing/selftests/bpf/test_progs.h
+++ b/tools/testing/selftests/bpf/test_progs.h
@@ -39,6 +39,13 @@ typedef __u16 __sum16;
 #include "trace_helpers.h"
 #include "flow_dissector_load.h"
 
+enum verbosity {
+       VERBOSE_NONE,
+       VERBOSE_NORMAL,
+       VERBOSE_VERY,
+       VERBOSE_SUPER,
+};
+
 struct test_selector {
        const char *name;
        bool *num_set;
@@ -49,8 +56,7 @@ struct test_env {
        struct test_selector test_selector;
        struct test_selector subtest_selector;
        bool verifier_stats;
-       bool verbose;
-       bool very_verbose;
+       enum verbosity verbosity;
 
        bool jit_enabled;
 

diff --git a/tools/testing/selftests/bpf/test_stub.c b/tools/testing/selftests/bpf/test_stub.c
index 84e81a89e2f97129ba608f858d8bd1ea7c0d3086..47e1327262034601cdf256d54152cc383a0a3338 100644 (file)
--- a/tools/testing/selftests/bpf/test_stub.c
+++ b/tools/testing/selftests/bpf/test_stub.c
@@ -5,6 +5,8 @@
 #include <bpf/libbpf.h>
 #include <string.h>
 
+int extra_prog_load_log_flags = 0;
+
 int bpf_prog_test_load(const char *file, enum bpf_prog_type type,
                       struct bpf_object **pobj, int *prog_fd)
 {
@@ -15,6 +17,7 @@ int bpf_prog_test_load(const char *file, enum bpf_prog_type type,
        attr.prog_type = type;
        attr.expected_attach_type = 0;
        attr.prog_flags = BPF_F_TEST_RND_HI32;
+       attr.log_level = extra_prog_load_log_flags;
 
        return bpf_prog_load_xattr(&attr, pobj, prog_fd);
 }
@@ -35,6 +38,7 @@ int bpf_test_load_program(enum bpf_prog_type type, const struct bpf_insn *insns,
        load_attr.license = license;
        load_attr.kern_version = kern_version;
        load_attr.prog_flags = BPF_F_TEST_RND_HI32;
+       load_attr.log_level = extra_prog_load_log_flags;
 
        return bpf_load_program_xattr(&load_attr, log_buf, log_buf_sz);
 }