[dpdk-dev,v3,4/8] eal: change specific log levels at startup

Message ID 20170404164040.24132-5-olivier.matz@6wind.com (mailing list archive)
State Accepted, archived
Delegated to: Thomas Monjalon
Headers

Checks

Context Check Description
ci/checkpatch success coding style OK
ci/Intel-compilation fail Compilation issues

Commit Message

Olivier Matz April 4, 2017, 4:40 p.m. UTC
  Example of use:
  ./app/test-pmd --log-level='pmd\.i40e.*,8'

  This enables debug logs for all dynamic logs whose type starts with
  'pmd.i40e'.

Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
---
 lib/librte_eal/bsdapp/eal/eal.c            |  4 +--
 lib/librte_eal/common/eal_common_options.c | 49 +++++++++++++++++++++++-------
 lib/librte_eal/linuxapp/eal/eal.c          |  4 +--
 3 files changed, 40 insertions(+), 17 deletions(-)
  

Comments

Jianfeng Tan April 14, 2017, 5:33 a.m. UTC | #1
Hi Olivier,

If I understand it correctly, this patch is to shift log level setting 
earlier. But we did not remove the one in eal_parse_common_option(). So 
we can see this parameter will be analyzed twice. Does it make sense to 
remove analysis of log level in eal_parse_common_option()?

Thanks,
Jianfeng

