Re: [dpdk-dev] The use of --log-level and its default state

[Thomas Monjalon <thomas.monjalon@6wind.com>]

Keith, your mail is very long but it's maybe on purpose to show that
there are too many logs ;)

2015-06-05 12:32, Wiles, Keith:
> On 6/5/15, 5:00 AM, "Thomas Monjalon" <thomas.monjalon@6wind.com> wrote:
> >2015-05-27 15:10, Wiles, Keith:
> >> I would like to have the log-level default changed to not log
> >>everything,
> >> but the user needs to enable the log messages if he needs to see more
> >> information. Normally applications or systems are not so verbose, but if
> >> needed the user enables the verbose or debug messages.
> >> 
> >> Can we change the default logs and messages to be non-verbose instead?
> >
> >Do you mean changing this line?
> >    /* default value from build option */
> >    internal_cfg->log_level = RTE_LOG_LEVEL;
> >It means using the most verbose level available in the build.
> >
> >Maybe we should set RTE_LOG_NOTICE or RTE_LOG_WARNING,
> >However, there is already --log-level for the user and rte_set_log_level()
> >for the application developper.
> >So this default log level is only used for DPDK trials and development.
> >Probably that being verbose is a good option for such cases?
> >
> The normal operation for most systems is no-news-is-good-news, meaning
> only report warnings and errors if someone wants informational output it
> should be enabled by the user. It seems PMDs and other parts of DPDK print
> out information which is not a warning or error, but are debug or
> informational messages that are not very useful. The debug information is
> more for the developer then a user or even a developer of DPDK as the
> debug information has nothing to do with the current developers goals.

This assumption is not fully true.
In normal applications DPDK doesn't show so many logs.
But in testpmd or examples, the log level is not set (by default) and they
behave as debug applications, which is probably a good default.
However, as you say below, the log level of some messages is not well tuned.

> We can change the RTE_LOG_LEVEL to a value that only prints warning and
> errors should always be printed. We can leave it or we can make that one
> change to reduce the amount of clutter on the screen. Some of the PMD
> information is printed out anytime the state changes, which effects the
> application screen output.
> 
> When I have to interact with users of DPDK they sometimes miss critical
> details in the output because of the sheer amount of output on the screen.
> Even most OSes try to output information to the screen is a sane way to
> allow someone to quickly spot a problem.
> 
> Here is a normal output with log level at the default:
> 
[...] 
> When I quit the application I get the four above are they really useful,
> not really IMO. The PMD information and the EAL information is not very
> use 99% of the time.

Yes it is a debug mode.

