[dpdk-dev] eal:Fix log messages always being printed from rte_eal_cpu_init

  The RTE_LOG(DEBUG, ...) messages in rte_eal_cpu_init() are printed
even when the log level on the command line was set to INFO or lower.

The problem is the rte_eal_cpu_init() routine was called before
the command line args are scanned. Setting --log-level=7 now
correctly does not print the messages from the rte_eal_cpu_init() routine.

Signed-off-by: Keith Wiles <keith.wiles@intel.com>
---
 lib/librte_eal/bsdapp/eal/eal.c   | 43 ++++++++++++++++++++++++++++++++++-----
 lib/librte_eal/linuxapp/eal/eal.c | 43 ++++++++++++++++++++++++++++++++++-----
 2 files changed, 76 insertions(+), 10 deletions(-)
  

On Sat, Jun 06, 2015 at 07:04:05PM -0500, Keith Wiles wrote:
> The RTE_LOG(DEBUG, ...) messages in rte_eal_cpu_init() are printed
> even when the log level on the command line was set to INFO or lower.
> 
> The problem is the rte_eal_cpu_init() routine was called before
> the command line args are scanned. Setting --log-level=7 now
> correctly does not print the messages from the rte_eal_cpu_init() routine.
> 
> Signed-off-by: Keith Wiles <keith.wiles@intel.com>

This seems a good idea - make it easy to reduce the verbosity on startup if
so desired. Some comments below.

> ---
>  lib/librte_eal/bsdapp/eal/eal.c   | 43 ++++++++++++++++++++++++++++++++++-----
>  lib/librte_eal/linuxapp/eal/eal.c | 43 ++++++++++++++++++++++++++++++++++-----
>  2 files changed, 76 insertions(+), 10 deletions(-)
> 
> diff --git a/lib/librte_eal/bsdapp/eal/eal.c b/lib/librte_eal/bsdapp/eal/eal.c
> index 43e8a47..ca10f2c 100644
> --- a/lib/librte_eal/bsdapp/eal/eal.c
> +++ b/lib/librte_eal/bsdapp/eal/eal.c
> @@ -306,6 +306,38 @@ eal_get_hugepage_mem_size(void)
>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>  }
>  
> +/* Parse the arguments for --log-level only */
> +static void
> +eal_log_level_parse(int argc, char **argv)
> +{
> +	int opt;
> +	char **argvopt;
> +	int option_index;
> +
> +	argvopt = argv;
> +
> +	eal_reset_internal_config(&internal_config);
> +
> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
> +				  eal_long_options, &option_index)) != EOF) {
> +
> +		int ret;
> +
> +		/* getopt is not happy, stop right now */
> +		if (opt == '?')
> +			break;
> +
> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
> +
> +		/* common parser is not happy */
> +		if (ret < 0)
> +			break;
> +	}
> +
> +	optind = 0; /* reset getopt lib */
> +}
> +
>  /* Parse the argument given in the command line of the application */
>  static int
>  eal_parse_args(int argc, char **argv)
> @@ -317,8 +349,6 @@ eal_parse_args(int argc, char **argv)
>  
>  	argvopt = argv;
>  
> -	eal_reset_internal_config(&internal_config);
> -
>  	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>  				  eal_long_options, &option_index)) != EOF) {
>  
> @@ -447,6 +477,12 @@ rte_eal_init(int argc, char **argv)
>  	if (rte_eal_log_early_init() < 0)
>  		rte_panic("Cannot init early logs\n");
>  
> +	eal_log_level_parse(argc, argv);
> +
> +	/* set log level as early as possible */
> +	rte_set_log_level(internal_config.log_level);
> +
> +	RTE_LOG(INFO, EAL,  "DPDK Version %s\n", rte_version());

There is already the -v option to the EAL to print the DPDK version. Just add
that flag to any command, as it has no other effects. I don't think we need to
increase the verbosity of startup by always printing it.

>  	if (rte_eal_cpu_init() < 0)
>  		rte_panic("Cannot detect lcores\n");
>  
> @@ -454,9 +490,6 @@ rte_eal_init(int argc, char **argv)
>  	if (fctret < 0)
>  		exit(1);
>  
> -	/* set log level as early as possible */
> -	rte_set_log_level(internal_config.log_level);
> -
>  	if (internal_config.no_hugetlbfs == 0 &&
>  			internal_config.process_type != RTE_PROC_SECONDARY &&
>  			eal_hugepage_info_init() < 0)
> diff --git a/lib/librte_eal/linuxapp/eal/eal.c b/lib/librte_eal/linuxapp/eal/eal.c
> index bd770cf..090ec99 100644
> --- a/lib/librte_eal/linuxapp/eal/eal.c
> +++ b/lib/librte_eal/linuxapp/eal/eal.c
> @@ -499,6 +499,38 @@ eal_get_hugepage_mem_size(void)
>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>  }
>  
> +/* Parse the arguments for --log-level only */
> +static void
> +eal_log_level_parse(int argc, char **argv)
> +{
> +	int opt;
> +	char **argvopt;
> +	int option_index;
> +
> +	argvopt = argv;
> +
> +	eal_reset_internal_config(&internal_config);
> +
> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
> +				  eal_long_options, &option_index)) != EOF) {
> +
> +		int ret;
> +
> +		/* getopt is not happy, stop right now */
> +		if (opt == '?')
> +			break;
> +
> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
> +
> +		/* common parser is not happy */
> +		if (ret < 0)
> +			break;
> +	}
> +
> +	optind = 0; /* reset getopt lib */
> +}
> +

