Re: [PATCH v3 1/4] ethdev: add trace points

[Jerin Jacob <jerinjacobk@gmail.com>]

On Wed, Dec 14, 2022 at 5:40 PM Ferruh Yigit <ferruh.yigit@amd.com> wrote:
>
> On 12/14/2022 10:40 AM, Jerin Jacob wrote:
> > On Wed, Dec 14, 2022 at 1:37 AM Ferruh Yigit <ferruh.yigit@amd.com> wrote:
> >>
> >> On 10/6/2022 4:18 PM, Ankur Dwivedi wrote:
> >>
> >> Hi Ankur, Jerin,
> >
> > Hi Ferruh, Please find answers to generic trace questions.
> >
> >>
> >> I have some major questions, I can see some already queried by Andrew as
> >> well:
> >>
> >> 1) How flexible are we on changing trace log output?
> >> Should we take trace log as kind of user interface and don't break it
> >> (as much as possible)? Or is it OK to change whenever we want?
> >
> > If you see https://doc.dpdk.org/guides/prog_guide/trace_lib.html
> > "Section: 6.9.3. Trace memory layout", Currently, we defined packet.header,
> > packet.context, trace.header as minimum as required. It can be
> > extended if needed.
> > Trace payload is not fixed, it is created based on arguments of RTE_TRACE_POINT.
> >
>
> I am aware payload is not fixed technically, but my concern is from user
> perspective.
>
> Lets get 'rte_ethdev_trace_info_get' as example, right now it records
> 'dev_info->if_index', if we remove it in next release, will it impact
> the users?
> Or if we start recording 'dev_info->max_rx_queues' in another release,
> it will change order of fields in output, will it impact the user?

No. IMO, That level of compatibility is not needed.

>
> If changing payload doesn't impact user, we can accept changes easier
> since we can tweak them as needed without user impact.
> But if the target is to stick to the payload layout as much as possible,
> we should be more careful before we finalize it.
>
> I am trying to understand how strict to be in accepting trace point patches.
>
> >>
> >>
> >> 2) What is the main purpose of the trace library.
> >> Is it to record type and frequency of the calls? Or is it to log values
> >> and state of the device/driver after each call?
> >
> > From the framework POV, it can be used for both.
> > I think, as first step, we can emit the traces for public DPDK APIs
> > with return type of each API.
> >
>
> Most of the trace point records only on success path, and not record at
> all when there is a failure in the API, that is why I think trace can't
> completely replace the logging.

Yes.

>
> But trace may be useful to analysis a functioning system for performance
> issues, overall system analysis, or unexpected behaviors.
> In that case I am not sure how much detail to record in trace.

For other projects(example:
https://docs.zephyrproject.org/2.6.0/guides/tracing/index.html), I see
it's just capturing the  PUBLIC APIs to know how application using the
library and debug
customer issues. i.e API contract between user and DPDK library,

>
> Because recording more fields comes with additional runtime cost and
> memory cost, right? Also useless records can be noise in the trace output.

Since each trace point can be disabled(using regex pattern) at
runtime, users have control on it

>
> OK to record return values but I don't know if it may be misleading
> because in some of the failure path trace functions not called at all,
> so recorded failures will be subset of the overall failures.
> BTW, I don't think that we should record all failures in trace log, that
> will create to much noise in the code.

Yes. Just the return value of the function is enough in most case.
Also, it is up to the specific subsystem maintainer to decide what
level of info needs to capture.

>
> >> This can guide us to decide
> >> - which values to record (should record only pointers or values of structs)
> >> - if to record API return values and failure paths
> >> - if to add tracing all APIs or not, like
> >> 'rte_eth_dev_rx_offload_name()' kind of helper function that converts
> >> offload to a string, which doesn't have any functional impact, or
> >> 'rte_eth_speed_bitflag()', and many more...
> >>
> >>
> >> 3) What is the runtime impact.
> >
> > Profiling overhead is one cycle. i.e. RTE_TRACE_POINT is added, and it
> > is disabled at runtime.
>
> Got it, there is '__RTE_TRACE_FIELD_ENABLE_MASK' check, and this is the
> only cost when trace is disabled.
>
> > For RTE_TRACE_POINT_FP it is zero if it is not enabled at compile time.
> >
>
> ack
>
> >
> >> As far as I can see some values copied and some memory is used for this
> >> support, even user is not interested in tracing. For control path APIs
> >> we can ignore the additional cost by memcpy, but how big memory
> >> requirement is?
> >
> > Currently, per core/thread 1MB trace buffer is created as default. The
> > size can be overridden via EAL command line argument.
> > See __rte_trace_mem_per_thread_alloc().
> > If you see https://doc.dpdk.org/guides/prog_guide/trace_lib.html
> > section "6.5. Event record mode", it has two modes
> > Overwrite - When the trace buffer is full, new trace events overwrites
> > the existing captured events in the trace buffer.
> > Discard - When the trace buffer is full, new trace events will be discarded.
> >
>
> OK, default 1M buffer doesn't look something to worry about.
>
> >>
> >>
> >> 4) Why we need to export trace point variables in the .map files,
> >> like '__rte_eth_trace_allmulticast_disable' one...
> >
> > If you see app/test/test_trace.c example
> >
> > There are two-way to operate on trace point, We need to export symbol
> > iff we need option 1
> >
> > option1:
> > rte_trace_point_enable(&__app_dpdk_test_tp);
> >
> > option2:
> > rte_trace_point_t *trace = rte_trace_point_lookup("app.dpdk.test.tp");
> > rte_trace_point_enable(trace);
> >
>
> got it, do we really need direct access to trace point (option 1), I
> would be OK to remove that option to not expose all these trace point
> objects.

Looks good to me.

>
> >
> >>
> >>
> >>
> >> 5) (bonus Q) Can we have an 'rte_trace_point_emit_xx()' function to
> >> record mac address (struct rte_ether_addr) as string?
> >> And maybe another set for array types?
> >
> > Yes it possible and better to add rte_trace_pint_emit_,mac() or so.
> >
>
> Thanks.
>
> >
> >>
> >>
> >> There are bunch of small comments inline, some are related to above
> >> highlevel question.
> >> But I stopped after some point, specifically after
> >> 'rte_eth_trace_timesync_adjust_time()' :), this is a big file, splitting
> >> it may help reviewers.
> >>
>