> Next is ‹log-level=0 on the command line.
> 
> EAL: Detected lcore 0 as core 0 on socket 0
> EAL: Detected lcore 1 as core 1 on socket 0
> EAL: Detected lcore 2 as core 2 on socket 0
> EAL: Detected lcore 3 as core 3 on socket 0
> EAL: Detected lcore 4 as core 4 on socket 0
> EAL: Detected lcore 5 as core 8 on socket 0
> EAL: Detected lcore 6 as core 9 on socket 0
> EAL: Detected lcore 7 as core 10 on socket 0
> EAL: Detected lcore 8 as core 11 on socket 0
> EAL: Detected lcore 9 as core 16 on socket 0
> EAL: Detected lcore 10 as core 17 on socket 0
> EAL: Detected lcore 11 as core 18 on socket 0
> EAL: Detected lcore 12 as core 19 on socket 0
> EAL: Detected lcore 13 as core 20 on socket 0
> EAL: Detected lcore 14 as core 24 on socket 0
> EAL: Detected lcore 15 as core 25 on socket 0
> EAL: Detected lcore 16 as core 26 on socket 0
> EAL: Detected lcore 17 as core 27 on socket 0
> EAL: Detected lcore 18 as core 0 on socket 1
> EAL: Detected lcore 19 as core 1 on socket 1
> EAL: Detected lcore 20 as core 2 on socket 1
> EAL: Detected lcore 21 as core 3 on socket 1
> EAL: Detected lcore 22 as core 4 on socket 1
> EAL: Detected lcore 23 as core 8 on socket 1
> EAL: Detected lcore 24 as core 9 on socket 1
> EAL: Detected lcore 25 as core 10 on socket 1
> EAL: Detected lcore 26 as core 11 on socket 1
> EAL: Detected lcore 27 as core 16 on socket 1
> EAL: Detected lcore 28 as core 17 on socket 1
> EAL: Detected lcore 29 as core 18 on socket 1
> EAL: Detected lcore 30 as core 19 on socket 1
> EAL: Detected lcore 31 as core 20 on socket 1
> EAL: Detected lcore 32 as core 24 on socket 1
> EAL: Detected lcore 33 as core 25 on socket 1
> EAL: Detected lcore 34 as core 26 on socket 1
> EAL: Detected lcore 35 as core 27 on socket 1
> EAL: Detected lcore 36 as core 0 on socket 0
> EAL: Detected lcore 37 as core 1 on socket 0
> EAL: Detected lcore 38 as core 2 on socket 0
> EAL: Detected lcore 39 as core 3 on socket 0
> EAL: Detected lcore 40 as core 4 on socket 0
> EAL: Detected lcore 41 as core 8 on socket 0
> EAL: Detected lcore 42 as core 9 on socket 0
> EAL: Detected lcore 43 as core 10 on socket 0
> EAL: Detected lcore 44 as core 11 on socket 0
> EAL: Detected lcore 45 as core 16 on socket 0
> EAL: Detected lcore 46 as core 17 on socket 0
> EAL: Detected lcore 47 as core 18 on socket 0
> EAL: Detected lcore 48 as core 19 on socket 0
> EAL: Detected lcore 49 as core 20 on socket 0
> EAL: Detected lcore 50 as core 24 on socket 0
> EAL: Detected lcore 51 as core 25 on socket 0
> EAL: Detected lcore 52 as core 26 on socket 0
> EAL: Detected lcore 53 as core 27 on socket 0
> EAL: Detected lcore 54 as core 0 on socket 1
> EAL: Detected lcore 55 as core 1 on socket 1
> EAL: Detected lcore 56 as core 2 on socket 1
> EAL: Detected lcore 57 as core 3 on socket 1
> EAL: Detected lcore 58 as core 4 on socket 1
> EAL: Detected lcore 59 as core 8 on socket 1
> EAL: Detected lcore 60 as core 9 on socket 1
> EAL: Detected lcore 61 as core 10 on socket 1
> EAL: Detected lcore 62 as core 11 on socket 1
> EAL: Detected lcore 63 as core 16 on socket 1
> EAL: Detected lcore 64 as core 17 on socket 1
> EAL: Detected lcore 65 as core 18 on socket 1
> EAL: Detected lcore 66 as core 19 on socket 1
> EAL: Detected lcore 67 as core 20 on socket 1
> EAL: Detected lcore 68 as core 24 on socket 1
> EAL: Detected lcore 69 as core 25 on socket 1
> EAL: Detected lcore 70 as core 26 on socket 1
> EAL: Detected lcore 71 as core 27 on socket 1
> EAL: Support maximum 128 logical core(s) by configuration.
> EAL: Detected 72 lcore(s)
> EAL: Auto-detected process type: PRIMARY
> 
> 
> I suggest only the last three line are even remotely useful and we do not
> even print out the DPDK version number. I would put these as information
> data and the EAL: does not need to be present and you can not turn that
> information off.

Yes, please fix the log level of the early messages.
Why do you want to remove the EAL prefix?

> Example output: (Email my wrap the lines below)
> 
> *** DPDK version 2.1.0 Copyright(c) 2010-2015 Intel Corporation. All
> rights reserved. ***
>   Detected 72 lcore(s) with supporting maximum 128 logical core(s) by
> configuration
>   Auto-detected process type: PRIMARY
> 
> Maybe print out the amount of memory configured and ports detected or
> devices.

These are info messages.

> One of the license statements it to output the copyright notice for binary
> distributions and it would be nice to just output them anyway even in
> source code form as they would need to do it anyway. We may need to add a
> couple more copyright notices as well here.

Not sure that licences and copyrights should be printed.

> Anyway let me know what you want to do here and I can try to produce a
> patch.

You may start by trying to remove early debug logs when level is higher.
Thanks