[tarantool-patches] [PATCH 1/1] Fixed non-informative error messages for log conf.

[tarantool-patches] [PATCH 1/1] Fixed non-informative error messages for log conf.

[Olga Arkhangelskaia]

In case of bad or erroneous options for log configurations
errors had ambiguous or absent messages. In some cases it lead to
app crashes.

Closes #3553
---
https://github.com/tarantool/tarantool/issues/3553
https://github.com/tarantool/tarantool/tree/OKriw/gh-3553-non-inf-error

 src/box/box.cc            | 25 ++++++++++++++++++-------
 src/say.c                 | 22 +++++++++++++++-------
 src/say.h                 |  4 +++-
 test/box-tap/cfg.test.lua |  2 +-
 4 files changed, 37 insertions(+), 16 deletions(-)

diff --git a/src/box/box.cc b/src/box/box.cc
index b6c22b081..c711cd55a 100644
--- a/src/box/box.cc
+++ b/src/box/box.cc
@@ -353,10 +353,13 @@ apply_initial_join_row(struct xstream *stream, struct xrow_header *row)
 static void
 box_check_say()
 {
-	const char *log = cfg_gets("log");
-	if (log == NULL)
-		return;
 	enum say_logger_type type;
+	const char *log = cfg_gets("log");
+	if (log == NULL) {
+		type = SAY_LOGGER_STDERR;
+		goto checks;
+	}
+	
 	if (say_parse_logger_type(&log, &type) < 0) {
 		tnt_raise(ClientError, ER_CFG, "log",
 			  diag_last_error(diag_get())->errmsg);
@@ -375,17 +378,21 @@ box_check_say()
 		say_free_syslog_opts(&opts);
 	}
 
+checks:
 	const char *log_format = cfg_gets("log_format");
 	enum say_format format = say_format_by_name(log_format);
 	if (format == say_format_MAX)
-		diag_set(ClientError, ER_CFG, "log_format",
+		tnt_raise(ClientError, ER_CFG, "log_format",
 			 "expected 'plain' or 'json'");
 	if (type == SAY_LOGGER_SYSLOG && format == SF_JSON) {
-		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_format");
+		tnt_raise(ClientError, ER_CFG, "log, log_format",
+			  "incompatible values");
 	}
 	int log_nonblock = cfg_getb("log_nonblock");
-	if (log_nonblock == 1 && type == SAY_LOGGER_FILE) {
-		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_nonblock");
+	if (log_nonblock == 1 &&
+	    (type == SAY_LOGGER_FILE || type == SAY_LOGGER_STDERR)) {
+		tnt_raise(ClientError, ER_CFG, "log, log_nonblock",
+			  "incompatible values");
 	}
 }
 
@@ -745,6 +752,10 @@ void
 box_set_log_format(void)
 {
 	enum say_format format = box_check_log_format(cfg_gets("log_format"));
+	if (say_set_log_format(format) < 0) {
+		 tnt_raise(ClientError, ER_CFG, "log_format",
+		           diag_last_error(diag_get())->errmsg);
+	}
 	say_set_log_format(format);
 }
 
diff --git a/src/say.c b/src/say.c
index b4836d9ee..8753bb865 100644
--- a/src/say.c
+++ b/src/say.c
@@ -190,7 +190,7 @@ say_set_log_level(int new_level)
 	log_set_level(log_default, (enum say_level) new_level);
 }
 
-void
+int
 say_set_log_format(enum say_format format)
 {
 	/*
@@ -204,22 +204,25 @@ say_set_log_format(enum say_format format)
 	case SF_JSON:
 
 		if (!allowed_to_change) {
-			say_error("json log format is not supported when output is '%s'",
+			diag_set(IllegalParams,
+				 "json log format is incompatible with '%s'log",
 				  say_logger_type_strs[log_default->type]);
-			return;
+			return -1;
 		}
 		log_set_format(log_default, say_format_json);
 		break;
 	case SF_PLAIN:
 		if (!allowed_to_change) {
-			return;
+			return 0;
 		}
 		log_set_format(log_default, say_format_plain);
 		break;
 	default:
-		unreachable();
+		diag_set(IllegalParams, "unsupported log_format, expected plain or json");
+		return -1;
 	}
 	log_format = format;
+	return 0;
 }
 
 static const char *say_format_strs[] = {
@@ -692,7 +695,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
 	say_set_log_level(level);
 	log_background = background;
 	log_pid = log_default->pid;
-	say_set_log_format(say_format_by_name(format));
+	if (say_set_log_format(say_format_by_name(format)) < 0)
+		goto error;
 
 	if (background) {
 		fflush(stderr);
@@ -715,6 +719,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
 fail:
 	diag_log();
 	panic("failed to initialize logging subsystem");
+error:
+	diag_log();
 }
 
 void
@@ -1071,8 +1077,10 @@ say_parse_logger_type(const char **str, enum say_logger_type *type)
 		*type = SAY_LOGGER_SYSLOG;
 	else if (strchr(*str, ':') == NULL)
 		*type = SAY_LOGGER_FILE;
-	else
+	else {
+		diag_set(IllegalParams, "unrecognized log type '%s'", *str);
 		return -1;
+	}
 	return 0;
 }
 
diff --git a/src/say.h b/src/say.h
index 6681aae98..9a76e07f3 100644
--- a/src/say.h
+++ b/src/say.h
@@ -222,8 +222,10 @@ say_set_log_level(int new_level);
  *
  * Can't be applied in case syslog or boot (will be ignored)
  * @param say format
+ * @retval 0 on success
+ * @retvel -1 on failure
  */
-void
+int
 say_set_log_format(enum say_format format);
 
 /**
diff --git a/test/box-tap/cfg.test.lua b/test/box-tap/cfg.test.lua
index 629faefaa..d0a635e33 100755
--- a/test/box-tap/cfg.test.lua
+++ b/test/box-tap/cfg.test.lua
@@ -51,7 +51,7 @@ invalid('vinyl_bloom_fpr', 1.1)
 
 local function invalid_combinations(name, val)
     local status, result = pcall(box.cfg, val)
-    test:ok(not status and result:match('Illegal'), 'invalid '..name)
+    test:ok(not status and result:match('Incorrect'), 'incompatible values'..name)
 end
 
 invalid_combinations("log, log_nonblock", {log = "1.log", log_nonblock = true})
-- 
2.14.3 (Apple Git-98)

Re: [tarantool-patches] [PATCH 1/1] Fixed non-informative error messages for log conf.

[Vladimir Davydov]

On Mon, Jul 30, 2018 at 04:58:01PM +0300, Olga Arkhangelskaia wrote:
> In case of bad or erroneous options for log configurations
> errors had ambiguous or absent messages. In some cases it lead to
> app crashes.
> 
> Closes #3553
> ---
> https://github.com/tarantool/tarantool/issues/3553
> https://github.com/tarantool/tarantool/tree/OKriw/gh-3553-non-inf-error

The branch is based on your other branch for syslog destination. Why?
AFAICS they are not interconnected and can be submitted separately.
Please re-base on 2.0 so that we can push this first.

> 
>  src/box/box.cc            | 25 ++++++++++++++++++-------
>  src/say.c                 | 22 +++++++++++++++-------
>  src/say.h                 |  4 +++-
>  test/box-tap/cfg.test.lua |  2 +-
>  4 files changed, 37 insertions(+), 16 deletions(-)
> 
> diff --git a/src/box/box.cc b/src/box/box.cc
> index b6c22b081..c711cd55a 100644
> --- a/src/box/box.cc
> +++ b/src/box/box.cc
> @@ -353,10 +353,13 @@ apply_initial_join_row(struct xstream *stream, struct xrow_header *row)
>  static void
>  box_check_say()
>  {
> -	const char *log = cfg_gets("log");
> -	if (log == NULL)
> -		return;
>  	enum say_logger_type type;
> +	const char *log = cfg_gets("log");
> +	if (log == NULL) {
> +		type = SAY_LOGGER_STDERR;
> +		goto checks;
> +	}
> +	
>  	if (say_parse_logger_type(&log, &type) < 0) {
>  		tnt_raise(ClientError, ER_CFG, "log",
>  			  diag_last_error(diag_get())->errmsg);

I prefer not to use labels when I can. This place can be easily
rewritten without the goto:

	enum say_logger_type type = SAY_LOGGER_STDERR; /* default */
	const char *log = cfg_gets("log");
	if (log != NULL && say_parse_logger_type(&log, &type) < 0) {
		tnt_raise(ClientError, ER_CFG, "log",
			  diag_last_error(diag_get())->errmsg);
	}
	if (type == SAY_LOGGER_SYSLOG) {
		...

> @@ -375,17 +378,21 @@ box_check_say()
>  		say_free_syslog_opts(&opts);
>  	}
>  
> +checks:
>  	const char *log_format = cfg_gets("log_format");
>  	enum say_format format = say_format_by_name(log_format);
>  	if (format == say_format_MAX)
> -		diag_set(ClientError, ER_CFG, "log_format",
> +		tnt_raise(ClientError, ER_CFG, "log_format",
>  			 "expected 'plain' or 'json'");

This is OK.

>  	if (type == SAY_LOGGER_SYSLOG && format == SF_JSON) {
> -		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_format");
> +		tnt_raise(ClientError, ER_CFG, "log, log_format",
> +			  "incompatible values");

The error message would look like:

	Incorrect value for option 'log, log_format': incompatible values

Note 'log, log_format' in quotes and 'option' in singular. Looks ugly.
Let's rewrite it so that it looks like:

	Incorrect value for option 'log_format': 'json' can't be used with syslog logger

or something like that.

>  	}
>  	int log_nonblock = cfg_getb("log_nonblock");
> -	if (log_nonblock == 1 && type == SAY_LOGGER_FILE) {
> -		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_nonblock");
> +	if (log_nonblock == 1 &&
> +	    (type == SAY_LOGGER_FILE || type == SAY_LOGGER_STDERR)) {
> +		tnt_raise(ClientError, ER_CFG, "log, log_nonblock",
> +			  "incompatible values");

Ditto: please beautify the error message.

>  	}
>  }
>  
> @@ -745,6 +752,10 @@ void
>  box_set_log_format(void)
>  {
>  	enum say_format format = box_check_log_format(cfg_gets("log_format"));
> +	if (say_set_log_format(format) < 0) {
> +		 tnt_raise(ClientError, ER_CFG, "log_format",
> +		           diag_last_error(diag_get())->errmsg);
> +	}
>  	say_set_log_format(format);

say_set_log_format() is called twice, which doesn't look right.

Ideally, the error message should look exactly like the one emitted by
box_check_say(). May be, you could simply call box_check_say() from
box_set_log_format()?

>  }
>  
> diff --git a/src/say.c b/src/say.c
> index b4836d9ee..8753bb865 100644
> --- a/src/say.c
> +++ b/src/say.c
> @@ -190,7 +190,7 @@ say_set_log_level(int new_level)
>  	log_set_level(log_default, (enum say_level) new_level);
>  }
>  
> -void
> +int
>  say_set_log_format(enum say_format format)

I guess if you called box_check_say() from box_set_log_format(), you
could simply add some assertions making sure that log format is
compatible with logger type instead of allowing this function to return
an error.

>  {
>  	/*
> @@ -204,22 +204,25 @@ say_set_log_format(enum say_format format)
>  	case SF_JSON:
>  
>  		if (!allowed_to_change) {
> -			say_error("json log format is not supported when output is '%s'",
> +			diag_set(IllegalParams,
> +				 "json log format is incompatible with '%s'log",
>  				  say_logger_type_strs[log_default->type]);
> -			return;
> +			return -1;
>  		}
>  		log_set_format(log_default, say_format_json);
>  		break;
>  	case SF_PLAIN:
>  		if (!allowed_to_change) {
> -			return;
> +			return 0;
>  		}
>  		log_set_format(log_default, say_format_plain);
>  		break;
>  	default:
> -		unreachable();
> +		diag_set(IllegalParams, "unsupported log_format, expected plain or json");
> +		return -1;
>  	}
>  	log_format = format;
> +	return 0;
>  }
>  
>  static const char *say_format_strs[] = {
> @@ -692,7 +695,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
>  	say_set_log_level(level);
>  	log_background = background;
>  	log_pid = log_default->pid;
> -	say_set_log_format(say_format_by_name(format));
> +	if (say_set_log_format(say_format_by_name(format)) < 0)
> +		goto error;
>  
>  	if (background) {
>  		fflush(stderr);
> @@ -715,6 +719,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
>  fail:
>  	diag_log();
>  	panic("failed to initialize logging subsystem");
> +error:
> +	diag_log();

panic() seems to be missing.

>  }
>  
>  void
> @@ -1071,8 +1077,10 @@ say_parse_logger_type(const char **str, enum say_logger_type *type)
>  		*type = SAY_LOGGER_SYSLOG;
>  	else if (strchr(*str, ':') == NULL)
>  		*type = SAY_LOGGER_FILE;
> -	else
> +	else {
> +		diag_set(IllegalParams, "unrecognized log type '%s'", *str);
>  		return -1;
> +	}

I think you should print logger_syntax_reminder instead, just like
log_create() does. You could remove diag_set from log_create() then.

>  	return 0;
>  }
>  
> diff --git a/src/say.h b/src/say.h
> index 6681aae98..9a76e07f3 100644
> --- a/src/say.h
> +++ b/src/say.h
> @@ -222,8 +222,10 @@ say_set_log_level(int new_level);
>   *
>   * Can't be applied in case syslog or boot (will be ignored)
>   * @param say format
> + * @retval 0 on success
> + * @retvel -1 on failure

s/retvel/retval

>   */
> -void
> +int
>  say_set_log_format(enum say_format format);
>  
>  /**
> diff --git a/test/box-tap/cfg.test.lua b/test/box-tap/cfg.test.lua
> index 629faefaa..d0a635e33 100755
> --- a/test/box-tap/cfg.test.lua
> +++ b/test/box-tap/cfg.test.lua
> @@ -51,7 +51,7 @@ invalid('vinyl_bloom_fpr', 1.1)
>  
>  local function invalid_combinations(name, val)
>      local status, result = pcall(box.cfg, val)
> -    test:ok(not status and result:match('Illegal'), 'invalid '..name)
> +    test:ok(not status and result:match('Incorrect'), 'incompatible values'..name)

I expect you to add some more tests that would check all the cases
I mentioned in the ticket.

>  end
>  
>  invalid_combinations("log, log_nonblock", {log = "1.log", log_nonblock = true})

Re: [tarantool-patches] Re: [PATCH 1/1] Fixed non-informative error messages for log conf.

[Olga Arkhangelskaia]

31/07/2018 15:03, Vladimir Davydov пишет:
> On Mon, Jul 30, 2018 at 04:58:01PM +0300, Olga Arkhangelskaia wrote:
>> In case of bad or erroneous options for log configurations
>> errors had ambiguous or absent messages. In some cases it lead to
>> app crashes.
>>
>> Closes #3553
>> ---
>> https://github.com/tarantool/tarantool/issues/3553
>> https://github.com/tarantool/tarantool/tree/OKriw/gh-3553-non-inf-error
> The branch is based on your other branch for syslog destination. Why?
> AFAICS they are not interconnected and can be submitted separately.
> Please re-base on 2.0 so that we can push this first.
>
>>   src/box/box.cc            | 25 ++++++++++++++++++-------
>>   src/say.c                 | 22 +++++++++++++++-------
>>   src/say.h                 |  4 +++-
>>   test/box-tap/cfg.test.lua |  2 +-
>>   4 files changed, 37 insertions(+), 16 deletions(-)
>>
>> diff --git a/src/box/box.cc b/src/box/box.cc
>> index b6c22b081..c711cd55a 100644
>> --- a/src/box/box.cc
>> +++ b/src/box/box.cc
>> @@ -353,10 +353,13 @@ apply_initial_join_row(struct xstream *stream, struct xrow_header *row)
>>   static void
>>   box_check_say()
>>   {
>> -	const char *log = cfg_gets("log");
>> -	if (log == NULL)
>> -		return;
>>   	enum say_logger_type type;
>> +	const char *log = cfg_gets("log");
>> +	if (log == NULL) {
>> +		type = SAY_LOGGER_STDERR;
>> +		goto checks;
>> +	}
>> +	
>>   	if (say_parse_logger_type(&log, &type) < 0) {
>>   		tnt_raise(ClientError, ER_CFG, "log",
>>   			  diag_last_error(diag_get())->errmsg);
> I prefer not to use labels when I can. This place can be easily
> rewritten without the goto:
>
> 	enum say_logger_type type = SAY_LOGGER_STDERR; /* default */
> 	const char *log = cfg_gets("log");
> 	if (log != NULL && say_parse_logger_type(&log, &type) < 0) {
> 		tnt_raise(ClientError, ER_CFG, "log",
> 			  diag_last_error(diag_get())->errmsg);
> 	}
> 	if (type == SAY_LOGGER_SYSLOG) {

I agree about labels.
However, in this particular I do insist. If we rewrite it like you
did - we miss two cases I mentioned in cover letter - setting format and 
setting nonblog, without
setting the log type. Label help us to leave this possibility but to 
check the input.
If no log is set - we need to check stderr type and other things that 
will be set

> 		...
>
>> @@ -375,17 +378,21 @@ box_check_say()
>>   		say_free_syslog_opts(&opts);
>>   	}
>>   
>> +checks:
>>   	const char *log_format = cfg_gets("log_format");
>>   	enum say_format format = say_format_by_name(log_format);
>>   	if (format == say_format_MAX)
>> -		diag_set(ClientError, ER_CFG, "log_format",
>> +		tnt_raise(ClientError, ER_CFG, "log_format",
>>   			 "expected 'plain' or 'json'");
> This is OK.
>
>>   	if (type == SAY_LOGGER_SYSLOG && format == SF_JSON) {
>> -		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_format");
>> +		tnt_raise(ClientError, ER_CFG, "log, log_format",
>> +			  "incompatible values");
> The error message would look like:
>
> 	Incorrect value for option 'log, log_format': incompatible values
>
> Note 'log, log_format' in quotes and 'option' in singular. Looks ugly.
> Let's rewrite it so that it looks like:
>
> 	Incorrect value for option 'log_format': 'json' can't be used with syslog logger
>
> or something like that.

Ok
>
>>   	}
>>   	int log_nonblock = cfg_getb("log_nonblock");
>> -	if (log_nonblock == 1 && type == SAY_LOGGER_FILE) {
>> -		tnt_raise(ClientError, ER_ILLEGAL_PARAMS, "log, log_nonblock");
>> +	if (log_nonblock == 1 &&
>> +	    (type == SAY_LOGGER_FILE || type == SAY_LOGGER_STDERR)) {
>> +		tnt_raise(ClientError, ER_CFG, "log, log_nonblock",
>> +			  "incompatible values");
> Ditto: please beautify the error message.
>
>>   	}
>>   }
>>   
>> @@ -745,6 +752,10 @@ void
>>   box_set_log_format(void)
>>   {
>>   	enum say_format format = box_check_log_format(cfg_gets("log_format"));
>> +	if (say_set_log_format(format) < 0) {
>> +		 tnt_raise(ClientError, ER_CFG, "log_format",
>> +		           diag_last_error(diag_get())->errmsg);
>> +	}
>>   	say_set_log_format(format);
> say_set_log_format() is called twice, which doesn't look right.
sorry, we do not need second call
> Ideally, the error message should look exactly like the one emitted by
> box_check_say().
Why? Format can be changed, so we need to say about format types that 
does not exist.
> May be, you could simply call box_check_say() from
> box_set_log_format()?

Again, why?  box_check_say() is used to check whole config, and check 
format - checks only format. We do not need check things like nonblock 
in there.

>
>>   }
>>   
>> diff --git a/src/say.c b/src/say.c
>> index b4836d9ee..8753bb865 100644
>> --- a/src/say.c
>> +++ b/src/say.c
>> @@ -190,7 +190,7 @@ say_set_log_level(int new_level)
>>   	log_set_level(log_default, (enum say_level) new_level);
>>   }
>>   
>> -void
>> +int
>>   say_set_log_format(enum say_format format)
> I guess if you called box_check_say() from box_set_log_format(), you
> could simply add some assertions making sure that log format is
> compatible with logger type instead of allowing this function to return
> an error.
I don't see why assertion is better.
We need to say to user/admin that the thing that he/she doing is wrong.


>>   {
>>   	/*
>> @@ -204,22 +204,25 @@ say_set_log_format(enum say_format format)
>>   	case SF_JSON:
>>   
>>   		if (!allowed_to_change) {
>> -			say_error("json log format is not supported when output is '%s'",
>> +			diag_set(IllegalParams,
>> +				 "json log format is incompatible with '%s'log",
>>   				  say_logger_type_strs[log_default->type]);
>> -			return;
>> +			return -1;
>>   		}
>>   		log_set_format(log_default, say_format_json);
>>   		break;
>>   	case SF_PLAIN:
>>   		if (!allowed_to_change) {
>> -			return;
>> +			return 0;
>>   		}
>>   		log_set_format(log_default, say_format_plain);
>>   		break;
>>   	default:
>> -		unreachable();
>> +		diag_set(IllegalParams, "unsupported log_format, expected plain or json");
>> +		return -1;
>>   	}
>>   	log_format = format;
>> +	return 0;
>>   }
>>   
>>   static const char *say_format_strs[] = {
>> @@ -692,7 +695,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
>>   	say_set_log_level(level);
>>   	log_background = background;
>>   	log_pid = log_default->pid;
>> -	say_set_log_format(say_format_by_name(format));
>> +	if (say_set_log_format(say_format_by_name(format)) < 0)
>> +		goto error;
>>   
>>   	if (background) {
>>   		fflush(stderr);
>> @@ -715,6 +719,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
>>   fail:
>>   	diag_log();
>>   	panic("failed to initialize logging subsystem");
>> +error:
>> +	diag_log();
> panic() seems to be missing.
no - panic means that tarantool is failed to initialize one of his 
systems, this is crash. However, error with the format - it is too much 
to crush, don't you think? We can leave the old one.
>
>>   }
>>   
>>   void
>> @@ -1071,8 +1077,10 @@ say_parse_logger_type(const char **str, enum say_logger_type *type)
>>   		*type = SAY_LOGGER_SYSLOG;
>>   	else if (strchr(*str, ':') == NULL)
>>   		*type = SAY_LOGGER_FILE;
>> -	else
>> +	else {
>> +		diag_set(IllegalParams, "unrecognized log type '%s'", *str);
>>   		return -1;
>> +	}
> I think you should print logger_syntax_reminder instead, just like
> log_create() does. You could remove diag_set from log_create() then.
Ok, i can do it.
>
>>   	return 0;
>>   }
>>   
>> diff --git a/src/say.h b/src/say.h
>> index 6681aae98..9a76e07f3 100644
>> --- a/src/say.h
>> +++ b/src/say.h
>> @@ -222,8 +222,10 @@ say_set_log_level(int new_level);
>>    *
>>    * Can't be applied in case syslog or boot (will be ignored)
>>    * @param say format
>> + * @retval 0 on success
>> + * @retvel -1 on failure
> s/retvel/retval
>
>>    */
>> -void
>> +int
>>   say_set_log_format(enum say_format format);
>>   
>>   /**
>> diff --git a/test/box-tap/cfg.test.lua b/test/box-tap/cfg.test.lua
>> index 629faefaa..d0a635e33 100755
>> --- a/test/box-tap/cfg.test.lua
>> +++ b/test/box-tap/cfg.test.lua
>> @@ -51,7 +51,7 @@ invalid('vinyl_bloom_fpr', 1.1)
>>   
>>   local function invalid_combinations(name, val)
>>       local status, result = pcall(box.cfg, val)
>> -    test:ok(not status and result:match('Illegal'), 'invalid '..name)
>> +    test:ok(not status and result:match('Incorrect'), 'incompatible values'..name)
> I expect you to add some more tests that would check all the cases
> I mentioned in the ticket.
I did not think about the tests, i will add this cases.

>
>>   end
>>   
>>   invalid_combinations("log, log_nonblock", {log = "1.log", log_nonblock = true})

Re: [tarantool-patches] Re: [PATCH 1/1] Fixed non-informative error messages for log conf.

[Vladimir Davydov]

On Tue, Jul 31, 2018 at 03:34:29PM +0300, Olga Arkhangelskaia wrote:
> > >   static void
> > >   box_check_say()
> > >   {
> > > -	const char *log = cfg_gets("log");
> > > -	if (log == NULL)
> > > -		return;
> > >   	enum say_logger_type type;
> > > +	const char *log = cfg_gets("log");
> > > +	if (log == NULL) {
> > > +		type = SAY_LOGGER_STDERR;
> > > +		goto checks;
> > > +	}
> > > +	
> > >   	if (say_parse_logger_type(&log, &type) < 0) {
> > >   		tnt_raise(ClientError, ER_CFG, "log",
> > >   			  diag_last_error(diag_get())->errmsg);
> > I prefer not to use labels when I can. This place can be easily
> > rewritten without the goto:
> > 
> > 	enum say_logger_type type = SAY_LOGGER_STDERR; /* default */
> > 	const char *log = cfg_gets("log");
> > 	if (log != NULL && say_parse_logger_type(&log, &type) < 0) {
> > 		tnt_raise(ClientError, ER_CFG, "log",
> > 			  diag_last_error(diag_get())->errmsg);
> > 	}
> > 	if (type == SAY_LOGGER_SYSLOG) {
> 
> I agree about labels.
> However, in this particular I do insist. If we rewrite it like you
> did - we miss two cases I mentioned in cover letter - setting format and
> setting nonblog, without
> setting the log type. Label help us to leave this possibility but to check
> the input.
> If no log is set - we need to check stderr type and other things that will
> be set

The code I posted above does exactly that. Note, there's no 'return'.

> > > @@ -745,6 +752,10 @@ void
> > >   box_set_log_format(void)
> > >   {
> > >   	enum say_format format = box_check_log_format(cfg_gets("log_format"));
> > > +	if (say_set_log_format(format) < 0) {
> > > +		 tnt_raise(ClientError, ER_CFG, "log_format",
> > > +		           diag_last_error(diag_get())->errmsg);
> > > +	}
> > >   	say_set_log_format(format);
> > say_set_log_format() is called twice, which doesn't look right.
> sorry, we do not need second call
> > Ideally, the error message should look exactly like the one emitted by
> > box_check_say().
> Why? Format can be changed, so we need to say about format types that does
> not exist.

Yep, and box_check_say() can do that for us. My point is that we can
avoid duplicating the code that performs the checks by reusing
box_check_say(), and it would result in consistent error messages, too.

> > May be, you could simply call box_check_say() from
> > box_set_log_format()?
> 
> Again, why?  box_check_say() is used to check whole config, and check format
> - checks only format. We do not need check things like nonblock in there.

It's a slow path so we can do some extra job there for the sake of
simplifying the code, I guess.

> 
> > 
> > >   }
> > > diff --git a/src/say.c b/src/say.c
> > > index b4836d9ee..8753bb865 100644
> > > --- a/src/say.c
> > > +++ b/src/say.c
> > > @@ -190,7 +190,7 @@ say_set_log_level(int new_level)
> > >   	log_set_level(log_default, (enum say_level) new_level);
> > >   }
> > > -void
> > > +int
> > >   say_set_log_format(enum say_format format)
> > I guess if you called box_check_say() from box_set_log_format(), you
> > could simply add some assertions making sure that log format is
> > compatible with logger type instead of allowing this function to return
> > an error.
> I don't see why assertion is better.
> We need to say to user/admin that the thing that he/she doing is wrong.

Yep, we do, but if this function was called only after box_check_say(),
which already performs the checks, assertion would be OK.

> 
> 
> > >   {
> > >   	/*
> > > @@ -204,22 +204,25 @@ say_set_log_format(enum say_format format)
> > >   	case SF_JSON:
> > >   		if (!allowed_to_change) {
> > > -			say_error("json log format is not supported when output is '%s'",
> > > +			diag_set(IllegalParams,
> > > +				 "json log format is incompatible with '%s'log",
> > >   				  say_logger_type_strs[log_default->type]);
> > > -			return;
> > > +			return -1;
> > >   		}
> > >   		log_set_format(log_default, say_format_json);
> > >   		break;
> > >   	case SF_PLAIN:
> > >   		if (!allowed_to_change) {
> > > -			return;
> > > +			return 0;
> > >   		}
> > >   		log_set_format(log_default, say_format_plain);
> > >   		break;
> > >   	default:
> > > -		unreachable();
> > > +		diag_set(IllegalParams, "unsupported log_format, expected plain or json");
> > > +		return -1;
> > >   	}
> > >   	log_format = format;
> > > +	return 0;
> > >   }
> > >   static const char *say_format_strs[] = {
> > > @@ -692,7 +695,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
> > >   	say_set_log_level(level);
> > >   	log_background = background;
> > >   	log_pid = log_default->pid;
> > > -	say_set_log_format(say_format_by_name(format));
> > > +	if (say_set_log_format(say_format_by_name(format)) < 0)
> > > +		goto error;
> > >   	if (background) {
> > >   		fflush(stderr);
> > > @@ -715,6 +719,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
> > >   fail:
> > >   	diag_log();
> > >   	panic("failed to initialize logging subsystem");
> > > +error:
> > > +	diag_log();
> > panic() seems to be missing.
> no - panic means that tarantool is failed to initialize one of his systems,
> this is crash. However, error with the format - it is too much to crush,
> don't you think? We can leave the old one.

I guess you're right. It's just those 'fail' label with 'panic' and
'error' without look weird.

Come to think of it, you can't get here anyway, because the validity of
the configuration should've been checked by box_check_config() is
called, no? Confusing...

That's why I'd prefer to have all validity checks consolidated in
one place - box_check_say(), and use assertions anywhere else (in
say_logger_init, say_logger_set_format, etc).

Re: [tarantool-patches] [PATCH 0/1] Fixed non-informative error messages for log conf

[Vladimir Davydov]

There's no point in a cover-letter if you're submitting a single patch.

You can include the text below either in the commit message or just put
it in the patch email after '---' if you don't want it in the git log.

On Mon, Jul 30, 2018 at 04:58:00PM +0300, Olga Arkhangelskaia wrote:
> Tarantool log used to have more serious problems than non-informative messages:
> No check on parameters like log_nonblock, log_format in case of unconfigured log.
> This means that there was a possibility to set any value in case when the
> first log conf. commands were: 
> box.cfg{log_format = ‘any’}
> box.cfg{log_nonblock=true} - (together with stderr)
> In case of log_format  with such scenario additional problem took place.
> When setting log format we change format_func
> (function that actually logs to log) to NULL, and wrong log_format
> lead to crash - because we could not log error with log format because of 
> format_func was not set yet, but already had been changed to null.
> In case of undefined log type  (“log=’:test:’:) we used to have empty
> exception - so,tarantool just silently crashed.
> I think the main problem that initial initialization is mixed up with
> configuring parameters.  So if we decide to refactor log we need to separate
> them. For example, have set of checking functions and set of configuring.
> One parameter - one check.
> End initial initialization should use the same way prior setting any parameter.
> 
> Patch fixes this problems using the easiest way, however if in future we need
> some more parameters - we should consider the idea of refactor.
>  
> Olga Arkhangelskaia (1):
>   Fixed non-informative error messages for log conf.
> 
>  src/box/box.cc            | 25 ++++++++++++++++++-------
>  src/say.c                 | 22 +++++++++++++++-------
>  src/say.h                 |  4 +++-
>  test/box-tap/cfg.test.lua |  2 +-
>  4 files changed, 37 insertions(+), 16 deletions(-)