[Tarantool-patches] [PATCH v9 1/2] lua/log: add ability to configure logging early

Cyrill Gorcunov gorcunov at gmail.com
Fri Jun 5 21:55:43 MSK 2020


In the patch we introduce an ability to configure logging
engine early without calling box.cfg{} at all. For this sake
we have to modify the load_cfg.lua (main cfg loader) together
with log.lua built in module.

In particular the configuration entries which are supposed to
be handled by modules are grouped in module_cfg table, where we
list box.cfg{} keys and methods to fetch/set the values. Same time
the template_cfg{} starts to carry 'module' keyword telling
prepare_cfg routine to use modules.

@TarantoolBot documnent
Title: Module log

To configure log module eary without initializing box module
at all call the `log.cfg({})` method, where the following
arguments are acceptable:

 - `log` to specify file, pipe or syslog (same as
   `box.cfg{log}` option); the default value is nil
   and stderr is used;

 - `level` to specify logging level; can be numbers (1-7) or
   strings (fatal,syserror,error,crit,warn,info,verbose,debug);
   the default value is 5 (i.e. 'info');

   While for symbolic representations of levels we allow only
   predefined keywords to be used, to keep backward compatibility
   the numbers can be any;

 - `format` to specify output encoding ('plain' or 'json');
   the default value is 'plain';

 - `nonblock` to open logging output in nonblocking mode
   (`true` or `false`); the default value is `false`.

Fixes #689

Signed-off-by: Cyrill Gorcunov <gorcunov at gmail.com>
---
 src/box/lua/load_cfg.lua    |  65 ++++--
 src/lua/log.lua             | 404 ++++++++++++++++++++++++++++++++++--
 test/box/reconfigure.result |   2 +-
 3 files changed, 431 insertions(+), 40 deletions(-)

diff --git a/src/box/lua/load_cfg.lua b/src/box/lua/load_cfg.lua
index c9c9eda3e..7a77b93f5 100644
--- a/src/box/lua/load_cfg.lua
+++ b/src/box/lua/load_cfg.lua
@@ -59,10 +59,11 @@ local default_cfg = {
     vinyl_range_size          = nil, -- set automatically
     vinyl_page_size           = 8 * 1024,
     vinyl_bloom_fpr           = 0.05,
-    log                 = nil,
-    log_nonblock        = nil,
-    log_level           = 5,
-    log_format          = "plain",
+
+    -- logging options are covered by
+    -- a separate log module; they are
+    -- 'log_' prefixed
+
     io_collect_interval = nil,
     readahead           = 16320,
     snap_io_rate_limit  = nil, -- no limit
@@ -99,6 +100,15 @@ local default_cfg = {
     sql_cache_size        = 5 * 1024 * 1024,
 }
 
+-- cfg variables which are covered by modules
+local module_cfg = {
+    -- logging
+    log                 = log.box_api,
+    log_nonblock        = log.box_api,
+    log_level           = log.box_api,
+    log_format          = log.box_api,
+}
+
 -- types of available options
 -- could be comma separated lua types or 'any' if any type is allowed
 local template_cfg = {
@@ -124,10 +134,11 @@ local template_cfg = {
     vinyl_page_size           = 'number',
     vinyl_bloom_fpr           = 'number',
 
-    log              = 'string',
-    log_nonblock     = 'boolean',
-    log_level           = 'number',
-    log_format          = 'string',
+    log                 = 'module',
+    log_nonblock        = 'module',
+    log_level           = 'module',
+    log_format          = 'module',
+
     io_collect_interval = 'number',
     readahead           = 'number',
     snap_io_rate_limit  = 'number',
@@ -233,8 +244,8 @@ end
 local dynamic_cfg = {
     listen                  = private.cfg_set_listen,
     replication             = private.cfg_set_replication,
-    log_level               = private.cfg_set_log_level,
-    log_format              = private.cfg_set_log_format,
+    log_level               = log.box_api.cfg_set_log_level,
+    log_format              = log.box_api.cfg_set_log_format,
     io_collect_interval     = private.cfg_set_io_collect_interval,
     readahead               = private.cfg_set_readahead,
     too_long_threshold      = private.cfg_set_too_long_threshold,
@@ -408,7 +419,8 @@ local function upgrade_cfg(cfg, translate_cfg)
     return result_cfg
 end
 
-local function prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg, prefix)
+local function prepare_cfg(cfg, default_cfg, template_cfg,
+                           module_cfg, modify_cfg, prefix)
     if cfg == nil then
         return {}
     end
@@ -424,6 +436,7 @@ local function prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg, prefix)
         readable_prefix = prefix .. '.'
     end
     local new_cfg = {}
+    local module_cfg_backup = {}
     for k,v in pairs(cfg) do
         local readable_name = readable_prefix .. k;
         if template_cfg[k] == nil then
@@ -437,7 +450,20 @@ local function prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg, prefix)
             if type(v) ~= 'table' then
                 box.error(box.error.CFG, readable_name, "should be a table")
             end
-            v = prepare_cfg(v, default_cfg[k], template_cfg[k], modify_cfg[k], readable_name)
+            v = prepare_cfg(v, default_cfg[k], template_cfg[k],
+                            module_cfg[k], modify_cfg[k], readable_name)
+        elseif template_cfg[k] == 'module' then
+            local old_value = module_cfg[k].cfg_get(k, v)
+            module_cfg_backup[k] = old_value
+
+            local ok, msg = module_cfg[k].cfg_set(k, v)
+            if not ok then
+                -- restore back the old values for modules
+                for module_k, module_v in pairs(module_cfg_backup) do
+                    module_cfg[module_k].cfg_set(module_k, module_v)
+                end
+                box.error(box.error.CFG, readable_name, msg)
+            end
         elseif (string.find(template_cfg[k], ',') == nil) then
             -- one type
             if type(v) ~= template_cfg[k] then
@@ -460,7 +486,7 @@ local function prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg, prefix)
     return new_cfg
 end
 
