Re: [PATCH bpf-next V2 3/6] selftests/bpf: xdp_hw_metadata RX hash return code info

[Jesper Dangaard Brouer <jbrouer@redhat.com>]

On 22/03/2023 20.33, Stanislav Fomichev wrote:
> On Wed, Mar 22, 2023 at 12:30 PM Alexei Starovoitov
> <alexei.starovoitov@gmail.com> wrote:
>>
>> On Wed, Mar 22, 2023 at 12:23 PM Stanislav Fomichev <sdf@google.com> wrote:
>>>
>>> On Wed, Mar 22, 2023 at 12:17 PM Alexei Starovoitov
>>> <alexei.starovoitov@gmail.com> wrote:
>>>>
>>>> On Wed, Mar 22, 2023 at 12:00 PM Stanislav Fomichev <sdf@google.com> wrote:
>>>>>
>>>>> On Wed, Mar 22, 2023 at 9:07 AM Alexei Starovoitov
>>>>> <alexei.starovoitov@gmail.com> wrote:
>>>>>>
>>>>>> On Wed, Mar 22, 2023 at 9:05 AM Jesper Dangaard Brouer
>>>>>> <jbrouer@redhat.com> wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On 21/03/2023 19.47, Stanislav Fomichev wrote:
>>>>>>>> On Tue, Mar 21, 2023 at 6:47 AM Jesper Dangaard Brouer
>>>>>>>> <brouer@redhat.com> wrote:
>>>>>>>>>
>>>>>>>>> When driver developers add XDP-hints kfuncs for RX hash it is
>>>>>>>>> practical to print the return code in bpf_printk trace pipe log.
>>>>>>>>>
>>>>>>>>> Print hash value as a hex value, both AF_XDP userspace and bpf_prog,
>>>>>>>>> as this makes it easier to spot poor quality hashes.
>>>>>>>>>
>>>>>>>>> Signed-off-by: Jesper Dangaard Brouer <brouer@redhat.com>
>>>>>>>>> ---
>>>>>>>>>    .../testing/selftests/bpf/progs/xdp_hw_metadata.c  |    9 ++++++---
>>>>>>>>>    tools/testing/selftests/bpf/xdp_hw_metadata.c      |    5 ++++-
>>>>>>>>>    2 files changed, 10 insertions(+), 4 deletions(-)
>>>>>>>>>
>>>>>>>>> diff --git a/tools/testing/selftests/bpf/progs/xdp_hw_metadata.c b/tools/testing/selftests/bpf/progs/xdp_hw_metadata.c
>>>>>>>>> index 40c17adbf483..ce07010e4d48 100644
>>>>>>>>> --- a/tools/testing/selftests/bpf/progs/xdp_hw_metadata.c
>>>>>>>>> +++ b/tools/testing/selftests/bpf/progs/xdp_hw_metadata.c
>>>>>>>>> @@ -77,10 +77,13 @@ int rx(struct xdp_md *ctx)
>>>>>>>>>                   meta->rx_timestamp = 0; /* Used by AF_XDP as not avail signal */
>>>>>>>>>           }
>>>>>>>>>
>>>>>>>>> -       if (!bpf_xdp_metadata_rx_hash(ctx, &meta->rx_hash))
>>>>>>>>> -               bpf_printk("populated rx_hash with %u", meta->rx_hash);
>>>>>>>>> -       else
>>>>>>>>> +       ret = bpf_xdp_metadata_rx_hash(ctx, &meta->rx_hash);
>>>>>>>>> +       if (ret >= 0) {
>>>>>>>>> +               bpf_printk("populated rx_hash with 0x%08X", meta->rx_hash);
>>>>>>>>> +       } else {
>>>>>>>>> +               bpf_printk("rx_hash not-avail errno:%d", ret);
>>>>>>>>>                   meta->rx_hash = 0; /* Used by AF_XDP as not avail signal */
>>>>>>>>> +       }
>>>>>>>>>
>>>>>>>>>           return bpf_redirect_map(&xsk, ctx->rx_queue_index, XDP_PASS);
>>>>>>>>>    }
>>>>>>>>> diff --git a/tools/testing/selftests/bpf/xdp_hw_metadata.c b/tools/testing/selftests/bpf/xdp_hw_metadata.c
>>>>>>>>> index 400bfe19abfe..f3ec07ccdc95 100644
>>>>>>>>> --- a/tools/testing/selftests/bpf/xdp_hw_metadata.c
>>>>>>>>> +++ b/tools/testing/selftests/bpf/xdp_hw_metadata.c
>>>>>>>>> @@ -3,6 +3,9 @@
>>>>>>>>>    /* Reference program for verifying XDP metadata on real HW. Functional test
>>>>>>>>>     * only, doesn't test the performance.
>>>>>>>>>     *
>>>>>>>>> + * BPF-prog bpf_printk info outout can be access via
>>>>>>>>> + * /sys/kernel/debug/tracing/trace_pipe
>>>>>>>>
>>>>>>>> s/outout/output/
>>>>>>>>
>>>>>>>
>>>>>>> Fixed in V3
>>>>>>>
>>>>>>>> But let's maybe drop it? If you want to make it more usable, let's
>>>>>>>> have a separate patch to enable tracing and periodically dump it to
>>>>>>>> the console instead (as previously discussed).
>>>>>>>
>>>>>>> Cat'ing /sys/kernel/debug/tracing/trace_pipe work for me regardless of
>>>>>>> setting in
>>>>>>> /sys/kernel/debug/tracing/events/bpf_trace/bpf_trace_printk/enable
>>>>>>>
>>>>>>> We likely need a followup patch that adds a BPF config switch that can
>>>>>>> disable bpf_printk calls, because this adds overhead and thus affects
>>>>>>> the timestamps.
>>>>>>
>>>>>> No. This is by design.
>>>>>> Do not use bpf_printk* in production.

I fully agree do not use bpf_printk in *production*.

>>>>>
>>>>> But that's not for the production? xdp_hw_metadata is a small tool to
>>>>> verify that the metadata being dumped is correct (during the
>>>>> development).
>>>>> We have a proper (less verbose) selftest in
>>>>> {progs,prog_tests}/xdp_metadata.c (over veth).
>>>>> This xdp_hw_metadata was supposed to be used for running it against
>>>>> the real hardware, so having as much debugging at hand as possible
>>>>> seems helpful? (at least it was helpful to me when playing with mlx4)

My experience when developing these kfuncs for igc (real hardware), this
"tool" xdp_hw_metadata was super helpful, because it was very verbose
(and I was juggling reading chip registers BE/LE and see patch1 a buggy
implementation for RX-hash).

As I wrote in cover-letter, I recommend other driver developers to do
the same, because it really help speed up the development. In theory
xdp_hw_metadata doesn't belong in selftests directory and IMHO it should
have been placed in samples/bpf/, but given the relationship with real
selftest {progs,prog_tests}/xdp_metadata.c I think it makes sense to
keep here.


>>>>
>>>> The only use of bpf_printk is for debugging of bpf progs themselves.
>>>> It should not be used in any tool.
>>>
>>> Hmm, good point. I guess it also means we won't have to mess with
>>> enabling/dumping ftrace (and don't need this comment about cat'ing the
>>> file).
>>> Jesper, maybe we can instead pass the status of those
>>> bpf_xdp_metadata_xxx kfuncs via 'struct xdp_meta'? And dump this info
>>> from the userspace if needed.
>>
>> There are so many other ways for bpf prog to communicate with user space.
>> Use ringbuf, perf_event buffer, global vars, maps, etc.
>> trace_pipe is debug only because it's global and will conflict with
>> all other debug sessions.

I want to highlight above paragraph: It is very true for production
code. (Anyone Googling this pay attention to above paragraph).

> 
> 👍 makes sense, ty! hopefully we won't have to add a separate channel
> for those and can (ab)use the metadata area.
> 

Proposed solution: How about default disabling the bpf_printk's via a 
macro define, and then driver developer can manually reenable them 
easily via a single define, to enable a debugging mode.

I was only watching /sys/kernel/debug/tracing/trace_pipe when I was 
debugging a driver issue.  Thus, an extra step of modifying a single 
define in BPF seems easier, than instrumenting my driver with printk.

--Jesper