bpf: change logging scheme for live stack analysis

Instead of breadcrumbs like:

  (d2,cs15) frame 0 insn 18 +live -16
  (d2,cs15) frame 0 insn 17 +live -16

Print final accumulated stack use/def data per-func_instance
per-instruction. printed func_instance's are ordered by callsite and
depth. For example:

  stack use/def subprog#0 shared_instance_must_write_overwrite (d0,cs0):
    0: (b7) r1 = 1
    1: (7b) *(u64 *)(r10 -8) = r1        ; def: fp0-8
    2: (7b) *(u64 *)(r10 -16) = r1       ; def: fp0-16
    3: (bf) r1 = r10
    4: (07) r1 += -8
    5: (bf) r2 = r10
    6: (07) r2 += -16
    7: (85) call pc+7                    ; use: fp0-8 fp0-16
    8: (bf) r1 = r10
    9: (07) r1 += -16
   10: (bf) r2 = r10
   11: (07) r2 += -8
   12: (85) call pc+2                    ; use: fp0-8 fp0-16
   13: (b7) r0 = 0
   14: (95) exit
  stack use/def subprog#1 forwarding_rw (d1,cs7):
   15: (85) call pc+1                    ; use: fp0-8 fp0-16
   16: (95) exit
  stack use/def subprog#1 forwarding_rw (d1,cs12):
   15: (85) call pc+1                    ; use: fp0-8 fp0-16
   16: (95) exit
  stack use/def subprog#2 write_first_read_second (d2,cs15):
   17: (7a) *(u64 *)(r1 +0) = 42
   18: (79) r0 = *(u64 *)(r2 +0)         ; use: fp0-8 fp0-16
   19: (95) exit

For groups of three or more consecutive stack slots, abbreviate as
follows:

   25: (85) call bpf_loop#181            ; use: fp2-8..-512 fp1-8..-512 fp0-8..-512

Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
Link: https://lore.kernel.org/r/20260410-patch-set-v4-10-5d4eecb343db@gmail.com
Signed-off-by: Alexei Starovoitov <ast@kernel.org>

diff --git a/include/linux/bpf_verifier.h b/include/linux/bpf_verifier.h
index d7fbc0e1559b51b215b858bb38cb83aacd8f878a..d3dc46aae2e71db64448c2050720e92d421f3063 100644 (file)
--- a/include/linux/bpf_verifier.h
+++ b/include/linux/bpf_verifier.h
@@ -256,11 +256,6 @@ static inline spis_t spis_and(spis_t a, spis_t b)
        return (spis_t){{ a.v[0] & b.v[0], a.v[1] & b.v[1] }};
 }
 