This function looks duplicated for linux and bsd. Can we move it to one of the
common files instead?

Regards,
/Bruce
  

On 6/8/15, 6:09 AM, "Richardson, Bruce" <bruce.richardson@intel.com> wrote:

>On Sat, Jun 06, 2015 at 07:04:05PM -0500, Keith Wiles wrote:
>> The RTE_LOG(DEBUG, ...) messages in rte_eal_cpu_init() are printed
>> even when the log level on the command line was set to INFO or lower.
>> 
>> The problem is the rte_eal_cpu_init() routine was called before
>> the command line args are scanned. Setting --log-level=7 now
>> correctly does not print the messages from the rte_eal_cpu_init()
>>routine.
>> 
>> Signed-off-by: Keith Wiles <keith.wiles@intel.com>
>
>This seems a good idea - make it easy to reduce the verbosity on startup
>if
>so desired. Some comments below.
>
>> ---
>>  lib/librte_eal/bsdapp/eal/eal.c   | 43
>>++++++++++++++++++++++++++++++++++-----
>>  lib/librte_eal/linuxapp/eal/eal.c | 43
>>++++++++++++++++++++++++++++++++++-----
>>  2 files changed, 76 insertions(+), 10 deletions(-)
>> 
>> diff --git a/lib/librte_eal/bsdapp/eal/eal.c
>>b/lib/librte_eal/bsdapp/eal/eal.c
>> index 43e8a47..ca10f2c 100644
>> --- a/lib/librte_eal/bsdapp/eal/eal.c
>> +++ b/lib/librte_eal/bsdapp/eal/eal.c
>> @@ -306,6 +306,38 @@ eal_get_hugepage_mem_size(void)
>>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>>  }
>>  
>> +/* Parse the arguments for --log-level only */
>> +static void
>> +eal_log_level_parse(int argc, char **argv)
>> +{
>> +	int opt;
>> +	char **argvopt;
>> +	int option_index;
>> +
>> +	argvopt = argv;
>> +
>> +	eal_reset_internal_config(&internal_config);
>> +
>> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>> +				  eal_long_options, &option_index)) != EOF) {
>> +
>> +		int ret;
>> +
>> +		/* getopt is not happy, stop right now */
>> +		if (opt == '?')
>> +			break;
>> +
>> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
>> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
>> +
>> +		/* common parser is not happy */
>> +		if (ret < 0)
>> +			break;
>> +	}
>> +
>> +	optind = 0; /* reset getopt lib */
>> +}
>> +
>>  /* Parse the argument given in the command line of the application */
>>  static int
>>  eal_parse_args(int argc, char **argv)
>> @@ -317,8 +349,6 @@ eal_parse_args(int argc, char **argv)
>>  
>>  	argvopt = argv;
>>  
>> -	eal_reset_internal_config(&internal_config);
>> -
>>  	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>>  				  eal_long_options, &option_index)) != EOF) {
>>  
>> @@ -447,6 +477,12 @@ rte_eal_init(int argc, char **argv)
>>  	if (rte_eal_log_early_init() < 0)
>>  		rte_panic("Cannot init early logs\n");
>>  
>> +	eal_log_level_parse(argc, argv);
>> +
>> +	/* set log level as early as possible */
>> +	rte_set_log_level(internal_config.log_level);
>> +
>> +	RTE_LOG(INFO, EAL,  "DPDK Version %s\n", rte_version());
>
>There is already the -v option to the EAL to print the DPDK version. Just
>add
>that flag to any command, as it has no other effects. I don't think we
>need to
>increase the verbosity of startup by always printing it.

OK will remove, but it is one of the things you always need to know when
someone submits the startup messages. This way you do not have to put it
in the email or ask them to tell you.
>
>>  	if (rte_eal_cpu_init() < 0)
>>  		rte_panic("Cannot detect lcores\n");
>>  
>> @@ -454,9 +490,6 @@ rte_eal_init(int argc, char **argv)
>>  	if (fctret < 0)
>>  		exit(1);
>>  
>> -	/* set log level as early as possible */
>> -	rte_set_log_level(internal_config.log_level);
>> -
>>  	if (internal_config.no_hugetlbfs == 0 &&
>>  			internal_config.process_type != RTE_PROC_SECONDARY &&
>>  			eal_hugepage_info_init() < 0)
>> diff --git a/lib/librte_eal/linuxapp/eal/eal.c
>>b/lib/librte_eal/linuxapp/eal/eal.c
>> index bd770cf..090ec99 100644
>> --- a/lib/librte_eal/linuxapp/eal/eal.c
>> +++ b/lib/librte_eal/linuxapp/eal/eal.c
>> @@ -499,6 +499,38 @@ eal_get_hugepage_mem_size(void)
>>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>>  }
>>  
>> +/* Parse the arguments for --log-level only */
>> +static void
>> +eal_log_level_parse(int argc, char **argv)
>> +{
>> +	int opt;
>> +	char **argvopt;
>> +	int option_index;
>> +
>> +	argvopt = argv;
>> +
>> +	eal_reset_internal_config(&internal_config);
>> +
>> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>> +				  eal_long_options, &option_index)) != EOF) {
>> +
>> +		int ret;
>> +
>> +		/* getopt is not happy, stop right now */
>> +		if (opt == '?')
>> +			break;
>> +
>> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
>> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
>> +
>> +		/* common parser is not happy */
>> +		if (ret < 0)
>> +			break;
>> +	}
>> +
>> +	optind = 0; /* reset getopt lib */
>> +}
>> +
>
>This function looks duplicated for linux and bsd. Can we move it to one
>of the
>common files instead?