On 4/5/2017 12:40 AM, Olivier Matz wrote:
> Example of use:
>    ./app/test-pmd --log-level='pmd\.i40e.*,8'
>
>    This enables debug logs for all dynamic logs whose type starts with
>    'pmd.i40e'.
>
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
> ---
>   lib/librte_eal/bsdapp/eal/eal.c            |  4 +--
>   lib/librte_eal/common/eal_common_options.c | 49 +++++++++++++++++++++++-------
>   lib/librte_eal/linuxapp/eal/eal.c          |  4 +--
>   3 files changed, 40 insertions(+), 17 deletions(-)
>
> diff --git a/lib/librte_eal/bsdapp/eal/eal.c b/lib/librte_eal/bsdapp/eal/eal.c
> index 4ee9c66fe..fae6c7e0a 100644
> --- a/lib/librte_eal/bsdapp/eal/eal.c
> +++ b/lib/librte_eal/bsdapp/eal/eal.c
> @@ -519,10 +519,8 @@ rte_eal_init(int argc, char **argv)
>   
>   	thread_id = pthread_self();
>   
> -	eal_log_level_parse(argc, argv);
> -
>   	/* set log level as early as possible */
> -	rte_set_log_level(internal_config.log_level);
> +	eal_log_level_parse(argc, argv);
>   
>   	if (rte_eal_cpu_init() < 0) {
>   		rte_eal_init_alert("Cannot detect lcores.");
> diff --git a/lib/librte_eal/common/eal_common_options.c b/lib/librte_eal/common/eal_common_options.c
> index f36bc5568..606695a7f 100644
> --- a/lib/librte_eal/common/eal_common_options.c
> +++ b/lib/librte_eal/common/eal_common_options.c
> @@ -739,25 +739,53 @@ eal_parse_syslog(const char *facility, struct internal_config *conf)
>   }
>   
>   static int
> -eal_parse_log_level(const char *level, uint32_t *log_level)
> +eal_parse_log_level(const char *arg, struct internal_config *conf)
>   {
> -	char *end;
> +	char *end, *str, *type, *level;
>   	unsigned long tmp;
>   
> +	str = strdup(arg);
> +	if (str == NULL)
> +		return -1;
> +
> +	if (strchr(str, ',') == NULL) {
> +		type = NULL;
> +		level = str;
> +	} else {
> +		type = strsep(&str, ",");
> +		level = strsep(&str, ",");
> +	}
> +
>   	errno = 0;
>   	tmp = strtoul(level, &end, 0);
>   
>   	/* check for errors */
>   	if ((errno != 0) || (level[0] == '\0') ||
> -	    end == NULL || (*end != '\0'))
> -		return -1;
> +		    end == NULL || (*end != '\0'))
> +		goto fail;
>   
>   	/* log_level is a uint32_t */
>   	if (tmp >= UINT32_MAX)
> -		return -1;
> +		goto fail;
> +
> +	printf("set log level %s,%lu\n",
> +		type, tmp);
> +
> +	if (type == NULL) {
> +		conf->log_level = tmp;
> +		rte_set_log_level(tmp);
> +	} else if (rte_log_set_level_regexp(type, tmp) < 0) {
> +		printf("cannot set log level %s,%lu\n",
> +			type, tmp);
> +		goto fail;
> +	}
>   
> -	*log_level = tmp;
> +	free(str);
>   	return 0;
> +
> +fail:
> +	free(str);
> +	return -1;
>   }
>   
>   static enum rte_proc_type_t
> @@ -898,15 +926,12 @@ eal_parse_common_option(int opt, const char *optarg,
>   		break;
>   
>   	case OPT_LOG_LEVEL_NUM: {
> -		uint32_t log;
> -
> -		if (eal_parse_log_level(optarg, &log) < 0) {
> +		if (eal_parse_log_level(optarg, conf) < 0) {
>   			RTE_LOG(ERR, EAL,
>   				"invalid parameters for --"
>   				OPT_LOG_LEVEL "\n");
>   			return -1;
>   		}
> -		conf->log_level = log;
>   		break;
>   	}
>   	case OPT_LCORES_NUM:
> @@ -1057,7 +1082,9 @@ eal_common_usage(void)
>   	       "  --"OPT_VMWARE_TSC_MAP"    Use VMware TSC map instead of native RDTSC\n"
>   	       "  --"OPT_PROC_TYPE"         Type of this process (primary|secondary|auto)\n"
>   	       "  --"OPT_SYSLOG"            Set syslog facility\n"
> -	       "  --"OPT_LOG_LEVEL"         Set default log level\n"
> +	       "  --"OPT_LOG_LEVEL"=<int>   Set global log level\n"
> +	       "  --"OPT_LOG_LEVEL"=<type-regexp>,<int>\n"
> +	       "                      Set specific log level\n"
>   	       "  -v                  Display version information on startup\n"
>   	       "  -h, --help          This help\n"
>   	       "\nEAL options for DEBUG use only:\n"
> diff --git a/lib/librte_eal/linuxapp/eal/eal.c b/lib/librte_eal/linuxapp/eal/eal.c
> index f0ded185b..d98d56d2f 100644
> --- a/lib/librte_eal/linuxapp/eal/eal.c
> +++ b/lib/librte_eal/linuxapp/eal/eal.c
> @@ -776,10 +776,8 @@ rte_eal_init(int argc, char **argv)
>   
>   	thread_id = pthread_self();
>   
> -	eal_log_level_parse(argc, argv);
> -
>   	/* set log level as early as possible */
> -	rte_set_log_level(internal_config.log_level);
> +	eal_log_level_parse(argc, argv);
>   
>   	if (rte_eal_cpu_init() < 0) {
>   		rte_eal_init_alert("Cannot detect lcores.");
  
Ferruh Yigit April 14, 2017, 3:32 p.m. UTC | #2
Hi Olivier,

On 4/4/2017 5:40 PM, Olivier Matz wrote:
> Example of use:
>   ./app/test-pmd --log-level='pmd\.i40e.*,8'
> 
>   This enables debug logs for all dynamic logs whose type starts with
>   'pmd.i40e'.
> 
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>

<...>

> index f0ded185b..d98d56d2f 100644
> --- a/lib/librte_eal/linuxapp/eal/eal.c
> +++ b/lib/librte_eal/linuxapp/eal/eal.c
> @@ -776,10 +776,8 @@ rte_eal_init(int argc, char **argv)
>  
>  	thread_id = pthread_self();
>  
> -	eal_log_level_parse(argc, argv);
> -
>  	/* set log level as early as possible */
> -	rte_set_log_level(internal_config.log_level);

Removing this line prevents using RTE_LOG_LEVEL config option.

When there is no command line argument provided, I think it makes sense
to use config option. Currently config option is set to INFO level but
app shows DEBUG level logs, this is confusing.

> +	eal_log_level_parse(argc, argv);
>  
>  	if (rte_eal_cpu_init() < 0) {
>  		rte_eal_init_alert("Cannot detect lcores.");
>
  
Ferruh Yigit April 14, 2017, 3:40 p.m. UTC | #3
On 4/4/2017 5:40 PM, Olivier Matz wrote:
> Example of use:
>   ./app/test-pmd --log-level='pmd\.i40e.*,8'
> 
>   This enables debug logs for all dynamic logs whose type starts with
>   'pmd.i40e'.
> 
> Signed-off-by: Olivier Matz <olivier.matz@6wind.com>

<...>

> +
> +	printf("set log level %s,%lu\n",
> +		type, tmp);

A printf seems left here, this prints always independent from log level,
do we want this?
  
Olivier Matz April 18, 2017, 8:02 a.m. UTC | #4
Hi Jianfeng, Ferruh,

Thank you for spotting these issues. I'm on it, I will send a patch
to fix them asap.

Olivier


On Fri, 14 Apr 2017 16:32:57 +0100, Ferruh Yigit <ferruh.yigit@intel.com> wrote:
> Hi Olivier,
> 
> On 4/4/2017 5:40 PM, Olivier Matz wrote:
> > Example of use:
> >   ./app/test-pmd --log-level='pmd\.i40e.*,8'
> > 
> >   This enables debug logs for all dynamic logs whose type starts with
> >   'pmd.i40e'.
> > 
> > Signed-off-by: Olivier Matz <olivier.matz@6wind.com>  
> 
> <...>
> 
> > index f0ded185b..d98d56d2f 100644
> > --- a/lib/librte_eal/linuxapp/eal/eal.c
> > +++ b/lib/librte_eal/linuxapp/eal/eal.c
> > @@ -776,10 +776,8 @@ rte_eal_init(int argc, char **argv)
> >  
> >  	thread_id = pthread_self();
> >  
> > -	eal_log_level_parse(argc, argv);
> > -
> >  	/* set log level as early as possible */
> > -	rte_set_log_level(internal_config.log_level);  
> 
> Removing this line prevents using RTE_LOG_LEVEL config option.
> 
> When there is no command line argument provided, I think it makes sense
> to use config option. Currently config option is set to INFO level but
> app shows DEBUG level logs, this is confusing.
> 
> > +	eal_log_level_parse(argc, argv);
> >  
> >  	if (rte_eal_cpu_init() < 0) {
> >  		rte_eal_init_alert("Cannot detect lcores.");
> >   
>
  
Olivier Matz April 18, 2017, 8:50 a.m. UTC | #5
Hi Jianfeng,

On Fri, 14 Apr 2017 13:33:49 +0800, "Tan, Jianfeng" <jianfeng.tan@intel.com> wrote:
> Hi Olivier,
> 
> If I understand it correctly, this patch is to shift log level setting 
> earlier. But we did not remove the one in eal_parse_common_option(). So 
> we can see this parameter will be analyzed twice. Does it make sense to 
> remove analysis of log level in eal_parse_common_option()?
> 

The patch does not change the way the log level is parsed: it was
already parsed twice, because we want to know the log level as soon
as possible.

But the patch introduces a bug, as seen by Ferruh: the default log
level is not set properly when no --log-level parameter is passed.

Regards,
Olivier


> Thanks,
> Jianfeng
> 
> On 4/5/2017 12:40 AM, Olivier Matz wrote:
> > Example of use:
> >    ./app/test-pmd --log-level='pmd\.i40e.*,8'
> >
> >    This enables debug logs for all dynamic logs whose type starts with
> >    'pmd.i40e'.
> >
> > Signed-off-by: Olivier Matz <olivier.matz@6wind.com>
> > ---
> >   lib/librte_eal/bsdapp/eal/eal.c            |  4 +--
> >   lib/librte_eal/common/eal_common_options.c | 49 +++++++++++++++++++++++-------
> >   lib/librte_eal/linuxapp/eal/eal.c          |  4 +--
> >   3 files changed, 40 insertions(+), 17 deletions(-)
> >
> > diff --git a/lib/librte_eal/bsdapp/eal/eal.c b/lib/librte_eal/bsdapp/eal/eal.c
> > index 4ee9c66fe..fae6c7e0a 100644
> > --- a/lib/librte_eal/bsdapp/eal/eal.c
> > +++ b/lib/librte_eal/bsdapp/eal/eal.c
> > @@ -519,10 +519,8 @@ rte_eal_init(int argc, char **argv)
> >   
> >   	thread_id = pthread_self();
> >   
> > -	eal_log_level_parse(argc, argv);
> > -
> >   	/* set log level as early as possible */
> > -	rte_set_log_level(internal_config.log_level);
> > +	eal_log_level_parse(argc, argv);
> >   
> >   	if (rte_eal_cpu_init() < 0) {
> >   		rte_eal_init_alert("Cannot detect lcores.");
> > diff --git a/lib/librte_eal/common/eal_common_options.c b/lib/librte_eal/common/eal_common_options.c
> > index f36bc5568..606695a7f 100644
> > --- a/lib/librte_eal/common/eal_common_options.c
> > +++ b/lib/librte_eal/common/eal_common_options.c
> > @@ -739,25 +739,53 @@ eal_parse_syslog(const char *facility, struct internal_config *conf)
> >   }
> >   
> >   static int
> > -eal_parse_log_level(const char *level, uint32_t *log_level)
> > +eal_parse_log_level(const char *arg, struct internal_config *conf)
> >   {
> > -	char *end;
> > +	char *end, *str, *type, *level;
> >   	unsigned long tmp;
> >   
> > +	str = strdup(arg);
> > +	if (str == NULL)
> > +		return -1;
> > +
> > +	if (strchr(str, ',') == NULL) {
> > +		type = NULL;
> > +		level = str;
> > +	} else {
> > +		type = strsep(&str, ",");
> > +		level = strsep(&str, ",");
> > +	}
> > +
> >   	errno = 0;
> >   	tmp = strtoul(level, &end, 0);
> >   
> >   	/* check for errors */
> >   	if ((errno != 0) || (level[0] == '\0') ||
> > -	    end == NULL || (*end != '\0'))
> > -		return -1;
> > +		    end == NULL || (*end != '\0'))
> > +		goto fail;
> >   
> >   	/* log_level is a uint32_t */
> >   	if (tmp >= UINT32_MAX)
> > -		return -1;
> > +		goto fail;
> > +
> > +	printf("set log level %s,%lu\n",
> > +		type, tmp);
> > +
> > +	if (type == NULL) {
> > +		conf->log_level = tmp;
> > +		rte_set_log_level(tmp);
> > +	} else if (rte_log_set_level_regexp(type, tmp) < 0) {
> > +		printf("cannot set log level %s,%lu\n",
> > +			type, tmp);
> > +		goto fail;
> > +	}
> >   
> > -	*log_level = tmp;
> > +	free(str);
> >   	return 0;
> > +
> > +fail:
> > +	free(str);
> > +	return -1;
> >   }
> >   
> >   static enum rte_proc_type_t
> > @@ -898,15 +926,12 @@ eal_parse_common_option(int opt, const char *optarg,
> >   		break;
> >   
> >   	case OPT_LOG_LEVEL_NUM: {
> > -		uint32_t log;
> > -
> > -		if (eal_parse_log_level(optarg, &log) < 0) {
> > +		if (eal_parse_log_level(optarg, conf) < 0) {
> >   			RTE_LOG(ERR, EAL,
> >   				"invalid parameters for --"
> >   				OPT_LOG_LEVEL "\n");
> >   			return -1;
> >   		}
> > -		conf->log_level = log;
> >   		break;
> >   	}
> >   	case OPT_LCORES_NUM:
> > @@ -1057,7 +1082,9 @@ eal_common_usage(void)
> >   	       "  --"OPT_VMWARE_TSC_MAP"    Use VMware TSC map instead of native RDTSC\n"
> >   	       "  --"OPT_PROC_TYPE"         Type of this process (primary|secondary|auto)\n"
> >   	       "  --"OPT_SYSLOG"            Set syslog facility\n"
> > -	       "  --"OPT_LOG_LEVEL"         Set default log level\n"
> > +	       "  --"OPT_LOG_LEVEL"=<int>   Set global log level\n"
> > +	       "  --"OPT_LOG_LEVEL"=<type-regexp>,<int>\n"
> > +	       "                      Set specific log level\n"
> >   	       "  -v                  Display version information on startup\n"
> >   	       "  -h, --help          This help\n"
> >   	       "\nEAL options for DEBUG use only:\n"
> > diff --git a/lib/librte_eal/linuxapp/eal/eal.c b/lib/librte_eal/linuxapp/eal/eal.c
> > index f0ded185b..d98d56d2f 100644
> > --- a/lib/librte_eal/linuxapp/eal/eal.c
> > +++ b/lib/librte_eal/linuxapp/eal/eal.c
> > @@ -776,10 +776,8 @@ rte_eal_init(int argc, char **argv)
> >   
> >   	thread_id = pthread_self();
> >   
> > -	eal_log_level_parse(argc, argv);
> > -
> >   	/* set log level as early as possible */
> > -	rte_set_log_level(internal_config.log_level);
> > +	eal_log_level_parse(argc, argv);
> >   
> >   	if (rte_eal_cpu_init() < 0) {
> >   		rte_eal_init_alert("Cannot detect lcores.");  
>
  
Jianfeng Tan April 18, 2017, 11:15 a.m. UTC | #6
On 4/18/2017 4:50 PM, Olivier MATZ wrote:
> Hi Jianfeng,
>
> On Fri, 14 Apr 2017 13:33:49 +0800, "Tan, Jianfeng" <jianfeng.tan@intel.com> wrote:
>> Hi Olivier,
>>
>> If I understand it correctly, this patch is to shift log level setting
>> earlier. But we did not remove the one in eal_parse_common_option(). So
>> we can see this parameter will be analyzed twice. Does it make sense to
>> remove analysis of log level in eal_parse_common_option()?
>>
> The patch does not change the way the log level is parsed: it was
> already parsed twice, because we want to know the log level as soon
> as possible.

Oh, yes, it's not introduced in this patch. How do you think if we move 
log parser out from eal_parse_common_option to avoid parsing log twice?

>
> But the patch introduces a bug, as seen by Ferruh: the default log
> level is not set properly when no --log-level parameter is passed.
>

Before this one, there is another one on usage of regexec(), which I put 
it here: http://dpdk.org/ml/archives/dev/2017-April/064031.html.

Thanks,
Jianfeng
  
Olivier Matz April 18, 2017, 11:56 a.m. UTC | #7
Hi Jianfeng,

On Tue, 18 Apr 2017 19:15:51 +0800, "Tan, Jianfeng" <jianfeng.tan@intel.com> wrote:
> On 4/18/2017 4:50 PM, Olivier MATZ wrote:
> > Hi Jianfeng,
> >
> > On Fri, 14 Apr 2017 13:33:49 +0800, "Tan, Jianfeng" <jianfeng.tan@intel.com> wrote:  
> >> Hi Olivier,
> >>
> >> If I understand it correctly, this patch is to shift log level setting
> >> earlier. But we did not remove the one in eal_parse_common_option(). So
> >> we can see this parameter will be analyzed twice. Does it make sense to
> >> remove analysis of log level in eal_parse_common_option()?
> >>  
> > The patch does not change the way the log level is parsed: it was
> > already parsed twice, because we want to know the log level as soon
> > as possible.  
> 
> Oh, yes, it's not introduced in this patch. How do you think if we move 
> log parser out from eal_parse_common_option to avoid parsing log twice?

Not sure it's so easy to do. The second pass can ignore the --log-level
argument, but it has to be recognized, else we would have an error. I
think it's ok like this.

> 
> >
> > But the patch introduces a bug, as seen by Ferruh: the default log
> > level is not set properly when no --log-level parameter is passed.
> >  
> 
> Before this one, there is another one on usage of regexec(), which I put 
> it here: http://dpdk.org/ml/archives/dev/2017-April/064031.html.

Yes, I've seen it, I'll send a patch for this today. Thanks.


Olivier
  

Patch

diff --git a/lib/librte_eal/bsdapp/eal/eal.c b/lib/librte_eal/bsdapp/eal/eal.c
index 4ee9c66fe..fae6c7e0a 100644
--- a/lib/librte_eal/bsdapp/eal/eal.c
+++ b/lib/librte_eal/bsdapp/eal/eal.c
@@ -519,10 +519,8 @@  rte_eal_init(int argc, char **argv)
 
 	thread_id = pthread_self();
 
-	eal_log_level_parse(argc, argv);
-
 	/* set log level as early as possible */
-	rte_set_log_level(internal_config.log_level);
+	eal_log_level_parse(argc, argv);
 
 	if (rte_eal_cpu_init() < 0) {
 		rte_eal_init_alert("Cannot detect lcores.");
diff --git a/lib/librte_eal/common/eal_common_options.c b/lib/librte_eal/common/eal_common_options.c
index f36bc5568..606695a7f 100644
--- a/lib/librte_eal/common/eal_common_options.c
+++ b/lib/librte_eal/common/eal_common_options.c
@@ -739,25 +739,53 @@  eal_parse_syslog(const char *facility, struct internal_config *conf)
 }
 
 static int
-eal_parse_log_level(const char *level, uint32_t *log_level)
+eal_parse_log_level(const char *arg, struct internal_config *conf)
 {
-	char *end;
+	char *end, *str, *type, *level;
 	unsigned long tmp;
 
+	str = strdup(arg);
+	if (str == NULL)
+		return -1;
+
+	if (strchr(str, ',') == NULL) {
+		type = NULL;
+		level = str;
+	} else {
+		type = strsep(&str, ",");
+		level = strsep(&str, ",");
+	}
+
 	errno = 0;
 	tmp = strtoul(level, &end, 0);
 
 	/* check for errors */
 	if ((errno != 0) || (level[0] == '\0') ||
-	    end == NULL || (*end != '\0'))
-		return -1;
+		    end == NULL || (*end != '\0'))
+		goto fail;
 
 	/* log_level is a uint32_t */
 	if (tmp >= UINT32_MAX)
-		return -1;
+		goto fail;
+
+	printf("set log level %s,%lu\n",
+		type, tmp);
+
+	if (type == NULL) {
+		conf->log_level = tmp;
+		rte_set_log_level(tmp);
+	} else if (rte_log_set_level_regexp(type, tmp) < 0) {
+		printf("cannot set log level %s,%lu\n",
+			type, tmp);
+		goto fail;
+	}
 
-	*log_level = tmp;
+	free(str);
 	return 0;
+
+fail:
+	free(str);
+	return -1;
 }
 
 static enum rte_proc_type_t
@@ -898,15 +926,12 @@  eal_parse_common_option(int opt, const char *optarg,
 		break;
 
 	case OPT_LOG_LEVEL_NUM: {
-		uint32_t log;
-
-		if (eal_parse_log_level(optarg, &log) < 0) {
+		if (eal_parse_log_level(optarg, conf) < 0) {
 			RTE_LOG(ERR, EAL,
 				"invalid parameters for --"
 				OPT_LOG_LEVEL "\n");
 			return -1;
 		}
-		conf->log_level = log;
 		break;
 	}
 	case OPT_LCORES_NUM:
@@ -1057,7 +1082,9 @@  eal_common_usage(void)
 	       "  --"OPT_VMWARE_TSC_MAP"    Use VMware TSC map instead of native RDTSC\n"
 	       "  --"OPT_PROC_TYPE"         Type of this process (primary|secondary|auto)\n"
 	       "  --"OPT_SYSLOG"            Set syslog facility\n"
-	       "  --"OPT_LOG_LEVEL"         Set default log level\n"
+	       "  --"OPT_LOG_LEVEL"=<int>   Set global log level\n"
+	       "  --"OPT_LOG_LEVEL"=<type-regexp>,<int>\n"
+	       "                      Set specific log level\n"
 	       "  -v                  Display version information on startup\n"
 	       "  -h, --help          This help\n"
 	       "\nEAL options for DEBUG use only:\n"
diff --git a/lib/librte_eal/linuxapp/eal/eal.c b/lib/librte_eal/linuxapp/eal/eal.c
index f0ded185b..d98d56d2f 100644
--- a/lib/librte_eal/linuxapp/eal/eal.c
+++ b/lib/librte_eal/linuxapp/eal/eal.c
@@ -776,10 +776,8 @@  rte_eal_init(int argc, char **argv)
 
 	thread_id = pthread_self();
 
-	eal_log_level_parse(argc, argv);
-
 	/* set log level as early as possible */
-	rte_set_log_level(internal_config.log_level);
+	eal_log_level_parse(argc, argv);
 
 	if (rte_eal_cpu_init() < 0) {
 		rte_eal_init_alert("Cannot detect lcores.");