From f6dafc20eaa8c462e74712168ee38a7b608deff4 Mon Sep 17 00:00:00 2001 From: "Zaiming (Stone) Shi" Date: Tue, 31 Jan 2023 14:20:34 +0100 Subject: [PATCH 1/4] feat: export API to read cluster and local overrides --- apps/emqx/src/emqx_config.erl | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) diff --git a/apps/emqx/src/emqx_config.erl b/apps/emqx/src/emqx_config.erl index 204e32a2b..117043911 100644 --- a/apps/emqx/src/emqx_config.erl +++ b/apps/emqx/src/emqx_config.erl @@ -24,6 +24,7 @@ init_load/2, init_load/3, read_override_conf/1, + read_override_confs/0, delete_override_conf_files/0, check_config/2, fill_defaults/1, @@ -326,9 +327,7 @@ init_load(SchemaMod, RawConf, Opts) when is_map(RawConf) -> ok = save_schema_mod_and_names(SchemaMod), %% Merge environment variable overrides on top RawConfWithEnvs = merge_envs(SchemaMod, RawConf), - ClusterOverrides = read_override_conf(#{override_to => cluster}), - LocalOverrides = read_override_conf(#{override_to => local}), - Overrides = hocon:deep_merge(ClusterOverrides, LocalOverrides), + Overrides = read_override_confs(), RawConfWithOverrides = hocon:deep_merge(RawConfWithEnvs, Overrides), RootNames = get_root_names(), RawConfAll = raw_conf_with_default(SchemaMod, RootNames, RawConfWithOverrides, Opts), @@ -337,6 +336,12 @@ init_load(SchemaMod, RawConf, Opts) when is_map(RawConf) -> save_to_app_env(AppEnvs), ok = save_to_config_map(CheckedConf, RawConfAll). +%% @doc Read merged cluster + local overrides. +read_override_confs() -> + ClusterOverrides = read_override_conf(#{override_to => cluster}), + LocalOverrides = read_override_conf(#{override_to => local}), + hocon:deep_merge(ClusterOverrides, LocalOverrides). + %% keep the raw and non-raw conf has the same keys to make update raw conf easier. raw_conf_with_default(SchemaMod, RootNames, RawConf, #{raw_with_default := true}) -> Fun = fun(Name, Acc) -> @@ -599,8 +604,16 @@ load_hocon_file(FileName, LoadType) -> case filelib:is_regular(FileName) of true -> Opts = #{include_dirs => include_dirs(), format => LoadType}, - {ok, Raw0} = hocon:load(FileName, Opts), - Raw0; + case hocon:load(FileName, Opts) of + {ok, Raw0} -> + Raw0; + {error, Reason} -> + throw(#{ + msg => failed_to_load_conf, + reason => Reason, + file => FileName + }) + end; false -> #{} end. From b0ac924ca91b9fe5801d73406d5a15f33276b316 Mon Sep 17 00:00:00 2001 From: "Zaiming (Stone) Shi" Date: Tue, 31 Jan 2023 14:40:06 +0100 Subject: [PATCH 2/4] refactor: less copy-paste --- apps/emqx/src/emqx_schema.erl | 12 ++++-------- apps/emqx_conf/src/emqx_conf_schema.erl | 15 ++------------- 2 files changed, 6 insertions(+), 21 deletions(-) diff --git a/apps/emqx/src/emqx_schema.erl b/apps/emqx/src/emqx_schema.erl index 8f016f684..48bd206c9 100644 --- a/apps/emqx/src/emqx_schema.erl +++ b/apps/emqx/src/emqx_schema.erl @@ -1815,16 +1815,12 @@ desc(_) -> %% utils -spec conf_get(string() | [string()], hocon:config()) -> term(). conf_get(Key, Conf) -> - V = hocon_maps:get(Key, Conf), - case is_binary(V) of - true -> - binary_to_list(V); - false -> - V - end. + ensure_list(hocon_maps:get(Key, Conf)). conf_get(Key, Conf, Default) -> - V = hocon_maps:get(Key, Conf, Default), + ensure_list(hocon_maps:get(Key, Conf, Default)). + +ensure_list(V) -> case is_binary(V) of true -> binary_to_list(V); diff --git a/apps/emqx_conf/src/emqx_conf_schema.erl b/apps/emqx_conf/src/emqx_conf_schema.erl index bc9154933..12f5a00ec 100644 --- a/apps/emqx_conf/src/emqx_conf_schema.erl +++ b/apps/emqx_conf/src/emqx_conf_schema.erl @@ -1308,11 +1308,9 @@ crash_dump_file_default() -> %% utils -spec conf_get(string() | [string()], hocon:config()) -> term(). -conf_get(Key, Conf) -> - ensure_list(hocon_maps:get(Key, Conf)). +conf_get(Key, Conf) -> emqx_schema:conf_get(Key, Conf). -conf_get(Key, Conf, Default) -> - ensure_list(hocon_maps:get(Key, Conf, Default)). +conf_get(Key, Conf, Default) -> emqx_schema:conf_get(Key, Conf, Default). filter(Opts) -> [{K, V} || {K, V} <- Opts, V =/= undefined]. @@ -1376,15 +1374,6 @@ to_atom(Str) when is_list(Str) -> to_atom(Bin) when is_binary(Bin) -> binary_to_atom(Bin, utf8). --spec ensure_list(binary() | list(char())) -> list(char()). -ensure_list(V) -> - case is_binary(V) of - true -> - binary_to_list(V); - false -> - V - end. - roots(Module) -> lists:map(fun({_BinName, Root}) -> Root end, hocon_schema:roots(Module)). From 605d9972e467b5b341ca283731bbee781196fc2a Mon Sep 17 00:00:00 2001 From: "Zaiming (Stone) Shi" Date: Tue, 31 Jan 2023 18:13:13 +0100 Subject: [PATCH 3/4] fix(config): avoid calling emqx:update_config/2 for logger refresh Prior to this fix, whatever configured for loggers are persisted to cluster-override.conf. This may cause troulbe for users who changes boot mode. For example if the node is once started in console mode, the logging config is persisted, with console enabled, but file disabled. Then if the user decide to start in daemon mode, all the logs will silently go to erlang.log.N and emqx.log.N will be empty. After this fix, only changes really made into cluter-override.conf will take effect. --- apps/emqx/src/config/emqx_config_logger.erl | 241 +++++++++++++++++--- apps/emqx_conf/src/emqx_conf_schema.erl | 140 +----------- 2 files changed, 218 insertions(+), 163 deletions(-) diff --git a/apps/emqx/src/config/emqx_config_logger.erl b/apps/emqx/src/config/emqx_config_logger.erl index 4b46e43d6..4d787ea0c 100644 --- a/apps/emqx/src/config/emqx_config_logger.erl +++ b/apps/emqx/src/config/emqx_config_logger.erl @@ -18,6 +18,7 @@ -behaviour(emqx_config_handler). %% API +-export([tr_handlers/1, tr_level/1]). -export([add_handler/0, remove_handler/0, refresh_config/0]). -export([post_config_update/5]). @@ -37,38 +38,224 @@ remove_handler() -> %% so we need to refresh the logger config after this node starts. %% It will not affect the logger config when cluster-override.conf is unchanged. refresh_config() -> - case emqx:get_raw_config(?LOG, undefined) of - %% no logger config when CT is running. - undefined -> - ok; - Log -> - {ok, _} = emqx:update_config(?LOG, Log), - ok - end. + Overrides = emqx_config:read_override_confs(), + refresh_config(Overrides). -post_config_update(?LOG, _Req, _NewConf, _OldConf, AppEnvs) -> - Kernel = proplists:get_value(kernel, AppEnvs), - NewHandlers = proplists:get_value(logger, Kernel, []), - Level = proplists:get_value(logger_level, Kernel, warning), - ok = update_log_handlers(NewHandlers), - ok = emqx_logger:set_primary_log_level(Level), - application:set_env(kernel, logger_level, Level), - ok; +refresh_config(#{<<"log">> := _}) -> + %% read the checked config + LogConfig = emqx:get_config(?LOG, undefined), + Conf = #{log => LogConfig}, + ok = do_refresh_config(Conf); +refresh_config(_) -> + %% No config override found for 'log', do nothing + %% because the 'kernel' app should already be configured + %% from the base configs. i.e. emqx.conf + env vars + ok. + +%% this call is shared between initial config refresh at boot +%% and dynamic config update from HTTP API +do_refresh_config(Conf) -> + Handlers = tr_handlers(Conf), + ok = update_log_handlers(Handlers), + Level = tr_level(Conf), + ok = maybe_update_log_level(Level), + ok. + +post_config_update(?LOG, _Req, NewConf, _OldConf, _AppEnvs) -> + ok = do_refresh_config(#{log => NewConf}); post_config_update(_ConfPath, _Req, _NewConf, _OldConf, _AppEnvs) -> ok. +maybe_update_log_level(NewLevel) -> + OldLevel = application:get_env(kernel, logger_level, warning), + case OldLevel =:= NewLevel of + true -> + %% no change + ok; + false -> + log_to_console("Config override: log level is set to '~p'~n", [NewLevel]) + end. + +log_to_console(Fmt, Args) -> + io:format(standard_error, Fmt, Args). + update_log_handlers(NewHandlers) -> OldHandlers = application:get_env(kernel, logger, []), - lists:foreach( - fun({handler, HandlerId, _Mod, _Conf}) -> - logger:remove_handler(HandlerId) + NewHandlersIds = lists:map(fun({handler, Id, _Mod, _Conf}) -> Id end, NewHandlers), + OldHandlersIds = lists:map(fun({handler, Id, _Mod, _Conf}) -> Id end, OldHandlers), + Removes = lists:map(fun(Id) -> {removed, Id} end, OldHandlersIds -- NewHandlersIds), + MapFn = fun({handler, Id, Mod, Conf} = Handler) -> + case lists:keyfind(Id, 2, OldHandlers) of + {handler, Id, Mod, Conf} -> + %% no change + false; + {handler, Id, _Mod, _Conf} -> + {true, {updated, Handler}}; + false -> + {true, {enabled, Handler}} + end + end, + AddsAndUpdates = lists:filtermap(MapFn, NewHandlers), + lists:foreach(fun update_log_handler/1, Removes ++ AddsAndUpdates), + _ = application:set_env(kernel, logger, NewHandlers), + ok. + +update_log_handler({removed, Id}) -> + log_to_console("Config override: ~s is removed~n", [id_for_log(Id)]), + logger:remove_handler(Id); +update_log_handler({Action, {handler, Id, Mod, Conf}}) -> + log_to_console("Config override: ~s is ~p~n", [id_for_log(Id), Action]), + % may return {error, {not_found, Id}} + _ = logger:remove_handler(Id), + ok = logger:add_handler(Id, Mod, Conf). + +id_for_log(console) -> "log.console_handler"; +id_for_log(Other) -> "log.file_handlers." ++ atom_to_list(Other). + +atom(Id) when is_binary(Id) -> binary_to_atom(Id, utf8); +atom(Id) when is_atom(Id) -> Id. + +%% @doc Translate raw config to app-env conpatible log handler configs list. +tr_handlers(Conf) -> + %% mute the default handler + tr_console_handler(Conf) ++ + tr_file_handlers(Conf). + +%% For the default logger that outputs to console +tr_console_handler(Conf) -> + case conf_get("log.console_handler.enable", Conf) of + true -> + ConsoleConf = conf_get("log.console_handler", Conf), + [ + {handler, console, logger_std_h, #{ + level => conf_get("log.console_handler.level", Conf), + config => (log_handler_conf(ConsoleConf))#{type => standard_io}, + formatter => log_formatter(ConsoleConf), + filters => log_filter(ConsoleConf) + }} + ]; + false -> + [] + end. + +%% For the file logger +tr_file_handlers(Conf) -> + Handlers = logger_file_handlers(Conf), + lists:map(fun tr_file_handler/1, Handlers). + +tr_file_handler({HandlerName, SubConf}) -> + {handler, atom(HandlerName), logger_disk_log_h, #{ + level => conf_get("level", SubConf), + config => (log_handler_conf(SubConf))#{ + type => + case conf_get("rotation.enable", SubConf) of + true -> wrap; + _ -> halt + end, + file => conf_get("file", SubConf), + max_no_files => conf_get("rotation.count", SubConf), + max_no_bytes => conf_get("max_size", SubConf) + }, + formatter => log_formatter(SubConf), + filters => log_filter(SubConf), + filesync_repeat_interval => no_repeat + }}. + +logger_file_handlers(Conf) -> + Handlers = maps:to_list(conf_get("log.file_handlers", Conf, #{})), + lists:filter( + fun({_Name, Opts}) -> + B = conf_get("enable", Opts), + true = is_boolean(B), + B end, - OldHandlers -- NewHandlers - ), - lists:foreach( - fun({handler, HandlerId, Mod, Conf}) -> - logger:add_handler(HandlerId, Mod, Conf) + Handlers + ). + +conf_get(Key, Conf) -> emqx_schema:conf_get(Key, Conf). +conf_get(Key, Conf, Default) -> emqx_schema:conf_get(Key, Conf, Default). + +log_handler_conf(Conf) -> + SycModeQlen = conf_get("sync_mode_qlen", Conf), + DropModeQlen = conf_get("drop_mode_qlen", Conf), + FlushQlen = conf_get("flush_qlen", Conf), + Overkill = conf_get("overload_kill", Conf), + BurstLimit = conf_get("burst_limit", Conf), + #{ + sync_mode_qlen => SycModeQlen, + drop_mode_qlen => DropModeQlen, + flush_qlen => FlushQlen, + overload_kill_enable => conf_get("enable", Overkill), + overload_kill_qlen => conf_get("qlen", Overkill), + overload_kill_mem_size => conf_get("mem_size", Overkill), + overload_kill_restart_after => conf_get("restart_after", Overkill), + burst_limit_enable => conf_get("enable", BurstLimit), + burst_limit_max_count => conf_get("max_count", BurstLimit), + burst_limit_window_time => conf_get("window_time", BurstLimit) + }. + +log_formatter(Conf) -> + CharsLimit = + case conf_get("chars_limit", Conf) of + unlimited -> unlimited; + V when V > 0 -> V end, - NewHandlers -- OldHandlers - ), - application:set_env(kernel, logger, NewHandlers). + TimeOffSet = + case conf_get("time_offset", Conf) of + "system" -> ""; + "utc" -> 0; + OffSetStr -> OffSetStr + end, + SingleLine = conf_get("single_line", Conf), + Depth = conf_get("max_depth", Conf), + do_formatter(conf_get("formatter", Conf), CharsLimit, SingleLine, TimeOffSet, Depth). + +%% helpers +do_formatter(json, CharsLimit, SingleLine, TimeOffSet, Depth) -> + {emqx_logger_jsonfmt, #{ + chars_limit => CharsLimit, + single_line => SingleLine, + time_offset => TimeOffSet, + depth => Depth + }}; +do_formatter(text, CharsLimit, SingleLine, TimeOffSet, Depth) -> + {emqx_logger_textfmt, #{ + template => [time, " [", level, "] ", msg, "\n"], + chars_limit => CharsLimit, + single_line => SingleLine, + time_offset => TimeOffSet, + depth => Depth + }}. + +log_filter(Conf) -> + case conf_get("supervisor_reports", Conf) of + error -> [{drop_progress_reports, {fun logger_filters:progress/2, stop}}]; + progress -> [] + end. + +tr_level(Conf) -> + ConsoleLevel = conf_get("log.console_handler.level", Conf, undefined), + FileLevels = [ + conf_get("level", SubConf) + || {_, SubConf} <- + logger_file_handlers(Conf) + ], + case FileLevels ++ [ConsoleLevel || ConsoleLevel =/= undefined] of + %% warning is the default level we should use + [] -> warning; + Levels -> least_severe_log_level(Levels) + end. + +least_severe_log_level(Levels) -> + hd(sort_log_levels(Levels)). + +sort_log_levels(Levels) -> + lists:sort( + fun(A, B) -> + case logger:compare_levels(A, B) of + R when R == lt; R == eq -> true; + gt -> false + end + end, + Levels + ). diff --git a/apps/emqx_conf/src/emqx_conf_schema.erl b/apps/emqx_conf/src/emqx_conf_schema.erl index 12f5a00ec..9793e00d0 100644 --- a/apps/emqx_conf/src/emqx_conf_schema.erl +++ b/apps/emqx_conf/src/emqx_conf_schema.erl @@ -993,7 +993,7 @@ translation("ekka") -> translation("kernel") -> [ {"logger_level", fun tr_logger_level/1}, - {"logger", fun tr_logger/1}, + {"logger", fun tr_logger_handlers/1}, {"error_logger", fun(_) -> silent end} ]; translation("emqx") -> @@ -1065,70 +1065,10 @@ tr_cluster_discovery(Conf) -> -spec tr_logger_level(hocon:config()) -> logger:level(). tr_logger_level(Conf) -> - ConsoleLevel = conf_get("log.console_handler.level", Conf, undefined), - FileLevels = [ - conf_get("level", SubConf) - || {_, SubConf} <- - logger_file_handlers(Conf) - ], - case FileLevels ++ [ConsoleLevel || ConsoleLevel =/= undefined] of - %% warning is the default level we should use - [] -> warning; - Levels -> least_severe_log_level(Levels) - end. + emqx_config_logger:tr_level(Conf). -logger_file_handlers(Conf) -> - Handlers = maps:to_list(conf_get("log.file_handlers", Conf, #{})), - lists:filter( - fun({_Name, Opts}) -> - B = conf_get("enable", Opts), - true = is_boolean(B), - B - end, - Handlers - ). - -tr_logger(Conf) -> - %% For the default logger that outputs to console - ConsoleHandler = - case conf_get("log.console_handler.enable", Conf) of - true -> - ConsoleConf = conf_get("log.console_handler", Conf), - [ - {handler, console, logger_std_h, #{ - level => conf_get("log.console_handler.level", Conf), - config => (log_handler_conf(ConsoleConf))#{type => standard_io}, - formatter => log_formatter(ConsoleConf), - filters => log_filter(ConsoleConf) - }} - ]; - false -> - [] - end, - %% For the file logger - FileHandlers = - [ - begin - {handler, to_atom(HandlerName), logger_disk_log_h, #{ - level => conf_get("level", SubConf), - config => (log_handler_conf(SubConf))#{ - type => - case conf_get("rotation.enable", SubConf) of - true -> wrap; - _ -> halt - end, - file => conf_get("file", SubConf), - max_no_files => conf_get("rotation.count", SubConf), - max_no_bytes => conf_get("max_size", SubConf) - }, - formatter => log_formatter(SubConf), - filters => log_filter(SubConf), - filesync_repeat_interval => no_repeat - }} - end - || {HandlerName, SubConf} <- logger_file_handlers(Conf) - ], - [{handler, default, undefined}] ++ ConsoleHandler ++ FileHandlers. +tr_logger_handlers(Conf) -> + emqx_config_logger:tr_handlers(Conf). log_handler_common_confs(Enable) -> [ @@ -1225,78 +1165,6 @@ log_handler_common_confs(Enable) -> )} ]. -log_handler_conf(Conf) -> - SycModeQlen = conf_get("sync_mode_qlen", Conf), - DropModeQlen = conf_get("drop_mode_qlen", Conf), - FlushQlen = conf_get("flush_qlen", Conf), - Overkill = conf_get("overload_kill", Conf), - BurstLimit = conf_get("burst_limit", Conf), - #{ - sync_mode_qlen => SycModeQlen, - drop_mode_qlen => DropModeQlen, - flush_qlen => FlushQlen, - overload_kill_enable => conf_get("enable", Overkill), - overload_kill_qlen => conf_get("qlen", Overkill), - overload_kill_mem_size => conf_get("mem_size", Overkill), - overload_kill_restart_after => conf_get("restart_after", Overkill), - burst_limit_enable => conf_get("enable", BurstLimit), - burst_limit_max_count => conf_get("max_count", BurstLimit), - burst_limit_window_time => conf_get("window_time", BurstLimit) - }. - -log_formatter(Conf) -> - CharsLimit = - case conf_get("chars_limit", Conf) of - unlimited -> unlimited; - V when V > 0 -> V - end, - TimeOffSet = - case conf_get("time_offset", Conf) of - "system" -> ""; - "utc" -> 0; - OffSetStr -> OffSetStr - end, - SingleLine = conf_get("single_line", Conf), - Depth = conf_get("max_depth", Conf), - do_formatter(conf_get("formatter", Conf), CharsLimit, SingleLine, TimeOffSet, Depth). - -%% helpers -do_formatter(json, CharsLimit, SingleLine, TimeOffSet, Depth) -> - {emqx_logger_jsonfmt, #{ - chars_limit => CharsLimit, - single_line => SingleLine, - time_offset => TimeOffSet, - depth => Depth - }}; -do_formatter(text, CharsLimit, SingleLine, TimeOffSet, Depth) -> - {emqx_logger_textfmt, #{ - template => [time, " [", level, "] ", msg, "\n"], - chars_limit => CharsLimit, - single_line => SingleLine, - time_offset => TimeOffSet, - depth => Depth - }}. - -log_filter(Conf) -> - case conf_get("supervisor_reports", Conf) of - error -> [{drop_progress_reports, {fun logger_filters:progress/2, stop}}]; - progress -> [] - end. - -least_severe_log_level(Levels) -> - hd(sort_log_levels(Levels)). - -sort_log_levels(Levels) -> - lists:sort( - fun(A, B) -> - case logger:compare_levels(A, B) of - R when R == lt; R == eq -> true; - gt -> false - end - end, - Levels - ). - crash_dump_file_default() -> case os:getenv("RUNNER_LOG_DIR") of false -> From ddfbc0a19f489219902f26af228c5f2de0799db9 Mon Sep 17 00:00:00 2001 From: "Zaiming (Stone) Shi" Date: Tue, 31 Jan 2023 18:33:10 +0100 Subject: [PATCH 4/4] refactor: refresh logger config before starting listeners --- apps/emqx/src/emqx_app.erl | 1 + apps/emqx/src/emqx_config.erl | 1 - 2 files changed, 1 insertion(+), 1 deletion(-) diff --git a/apps/emqx/src/emqx_app.erl b/apps/emqx/src/emqx_app.erl index 6188d8030..c56cdb520 100644 --- a/apps/emqx/src/emqx_app.erl +++ b/apps/emqx/src/emqx_app.erl @@ -42,6 +42,7 @@ start(_Type, _Args) -> ok = maybe_load_config(), ok = emqx_persistent_session:init_db_backend(), + ok = emqx_config_logger:refresh_config(), ok = maybe_start_quicer(), ok = emqx_bpapi:start(), wait_boot_shards(), diff --git a/apps/emqx/src/emqx_config.erl b/apps/emqx/src/emqx_config.erl index 117043911..6d706316c 100644 --- a/apps/emqx/src/emqx_config.erl +++ b/apps/emqx/src/emqx_config.erl @@ -592,7 +592,6 @@ save_to_override_conf(RawConf, Opts) -> add_handlers() -> ok = emqx_config_logger:add_handler(), emqx_sys_mon:add_handler(), - emqx_config_logger:refresh_config(), ok. remove_handlers() ->