On Fri, 2022-08-26 at 16:15 -0700, Andrii Nakryiko wrote:
> Add a small tool, veristat, that allows mass-verification of
> a set of *libbpf-compatible* BPF ELF object files. For each such
> object
> file, veristat will attempt to verify each BPF program
> *individually*.
> Regardless of success or failure, it parses BPF verifier stats and
> outputs them in human-readable table format. In the future we can
> also
> add CSV and JSON output for more scriptable post-processing, if
> necessary.
>
> veristat allows to specify a set of stats that should be output and
> ordering between multiple objects and files (e.g., so that one can
> easily order by total instructions processed, instead of default file
> name, prog name, verdict, total instructions order).
>
> This tool should be useful for validating various BPF verifier
> changes
> or even validating different kernel versions for regressions.
>
> Here's an example for some of the heaviest selftests/bpf BPF object
> files:
>
> $ sudo ./veristat -s insns,file,prog
> {pyperf,loop,test_verif_scale,strobemeta,test_cls_redirect,profiler}*
> .linked3.o
> File
> Program Verdict Duration, us Total
> insns Total states Peak states
> ------------------------------------ -----------------------------
> ------- ------- ------------ ----------- ------------ ----------
> -
> loop3.linked3.o
> while_true failure 350990
> 1000001 9663 9663
> test_verif_scale3.linked3.o
> balancer_ingress success 115244
> 845499 8636 2141
> test_verif_scale2.linked3.o
> balancer_ingress success 77688
> 773445 3048 788
> pyperf600.linked3.o
> on_event success 2079872
> 624585 30335 30241
> pyperf600_nounroll.linked3.o
> on_event success 353972
> 568128 37101 2115
> strobemeta.linked3.o
> on_event success 455230
> 557149 15915 13537
> test_verif_scale1.linked3.o
> balancer_ingress success 89880
> 554754 8636 2141
> strobemeta_nounroll2.linked3.o
> on_event success 433906
> 501725 17087 1912
> loop6.linked3.o
> trace_virtqueue_add_sgs success 282205
> 398057 8717 919
> loop1.linked3.o
> nested_loops success 125630
> 361349 5504 5504
> pyperf180.linked3.o
> on_event success 2511740
> 160398 11470 11446
> pyperf100.linked3.o
> on_event success 744329
> 87681 6213 6191
> test_cls_redirect.linked3.o
> cls_redirect success 54087
> 78925 4782 903
> strobemeta_subprogs.linked3.o
> on_event success 57898
> 65420 1954 403
> test_cls_redirect_subprogs.linked3.o
> cls_redirect success 54522
> 64965 4619 958
> strobemeta_nounroll1.linked3.o
> on_event success 43313
> 57240 1757 382
> pyperf50.linked3.o
> on_event success 194355
> 46378 3263 3241
> profiler2.linked3.o
> tracepoint__syscalls__sys_enter_kill success 23869
> 43372 1423 542
> pyperf_subprogs.linked3.o
> on_event success 29179
> 36358 2499 2499
> profiler1.linked3.o
> tracepoint__syscalls__sys_enter_kill success 13052
> 27036 1946 936
> profiler3.linked3.o
> tracepoint__syscalls__sys_enter_kill success 21023
> 26016 2186 915
> profiler2.linked3.o
> kprobe__vfs_link success 5255
> 13896 303 271
> profiler1.linked3.o
> kprobe__vfs_link success 7792
> 12687 1042 1041
> profiler3.linked3.o
> kprobe__vfs_link success 7332
> 10601 865 865
> profiler2.linked3.o
> kprobe_ret__do_filp_open success 3417
> 8900 216 199
> profiler2.linked3.o
> kprobe__vfs_symlink success 3548
> 8775 203 186
> pyperf_global.linked3.o
> on_event success 10007
> 7563 520 520
> profiler3.linked3.o
> kprobe_ret__do_filp_open success 4708
> 6464 532 532
> profiler1.linked3.o
> kprobe_ret__do_filp_open success 3090
> 6445 508 508
> profiler3.linked3.o
> kprobe__vfs_symlink success 4477
> 6358 521 521
> profiler1.linked3.o
> kprobe__vfs_symlink success 3381
> 6347 507 507
> profiler2.linked3.o
> raw_tracepoint__sched_process_exec success 2464
> 5874 292 189
> profiler3.linked3.o
> raw_tracepoint__sched_process_exec success 2677
> 4363 397 283
> profiler2.linked3.o
> kprobe__proc_sys_write success 1800
> 4355 143 138
> profiler1.linked3.o
> raw_tracepoint__sched_process_exec success 1649
> 4019 333 240
> pyperf600_bpf_loop.linked3.o
> on_event success 2711
> 3966 306 306
> profiler2.linked3.o
> raw_tracepoint__sched_process_exit success 1234
> 3138 83 66
> profiler3.linked3.o
> kprobe__proc_sys_write success 1755
> 2623 223 223
> profiler1.linked3.o
> kprobe__proc_sys_write success 1222
> 2456 193 193
> loop2.linked3.o
> while_true success 608
> 1783 57 30
> profiler3.linked3.o
> raw_tracepoint__sched_process_exit success 789
> 1680 146 146
> profiler1.linked3.o
> raw_tracepoint__sched_process_exit success 592
> 1526 133 133
> strobemeta_bpf_loop.linked3.o
> on_event success 1015
> 1512 106 106
> loop4.linked3.o
> combinations success 165
> 524 18 17
> profiler3.linked3.o
> raw_tracepoint__sched_process_fork success 196
> 299 25 25
> profiler1.linked3.o
> raw_tracepoint__sched_process_fork success 109
> 265 19 19
> profiler2.linked3.o
> raw_tracepoint__sched_process_fork success 111
> 265 19 19
> loop5.linked3.o
> while_true success 47
> 84 9 9
> ------------------------------------ -----------------------------
> ------- ------- ------------ ----------- ------------ ----------
> -
>
> Signed-off-by: Andrii Nakryiko <andrii@xxxxxxxxxx>
> ---
> tools/testing/selftests/bpf/.gitignore | 1 +
> tools/testing/selftests/bpf/Makefile | 6 +-
> tools/testing/selftests/bpf/veristat.c | 541
> +++++++++++++++++++++++++
> 3 files changed, 547 insertions(+), 1 deletion(-)
> create mode 100644 tools/testing/selftests/bpf/veristat.c
>
> diff --git a/tools/testing/selftests/bpf/.gitignore
> b/tools/testing/selftests/bpf/.gitignore
> index 3a8cb2404ea6..3b288562963e 100644
> --- a/tools/testing/selftests/bpf/.gitignore
> +++ b/tools/testing/selftests/bpf/.gitignore
> @@ -39,6 +39,7 @@ test_cpp
> /tools
> /runqslower
> /bench
> +/veristat
> *.ko
> *.tmp
> xskxceiver
[...]
> +
> +static int process_prog(const char *filename, struct bpf_object
> *obj, struct bpf_program *prog)
> +{
> + const char *prog_name = bpf_program__name(prog);
> + size_t buf_sz = sizeof(verif_log_buf);
> + char *buf = verif_log_buf;
> + struct verif_stats *stats;
> + int err = 0;
> + void *tmp;
> +
> + tmp = realloc(env.prog_stats, (env.prog_stat_cnt + 1) *
> sizeof(*env.prog_stats));
> + if (!tmp)
> + return -ENOMEM;
> + env.prog_stats = tmp;
> + stats = &env.prog_stats[env.prog_stat_cnt++];
> + memset(stats, 0, sizeof(*stats));
> +
> + if (env.verbose) {
> + buf_sz = 16 * 1024 * 1024;
> + buf = malloc(buf_sz);
> + if (!buf)
> + return -ENOMEM;
> + bpf_program__set_log_buf(prog, buf, buf_sz);
> + bpf_program__set_log_level(prog, 1 | 4); /* stats +
> log */
> + } else {
> + bpf_program__set_log_buf(prog, buf, buf_sz);
> + bpf_program__set_log_level(prog, 4); /* only verifier
> stats */
> + }
> + verif_log_buf[0] = '\0';
> +
> + err = bpf_object__load(obj);
> +
> + stats->file_name = strdup(basename(filename));
> + stats->prog_name = strdup(bpf_program__name(prog));
> + stats->stats[VERDICT] = err == 0; /* 1 - success, 0 - failure
> */
> + parse_verif_log(buf, buf_sz, stats);
> +
> + if (env.verbose) {
> + printf("PROCESSING %s/%s, DURATION US: %ld, VERDICT:
> %s, VERIFIER LOG:\n%s\n",
> + filename, prog_name, stats->stats[DURATION],
> + err ? "failure" : "success", buf);
> + }
> +
> + if (verif_log_buf != buf)
> + free(buf);
> +
> + return 0;
> +};
> +
> +static int process_obj(const char *filename)
> +{
> + struct bpf_object *obj = NULL, *tobj;
> + struct bpf_program *prog, *tprog, *lprog;
> + libbpf_print_fn_t old_libbpf_print_fn;
> + LIBBPF_OPTS(bpf_object_open_opts, opts);
> + int err = 0, prog_cnt = 0;
> +
> + old_libbpf_print_fn = libbpf_set_print(libbpf_print_fn);
> +
> + obj = bpf_object__open_file(filename, &opts);
> + if (!obj) {
> + err = -errno;
> + fprintf(stderr, "Failed to open '%s': %d\n",
> filename, err);
> + goto cleanup;
> + }
> +
> + bpf_object__for_each_program(prog, obj) {
> + prog_cnt++;
> + }
> +
> + if (prog_cnt == 1) {
> + prog = bpf_object__next_program(obj, NULL);
> + bpf_program__set_autoload(prog, true);
> + process_prog(filename, obj, prog);
> + bpf_object__close(obj);
> + goto cleanup;
> + }
> +
> + bpf_object__for_each_program(prog, obj) {
> + const char *prog_name = bpf_program__name(prog);
> +
> + tobj = bpf_object__open_file(filename, &opts);
> + if (!tobj) {
> + err = -errno;
> + fprintf(stderr, "Failed to open '%s': %d\n",
> filename, err);
> + goto cleanup;
> + }
> +
> + bpf_object__for_each_program(tprog, tobj) {
> + const char *tprog_name =
> bpf_program__name(tprog);
> +
> + if (strcmp(prog_name, tprog_name) == 0) {
> + bpf_program__set_autoload(tprog,
> true);
> + lprog = tprog;
> + } else {
> + bpf_program__set_autoload(tprog,
> false);
> + }
> + }
> +
> + process_prog(filename, tobj, lprog);
> + bpf_object__close(tobj);
> + }
It leaks obj.
> > +
> +cleanup:
> + libbpf_set_print(old_libbpf_print_fn);
> + return err;
> +}
> +
> +static int cmp_stat(const struct verif_stats *s1, const struct
> verif_stats *s2,
> + enum stat_id id, bool asc)
> +{
> + int cmp = 0;
> +
> + switch (id) {
> + case FILE_NAME:
> + cmp = strcmp(s1->file_name, s2->file_name);
> + break;
> + case PROG_NAME:
> + cmp = strcmp(s1->prog_name, s2->prog_name);
> + break;
> + case VERDICT:
> + case DURATION:
> + case TOTAL_INSNS:
> + case TOTAL_STATES:
> + case PEAK_STATES:
> + case MAX_STATES_PER_INSN:
> + case MARK_READ_MAX_LEN: {
> + long v1 = s1->stats[id];
> + long v2 = s2->stats[id];
> +
> + if (v1 != v2)
> + cmp = v1 < v2 ? -1 : 1;
> + break;
> + }
> + default:
> + fprintf(stderr, "Unrecognized stat #%d\n", id);
> + exit(1);
> + }
> +
> + return asc ? cmp : -cmp;
> +}
> +
> +static int cmp_prog_stats(const void *v1, const void *v2)
> +{
> + const struct verif_stats *s1 = v1, *s2 = v2;
> + int i, cmp;
> +
> + for (i = 0; i < env.sort_spec.spec_cnt; i++) {
> + cmp = cmp_stat(s1, s2, env.sort_spec.ids[i],
> env.sort_spec.asc[i]);
> + if (cmp != 0)
> + return cmp;
> + }
> +
> + return 0;
> +}
> +
> +#define snappendf(dst, len, fmt,
> args...) \
> + len += snprintf(dst +
> len, \
> + sizeof(dst) < len ? 0 : sizeof(dst) -
> len, \
> + fmt, ##args)
Never been used?
> +
> +#define HEADER_CHAR '-'
> +#define COLUMN_SEP " "
> +
> +static void output_headers(bool calc_len)
> +{
> + int i, len;
> +
> + for (i = 0; i < env.output_spec.spec_cnt; i++) {
> + int id = env.output_spec.ids[i];
> + int *max_len = &env.output_spec.lens[i];
> +
> + if (calc_len) {
> + len = snprintf(NULL, 0, "%s",
> stat_defs[id].header);
Is there any reason to no use strlen()?
It would be ok to merge this block to one line since this function is
always called exactly once before output_stats() with calc_len being
true. For example,
*max_len = strlen(...)
> + if (len > *max_len)
> + *max_len = len;
> + } else {
> + printf("%s%-*s", i == 0 ? "" : COLUMN_SEP,
> *max_len, stat_defs[id].header);
> + }
> + }
> +
> + if (!calc_len)
> + printf("\n");
> +}
> +
> +static void output_lines(void)
lines? It is confusing for me since it always prints exactly one line.
How about something like output_sep_line()?
> +{
> + int i, j, len;
> +
> + for (i = 0; i < env.output_spec.spec_cnt; i++) {
> + len = env.output_spec.lens[i];
> +
> + printf("%s", i == 0 ? "" : COLUMN_SEP);
> + for (j = 0; j < len; j++)
> + printf("%c", HEADER_CHAR);
> + }
> + printf("\n");
> +}
> +
> +static void output_stats(const struct verif_stats *s, bool calc_len)
> +{
> + int i;
> +
> + for (i = 0; i < env.output_spec.spec_cnt; i++) {
> + int id = env.output_spec.ids[i];
> + int *max_len = &env.output_spec.lens[i], len;
> + const char *str = NULL;
> + long val = 0;
> +
> + switch (id) {
> + case FILE_NAME:
> + str = s->file_name;
> + break;
> + case PROG_NAME:
> + str = s->prog_name;
> + break;
> + case VERDICT:
> + str = s->stats[VERDICT] ? "success" :
> "failure";
> + break;
> + case DURATION:
> + case TOTAL_INSNS:
> + case TOTAL_STATES:
> + case PEAK_STATES:
> + case MAX_STATES_PER_INSN:
> + case MARK_READ_MAX_LEN:
> + val = s->stats[id];
> + break;
> + default:
> + fprintf(stderr, "Unrecognized stat #%d\n",
> id);
> + exit(1);
> + }
> +
> + if (calc_len) {
> + if (str)
> + len = snprintf(NULL, 0, "%s", str);
> + else
> + len = snprintf(NULL, 0, "%ld", val);
> + if (len > *max_len)
> + *max_len = len;
> + } else {
> + if (str)
> + printf("%s%-*s", i == 0 ? "" :
> COLUMN_SEP, *max_len, str);
> + else
> + printf("%s%*ld", i == 0 ? "" :
> COLUMN_SEP, *max_len, val);
> + }
> + }
> +
> + if (!calc_len)
> + printf("\n");
> +}
> +
> +int main(int argc, char **argv)
> +{
> + static const struct argp argp = {
> + .options = opts,
> + .parser = parse_arg,
> + .doc = argp_program_doc,
> + };
> + int err = 0, i;
> +
> + if (argp_parse(&argp, argc, argv, 0, NULL, NULL))
> + return 1;
> +
> + if (env.filename_cnt == 0) {
> + fprintf(stderr, "Please provide path to BPF object
> file!\n");
> + argp_help(&argp, stderr, ARGP_HELP_USAGE,
> "veristat");
> + return 1;
> + }
> +
> + if (env.output_spec.spec_cnt == 0)
> + env.output_spec = default_output_spec;
> + if (env.sort_spec.spec_cnt == 0)
> + env.sort_spec = default_sort_spec;
> +
> + for (i = 0; i < env.filename_cnt; i++) {
> + err = process_obj(env.filenames[i]);
> + if (err) {
> + fprintf(stderr, "Failed to process '%s':
> %d\n", env.filenames[i], err);
> + goto cleanup;
> + }
> + }
> +
> + qsort(env.prog_stats, env.prog_stat_cnt,
> sizeof(*env.prog_stats), cmp_prog_stats);
> +
> + /* calculate column widths */
> + output_headers(true);
> + for (i = 0; i < env.prog_stat_cnt; i++) {
> + output_stats(&env.prog_stats[i], true);
> + }
> +
> + /* actually output the table */
> + output_headers(false);
> + output_lines();
> + for (i = 0; i < env.prog_stat_cnt; i++) {
> + output_stats(&env.prog_stats[i], false);
> + }
> + output_lines();
> + printf("\n");
> +
> + printf("Done. Processed %d object files, %d programs.\n",
> + env.filename_cnt, env.prog_stat_cnt);
> +
> +cleanup:
> + for (i = 0; i < env.prog_stat_cnt; i++) {
> + free(env.prog_stats[i].file_name);
> + free(env.prog_stats[i].prog_name);
> + }
> + free(env.prog_stats);
> + for (i = 0; i < env.filename_cnt; i++)
> + free(env.filenames[i]);
> + free(env.filenames);
> + return -err;
> +}
