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

["Wiles, Keith" <keith.wiles@intel.com>]

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.

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:

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
EAL: VFIO modules not all loaded, skip VFIO support...
EAL: Setting up memory...
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd8b0c00000 (size = 0x200000)
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd8b0800000 (size = 0x200000)
EAL: Ask a virtual area of 0x15000000 bytes
EAL: Virtual area found at 0x7fd89b600000 (size = 0x15000000)
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd89b200000 (size = 0x200000)
EAL: Ask a virtual area of 0x6a800000 bytes
EAL: Virtual area found at 0x7fd830800000 (size = 0x6a800000)
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd830400000 (size = 0x200000)
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd830000000 (size = 0x200000)
EAL: Ask a virtual area of 0x7fc00000 bytes
EAL: Virtual area found at 0x7fd7b0200000 (size = 0x7fc00000)
EAL: Ask a virtual area of 0x200000 bytes
EAL: Virtual area found at 0x7fd7afe00000 (size = 0x200000)
EAL: Requesting 256 pages of size 2MB from socket 0
EAL: Requesting 256 pages of size 2MB from socket 1
EAL: TSC frequency is ~2299999 KHz
EAL: Master lcore 4 is ready (tid=b289f900;cpuset=[4])
EAL: lcore 13 is ready (tid=971f7700;cpuset=[13])
EAL: lcore 15 is ready (tid=961f5700;cpuset=[15])
EAL: lcore 6 is ready (tid=9a9fe700;cpuset=[6])
EAL: lcore 11 is ready (tid=981f9700;cpuset=[11])
EAL: lcore 5 is ready (tid=9b1ff700;cpuset=[5])
EAL: lcore 16 is ready (tid=959f4700;cpuset=[16])
EAL: lcore 7 is ready (tid=9a1fd700;cpuset=[7])
EAL: lcore 10 is ready (tid=989fa700;cpuset=[10])
EAL: lcore 14 is ready (tid=969f6700;cpuset=[14])
EAL: lcore 8 is ready (tid=999fc700;cpuset=[8])
EAL: lcore 9 is ready (tid=991fb700;cpuset=[9])
EAL: lcore 12 is ready (tid=979f8700;cpuset=[12])
EAL: PCI device 0000:06:00.0 on NUMA socket 0
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:06:00.1 on NUMA socket 0
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:08:00.0 on NUMA socket 0
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:08:00.1 on NUMA socket 0
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:09:00.0 on NUMA socket 0
EAL:   probe driver: 8086:1521 rte_igb_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:09:00.1 on NUMA socket 0
EAL:   probe driver: 8086:1521 rte_igb_pmd
EAL:   Device is blacklisted, not initializing
EAL: PCI device 0000:87:00.0 on NUMA socket 1
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   PCI memory mapped at 0x7fd8b0e00000
EAL:   PCI memory mapped at 0x7fd8b0f00000
PMD: eth_ixgbe_dev_init(): MAC: 2, PHY: 19
PMD: eth_ixgbe_dev_init(): port 0 vendorID=0x8086 deviceID=0x1558
EAL: PCI device 0000:87:00.1 on NUMA socket 1
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   PCI memory mapped at 0x7fd8b2769000
EAL:   PCI memory mapped at 0x7fd8b28bb000
PMD: eth_ixgbe_dev_init(): MAC: 2, PHY: 19
PMD: eth_ixgbe_dev_init(): port 1 vendorID=0x8086 deviceID=0x1558
EAL: PCI device 0000:89:00.0 on NUMA socket 1
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   PCI memory mapped at 0x7fd8b0b00000
EAL:   PCI memory mapped at 0x7fd8b28b7000
PMD: eth_ixgbe_dev_init(): MAC: 2, PHY: 19
PMD: eth_ixgbe_dev_init(): port 2 vendorID=0x8086 deviceID=0x1558
EAL: PCI device 0000:89:00.1 on NUMA socket 1
EAL:   probe driver: 8086:1558 rte_ixgbe_pmd
EAL:   PCI memory mapped at 0x7fd8b0a00000
EAL:   PCI memory mapped at 0x7fd8b28b3000
PMD: eth_ixgbe_dev_init(): MAC: 2, PHY: 19
PMD: eth_ixgbe_dev_init(): port 3 vendorID=0x8086 deviceID=0x1558

PMD: ixgbe_dev_rx_queue_setup(): sw_ring=0x7fd8312cd6c0
sw_sc_ring=0x7fd8312cc580 hw_ring=0x7fd8b0c31500 dma_addr=0x36e31500

PMD: ixgbe_dev_tx_queue_setup(): sw_ring=0x7fd8312ca040
hw_ring=0x7fd8b09a1100 dma_addr=0x601a1100
PMD: ixgbe_set_tx_function(): Using simple tx code path
PMD: ixgbe_set_tx_function(): Vector tx enabled.

PMD: ixgbe_dev_rx_queue_setup(): sw_ring=0x7fd8312bb000
sw_sc_ring=0x7fd8312b9ec0 hw_ring=0x7fd8b09c1180 dma_addr=0x601c1180

PMD: ixgbe_dev_tx_queue_setup(): sw_ring=0x7fd8312b7980
hw_ring=0x7fd89b3a1100 dma_addr=0x3f71a1100
PMD: ixgbe_set_tx_function(): Using simple tx code path
PMD: ixgbe_set_tx_function(): Vector tx enabled.

PMD: ixgbe_dev_rx_queue_setup(): sw_ring=0x7fd8312a8940
sw_sc_ring=0x7fd8312a7800 hw_ring=0x7fd89b3c1180 dma_addr=0x3f71c1180

PMD: ixgbe_dev_tx_queue_setup(): sw_ring=0x7fd8312a52c0
hw_ring=0x7fd8b0c91c80 dma_addr=0x36e91c80
PMD: ixgbe_set_tx_function(): Using simple tx code path
PMD: ixgbe_set_tx_function(): Vector tx enabled.

PMD: ixgbe_dev_rx_queue_setup(): sw_ring=0x7fd831296280
sw_sc_ring=0x7fd831295140 hw_ring=0x7fd8b0cb1d00 dma_addr=0x36eb1d00

PMD: ixgbe_dev_tx_queue_setup(): sw_ring=0x7fd831292c00
hw_ring=0x7fd8b0cf1f00 dma_addr=0x36ef1f00
PMD: ixgbe_set_tx_function(): Using simple tx code path
PMD: ixgbe_set_tx_function(): Vector tx enabled.

PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=0).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=1).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=2).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=3).

PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=1).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=2).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=3).
PMD: ixgbe_set_rx_function(): Using Vector Scattered Rx callback (port=0).

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.

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.

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.

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.

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

Regards
++Keith 

>