Re: [PATCH v3 bpf-next] Small BPF verifier log improvements

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




> On Feb 23, 2022, at 3:33 PM, Andrii Nakryiko <andrii.nakryiko@xxxxxxxxx> wrote:
> 
> On Wed, Feb 23, 2022 at 3:25 PM Mykola Lysenko <mykolal@xxxxxx> wrote:
>> 
>> 
>>> On Feb 23, 2022, at 1:52 PM, Andrii Nakryiko <andrii.nakryiko@xxxxxxxxx> wrote:
>>> 
>>> On Tue, Feb 22, 2022 at 8:23 PM Andrii Nakryiko
>>> <andrii.nakryiko@xxxxxxxxx> wrote:
>>>> 
>>>> On Tue, Feb 22, 2022 at 6:07 PM Mykola Lysenko <mykolal@xxxxxx> wrote:
>>>>> 
>>>>> In particular:
>>>>> 1) remove output of inv for scalars
>>>>> 2) remove _value suffixes for umin/umax/s32_min/etc (except map_value)
>>>>> 3) remove output of id=0
>>>>> 4) remove output of ref_obj_id=0
>>>>> 
>>>>> Signed-off-by: Mykola Lysenko <mykolal@xxxxxx>
>>>>> ---
>>>> 
>>>> LGTM, thanks.
>>>> 
>>>> Acked-by: Andrii Nakryiko <andrii@xxxxxxxxxx>
>>> 
>>> Actually seems like you missed updating some tests, please take a look:
>>> 
>>> [0] https://github.com/kernel-patches/bpf/runs/5297754845?check_suite_focus=true
>> 
>> Great catch! Thanks.
>> 
>> Reviewing failed test logs I realized that while print_verifier_state works as expected and makes output tidier, my change did broke error messages.
>> 
>> For example, my change turned
>> ______________________
>> R2 invalid mem access ‘inv’
>> ______________________
>> into
>> ______________________
>> R2 invalid mem access ‘’
>> ______________________
>> 
>> Removing inv in this case does not make sense. We should either leave inv here, or substitute it with something more obvious, like ’scalar’.
>> 
>> Thoughts?
> 
> Yeah, scalar here would make most sense in this context. Would it be
> possible to use "scalar" in this error message, but still have empty
> string output in register state?
> 

Yes, I think it should be possible, let me prepare v4

