Re: [PATCH v3 bpf-next 2/3] Right align verifier states in verifier logs

[Alexei Starovoitov <alexei.starovoitov@gmail.com>]

On Thu, Dec 16, 2021 at 1:34 PM Christy Lee <christylee@fb.com> wrote:
> +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)) {

redundant ()

> +               /* remove new line character*/

missing ' ' before */

> +               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.
> @@ -2724,10 +2743,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)
> @@ -3422,11 +3441,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
> @@ -4565,6 +4581,8 @@ static int check_mem_access(struct bpf_verifier_env *env, int insn_idx, u32 regn
>
>  static int check_atomic(struct bpf_verifier_env *env, int insn_idx, struct bpf_insn *insn)
>  {
> +       struct bpf_verifier_state *vstate = env->cur_state;
> +       struct bpf_func_state *state = vstate->frame[vstate->curframe];
>         int load_reg;
>         int err;
>
> @@ -4651,6 +4669,9 @@ static int check_atomic(struct bpf_verifier_env *env, int insn_idx, struct bpf_i
>         if (err)
>                 return err;
>
> +       if (env->log.level & BPF_LOG_LEVEL)
> +               print_insn_state(env, state);
> +

I couldn't figure out why check_atomic() is special
when the main loop in do_check() is doing it anyway.
So I've removed this hunk and one above.

> -               if ((env->log.level & BPF_LOG_LEVEL2) ||
> -                   (env->log.level & BPF_LOG_LEVEL && do_print_state)) {
> -                       if (verifier_state_scratched(env) &&
> -                           (env->log.level & BPF_LOG_LEVEL2))
> -                               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_LEVEL1) && do_print_state) {

redundant ()

> +                       verbose(env, "\nfrom %d to %d%s:\n", env->prev_insn_idx,
> +                               env->insn_idx, env->cur_state->speculative ?
> +                               " (speculative execution)" : "");

Due to vlog_reset at log_level=1 "from %d to %d"
is not seen anymore.
So it should be LEVEL2 instead of LEVEL1.
Then this 'from %d to %d' becomes meaningful in full verifier log.

> @@ -11328,9 +11340,16 @@ 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;

no need to wrap the line.

I fixed it all up while applying.