Re: [dpdk-dev] [RFC 0/8] eal: dynamic logs

[Olivier Matz <olivier.matz@6wind.com>]

On Mon, 6 Feb 2017 15:55:20 +0000, "Wiles, Keith"
<keith.wiles@intel.com> wrote:
> > On Feb 6, 2017, at 9:27 AM, Olivier Matz <olivier.matz@6wind.com>
> > wrote:
> > 
> > On Mon, 6 Feb 2017 15:01:30 +0000, "Wiles, Keith"
> > <keith.wiles@intel.com> wrote:  
> >>> On Feb 6, 2017, at 8:10 AM, Olivier Matz <olivier.matz@6wind.com>
> >>> wrote:
> >>> 
> >>> Hi Bruce,
> >>> 
> >>> On Mon, 6 Feb 2017 13:49:03 +0000, Bruce Richardson
> >>> <bruce.richardson@intel.com> wrote:    
> >>>> On Mon, Feb 06, 2017 at 02:29:08PM +0100, Olivier Matz wrote:    
> >>>>> The objective of this RFC patchset is to introduce a framework
> >>>>> to support dynamic log types in EAL. It also provides one
> >>>>> example of use (in i40e).
> >>>>> 
> >>>>> Features:
> >>>>> - log types are identified by a string
> >>>>> - at registration, a uniq identifier is associated to a log type
> >>>>> - each log type can have its level changed dynamically
> >>>>> - extend command line parameters to set the log level of a
> >>>>> specific type, or logs matching a regular expression
> >>>>> - keep compat with other legacy types (eal, malloc, ring, user*,
> >>>>> etc... keep their hardcoded log type value)
> >>>>> 
> >>>>> At the end, when, we can expect that all non-dataplane logs are
> >>>>> moved to be dynamic, so we can enable/disable them at runtime,
> >>>>> without recompiling. Many debug options can probably be removed
> >>>>> from configuration:
> >>>>> $ git grep DEBUG config/common_base | wc -l
> >>>>> 89
> >>>>> 
> >>>>> Comments are welcome!
> >>>>>   
> >>>> Initial scan through the patches this looks pretty good. However,
> >>>> rather than continuing with our own logging system, have you
> >>>> investigated what other tracing and logging systems might be out
> >>>> there that we could possibly re-use? Could LTTng be a good fit
> >>>> for DPDK, perhaps?    
> >>> 
> >>> I did not investigate much about existing logging system. I agree
> >>> that could be a good alternative too.
> >>> 
> >>> On the other hand, I'm not really confident in adding a dependency
> >>> to an external lib for a core component like eal. What if we
> >>> deicide tomorrow to port dpdk to windows or any baremetal env?
> >>> 
> >>> Also, as far as I remember, the components that depend on external
> >>> libraries are disabled today because we don't know how to properly
> >>> manage the dependency (ex: pmd-pcap, vhost-numa, pmd-mlx, …).    
> >> 
> >> In a previous project I worked in we did not use log levels per say
> >> for debugging code. We did have a couple general logging for misc
> >> type logging.
> >> 
> >> When debugging you normally only need a couple files or functions
> >> that need to produce logging output. In that case we defined
> >> logging using the file and function as the key to determine if the
> >> dynamic log messages are output. We use a string in the format of
> >> "filename:function” we allowed for a wildcard to enable all
> >> functions in a file or you can select a single function.
> >> 
> >> Using this type of logging for debugging a system is the most
> >> useful if you just want general logging then we define something
> >> similar to what we have today.  
> > 
> > I think the "filename:function" is not adequate if you are not the
> > developer of that code. Example: you have a problem with a PMD, you
> > just enable all logs for this PMD (or even all PMDs), you can check
> > it and if you don't find the problem, you can send them on the ML
> > for help. I think you don't care where the code is located.  
> 
> I do not understand your concern the design allows you to enable a
> single file, which means all functions within a file “filename:*".

I think the user doesn't want to care about the file name of the C
source.


> In
> the case of the all PMDs it not the best way to debug as you get a
> lot of output that may not be even related to the problem you are
> trying to solve. The design does allow you to enable one or more PMDs
> if say you are debugging say two PMDs. The output would be more
> readable and less cluttered with output that is not germane to the
> problem.
> 
> If I was debugging the TAP driver I would like to just enable
> “rte_eth_tap_pmd.c:*” or maybe we can define a something registered
> other then file name e.g. rte_log_register(“tap_pmd”); “tap_pmd:*” or
> “tap_pmd:pmd_rx_burst” or “tap_pmd:rte_tap_pmd_probe”. We could for
> the PMDs just use the PMD name we define at registration.

That's very similar to what is proposed in the patch...

See:

+	i40e_logtype_init = rte_log_register("pmd.i40e.init");

+	i40e_logtype_driver = rte_log_register("pmd.i40e.driver");


> 
> Maybe the register option brings us closer to the same goal, but add
> the function or selecting a specific set functions. The design does
> require a more active lookup at run time for dynamic debugging and we
> would have to make sure if enabled it does not effect performance. We
> used a hash table to locate the enabled debug log output.

Again, I don't really see the added value to be able enable logs on a
per function basis. For users, it brings more complexity.

 
> The design allowed us to use the command line or CLI to
> enable/disable logging output.

Same with this proposal.