I looked at moving this function to the common location, but the problem
is all of the routines of this type are all static functions. I did not
want to add yet another global function to the mix. I will look at it and
see what I can do.
>
>Regards,
>/Bruce
  

On 6/8/15, 8:33 AM, "Wiles, Keith" <keith.wiles@intel.com> wrote:

>
>
>On 6/8/15, 6:09 AM, "Richardson, Bruce" <bruce.richardson@intel.com>
>wrote:
>
>>On Sat, Jun 06, 2015 at 07:04:05PM -0500, Keith Wiles wrote:
>>> The RTE_LOG(DEBUG, ...) messages in rte_eal_cpu_init() are printed
>>> even when the log level on the command line was set to INFO or lower.
>>> 
>>> The problem is the rte_eal_cpu_init() routine was called before
>>> the command line args are scanned. Setting --log-level=7 now
>>> correctly does not print the messages from the rte_eal_cpu_init()
>>>routine.
>>> 
>>> Signed-off-by: Keith Wiles <keith.wiles@intel.com>
>>
>>This seems a good idea - make it easy to reduce the verbosity on startup
>>if
>>so desired. Some comments below.
>>
>>> ---
>>>  lib/librte_eal/bsdapp/eal/eal.c   | 43
>>>++++++++++++++++++++++++++++++++++-----
>>>  lib/librte_eal/linuxapp/eal/eal.c | 43
>>>++++++++++++++++++++++++++++++++++-----
>>>  2 files changed, 76 insertions(+), 10 deletions(-)
>>> 
>>> diff --git a/lib/librte_eal/bsdapp/eal/eal.c
>>>b/lib/librte_eal/bsdapp/eal/eal.c
>>> index 43e8a47..ca10f2c 100644
>>> --- a/lib/librte_eal/bsdapp/eal/eal.c
>>> +++ b/lib/librte_eal/bsdapp/eal/eal.c
>>> @@ -306,6 +306,38 @@ eal_get_hugepage_mem_size(void)
>>>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>>>  }
>>>  
>>> +/* Parse the arguments for --log-level only */
>>> +static void
>>> +eal_log_level_parse(int argc, char **argv)
>>> +{
>>> +	int opt;
>>> +	char **argvopt;
>>> +	int option_index;
>>> +
>>> +	argvopt = argv;
>>> +
>>> +	eal_reset_internal_config(&internal_config);
>>> +
>>> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>>> +				  eal_long_options, &option_index)) != EOF) {
>>> +
>>> +		int ret;
>>> +
>>> +		/* getopt is not happy, stop right now */
>>> +		if (opt == '?')
>>> +			break;
>>> +
>>> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
>>> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
>>> +
>>> +		/* common parser is not happy */
>>> +		if (ret < 0)
>>> +			break;
>>> +	}
>>> +
>>> +	optind = 0; /* reset getopt lib */
>>> +}
>>> +
>>>  /* Parse the argument given in the command line of the application */
>>>  static int
>>>  eal_parse_args(int argc, char **argv)
>>> @@ -317,8 +349,6 @@ eal_parse_args(int argc, char **argv)
>>>  
>>>  	argvopt = argv;
>>>  
>>> -	eal_reset_internal_config(&internal_config);
>>> -
>>>  	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>>>  				  eal_long_options, &option_index)) != EOF) {
>>>  
>>> @@ -447,6 +477,12 @@ rte_eal_init(int argc, char **argv)
>>>  	if (rte_eal_log_early_init() < 0)
>>>  		rte_panic("Cannot init early logs\n");
>>>  
>>> +	eal_log_level_parse(argc, argv);
>>> +
>>> +	/* set log level as early as possible */
>>> +	rte_set_log_level(internal_config.log_level);
>>> +
>>> +	RTE_LOG(INFO, EAL,  "DPDK Version %s\n", rte_version());
>>
>>There is already the -v option to the EAL to print the DPDK version. Just
>>add
>>that flag to any command, as it has no other effects. I don't think we
>>need to
>>increase the verbosity of startup by always printing it.
>
>OK will remove, but it is one of the things you always need to know when
>someone submits the startup messages. This way you do not have to put it
>in the email or ask them to tell you.
>>
>>>  	if (rte_eal_cpu_init() < 0)
>>>  		rte_panic("Cannot detect lcores\n");
>>>  
>>> @@ -454,9 +490,6 @@ rte_eal_init(int argc, char **argv)
>>>  	if (fctret < 0)
>>>  		exit(1);
>>>  
>>> -	/* set log level as early as possible */
>>> -	rte_set_log_level(internal_config.log_level);
>>> -
>>>  	if (internal_config.no_hugetlbfs == 0 &&
>>>  			internal_config.process_type != RTE_PROC_SECONDARY &&
>>>  			eal_hugepage_info_init() < 0)
>>> diff --git a/lib/librte_eal/linuxapp/eal/eal.c
>>>b/lib/librte_eal/linuxapp/eal/eal.c
>>> index bd770cf..090ec99 100644
>>> --- a/lib/librte_eal/linuxapp/eal/eal.c
>>> +++ b/lib/librte_eal/linuxapp/eal/eal.c
>>> @@ -499,6 +499,38 @@ eal_get_hugepage_mem_size(void)
>>>  	return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX;
>>>  }
>>>  
>>> +/* Parse the arguments for --log-level only */
>>> +static void
>>> +eal_log_level_parse(int argc, char **argv)
>>> +{
>>> +	int opt;
>>> +	char **argvopt;
>>> +	int option_index;
>>> +
>>> +	argvopt = argv;
>>> +
>>> +	eal_reset_internal_config(&internal_config);
>>> +
>>> +	while ((opt = getopt_long(argc, argvopt, eal_short_options,
>>> +				  eal_long_options, &option_index)) != EOF) {
>>> +
>>> +		int ret;
>>> +
>>> +		/* getopt is not happy, stop right now */
>>> +		if (opt == '?')
>>> +			break;
>>> +
>>> +		ret = (opt == OPT_LOG_LEVEL_NUM)?
>>> +			eal_parse_common_option(opt, optarg, &internal_config) : 0;
>>> +
>>> +		/* common parser is not happy */
>>> +		if (ret < 0)
>>> +			break;
>>> +	}
>>> +
>>> +	optind = 0; /* reset getopt lib */
>>> +}
>>> +
>>
>>This function looks duplicated for linux and bsd. Can we move it to one
>>of the
>>common files instead?
>
>I looked at moving this function to the common location, but the problem
>is all of the routines of this type are all static functions. I did not
>want to add yet another global function to the mix. I will look at it and
>see what I can do.

Well it looks like a fair number of the functions in eal.c are common
between both versions. I could try to move them all or just leave the code
as is. What do you want here?
>>
>>Regards,
>>/Bruce
>