-static inline spis_t spis_xor(spis_t a, spis_t b)
-{
-       return (spis_t){{ a.v[0] ^ b.v[0], a.v[1] ^ b.v[1] }};
-}
-
 static inline spis_t spis_not(spis_t s)
 {
        return (spis_t){{ ~s.v[0], ~s.v[1] }};

diff --git a/kernel/bpf/liveness.c b/kernel/bpf/liveness.c
index e797f8f76bc768016b8e46d8e7fb2060c70cd484..9bb6574d73feb97c094453175b4cb3655e11ead4 100644 (file)
--- a/kernel/bpf/liveness.c
+++ b/kernel/bpf/liveness.c
@@ -6,6 +6,7 @@
 #include <linux/hashtable.h>
 #include <linux/jhash.h>
 #include <linux/slab.h>
+#include <linux/sort.h>
 
 #define verbose(env, fmt, args...) bpf_verifier_log_write(env, fmt, ##args)
 
@@ -197,64 +198,6 @@ static int mark_stack_write(struct func_instance *instance, u32 frame, u32 insn_
        return 0;
 }
 
-static char *fmt_instance(struct bpf_verifier_env *env, struct func_instance *instance)
-{
-       snprintf(env->tmp_str_buf, sizeof(env->tmp_str_buf),
-                "(d%d,cs%d)", instance->depth, instance->callsite);
-       return env->tmp_str_buf;
-}
-
-/*
- * When both halves of an 8-byte SPI are set, print as "-8","-16",...
- * When only one half is set, print as "-4h","-8h",...
- */
-static void bpf_fmt_spis_mask(char *buf, ssize_t buf_sz, spis_t spis)
-{
-       bool first = true;
-       int spi, n;
-
-       buf[0] = '\0';
-
-       for (spi = 0; spi < STACK_SLOTS / 2 && buf_sz > 0; spi++) {
-               bool lo = spis_test_bit(spis, spi * 2);
-               bool hi = spis_test_bit(spis, spi * 2 + 1);
-
-               if (!lo && !hi)
-                       continue;
-               n = snprintf(buf, buf_sz, "%s%d%s",
-                            first ? "" : ",",
-                            -(spi + 1) * BPF_REG_SIZE + (lo && !hi ? BPF_HALF_REG_SIZE : 0),
-                            lo && hi ? "" : "h");
-               first = false;
-               buf += n;
-               buf_sz -= n;
-       }
-}
-
-static void log_mask_change(struct bpf_verifier_env *env, struct func_instance *instance,
-                           char *pfx, u32 frame, u32 insn_idx,
-                           spis_t old, spis_t new)
-{
-       spis_t changed_bits, new_ones, new_zeros;
-
-       changed_bits = spis_xor(old, new);
-       new_ones = spis_and(new, changed_bits);
-       new_zeros = spis_and(spis_not(new), changed_bits);
-
-       if (spis_is_zero(changed_bits))
-               return;
-       bpf_log(&env->log, "%s frame %d insn %d ", fmt_instance(env, instance), frame, insn_idx);
-       if (!spis_is_zero(new_ones)) {
-               bpf_fmt_spis_mask(env->tmp_str_buf, sizeof(env->tmp_str_buf), new_ones);
-               bpf_log(&env->log, "+%s %s ", pfx, env->tmp_str_buf);
-       }
-       if (!spis_is_zero(new_zeros)) {
-               bpf_fmt_spis_mask(env->tmp_str_buf, sizeof(env->tmp_str_buf), new_zeros);
-               bpf_log(&env->log, "-%s %s", pfx, env->tmp_str_buf);
-       }
-       bpf_log(&env->log, "\n");
-}
-
 int bpf_jmp_offset(struct bpf_insn *insn)
 {
        u8 code = insn->code;
@@ -330,7 +273,6 @@ __diag_pop();
 static inline bool update_insn(struct bpf_verifier_env *env,
                               struct func_instance *instance, u32 frame, u32 insn_idx)
 {
-       struct bpf_insn_aux_data *aux = env->insn_aux_data;
        spis_t new_before, new_after;
        struct per_frame_masks *insn, *succ_insn;
        struct bpf_iarray *succ;
@@ -357,13 +299,6 @@ static inline bool update_insn(struct bpf_verifier_env *env,
        new_before = spis_or(spis_and(new_after, spis_not(insn->must_write)),
                             insn->may_read);
        changed |= !spis_equal(new_before, insn->live_before);
-       if (unlikely(env->log.level & BPF_LOG_LEVEL2) &&
-           (!spis_is_zero(insn->may_read) || !spis_is_zero(insn->must_write) ||
-            insn_idx == instance->subprog_start ||
-            aux[insn_idx].prune_point)) {
-               log_mask_change(env, instance, "live",
-                               frame, insn_idx, insn->live_before, new_before);
-       }
        insn->live_before = new_before;
        return changed;
 }
@@ -393,10 +328,6 @@ static void update_instance(struct bpf_verifier_env *env, struct func_instance *
                                changed |= update_insn(env, instance, frame, insn_postorder[i]);
                }
        } while (changed);
-
-       if (env->log.level & BPF_LOG_LEVEL2)
-               bpf_log(&env->log, "%s live stack update done in %d iterations\n",
-                       fmt_instance(env, instance), cnt);
 }
 
 static bool is_live_before(struct func_instance *instance, u32 insn_idx, u32 frameno, u32 half_spi)
@@ -476,6 +407,166 @@ bool bpf_stack_slot_alive(struct bpf_verifier_env *env, u32 frameno, u32 half_sp
        return false;
 }
 
+static char *fmt_subprog(struct bpf_verifier_env *env, int subprog)
+{
+       const char *name = env->subprog_info[subprog].name;
+
+       snprintf(env->tmp_str_buf, sizeof(env->tmp_str_buf),
+                "subprog#%d%s%s", subprog, name ? " " : "", name ? name : "");
+       return env->tmp_str_buf;
+}
+
+static char *fmt_instance(struct bpf_verifier_env *env, struct func_instance *instance)
+{
+       snprintf(env->tmp_str_buf, sizeof(env->tmp_str_buf),
+                "(d%d,cs%d)", instance->depth, instance->callsite);
+       return env->tmp_str_buf;
+}
+
+static int spi_off(int spi)
+{
+       return -(spi + 1) * BPF_REG_SIZE;
+}
+
+/*
+ * When both halves of an 8-byte SPI are set, print as "-8","-16",...
+ * When only one half is set, print as "-4h","-8h",...
+ * Runs of 3+ consecutive fully-set SPIs are collapsed: "fp0-8..-24"
+ */
+static char *fmt_spis_mask(struct bpf_verifier_env *env, int frame, bool first, spis_t spis)
+{
+       int buf_sz = sizeof(env->tmp_str_buf);
+       char *buf = env->tmp_str_buf;
+       int spi, n, run_start;
+
+       buf[0] = '\0';
+
+       for (spi = 0; spi < STACK_SLOTS / 2 && buf_sz > 0; spi++) {
+               bool lo = spis_test_bit(spis, spi * 2);
+               bool hi = spis_test_bit(spis, spi * 2 + 1);
+               const char *space = first ? "" : " ";
+
+               if (!lo && !hi)
+                       continue;
+
+               if (!lo || !hi) {
+                       /* half-spi */
+                       n = scnprintf(buf, buf_sz, "%sfp%d%d%s",
+                                     space, frame, spi_off(spi) + (lo ? STACK_SLOT_SZ : 0), "h");
+               } else if (spi + 2 < STACK_SLOTS / 2 &&
+                          spis_test_bit(spis, spi * 2 + 2) &&
+                          spis_test_bit(spis, spi * 2 + 3) &&
+                          spis_test_bit(spis, spi * 2 + 4) &&
+                          spis_test_bit(spis, spi * 2 + 5)) {
+                       /* 3+ consecutive full spis */
+                       run_start = spi;
+                       while (spi + 1 < STACK_SLOTS / 2 &&
+                              spis_test_bit(spis, (spi + 1) * 2) &&
+                              spis_test_bit(spis, (spi + 1) * 2 + 1))
+                               spi++;
+                       n = scnprintf(buf, buf_sz, "%sfp%d%d..%d",
+                                     space, frame, spi_off(run_start), spi_off(spi));
+               } else {
+                       /* just a full spi */
+                       n = scnprintf(buf, buf_sz, "%sfp%d%d", space, frame, spi_off(spi));
+               }
+               first = false;
+               buf += n;
+               buf_sz -= n;
+       }
+       return env->tmp_str_buf;
+}
+
+static void print_instance(struct bpf_verifier_env *env, struct func_instance *instance)
+{
+       int start = env->subprog_info[instance->subprog].start;
+       struct bpf_insn *insns = env->prog->insnsi;
+       struct per_frame_masks *masks;
+       int len = instance->insn_cnt;
+       int insn_idx, frame, i;
+       bool has_use, has_def;
+       u64 pos, insn_pos;
+
+       if (!(env->log.level & BPF_LOG_LEVEL2))
+               return;
+
+       verbose(env, "stack use/def %s ", fmt_subprog(env, instance->subprog));
+       verbose(env, "%s:\n", fmt_instance(env, instance));
+       for (i = 0; i < len; i++) {
+               insn_idx = start + i;
+               has_use = false;
+               has_def = false;
+               pos = env->log.end_pos;
+               verbose(env, "%3d: ", insn_idx);
+               bpf_verbose_insn(env, &insns[insn_idx]);
+               bpf_vlog_reset(&env->log, env->log.end_pos - 1); /* remove \n */
+               insn_pos = env->log.end_pos;
+               verbose(env, "%*c;", bpf_vlog_alignment(insn_pos - pos), ' ');
+               pos = env->log.end_pos;
+               verbose(env, " use: ");
+               for (frame = instance->depth; frame >= 0; --frame) {
+                       masks = get_frame_masks(instance, frame, insn_idx);
+                       if (!masks || spis_is_zero(masks->may_read))
+                               continue;
+                       verbose(env, "%s", fmt_spis_mask(env, frame, !has_use, masks->may_read));
+                       has_use = true;
+               }
+               if (!has_use)
+                       bpf_vlog_reset(&env->log, pos);
+               pos = env->log.end_pos;
+               verbose(env, " def: ");
+               for (frame = instance->depth; frame >= 0; --frame) {
+                       masks = get_frame_masks(instance, frame, insn_idx);
+                       if (!masks || spis_is_zero(masks->must_write))
+                               continue;
+                       verbose(env, "%s", fmt_spis_mask(env, frame, !has_def, masks->must_write));
+                       has_def = true;
+               }
+               if (!has_def)
+                       bpf_vlog_reset(&env->log, has_use ? pos : insn_pos);
+               verbose(env, "\n");
+               if (bpf_is_ldimm64(&insns[insn_idx]))
+                       i++;
+       }
+}
+
+static int cmp_instances(const void *pa, const void *pb)
+{
+       struct func_instance *a = *(struct func_instance **)pa;
+       struct func_instance *b = *(struct func_instance **)pb;
+       int dcallsite = (int)a->callsite - b->callsite;
+       int ddepth = (int)a->depth - b->depth;
+
+       if (dcallsite)
+               return dcallsite;
+       if (ddepth)
+               return ddepth;
+       return 0;
+}
+
+/* print use/def slots for all instances ordered by callsite first, then by depth */
+static int print_instances(struct bpf_verifier_env *env)
+{
+       struct func_instance *instance, **sorted_instances;
+       struct bpf_liveness *liveness = env->liveness;
+       int i, bkt, cnt;
+
+       cnt = 0;
+       hash_for_each(liveness->func_instances, bkt, instance, hl_node)
+               cnt++;
+       sorted_instances = kvmalloc_objs(*sorted_instances, cnt, GFP_KERNEL_ACCOUNT);
+       if (!sorted_instances)
+               return -ENOMEM;
+       cnt = 0;
+       hash_for_each(liveness->func_instances, bkt, instance, hl_node)
+               sorted_instances[cnt++] = instance;
+       sort(sorted_instances, cnt, sizeof(*sorted_instances), cmp_instances, NULL);
+       for (i = 0; i < cnt; i++)
+               print_instance(env, sorted_instances[i]);
+       kvfree(sorted_instances);
+       return 0;
+}
+
 /*
  * Per-register tracking state for compute_subprog_args().
  * Tracks which frame's FP a value is derived from
@@ -1363,12 +1454,7 @@ static void print_subprog_arg_access(struct bpf_verifier_env *env,
        if (!(env->log.level & BPF_LOG_LEVEL2))
                return;
 
-       verbose(env, "subprog#%d %s:\n", subprog,
-               env->prog->aux->func_info
-               ? btf_name_by_offset(env->prog->aux->btf,
-                                    btf_type_by_id(env->prog->aux->btf,
-                                                   env->prog->aux->func_info[subprog].type_id)->name_off)
-               : "");
+       verbose(env, "%s:\n", fmt_subprog(env, subprog));
        for (i = 0; i < len; i++) {
                int idx = start + i;
                bool has_extra = false;
@@ -1856,6 +1942,9 @@ int bpf_compute_subprog_arg_access(struct bpf_verifier_env *env)
                        goto out;
        }
 
+       if (env->log.level & BPF_LOG_LEVEL2)
+               err = print_instances(env);
+
 out:
        for (k = 0; k < insn_cnt; k++)
                kvfree(env->callsite_at_stack[k]);