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

  • From: Olga Arkhangelskaia <arkholga@xxxxxxxxxxxxx>
  • To: Vladimir Davydov <vdavydov.dev@xxxxxxxxx>
  • Date: Tue, 31 Jul 2018 15:34:29 +0300



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


Other related posts: