bpf: Right align verifier states in verifier logs.
authorChristy Lee <christylee@fb.com>
Fri, 17 Dec 2021 03:42:45 +0000 (19:42 -0800)
committerAlexei Starovoitov <ast@kernel.org>
Fri, 17 Dec 2021 03:43:49 +0000 (19:43 -0800)
Make the verifier logs more readable, print the verifier states
on the corresponding instruction line. If the previous line was
not a bpf instruction, then print the verifier states on its own
line.

Before:

Validating test_pkt_access_subprog3() func#3...
86: R1=invP(id=0) R2=ctx(id=0,off=0,imm=0) R10=fp0
; int test_pkt_access_subprog3(int val, struct __sk_buff *skb)
86: (bf) r6 = r2
87: R2=ctx(id=0,off=0,imm=0) R6_w=ctx(id=0,off=0,imm=0)
87: (bc) w7 = w1
88: R1=invP(id=0) R7_w=invP(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
; return get_skb_len(skb) * get_skb_ifindex(val, skb, get_constant(123));
88: (bf) r1 = r6
89: R1_w=ctx(id=0,off=0,imm=0) R6_w=ctx(id=0,off=0,imm=0)
89: (85) call pc+9
Func#4 is global and valid. Skipping.
90: R0_w=invP(id=0)
90: (bc) w8 = w0
91: R0_w=invP(id=0) R8_w=invP(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
; return get_skb_len(skb) * get_skb_ifindex(val, skb, get_constant(123));
91: (b7) r1 = 123
92: R1_w=invP123
92: (85) call pc+65
Func#5 is global and valid. Skipping.
93: R0=invP(id=0)

After:

86: R1=invP(id=0) R2=ctx(id=0,off=0,imm=0) R10=fp0
; int test_pkt_access_subprog3(int val, struct __sk_buff *skb)
86: (bf) r6 = r2                      ; R2=ctx(id=0,off=0,imm=0) R6_w=ctx(id=0,off=0,imm=0)
87: (bc) w7 = w1                      ; R1=invP(id=0) R7_w=invP(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
; return get_skb_len(skb) * get_skb_ifindex(val, skb, get_constant(123));
88: (bf) r1 = r6                      ; R1_w=ctx(id=0,off=0,imm=0) R6_w=ctx(id=0,off=0,imm=0)
89: (85) call pc+9
Func#4 is global and valid. Skipping.
90: R0_w=invP(id=0)
90: (bc) w8 = w0                      ; R0_w=invP(id=0) R8_w=invP(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
; return get_skb_len(skb) * get_skb_ifindex(val, skb, get_constant(123));
91: (b7) r1 = 123                     ; R1_w=invP123
92: (85) call pc+65
Func#5 is global and valid. Skipping.
93: R0=invP(id=0)

Signed-off-by: Christy Lee <christylee@fb.com>
Acked-by: Andrii Nakryiko <andrii@kernel.org>
Signed-off-by: Alexei Starovoitov <ast@kernel.org>
include/linux/bpf_verifier.h
kernel/bpf/verifier.c
tools/testing/selftests/bpf/prog_tests/align.c

index c66f238c538dc8f7178d0917f0ba1315d5bc8b52..ee931398f311a97748c953b74544df684bcdc800 100644 (file)
@@ -388,6 +388,8 @@ static inline bool bpf_verifier_log_full(const struct bpf_verifier_log *log)
 #define BPF_LOG_LEVEL  (BPF_LOG_LEVEL1 | BPF_LOG_LEVEL2)
 #define BPF_LOG_MASK   (BPF_LOG_LEVEL | BPF_LOG_STATS)
 #define BPF_LOG_KERNEL (BPF_LOG_MASK + 1) /* kernel internal flag */
+#define BPF_LOG_MIN_ALIGNMENT 8U
+#define BPF_LOG_ALIGNMENT 40U
 
 static inline bool bpf_verifier_log_needed(const struct bpf_verifier_log *log)
 {
@@ -481,6 +483,7 @@ struct bpf_verifier_env {
        u32 scratched_regs;
        /* Same as scratched_regs but for stack slots */
        u64 scratched_stack_slots;
+       u32 prev_log_len, prev_insn_print_len;
 };
 
 __printf(2, 0) void bpf_verifier_vlog(struct bpf_verifier_log *log,
index ded6e816dcd96b2d1df12a9b9e4c110e1c803940..72c4a6bbb5bce7fefa5fc36703ca3c2d989e04b4 100644 (file)
@@ -797,6 +797,25 @@ static void print_verifier_state(struct bpf_verifier_env *env,
        mark_verifier_state_clean(env);
 }
 
+static inline u32 vlog_alignment(u32 pos)
+{
+       return round_up(max(pos + BPF_LOG_MIN_ALIGNMENT / 2, BPF_LOG_ALIGNMENT),
+                       BPF_LOG_MIN_ALIGNMENT) - pos - 1;
+}
+
+static void print_insn_state(struct bpf_verifier_env *env,
+                            const struct bpf_func_state *state)
+{
+       if (env->prev_log_len && env->prev_log_len == env->log.len_used) {
+               /* remove new line character */
+               bpf_vlog_reset(&env->log, env->prev_log_len - 1);
+               verbose(env, "%*c;", vlog_alignment(env->prev_insn_print_len), ' ');
+       } else {
+               verbose(env, "%d:", env->insn_idx);
+       }
+       print_verifier_state(env, state, false);
+}
+
 /* copy array src of length n * size bytes to dst. dst is reallocated if it's too
  * small to hold src. This is different from krealloc since we don't want to preserve
  * the contents of dst.
@@ -2725,10 +2744,10 @@ static int __mark_chain_precision(struct bpf_verifier_env *env, int regno,
                        reg->precise = true;
                }
                if (env->log.level & BPF_LOG_LEVEL) {
-                       print_verifier_state(env, func, false);
-                       verbose(env, "parent %s regs=%x stack=%llx marks\n",
+                       verbose(env, "parent %s regs=%x stack=%llx marks:",
                                new_marks ? "didn't have" : "already had",
                                reg_mask, stack_mask);
+                       print_verifier_state(env, func, true);
                }
 
                if (!reg_mask && !stack_mask)
@@ -3423,11 +3442,8 @@ static int check_mem_region_access(struct bpf_verifier_env *env, u32 regno,
        /* We may have adjusted the register pointing to memory region, so we
         * need to try adding each of min_value and max_value to off
         * to make sure our theoretical access will be safe.
-        */
-       if (env->log.level & BPF_LOG_LEVEL)
-               print_verifier_state(env, state, false);
-
-       /* The minimum value is only important with signed
+        *
+        * The minimum value is only important with signed
         * comparisons where we can't assume the floor of a
         * value is 0.  If we are using signed variables for our
         * index'es we need to make sure that whatever we use
@@ -9438,7 +9454,7 @@ static int check_cond_jmp_op(struct bpf_verifier_env *env,
                return -EACCES;
        }
        if (env->log.level & BPF_LOG_LEVEL)
-               print_verifier_state(env, this_branch->frame[this_branch->curframe], false);
+               print_insn_state(env, this_branch->frame[this_branch->curframe]);
        return 0;
 }
 
@@ -11306,19 +11322,12 @@ static int do_check(struct bpf_verifier_env *env)
                if (need_resched())
                        cond_resched();
 
-               if (env->log.level & BPF_LOG_LEVEL2 ||
-                   (env->log.level & BPF_LOG_LEVEL && do_print_state)) {
-                       if (env->log.level & BPF_LOG_LEVEL2) {
-                               if (verifier_state_scratched(env))
-                                       verbose(env, "%d:", env->insn_idx);
-                       } else {
-                               verbose(env, "\nfrom %d to %d%s:",
-                                       env->prev_insn_idx, env->insn_idx,
-                                       env->cur_state->speculative ?
-                                       " (speculative execution)" : "");
-                       }
-                       print_verifier_state(env, state->frame[state->curframe],
-                                            false);
+               if (env->log.level & BPF_LOG_LEVEL2 && do_print_state) {
+                       verbose(env, "\nfrom %d to %d%s:",
+                               env->prev_insn_idx, env->insn_idx,
+                               env->cur_state->speculative ?
+                               " (speculative execution)" : "");
+                       print_verifier_state(env, state->frame[state->curframe], true);
                        do_print_state = false;
                }
 
@@ -11329,9 +11338,15 @@ static int do_check(struct bpf_verifier_env *env)
                                .private_data   = env,
                        };
 
+                       if (verifier_state_scratched(env))
+                               print_insn_state(env, state->frame[state->curframe]);
+
                        verbose_linfo(env, env->insn_idx, "; ");
+                       env->prev_log_len = env->log.len_used;
                        verbose(env, "%d: ", env->insn_idx);
                        print_bpf_insn(&cbs, insn, env->allow_ptr_leaks);
+                       env->prev_insn_print_len = env->log.len_used - env->prev_log_len;
+                       env->prev_log_len = env->log.len_used;
                }
 
                if (bpf_prog_is_dev_bound(env->prog->aux)) {
index aeb2080a67f74d192effd06ef7a3955be115bd92..0ee29e11eaee212e0784286c308d60a0e78ce36b 100644 (file)
@@ -41,11 +41,11 @@ static struct bpf_align_test tests[] = {
                .matches = {
                        {0, "R1=ctx(id=0,off=0,imm=0)"},
                        {0, "R10=fp0"},
-                       {1, "R3_w=inv2"},
-                       {2, "R3_w=inv4"},
-                       {3, "R3_w=inv8"},
-                       {4, "R3_w=inv16"},
-                       {5, "R3_w=inv32"},
+                       {0, "R3_w=inv2"},
+                       {1, "R3_w=inv4"},
+                       {2, "R3_w=inv8"},
+                       {3, "R3_w=inv16"},
+                       {4, "R3_w=inv32"},
                },
        },
        {
@@ -69,17 +69,17 @@ static struct bpf_align_test tests[] = {
                .matches = {
                        {0, "R1=ctx(id=0,off=0,imm=0)"},
                        {0, "R10=fp0"},
-                       {1, "R3_w=inv1"},
-                       {2, "R3_w=inv2"},
-                       {3, "R3_w=inv4"},
-                       {4, "R3_w=inv8"},
-                       {5, "R3_w=inv16"},
-                       {6, "R3_w=inv1"},
-                       {7, "R4_w=inv32"},
-                       {8, "R4_w=inv16"},
-                       {9, "R4_w=inv8"},
-                       {10, "R4_w=inv4"},
-                       {11, "R4_w=inv2"},
+                       {0, "R3_w=inv1"},
+                       {1, "R3_w=inv2"},
+                       {2, "R3_w=inv4"},
+                       {3, "R3_w=inv8"},
+                       {4, "R3_w=inv16"},
+                       {5, "R3_w=inv1"},
+                       {6, "R4_w=inv32"},
+                       {7, "R4_w=inv16"},
+                       {8, "R4_w=inv8"},
+                       {9, "R4_w=inv4"},
+                       {10, "R4_w=inv2"},
                },
        },
        {
@@ -98,12 +98,12 @@ static struct bpf_align_test tests[] = {
                .matches = {
                        {0, "R1=ctx(id=0,off=0,imm=0)"},
                        {0, "R10=fp0"},
-                       {1, "R3_w=inv4"},
-                       {2, "R3_w=inv8"},
-                       {3, "R3_w=inv10"},
-                       {4, "R4_w=inv8"},
-                       {5, "R4_w=inv12"},
-                       {6, "R4_w=inv14"},
+                       {0, "R3_w=inv4"},
+                       {1, "R3_w=inv8"},
+                       {2, "R3_w=inv10"},
+                       {3, "R4_w=inv8"},
+                       {4, "R4_w=inv12"},
+                       {5, "R4_w=inv14"},
                },
        },
        {
@@ -120,10 +120,10 @@ static struct bpf_align_test tests[] = {
                .matches = {
                        {0, "R1=ctx(id=0,off=0,imm=0)"},
                        {0, "R10=fp0"},
+                       {0, "R3_w=inv7"},
                        {1, "R3_w=inv7"},
-                       {2, "R3_w=inv7"},
-                       {3, "R3_w=inv14"},
-                       {4, "R3_w=inv56"},
+                       {2, "R3_w=inv14"},
+                       {3, "R3_w=inv56"},
                },
        },
 
@@ -162,18 +162,18 @@ static struct bpf_align_test tests[] = {
                .prog_type = BPF_PROG_TYPE_SCHED_CLS,
                .matches = {
                        {6, "R0_w=pkt(id=0,off=8,r=8,imm=0)"},
-                       {7, "R3_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
-                       {8, "R3_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
-                       {9, "R3_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
-                       {10, "R3_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
-                       {11, "R3_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
-                       {13, "R3_w=pkt_end(id=0,off=0,imm=0)"},
-                       {18, "R4_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
-                       {19, "R4_w=inv(id=0,umax_value=8160,var_off=(0x0; 0x1fe0))"},
-                       {20, "R4_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
-                       {21, "R4_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
-                       {22, "R4_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
-                       {23, "R4_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
+                       {6, "R3_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
+                       {7, "R3_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
+                       {8, "R3_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {9, "R3_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
+                       {10, "R3_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
+                       {12, "R3_w=pkt_end(id=0,off=0,imm=0)"},
+                       {17, "R4_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
+                       {18, "R4_w=inv(id=0,umax_value=8160,var_off=(0x0; 0x1fe0))"},
+                       {19, "R4_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
+                       {20, "R4_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
+                       {21, "R4_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {22, "R4_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
                },
        },
        {
@@ -194,16 +194,16 @@ static struct bpf_align_test tests[] = {
                },
                .prog_type = BPF_PROG_TYPE_SCHED_CLS,
                .matches = {
-                       {7, "R3_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
-                       {8, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
-                       {9, "R4_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
-                       {10, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
-                       {11, "R4_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
-                       {12, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
-                       {13, "R4_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
-                       {14, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
-                       {15, "R4_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
-                       {16, "R4_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
+                       {6, "R3_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
+                       {7, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
+                       {8, "R4_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
+                       {9, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
+                       {10, "R4_w=inv(id=0,umax_value=510,var_off=(0x0; 0x1fe))"},
+                       {11, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
+                       {12, "R4_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {13, "R4_w=inv(id=1,umax_value=255,var_off=(0x0; 0xff))"},
+                       {14, "R4_w=inv(id=0,umax_value=2040,var_off=(0x0; 0x7f8))"},
+                       {15, "R4_w=inv(id=0,umax_value=4080,var_off=(0x0; 0xff0))"},
                },
        },
        {
@@ -234,14 +234,14 @@ static struct bpf_align_test tests[] = {
                },
                .prog_type = BPF_PROG_TYPE_SCHED_CLS,
                .matches = {
-                       {3, "R5_w=pkt(id=0,off=0,r=0,imm=0)"},
-                       {5, "R5_w=pkt(id=0,off=14,r=0,imm=0)"},
-                       {6, "R4_w=pkt(id=0,off=14,r=0,imm=0)"},
+                       {2, "R5_w=pkt(id=0,off=0,r=0,imm=0)"},
+                       {4, "R5_w=pkt(id=0,off=14,r=0,imm=0)"},
+                       {5, "R4_w=pkt(id=0,off=14,r=0,imm=0)"},
                        {9, "R2=pkt(id=0,off=0,r=18,imm=0)"},
                        {10, "R5=pkt(id=0,off=14,r=18,imm=0)"},
                        {10, "R4_w=inv(id=0,umax_value=255,var_off=(0x0; 0xff))"},
+                       {13, "R4_w=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff))"},
                        {14, "R4_w=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff))"},
-                       {15, "R4_w=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff))"},
                },
        },
        {
@@ -297,7 +297,7 @@ static struct bpf_align_test tests[] = {
                         * alignment of 4.
                         */
                        {6, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
-                       {8, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {7, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Offset is added to packet pointer R5, resulting in
                         * known fixed offset, and variable offset from R6.
                         */
@@ -313,11 +313,11 @@ static struct bpf_align_test tests[] = {
                        /* Variable offset is added to R5 packet pointer,
                         * resulting in auxiliary alignment of 4.
                         */
-                       {18, "R5_w=pkt(id=2,off=0,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {17, "R5_w=pkt(id=2,off=0,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Constant offset is added to R5, resulting in
                         * reg->off of 14.
                         */
-                       {19, "R5_w=pkt(id=2,off=14,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {18, "R5_w=pkt(id=2,off=14,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* At the time the word size load is performed from R5,
                         * its total fixed offset is NET_IP_ALIGN + reg->off
                         * (14) which is 16.  Then the variable offset is 4-byte
@@ -329,18 +329,18 @@ static struct bpf_align_test tests[] = {
                        /* Constant offset is added to R5 packet pointer,
                         * resulting in reg->off value of 14.
                         */
-                       {26, "R5_w=pkt(id=0,off=14,r=8"},
+                       {25, "R5_w=pkt(id=0,off=14,r=8"},
                        /* Variable offset is added to R5, resulting in a
                         * variable offset of (4n).
                         */
-                       {27, "R5_w=pkt(id=3,off=14,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {26, "R5_w=pkt(id=3,off=14,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Constant is added to R5 again, setting reg->off to 18. */
-                       {28, "R5_w=pkt(id=3,off=18,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {27, "R5_w=pkt(id=3,off=18,r=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* And once more we add a variable; resulting var_off
                         * is still (4n), fixed offset is not changed.
                         * Also, we create a new reg->id.
                         */
-                       {29, "R5_w=pkt(id=4,off=18,r=0,umax_value=2040,var_off=(0x0; 0x7fc)"},
+                       {28, "R5_w=pkt(id=4,off=18,r=0,umax_value=2040,var_off=(0x0; 0x7fc)"},
                        /* At the time the word size load is performed from R5,
                         * its total fixed offset is NET_IP_ALIGN + reg->off (18)
                         * which is 20.  Then the variable offset is (4n), so
@@ -387,12 +387,12 @@ static struct bpf_align_test tests[] = {
                         * alignment of 4.
                         */
                        {6, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
-                       {8, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {7, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Adding 14 makes R6 be (4n+2) */
-                       {9, "R6_w=inv(id=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc))"},
+                       {8, "R6_w=inv(id=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc))"},
                        /* Packet pointer has (4n+2) offset */
                        {11, "R5_w=pkt(id=1,off=0,r=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc)"},
-                       {13, "R4=pkt(id=1,off=4,r=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc)"},
+                       {12, "R4=pkt(id=1,off=4,r=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc)"},
                        /* At the time the word size load is performed from R5,
                         * its total fixed offset is NET_IP_ALIGN + reg->off (0)
                         * which is 2.  Then the variable offset is (4n+2), so
@@ -403,12 +403,12 @@ static struct bpf_align_test tests[] = {
                        /* Newly read value in R6 was shifted left by 2, so has
                         * known alignment of 4.
                         */
-                       {18, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {17, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Added (4n) to packet pointer's (4n+2) var_off, giving
                         * another (4n+2).
                         */
                        {19, "R5_w=pkt(id=2,off=0,r=0,umin_value=14,umax_value=2054,var_off=(0x2; 0xffc)"},
-                       {21, "R4=pkt(id=2,off=4,r=0,umin_value=14,umax_value=2054,var_off=(0x2; 0xffc)"},
+                       {20, "R4=pkt(id=2,off=4,r=0,umin_value=14,umax_value=2054,var_off=(0x2; 0xffc)"},
                        /* At the time the word size load is performed from R5,
                         * its total fixed offset is NET_IP_ALIGN + reg->off (0)
                         * which is 2.  Then the variable offset is (4n+2), so
@@ -448,18 +448,18 @@ static struct bpf_align_test tests[] = {
                .prog_type = BPF_PROG_TYPE_SCHED_CLS,
                .result = REJECT,
                .matches = {
-                       {4, "R5_w=pkt_end(id=0,off=0,imm=0)"},
+                       {3, "R5_w=pkt_end(id=0,off=0,imm=0)"},
                        /* (ptr - ptr) << 2 == unknown, (4n) */
-                       {6, "R5_w=inv(id=0,smax_value=9223372036854775804,umax_value=18446744073709551612,var_off=(0x0; 0xfffffffffffffffc)"},
+                       {5, "R5_w=inv(id=0,smax_value=9223372036854775804,umax_value=18446744073709551612,var_off=(0x0; 0xfffffffffffffffc)"},
                        /* (4n) + 14 == (4n+2).  We blow our bounds, because
                         * the add could overflow.
                         */
-                       {7, "R5_w=inv(id=0,smin_value=-9223372036854775806,smax_value=9223372036854775806,umin_value=2,umax_value=18446744073709551614,var_off=(0x2; 0xfffffffffffffffc)"},
+                       {6, "R5_w=inv(id=0,smin_value=-9223372036854775806,smax_value=9223372036854775806,umin_value=2,umax_value=18446744073709551614,var_off=(0x2; 0xfffffffffffffffc)"},
                        /* Checked s>=0 */
                        {9, "R5=inv(id=0,umin_value=2,umax_value=9223372036854775806,var_off=(0x2; 0x7ffffffffffffffc)"},
                        /* packet pointer + nonnegative (4n+2) */
-                       {12, "R6_w=pkt(id=1,off=0,r=0,umin_value=2,umax_value=9223372036854775806,var_off=(0x2; 0x7ffffffffffffffc)"},
-                       {13, "R4_w=pkt(id=1,off=4,r=0,umin_value=2,umax_value=9223372036854775806,var_off=(0x2; 0x7ffffffffffffffc)"},
+                       {11, "R6_w=pkt(id=1,off=0,r=0,umin_value=2,umax_value=9223372036854775806,var_off=(0x2; 0x7ffffffffffffffc)"},
+                       {12, "R4_w=pkt(id=1,off=4,r=0,umin_value=2,umax_value=9223372036854775806,var_off=(0x2; 0x7ffffffffffffffc)"},
                        /* NET_IP_ALIGN + (4n+2) == (4n), alignment is fine.
                         * We checked the bounds, but it might have been able
                         * to overflow if the packet pointer started in the
@@ -502,14 +502,14 @@ static struct bpf_align_test tests[] = {
                        /* Calculated offset in R6 has unknown value, but known
                         * alignment of 4.
                         */
-                       {7, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
-                       {9, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {6, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
+                       {8, "R6_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Adding 14 makes R6 be (4n+2) */
-                       {10, "R6_w=inv(id=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc))"},
+                       {9, "R6_w=inv(id=0,umin_value=14,umax_value=1034,var_off=(0x2; 0x7fc))"},
                        /* New unknown value in R7 is (4n) */
-                       {11, "R7_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
+                       {10, "R7_w=inv(id=0,umax_value=1020,var_off=(0x0; 0x3fc))"},
                        /* Subtracting it from R6 blows our unsigned bounds */
-                       {12, "R6=inv(id=0,smin_value=-1006,smax_value=1034,umin_value=2,umax_value=18446744073709551614,var_off=(0x2; 0xfffffffffffffffc)"},
+                       {11, "R6=inv(id=0,smin_value=-1006,smax_value=1034,umin_value=2,umax_value=18446744073709551614,var_off=(0x2; 0xfffffffffffffffc)"},
                        /* Checked s>= 0 */
                        {14, "R6=inv(id=0,umin_value=2,umax_value=1034,var_off=(0x2; 0x7fc))"},
                        /* At the time the word size load is performed from R5,
@@ -556,14 +556,14 @@ static struct bpf_align_test tests[] = {
                        /* Calculated offset in R6 has unknown value, but known
                         * alignment of 4.
                         */
-                       {7, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
-                       {10, "R6_w=inv(id=0,umax_value=60,var_off=(0x0; 0x3c))"},
+                       {6, "R2_w=pkt(id=0,off=0,r=8,imm=0)"},
+                       {9, "R6_w=inv(id=0,umax_value=60,var_off=(0x0; 0x3c))"},
                        /* Adding 14 makes R6 be (4n+2) */
-                       {11, "R6_w=inv(id=0,umin_value=14,umax_value=74,var_off=(0x2; 0x7c))"},
+                       {10, "R6_w=inv(id=0,umin_value=14,umax_value=74,var_off=(0x2; 0x7c))"},
                        /* Subtracting from packet pointer overflows ubounds */
                        {13, "R5_w=pkt(id=2,off=0,r=8,umin_value=18446744073709551542,umax_value=18446744073709551602,var_off=(0xffffffffffffff82; 0x7c)"},
                        /* New unknown value in R7 is (4n), >= 76 */
-                       {15, "R7_w=inv(id=0,umin_value=76,umax_value=1096,var_off=(0x0; 0x7fc))"},
+                       {14, "R7_w=inv(id=0,umin_value=76,umax_value=1096,var_off=(0x0; 0x7fc))"},
                        /* Adding it to packet pointer gives nice bounds again */
                        {16, "R5_w=pkt(id=3,off=0,r=0,umin_value=2,umax_value=1082,var_off=(0x2; 0xfffffffc)"},
                        /* At the time the word size load is performed from R5,
@@ -625,12 +625,15 @@ static int do_test_single(struct bpf_align_test *test)
                line_ptr = strtok(bpf_vlog_copy, "\n");
                for (i = 0; i < MAX_MATCHES; i++) {
                        struct bpf_reg_match m = test->matches[i];
+                       int tmp;
 
                        if (!m.match)
                                break;
                        while (line_ptr) {
                                cur_line = -1;
                                sscanf(line_ptr, "%u: ", &cur_line);
+                               if (cur_line == -1)
+                                       sscanf(line_ptr, "from %u to %u: ", &tmp, &cur_line);
                                if (cur_line == m.line)
                                        break;
                                line_ptr = strtok(NULL, "\n");
@@ -642,7 +645,19 @@ static int do_test_single(struct bpf_align_test *test)
                                printf("%s", bpf_vlog);
                                break;
                        }
+                       /* Check the next line as well in case the previous line
+                        * did not have a corresponding bpf insn. Example:
+                        * func#0 @0
+                        * 0: R1=ctx(id=0,off=0,imm=0) R10=fp0
+                        * 0: (b7) r3 = 2                 ; R3_w=inv2
+                        */
                        if (!strstr(line_ptr, m.match)) {
+                               cur_line = -1;
+                               line_ptr = strtok(NULL, "\n");
+                               sscanf(line_ptr, "%u: ", &cur_line);
+                       }
+                       if (cur_line != m.line || !line_ptr ||
+                           !strstr(line_ptr, m.match)) {
                                printf("Failed to find match %u: %s\n",
                                       m.line, m.match);
                                ret = 1;