>> 
>> 
>>> 
>>>> 
>>>>> kernel/bpf/verifier.c                         |  59 ++---
>>>>> .../testing/selftests/bpf/prog_tests/align.c  | 218 +++++++++---------
>>>>> .../selftests/bpf/prog_tests/log_buf.c        |   4 +-
>>>>> 3 files changed, 143 insertions(+), 138 deletions(-)
>>>>> 
>>>>> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
>>>>> index d7473fee247c..91154806715d 100644
>>>>> --- a/kernel/bpf/verifier.c
>>>>> +++ b/kernel/bpf/verifier.c
>>>>> @@ -539,7 +539,7 @@ static const char *reg_type_str(struct bpf_verifier_env *env,
>>>>>       char postfix[16] = {0}, prefix[32] = {0};
>>>>>       static const char * const str[] = {
>>>>>               [NOT_INIT]              = "?",
>>>>> -               [SCALAR_VALUE]          = "inv",
>>>>> +               [SCALAR_VALUE]          = "",
>>>>>               [PTR_TO_CTX]            = "ctx",
>>>>>               [CONST_PTR_TO_MAP]      = "map_ptr",
>>>>>               [PTR_TO_MAP_VALUE]      = "map_value",
>>>>> @@ -693,66 +693,71 @@ static void print_verifier_state(struct bpf_verifier_env *env,
>>>>>                       /* reg->off should be 0 for SCALAR_VALUE */
>>>>>                       verbose(env, "%lld", reg->var_off.value + reg->off);
>>>>>               } else {
>>>>> +                       const char *sep = "";
>>>>> +
>>>>>                       if (base_type(t) == PTR_TO_BTF_ID ||
>>>>>                           base_type(t) == PTR_TO_PERCPU_BTF_ID)
>>>>>                               verbose(env, "%s", kernel_type_name(reg->btf, reg->btf_id));
>>>>> -                       verbose(env, "(id=%d", reg->id);
>>>>> -                       if (reg_type_may_be_refcounted_or_null(t))
>>>>> -                               verbose(env, ",ref_obj_id=%d", reg->ref_obj_id);
>>>>> +                       verbose(env, "(");
>>>>> +
>>>>> +/*
>>>>> + * _a stands for append, was shortened to avoid multiline statements below. this macro is used to
>>>>> + * output a comma separated list of attributes
>>>>> + */
>>>>> +#define verbose_a(fmt, ...) ({ verbose(env, "%s" fmt, sep, __VA_ARGS__); sep = ","; })
>>>> 
>>>> it's a very local macro so it probably doesn't matter all that much,
>>>> but a bit more readable name could be verbose_attr() or even just
>>>> log_attr(). I'll leave it up to Alexei and Daniel to decide if they'd
>>>> like to change it.
>>>> 
>>>>> +
>>>>> +                       if (reg->id)
>>>>> +                               verbose_a("id=%d", reg->id);
>>>>> +                       if (reg_type_may_be_refcounted_or_null(t) && reg->ref_obj_id)
>>>>> +                               verbose_a("ref_obj_id=%d", reg->ref_obj_id);
>>>>>                       if (t != SCALAR_VALUE)
>>>>> -                               verbose(env, ",off=%d", reg->off);
>>>>> +                               verbose_a("off=%d", reg->off);
>>>>>                       if (type_is_pkt_pointer(t))
>>>>> -                               verbose(env, ",r=%d", reg->range);
>>>>> +                               verbose_a("r=%d", reg->range);
>>>>>                       else if (base_type(t) == CONST_PTR_TO_MAP ||
>>>>>                                base_type(t) == PTR_TO_MAP_KEY ||
>>>>>                                base_type(t) == PTR_TO_MAP_VALUE)
>>>>> -                               verbose(env, ",ks=%d,vs=%d",
>>>>> -                                       reg->map_ptr->key_size,
>>>>> -                                       reg->map_ptr->value_size);
>>>>> +                               verbose_a("ks=%d,vs=%d",
>>>>> +                                         reg->map_ptr->key_size,
>>>>> +                                         reg->map_ptr->value_size);
>>>>>                       if (tnum_is_const(reg->var_off)) {
>>>>>                               /* Typically an immediate SCALAR_VALUE, but
>>>>>                                * could be a pointer whose offset is too big
>>>>>                                * for reg->off
>>>>>                                */
>>>>> -                               verbose(env, ",imm=%llx", reg->var_off.value);
>>>>> +                               verbose_a("imm=%llx", reg->var_off.value);
>>>>>                       } else {
>>>>>                               if (reg->smin_value != reg->umin_value &&
>>>>>                                   reg->smin_value != S64_MIN)
>>>>> -                                       verbose(env, ",smin_value=%lld",
>>>>> -                                               (long long)reg->smin_value);
>>>>> +                                       verbose_a("smin=%lld", (long long)reg->smin_value);
>>>>>                               if (reg->smax_value != reg->umax_value &&
>>>>>                                   reg->smax_value != S64_MAX)
>>>>> -                                       verbose(env, ",smax_value=%lld",
>>>>> -                                               (long long)reg->smax_value);
>>>>> +                                       verbose_a("smax=%lld", (long long)reg->smax_value);
>>>>>                               if (reg->umin_value != 0)
>>>>> -                                       verbose(env, ",umin_value=%llu",
>>>>> -                                               (unsigned long long)reg->umin_value);
>>>>> +                                       verbose_a("umin=%llu", (unsigned long long)reg->umin_value);
>>>>>                               if (reg->umax_value != U64_MAX)
>>>>> -                                       verbose(env, ",umax_value=%llu",
>>>>> -                                               (unsigned long long)reg->umax_value);
>>>>> +                                       verbose_a("umax=%llu", (unsigned long long)reg->umax_value);
>>>>>                               if (!tnum_is_unknown(reg->var_off)) {
>>>>>                                       char tn_buf[48];
>>>>> 
>>>>>                                       tnum_strn(tn_buf, sizeof(tn_buf), reg->var_off);
>>>>> -                                       verbose(env, ",var_off=%s", tn_buf);
>>>>> +                                       verbose_a("var_off=%s", tn_buf);
>>>>>                               }
>>>>>                               if (reg->s32_min_value != reg->smin_value &&
>>>>>                                   reg->s32_min_value != S32_MIN)
>>>>> -                                       verbose(env, ",s32_min_value=%d",
>>>>> -                                               (int)(reg->s32_min_value));
>>>>> +                                       verbose_a("s32_min=%d", (int)(reg->s32_min_value));
>>>>>                               if (reg->s32_max_value != reg->smax_value &&
>>>>>                                   reg->s32_max_value != S32_MAX)
>>>>> -                                       verbose(env, ",s32_max_value=%d",
>>>>> -                                               (int)(reg->s32_max_value));
>>>>> +                                       verbose_a("s32_max=%d", (int)(reg->s32_max_value));
>>>>>                               if (reg->u32_min_value != reg->umin_value &&
>>>>>                                   reg->u32_min_value != U32_MIN)
>>>>> -                                       verbose(env, ",u32_min_value=%d",
>>>>> -                                               (int)(reg->u32_min_value));
>>>>> +                                       verbose_a("u32_min=%d", (int)(reg->u32_min_value));
>>>>>                               if (reg->u32_max_value != reg->umax_value &&
>>>>>                                   reg->u32_max_value != U32_MAX)
>>>>> -                                       verbose(env, ",u32_max_value=%d",
>>>>> -                                               (int)(reg->u32_max_value));
>>>>> +                                       verbose_a("u32_max=%d", (int)(reg->u32_max_value));
>>>>>                       }
>>>>> +#undef verbose_a
>>>>> +
>>>>>                       verbose(env, ")");
>>>>>               }
>>>>>       }
>>>> 
>>>> [...]





[Index of Archives]     [Linux Samsung SoC]     [Linux Rockchip SoC]     [Linux Actions SoC]     [Linux for Synopsys ARC Processors]     [Linux NFS]     [Linux NILFS]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]


  Powered by Linux