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

[Olga Arkhangelskaia <arkholga@tarantool.org>]

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})