* [Tarantool-patches] [PATCH v9 1/2] lua/log: add ability to configure logging early
2020-06-05 18:55 [Tarantool-patches] [PATCH v9 0/2] lua/log: add an ability to setup logger without box.cfg{} Cyrill Gorcunov
@ 2020-06-05 18:55 ` Cyrill Gorcunov
2020-06-05 18:55 ` [Tarantool-patches] [PATCH v9 2/2] test: app-tap/logger -- test new modes Cyrill Gorcunov
` (2 subsequent siblings)
3 siblings, 0 replies; 6+ messages in thread
From: Cyrill Gorcunov @ 2020-06-05 18:55 UTC (permalink / raw)
To: tml
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@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
^ permalink raw reply [flat|nested] 6+ messages in thread