-local function apply_default_cfg(cfg, default_cfg)
+local function apply_default_cfg(cfg, default_cfg, module_cfg)
     for k,v in pairs(default_cfg) do
         if cfg[k] == nil then
             cfg[k] = v
@@ -468,6 +494,11 @@ local function apply_default_cfg(cfg, default_cfg)
             apply_default_cfg(cfg[k], v)
         end
     end
+    for k, v in pairs(module_cfg) do
+        if cfg[k] == nil then
+            cfg[k] = module_cfg[k].cfg_get(k)
+        end
+    end
 end
 
 -- Return true if two configurations are equivalent.
@@ -491,7 +522,8 @@ end
 
 local function reload_cfg(oldcfg, cfg)
     cfg = upgrade_cfg(cfg, translate_cfg)
-    local newcfg = prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg)
+    local newcfg = prepare_cfg(cfg, default_cfg, template_cfg,
+                               module_cfg, modify_cfg)
     local ordered_cfg = {}
     -- iterate over original table because prepare_cfg() may store NILs
     for key, val in pairs(cfg) do
@@ -552,8 +584,9 @@ setmetatable(box, {
 
 local function load_cfg(cfg)
     cfg = upgrade_cfg(cfg, translate_cfg)
-    cfg = prepare_cfg(cfg, default_cfg, template_cfg, modify_cfg)
-    apply_default_cfg(cfg, default_cfg);
+    cfg = prepare_cfg(cfg, default_cfg, template_cfg,
+                      module_cfg, modify_cfg)
+    apply_default_cfg(cfg, default_cfg, module_cfg);
     -- Save new box.cfg
     box.cfg = cfg
     if not pcall(private.cfg_check)  then
diff --git a/src/lua/log.lua b/src/lua/log.lua
index d5a99076d..bed690526 100644
--- a/src/lua/log.lua
+++ b/src/lua/log.lua
@@ -101,6 +101,155 @@ local function fmt_list()
     return table.concat(keyset, ',')
 end
 
+-- Logging levels symbolic representation.
+local log_level_keys = {
+    ['fatal']       = ffi.C.S_FATAL,
+    ['syserror']    = ffi.C.S_SYSERROR,
+    ['error']       = ffi.C.S_ERROR,
+    ['crit']        = ffi.C.S_CRIT,
+    ['warn']        = ffi.C.S_WARN,
+    ['info']        = ffi.C.S_INFO,
+    ['verbose']     = ffi.C.S_VERBOSE,
+    ['debug']       = ffi.C.S_DEBUG,
+}
+
+local function log_level_list()
+    local keyset = {}
+    for k in pairs(log_level_keys) do
+        keyset[#keyset + 1] = k
+    end
+    return table.concat(keyset, ',')
+end
+
+-- Default options. The keys are part of
+-- user API , so change with caution.
+local log_cfg = {
+    log             = nil,
+    nonblock        = nil,
+    level           = S_INFO,
+    format          = fmt_num2str[ffi.C.SF_PLAIN],
+}
+
+-- Name mapping from box to log module and
+-- back. Make sure all required fields
+-- are covered!
+local log2box_keys = {
+    ['log']             = 'log',
+    ['nonblock']        = 'log_nonblock',
+    ['level']           = 'log_level',
+    ['format']          = 'log_format',
+}
+
+local box2log_keys = {
+    ['log']             = 'log',
+    ['log_nonblock']    = 'nonblock',
+    ['log_level']       = 'level',
+    ['log_format']      = 'format',
+}
+
+-- Update cfg value(s) in box.cfg instance conditionally
+local function box_cfg_update(log_key)
+    -- if it is not yet even exist just exit early
+    if type(box.cfg) ~= 'table' then
+        return
+    end
+
+    local update = function(log_key, box_key)
+        -- the box entry may be under configuration
+        -- process thus equal to nil, skip it then
+        if log_cfg[log_key] ~= nil and
+            box.cfg[box_key] ~= nil and
+            box.cfg[box_key] ~= log_cfg[log_key] then
+            box.cfg[box_key] = log_cfg[log_key]
+        end
+    end
+
+    if log_key == nil then
+        for k, v in pairs(log2box_keys) do
+            update(k, v)
+        end
+    else
+        assert(log2box_keys[log_key] ~= nil)
+        update(log_key, log2box_keys[log_key])
+    end
+end
+
+-- Log options which can be set ony once.
+local cfg_static_keys = {
+    log         = true,
+    nonblock    = true,
+}
+
+-- Test if static key is not changed.
+local function verify_static(k, v)
+    assert(cfg_static_keys[k] ~= nil)
+
+    if ffi.C.say_logger_initialized() == true then
+        if log_cfg[k] ~= v then
+            return false, "can't be set dynamically"
+        end
+    end
+
+    return true
+end
+
+-- Test if format is valid.
+local function verify_format(key, name)
+    assert(log_cfg[key] ~= nil)
+
+    if not fmt_str2num[name] then
+        local m = "expected %s"
+        return false, m:format(fmt_list())
+    end
+
+    if fmt_str2num[name] == ffi.C.SF_JSON then
+        if ffi.C.log_type() == ffi.C.SAY_LOGGER_SYSLOG or
+            ffi.C.log_type() == ffi.C.SAY_LOGGER_BOOT then
+            local m = "%s can't be used with " ..
+            "syslog or boot-time logger"
+            return false, m:format(fmt_num2str[ffi.C.SF_JSON])
+        end
+    end
+
+    return true
+end
+
+-- Test if level is a valid string. The
+-- number may be any for to backward compatibility.
+local function verify_level(key, level)
+    assert(log_cfg[key] ~= nil)
+
+    if type(level) == 'string' then
+        if not log_level_keys[level] then
+            local m = "expected %s"
+            return false, m:format(log_level_list())
+        end
+    elseif type(level) ~= 'number' then
+            return false, "must be a number or a string"
+    end
+
+    return true
+end
+
+local verify_ops = {
+    ['log']         = verify_static,
+    ['nonblock']    = verify_static,
+    ['format']      = verify_format,
+    ['level']       = verify_level,
+}
+
+-- Verify a value for the particular key.
+local function verify_option(k, v)
+    assert(k ~= nil)
+
+    if verify_ops[k] ~= nil then
+        return verify_ops[k](k, v)
+    end
+
+    return true
+end
+
+-- Main routine which pass data to C logging code.
 local function say(level, fmt, ...)
     if ffi.C.log_level < level then
         -- don't waste cycles on debug.getinfo()
@@ -139,43 +288,234 @@ local function say(level, fmt, ...)
     ffi.C._say(level, file, line, nil, format, fmt)
 end
 
+-- Just a syntactic sugar over say routine.
 local function say_closure(lvl)
     return function (fmt, ...)
         say(lvl, fmt, ...)
     end
 end
 
+-- Rotate log (basically reopen the log file and
+-- start writting into it).
 local function log_rotate()
     ffi.C.say_logrotate(nil, nil, 0)
 end
 
-local function log_level(level)
-    return ffi.C.say_set_log_level(level)
+-- Set new logging level, the level must be valid!
+local function set_log_level(level, update_box_cfg)
+    assert(type(level) == 'number')
+
+    ffi.C.say_set_log_level(level)
+
+    rawset(log_cfg, 'level', level)
+
+    if update_box_cfg then
+        box_cfg_update('level')
+    end
+
+    local m = "log: level set to %s"
+    say(S_DEBUG, m:format(level))
 end
 
-local function log_format(name)
-    if not fmt_str2num[name] then
-        local m = "log_format: expected %s"
-        error(m:format(fmt_list()))
+-- Tries to set a new level, or print an error.
+local function log_level(level, update_box_cfg)
+    local ok, msg = verify_option('level', level)
+    if not ok then
+        error(msg)
+    end
+
+    if type(level) == 'string' then
+        level = log_level_keys[level]
     end
 
+    set_log_level(level, true)
+end
+
+-- Set a new logging format, the name must be valid!
+local function set_log_format(name, update_box_cfg)
+    assert(fmt_str2num[name] ~= nil)
+
     if fmt_str2num[name] == ffi.C.SF_JSON then
-        if ffi.C.log_type() == ffi.C.SAY_LOGGER_SYSLOG or
-            ffi.C.log_type() == ffi.C.SAY_LOGGER_BOOT then
-            local m = "log_format: %s can't be used with " ..
-                    "syslog or boot-time logger"
-            error(m:format(fmt_num2str[ffi.C.SF_JSON]))
-        end
         ffi.C.say_set_log_format(ffi.C.SF_JSON)
     else
         ffi.C.say_set_log_format(ffi.C.SF_PLAIN)
     end
+
+    rawset(log_cfg, 'format', name)
+
+    if update_box_cfg then
+        box_cfg_update('format')
+    end
+
+    local m = "log: format set to '%s'"
+    say(S_DEBUG, m:format(name))
+end
+
+-- Tries to set a new format, or print an error.
+local function log_format(name)
+    local ok, msg = verify_option('format', name)
+    if not ok then
+        error(msg)
+    end
+
+    set_log_format(name, true)
 end
 
+-- Returns pid of a pipe process.
 local function log_pid()
     return tonumber(ffi.C.log_pid)
 end
 
+-- Fetch a value from log to box.cfg{}.
+local function box_api_cfg_get(key)
+    return log_cfg[box2log_keys[key]]
+end
+
+-- Set value to log from box.cfg{}.
+local function box_api_cfg_set(key, value)
+    local log_key = box2log_keys[key]
+
+    local ok, msg = verify_option(log_key, value)
+    if not ok then
+        return false, msg
+    end
+
+    log_cfg[log_key] = value
+    return true
+end
+
+-- Set logging level from reloading box.cfg{}
+local function box_api_cfg_set_log_level()
+    local log_key = box2log_keys['log_level']
+    local v = box.cfg['log_level']
+
+    local ok, msg = verify_option(log_key, v)
+    if not ok then
+        return false, msg
+    end
+
+    if type(v) == 'string' then
+        v = log_level_keys[v]
+    end
+
+    set_log_level(v, false)
+    return true
+end
+
+-- Set logging format from reloading box.cfg{}
+local function box_api_set_log_format()
+    local log_key = box2log_keys['log_format']
+    local v = box.cfg['log_format']
+
+    local ok, msg = verify_option(log_key, v)
+    if not ok then
+        return false, msg
+    end
+
+    set_log_format(v, false)
+    return true
+end
+
+-- Reload dynamic options.
+local function reload_cfg(cfg)
+    for k in pairs(cfg_static_keys) do
+        if cfg[k] ~= nil then
+            local ok, msg = verify_static(k, cfg[k])
+            if not ok then
+                local m = "log.cfg: \'%s\' %s"
+                error(m:format(k, msg))
+            end
+        end
+    end
+
+    if cfg.level ~= nil then
+        log_level(cfg.level)
+    end
+
+    if cfg.format ~= nil then
+        log_format(cfg.format)
+    end
+end
+
+-- Load or reload configuration via log.cfg({}) call.
+local function load_cfg(oldcfg, cfg)
+    cfg = cfg or {}
+
+    -- log option might be zero length string, which
+    -- is fine, we should treat it as nil.
+    if cfg.log ~= nil then
+        if type(cfg.log) == 'string' and cfg.log:len() == 0 then
+            cfg.log = nil
+        end
+    end
+
+    if cfg.format ~= nil then
+        local ok, msg = verify_option('format', cfg.format)
+        if not ok then
+            local m = "log.cfg: \'%s\' %s"
+            error(m:format('format', msg))
+        end
+    end
+
+    if cfg.level ~= nil then
+        local ok, msg = verify_option('level', cfg.level)
+        if not ok then
+            local m = "log.cfg: \'%s\' %s"
+            error(m:format('level', msg))
+        end
+    end
+
+    if cfg.nonblock ~= nil then
+        if type(cfg.nonblock) ~= 'boolean' then
+            error("log.cfg: 'nonblock' option must be 'true' or 'false'")
+        end
+    end
+
+    if ffi.C.say_logger_initialized() == true then
+        return reload_cfg(cfg)
+    end
+
+    cfg.level = cfg.level or log_cfg.level
+    cfg.format = cfg.format or log_cfg.format
+    cfg.nonblock = cfg.nonblock or log_cfg.nonblock
+
+    -- nonblock is special: it has to become integer
+    -- for ffi call but in config we have to save
+    -- true value only for backward compatibility!
+    local nonblock = cfg.nonblock
+
+    if nonblock == nil or nonblock == false then
+        nonblock = 0
+    else
+        nonblock = 1
+    end
+
+    -- We never allow confgure the logger in background
+    -- mode since we don't know how the box will be configured
+    -- later.
+    ffi.C.say_logger_init(cfg.log, cfg.level,
+                          nonblock, cfg.format, 0)
+
+    if nonblock == 1 then
+        nonblock = true
+    else
+        nonblock = nil
+    end
+
+    -- Update log_cfg vars to show them in module
+    -- configuration output.
+    rawset(log_cfg, 'log', cfg.log)
+    rawset(log_cfg, 'level', cfg.level)
+    rawset(log_cfg, 'nonblock', nonblock)
+    rawset(log_cfg, 'format', cfg.format)
+
+    -- and box.cfg output as well.
+    box_cfg_update()
+
+    local m = "log.cfg({log=%s,level=%s,nonblock=%s,format=\'%s\'})"
+    say(S_DEBUG, m:format(cfg.log, cfg.level, cfg.nonblock, cfg.format))
+end
+
 local compat_warning_said = false
 local compat_v16 = {
     logger_pid = function()
@@ -187,16 +527,34 @@ local compat_v16 = {
     end;
 }
 
-return setmetatable({
-    warn = say_closure(S_WARN);
-    info = say_closure(S_INFO);
-    verbose = say_closure(S_VERBOSE);
-    debug = say_closure(S_DEBUG);
-    error = say_closure(S_ERROR);
-    rotate = log_rotate;
-    pid = log_pid;
-    level = log_level;
-    log_format = log_format;
-}, {
+local log = {
+    warn = say_closure(S_WARN),
+    info = say_closure(S_INFO),
+    verbose = say_closure(S_VERBOSE),
+    debug = say_closure(S_DEBUG),
+    error = say_closure(S_ERROR),
+    rotate = log_rotate,
+    pid = log_pid,
+    level = log_level,
+    log_format = log_format,
+    cfg = setmetatable(log_cfg, {
+        __call = load_cfg,
+    }),
+    box_api = {
+        cfg_get = box_api_cfg_get,
+        cfg_set = box_api_cfg_set,
+        cfg_set_log_level = box_api_cfg_set_log_level,
+        cfg_set_log_format = box_api_set_log_format,
+    },
+}
+
+setmetatable(log, {
+    __serialize = function(self)
+        local res = table.copy(self)
+        res.box_api = nil
+        return setmetatable(res, {})
+    end,
     __index = compat_v16;
 })
+
+return log
diff --git a/test/box/reconfigure.result b/test/box/reconfigure.result
index d24938442..7af392bfa 100644
--- a/test/box/reconfigure.result
+++ b/test/box/reconfigure.result
@@ -93,7 +93,7 @@ box.cfg{memtx_dir="dynamic"}
 ...
 box.cfg{log="new logger"}
 ---
-- error: Can't set option 'log' dynamically
+- error: 'Incorrect value for option ''log'': can''t be set dynamically'
 ...
 -- bad1
 box.cfg{memtx_memory=53687091}
-- 
2.26.2



More information about the Tarantool-patches mailing list