From b6289e914c67bd786da829503b144c039303bfd3 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 14 Aug 2018 11:43:18 +0200 Subject: [logger] Refactor some logger internals --- lib/kernel/src/logger.erl | 7 +--- lib/kernel/src/logger_backend.erl | 2 +- lib/kernel/src/logger_config.erl | 23 ++--------- lib/kernel/src/logger_disk_log_h.erl | 5 +-- lib/kernel/src/logger_server.erl | 74 +++++++++++++++++------------------- lib/kernel/src/logger_std_h.erl | 5 +-- 6 files changed, 43 insertions(+), 73 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 0020fe220b..7b1377b8ca 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -434,12 +434,7 @@ get_primary_config() -> HandlerId :: handler_id(), Config :: handler_config(). get_handler_config(HandlerId) -> - case logger_config:get(?LOGGER_TABLE,HandlerId) of - {ok,{_,Config}} -> - {ok,Config}; - Error -> - Error - end. + logger_config:get(?LOGGER_TABLE,HandlerId). -spec get_handler_config() -> [Config] when Config :: handler_config(). diff --git a/lib/kernel/src/logger_backend.erl b/lib/kernel/src/logger_backend.erl index 4d7bd6b2a0..432c671afd 100644 --- a/lib/kernel/src/logger_backend.erl +++ b/lib/kernel/src/logger_backend.erl @@ -41,7 +41,7 @@ log_allowed(Log, Tid) -> call_handlers(#{level:=Level}=Log,[Id|Handlers],Tid) -> case logger_config:get(Tid,Id,Level) of - {ok,{Module,Config}} -> + {ok,#{module:=Module}=Config} -> Filters = maps:get(filters,Config,[]), case apply_filters(Id,Log,Filters,Config) of stop -> diff --git a/lib/kernel/src/logger_config.erl b/lib/kernel/src/logger_config.erl index 55427dce5a..6bfe658552 100644 --- a/lib/kernel/src/logger_config.erl +++ b/lib/kernel/src/logger_config.erl @@ -22,8 +22,8 @@ -export([new/1,delete/2, exist/2, allow/2,allow/3, - get/2, get/3, get/1, - create/3, create/4, set/3, + get/2, get/3, + create/3, set/3, set_module_level/3,unset_module_level/2, get_module_level/1,cache_module_level/2, level_to_int/1]). @@ -64,27 +64,19 @@ get(Tid,What) -> case ets:lookup(Tid,table_key(What)) of [{_,_,Config}] -> {ok,Config}; - [{_,_,Config,Module}] -> - {ok,{Module,Config}}; [] -> {error,{not_found,What}} end. get(Tid,What,Level) -> - MS = [{{table_key(What),'$1','$2'}, % primary config + MS = [{{table_key(What),'$1','$2'}, [{'>=','$1',level_to_int(Level)}], - ['$2']}, - {{table_key(What),'$1','$2','$3'}, % handler config - [{'>=','$1',level_to_int(Level)}], - [{{'$3','$2'}}]}], + ['$2']}], case ets:select(Tid,MS) of [] -> error; [Data] -> {ok,Data} end. -create(Tid,What,Module,Config) -> - LevelInt = level_to_int(maps:get(level,Config)), - ets:insert(Tid,{table_key(What),LevelInt,Config,Module}). create(Tid,What,Config) -> LevelInt = level_to_int(maps:get(level,Config)), ets:insert(Tid,{table_key(What),LevelInt,Config}). @@ -129,13 +121,6 @@ cache_module_level(Tid,Module) -> ets:insert_new(Tid,{Module,{GlobalLevelInt,cached}}), ok. -get(Tid) -> - {ok,Primary} = get(Tid,primary), - HMS = [{{table_key('$1'),'_','$2','$3'},[],[{{'$1','$3','$2'}}]}], - Handlers = ets:select(Tid,HMS), - Modules = get_module_level(Tid), - {Primary,Handlers,Modules}. - level_to_int(none) -> ?LOG_NONE; level_to_int(emergency) -> ?EMERGENCY; level_to_int(alert) -> ?ALERT; diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index e56531c3cb..3c12c9e68b 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -294,7 +294,7 @@ init([Name, %% initial start ok end, - enter_loop(Config1, State1) + gen_server:enter_loop(?MODULE, [], State1) catch _:Error -> unregister(RegName), @@ -307,9 +307,6 @@ init([Name, proc_lib:init_ack(Error) end. -enter_loop(_Config,State) -> - gen_server:enter_loop(?MODULE,[],State). - %% This is the synchronous log event. handle_call({log, Bin}, _From, State) -> {Result,State1} = do_log(Bin, call, State), diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 644fdd5af2..01ac1b4b50 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -146,7 +146,7 @@ init([]) -> filters=>?DEFAULT_HANDLER_FILTERS}), %% If this fails, then the node should crash {ok,SimpleConfig} = logger_simple_h:adding_handler(SimpleConfig0), - logger_config:create(Tid,simple,logger_simple_h,SimpleConfig), + logger_config:create(Tid,simple,SimpleConfig), {ok, #state{tid=Tid, async_req_queue = queue:new()}}. handle_call({add_handler,Id,Module,HConfig}, From, #state{tid=Tid}=State) -> @@ -165,11 +165,11 @@ handle_call({add_handler,Id,Module,HConfig}, From, #state{tid=Tid}=State) -> %% to find out if this is a valid handler case erlang:function_exported(Module, log, 2) of true -> - logger_config:create(Tid,Id,Module,HConfig1), - {ok,Config} = do_get_config(Tid,primary), + logger_config:create(Tid,Id,HConfig1), + {ok,Config} = logger_config:get(Tid,primary), Handlers = maps:get(handlers,Config,[]), - do_set_config(Tid,primary, - Config#{handlers=>[Id|Handlers]}); + logger_config:set(Tid,primary, + Config#{handlers=>[Id|Handlers]}); false -> {error,{invalid_handler, {function_not_exported, @@ -181,8 +181,8 @@ handle_call({add_handler,Id,Module,HConfig}, From, #state{tid=Tid}=State) -> end; handle_call({remove_handler,HandlerId}, From, #state{tid=Tid}=State) -> case logger_config:get(Tid,HandlerId) of - {ok,{Module,HConfig}} -> - {ok,Config} = do_get_config(Tid,primary), + {ok,#{module:=Module}=HConfig} -> + {ok,Config} = logger_config:get(Tid,primary), Handlers0 = maps:get(handlers,Config,[]), Handlers = lists:delete(HandlerId,Handlers0), call_h_async( @@ -191,7 +191,7 @@ handle_call({remove_handler,HandlerId}, From, #state{tid=Tid}=State) -> call_h(Module,removing_handler,[HConfig],ok) end, fun(_Res) -> - do_set_config(Tid,primary,Config#{handlers=>Handlers}), + logger_config:set(Tid,primary,Config#{handlers=>Handlers}), logger_config:delete(Tid,HandlerId), ok end,From,State); @@ -204,25 +204,35 @@ handle_call({add_filter,Id,Filter}, _From,#state{tid=Tid}=State) -> handle_call({remove_filter,Id,FilterId}, _From, #state{tid=Tid}=State) -> Reply = do_remove_filter(Tid,Id,FilterId), {reply,Reply,State}; -handle_call({update_config,Id,NewConfig}, From, #state{tid=Tid}=State) -> - case logger_config:get(Tid,Id) of - {ok,{_Module,OldConfig}} -> - Config = maps:merge(OldConfig,NewConfig), - handle_call({set_config,Id,Config}, From, State); - {ok,OldConfig} -> +handle_call({update_config,primary,NewConfig}, _From, #state{tid=Tid}=State) -> + {ok,OldConfig} = logger_config:get(Tid,primary), + Config = maps:merge(OldConfig,NewConfig), + {reply,logger_config:set(Tid,primary,Config),State}; +handle_call({update_config,HandlerId,NewConfig}, From, #state{tid=Tid}=State) -> + case logger_config:get(Tid,HandlerId) of + {ok,#{module:=Module}=OldConfig} -> Config = maps:merge(OldConfig,NewConfig), - {reply,do_set_config(Tid,Id,Config),State}; + call_h_async( + fun() -> + call_h(Module,changing_config,[OldConfig,Config], + {ok,Config}) + end, + fun({ok,Config1}) -> + logger_config:set(Tid,HandlerId,Config1); + (Error) -> + Error + end,From,State); Error -> {reply,Error,State} end; handle_call({set_config,primary,Config0}, _From, #state{tid=Tid}=State) -> Config = maps:merge(default_config(primary),Config0), {ok,#{handlers:=Handlers}} = logger_config:get(Tid,primary), - Reply = do_set_config(Tid,primary,Config#{handlers=>Handlers}), + Reply = logger_config:set(Tid,primary,Config#{handlers=>Handlers}), {reply,Reply,State}; handle_call({set_config,HandlerId,Config0}, From, #state{tid=Tid}=State) -> case logger_config:get(Tid,HandlerId) of - {ok,{Module,OldConfig}} -> + {ok,#{module:=Module}=OldConfig} -> Config = maps:merge(default_config(HandlerId,Module),Config0), call_h_async( fun() -> @@ -230,7 +240,7 @@ handle_call({set_config,HandlerId,Config0}, From, #state{tid=Tid}=State) -> {ok,Config}) end, fun({ok,Config1}) -> - do_set_config(Tid,HandlerId,Config1); + logger_config:set(Tid,HandlerId,Config1); (Error) -> Error end,From,State); @@ -241,12 +251,12 @@ handle_call({update_formatter_config,HandlerId,NewFConfig},_From, #state{tid=Tid}=State) -> Reply = case logger_config:get(Tid,HandlerId) of - {ok,{_Mod,#{formatter:={FMod,OldFConfig}}=Config}} -> + {ok,#{formatter:={FMod,OldFConfig}}=Config} -> try FConfig = maps:merge(OldFConfig,NewFConfig), check_formatter({FMod,FConfig}), - do_set_config(Tid,HandlerId, - Config#{formatter=>{FMod,FConfig}}) + logger_config:set(Tid,HandlerId, + Config#{formatter=>{FMod,FConfig}}) catch throw:Reason -> {error,Reason} end; _ -> @@ -316,26 +326,26 @@ call(Request) -> end. do_add_filter(Tid,Id,{FId,_} = Filter) -> - case do_get_config(Tid,Id) of + case logger_config:get(Tid,Id) of {ok,Config} -> Filters = maps:get(filters,Config,[]), case lists:keymember(FId,1,Filters) of true -> {error,{already_exist,FId}}; false -> - do_set_config(Tid,Id,Config#{filters=>[Filter|Filters]}) + logger_config:set(Tid,Id,Config#{filters=>[Filter|Filters]}) end; Error -> Error end. do_remove_filter(Tid,Id,FilterId) -> - case do_get_config(Tid,Id) of + case logger_config:get(Tid,Id) of {ok,Config} -> Filters0 = maps:get(filters,Config,[]), case lists:keytake(FilterId,1,Filters0) of {value,_,Filters} -> - do_set_config(Tid,Id,Config#{filters=>Filters}); + logger_config:set(Tid,Id,Config#{filters=>Filters}); false -> {error,{not_found,FilterId}} end; @@ -343,20 +353,6 @@ do_remove_filter(Tid,Id,FilterId) -> Error end. -do_get_config(Tid,Id) -> - case logger_config:get(Tid,Id) of - {ok,{_,Config}} -> - {ok,Config}; - {ok,Config} -> - {ok,Config}; - Error -> - Error - end. - -do_set_config(Tid,Id,Config) -> - logger_config:set(Tid,Id,Config), - ok. - default_config(primary) -> #{level=>notice, filters=>[], diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index 9a2a1443b3..b60e7cf587 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -259,7 +259,7 @@ init([Name, Config = #{config := HConfig}, mode_tab => ModeTab}}, proc_lib:init_ack({ok,self(),Config1}), gen_server:cast(self(), repeated_filesync), - enter_loop(Config1, State1) + gen_server:enter_loop(?MODULE, [], State1) catch _:Error -> unregister(RegName), @@ -290,9 +290,6 @@ do_init(Name, Type) -> Error end. -enter_loop(_Config,State) -> - gen_server:enter_loop(?MODULE,[],State). - %% This is the synchronous log event. handle_call({log, Bin}, _From, State) -> {Result,State1} = do_log(Bin, call, State), -- cgit v1.2.3 From 96c1aa0041b368afceef0aef88e82a6c9f8e901d Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 31 Aug 2018 17:08:24 +0200 Subject: [logger] Remove encoding option from logger_formatter The encoding option was introduced in commit 270d909696a753af022df72a404c73f2895b4a02, to allow report callbacks to format according to a given encoding. There was, however, no connection between this encoding option, and the encoding of the device to which the logger handler was writing. Since a formatter is defined to return unicode:chardata(), and in order to avoid mismatch with the encoding of the device, the encoding option is now removed from the formatter. The handler itself must make sure that it does not write illegal data to its device. --- lib/kernel/src/logger.erl | 3 +- lib/kernel/src/logger_formatter.erl | 68 +++++++++++++++---------------------- lib/kernel/src/logger_h_common.erl | 20 ++++++++--- 3 files changed, 44 insertions(+), 47 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 7b1377b8ca..df96367d82 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -77,8 +77,7 @@ -type report() :: map() | [{atom(),term()}]. -type report_cb() :: fun((report()) -> {io:format(),[term()]}) | fun((report(),report_cb_config()) -> unicode:chardata()). --type report_cb_config() :: #{encoding := unicode:encoding(), - depth := pos_integer() | unlimited, +-type report_cb_config() :: #{depth := pos_integer() | unlimited, chars_limit := pos_integer() | unlimited}. -type msg_fun() :: fun((term()) -> {io:format(),[term()]} | report() | diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index b0d4adc14d..59aa6ec3af 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -28,7 +28,6 @@ %%% Types -type config() :: #{chars_limit => pos_integer() | unlimited, depth => pos_integer() | unlimited, - encoding => unicode:encoding(), legacy_header => boolean(), max_size => pos_integer() | unlimited, report_cb => logger:report_cb(), @@ -84,7 +83,7 @@ format(#{level:=Level,msg:=Msg0,meta:=Meta},Config0) true -> "" end, - truncate(B ++ MsgStr ++ A,maps:get(max_size,Config)). + truncate([B,MsgStr,A],maps:get(max_size,Config)). do_format(Level,Data,[level|Format],Config) -> [to_string(level,Level,Config)|do_format(Level,Data,Format,Config)]; @@ -147,7 +146,7 @@ printable_list(X) -> io_lib:printable_list(X). format_msg({string,Chardata},Meta,Config) -> - format_msg({s(Config),[Chardata]},Meta,Config); + format_msg({"~ts",[Chardata]},Meta,Config); format_msg({report,_}=Msg,Meta,#{report_cb:=Fun}=Config) when is_function(Fun,1); is_function(Fun,2) -> format_msg(Msg,Meta#{report_cb=>Fun},maps:remove(report_cb,Config)); @@ -166,13 +165,13 @@ format_msg({report,Report},#{report_cb:=Fun}=Meta,Config) when is_function(Fun,1 Meta,Config) end; format_msg({report,Report},#{report_cb:=Fun}=Meta,Config) when is_function(Fun,2) -> - try Fun(Report,maps:with([encoding,depth,chars_limit],Config)) of - String when ?IS_STRING(String) -> - try unicode:characters_to_list(String) + try Fun(Report,maps:with([depth,chars_limit],Config)) of + Chardata when ?IS_STRING(Chardata) -> + try chardata_to_list(Chardata) % already size limited by report_cb catch _:_ -> P = p(Config), format_msg({"REPORT_CB/2 ERROR: "++P++"; Returned: "++P, - [Report,String]},Meta,Config) + [Report,Chardata]},Meta,Config) end; Other -> P = p(Config), @@ -189,28 +188,27 @@ format_msg({report,Report},Meta,Config) -> Meta#{report_cb=>fun logger:format_report/1}, Config); format_msg(Msg,_Meta,#{depth:=Depth,chars_limit:=CharsLimit, - encoding:=Enc,single_line:=Single}) -> + single_line:=Single}) -> Opts = chars_limit_to_opts(CharsLimit), - format_msg(Msg, Depth, Opts, Enc, Single). + format_msg(Msg, Depth, Opts, Single). chars_limit_to_opts(unlimited) -> []; chars_limit_to_opts(CharsLimit) -> [{chars_limit,CharsLimit}]. -format_msg({Format0,Args},Depth,Opts,Enc,Single) -> +format_msg({Format0,Args},Depth,Opts,Single) -> try Format1 = io_lib:scan_format(Format0, Args), Format = reformat(Format1, Depth, Single), io_lib:build_text(Format,Opts) catch C:R:S -> - P = p(Enc,Single), + P = p(Single), FormatError = "FORMAT ERROR: "++P++" - "++P, case Format0 of FormatError -> %% already been here - avoid failing cyclically erlang:raise(C,R,S); _ -> - format_msg({FormatError,[Format0,Args]}, - Depth,Opts,Enc,Single) + format_msg({FormatError,[Format0,Args]},Depth,Opts,Single) end end. @@ -233,6 +231,14 @@ limit_depth(#{control_char:=C0, args:=Args}=M0, Depth) -> C = C0 - ($a - $A), %To uppercase. M0#{control_char:=C,args:=Args++[Depth]}. +chardata_to_list(Chardata) -> + case unicode:characters_to_list(Chardata,unicode) of + List when is_list(List) -> + List; + Error -> + throw(Error) + end. + truncate(String,unlimited) -> String; truncate(String,Size) -> @@ -278,12 +284,11 @@ maybe_add_legacy_header(Level, #{time:=Timestamp}=Meta, #{legacy_header:=true}=Config) -> #{title:=Title}=MyMeta = add_legacy_title(Level,Meta,Config), - {{Y,Mo,D},{H,Mi,Sec},Micro,UtcStr} = + {{Y,Mo,D},{H,Mi,S},Micro,UtcStr} = timestamp_to_datetimemicro(Timestamp,Config), - S = s(Config), Header = - io_lib:format("="++S++"==== ~w-~s-~4w::~2..0w:~2..0w:~2..0w.~6..0w ~s===", - [Title,D,month(Mo),Y,H,Mi,Sec,Micro,UtcStr]), + io_lib:format("=~ts==== ~w-~s-~4w::~2..0w:~2..0w:~2..0w.~6..0w ~s===", + [Title,D,month(Mo),Y,H,Mi,S,Micro,UtcStr]), Meta#{?MODULE=>MyMeta#{header=>Header}}; maybe_add_legacy_header(_,Meta,_) -> Meta. @@ -324,7 +329,6 @@ month(12) -> "Dec". add_default_config(Config0) -> Default = #{chars_limit=>unlimited, - encoding=>utf8, error_logger_notice_header=>info, legacy_header=>false, single_line=>true, @@ -502,25 +506,9 @@ check_timezone(Tz) -> error end. -p(#{encoding:=Enc, single_line:=Single}) -> - p(Enc,Single). - -p(Enc,Single) -> - "~"++p_width(Single)++p_char(Enc). - -p_width(true) -> - "0"; -p_width(false) -> - "". - -p_char(latin1) -> - "p"; -p_char(_) -> - "tp". - -s(#{encoding:=Enc}) -> - s(Enc); -s(latin1) -> - "~s"; -s(_) -> - "~ts". +p(#{single_line:=Single}) -> + p(Single); +p(true) -> + "~0tp"; +p(false) -> + "~tp". diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index 854e5479b9..2818a460f1 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -40,7 +40,7 @@ info_notify/1]). %%%----------------------------------------------------------------- -%%% Covert log data on any form to binary +%%% Convert log data on any form to binary -spec log_to_binary(LogEvent,Config) -> LogString when LogEvent :: logger:log_event(), Config :: logger:handler_config(), @@ -57,13 +57,14 @@ do_log_to_binary(Log,Config) -> {Formatter,FormatterConfig} = maps:get(formatter,Config,{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}), String = try_format(Log,Formatter,FormatterConfig), - try unicode:characters_to_binary(String) - catch _:_ -> + try string_to_binary(String) + catch C2:R2:S2 -> ?LOG_INTERNAL(debug,[{formatter_error,Formatter}, {config,FormatterConfig}, {log_event,Log}, - {bad_return_value,String}]), - <<"FORMATTER ERROR: bad_return_value">> + {bad_return_value,String}, + {catched,{C2,R2,S2}}]), + <<"FORMATTER ERROR: bad return value">> end. try_format(Log,Formatter,FormatterConfig) -> @@ -85,6 +86,15 @@ try_format(Log,Formatter,FormatterConfig) -> end end. +string_to_binary(String) -> + case unicode:characters_to_binary(String) of + Binary when is_binary(Binary) -> + Binary; + Error -> + throw(Error) + end. + + %%%----------------------------------------------------------------- %%% Check that the configuration term is valid check_common_config({mode_tab,_Tid}) -> -- cgit v1.2.3 From a9a72da93e9b93a1d7ee9936b8e223545277480e Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 6 Sep 2018 13:51:49 +0200 Subject: [logger] Refactor, and add error detection for configuration --- lib/kernel/src/logger.erl | 153 ++++++++++++++++++++++++++-------------------- 1 file changed, 88 insertions(+), 65 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index df96367d82..0ada8b4924 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -115,6 +115,11 @@ -type config_handler() :: {handler, handler_id(), module(), handler_config()}. +-type config_logger() :: [{handler,default,undefined} | + config_handler() | + {filters,log | stop,[{filter_id(),filter()}]} | + {module_level,level(),[module()]}]. + -export_type([log_event/0, level/0, report/0, @@ -582,19 +587,21 @@ get_config() -> %% tree is started. internal_init_logger() -> try + Env = get_logger_env(kernel), + check_logger_config(kernel,Env), ok = logger:set_primary_config(level, get_logger_level()), - ok = logger:set_primary_config(filter_default, get_primary_filter_default()), + ok = logger:set_primary_config(filter_default, + get_primary_filter_default(Env)), [case logger:add_primary_filter(Id, Filter) of ok -> ok; {error, Reason} -> throw(Reason) - end || {Id, Filter} <- get_primary_filters()], + end || {Id, Filter} <- get_primary_filters(Env)], - _ = [[case logger:set_module_level(Module, Level) of - ok -> ok; - {error, Reason} -> throw(Reason) - end || Module <- Modules] - || {module_level, Level, Modules} <- get_logger_env()], + [case logger:set_module_level(Modules, Level) of + ok -> ok; + {error, Reason} -> throw(Reason) + end || {module_level, Level, Modules} <- Env], case logger:set_handler_config(simple,filters, get_default_handler_filters()) of @@ -602,24 +609,24 @@ internal_init_logger() -> {error,{not_found,simple}} -> ok end, - init_kernel_handlers() + init_kernel_handlers(Env) catch throw:Reason -> ?LOG_ERROR("Invalid logger config: ~p", [Reason]), {error, {bad_config, {kernel, Reason}}} end. --spec init_kernel_handlers() -> ok | {error,term()}. +-spec init_kernel_handlers(config_logger()) -> ok | {error,term()}. %% Setup the kernel environment variables to be correct %% The actual handlers are started by a call to add_handlers. -init_kernel_handlers() -> +init_kernel_handlers(Env) -> try - case get_logger_type() of + case get_logger_type(Env) of {ok,silent} -> ok = logger:remove_handler(simple); {ok,false} -> ok; {ok,Type} -> - init_default_config(Type) + init_default_config(Type,Env) end catch throw:Reason -> ?LOG_ERROR("Invalid default handler config: ~p", [Reason]), @@ -634,10 +641,13 @@ init_kernel_handlers() -> %% and then starting the correct handlers. This is done after the %% kernel supervisor tree has been started as it needs the logger_sup. add_handlers(App) when is_atom(App) -> - add_handlers(application:get_env(App, logger, [])); + add_handlers(App,get_logger_env(App)); add_handlers(HandlerConfig) -> + add_handlers(application:get_application(),HandlerConfig). + +add_handlers(App,HandlerConfig) -> try - check_logger_config(HandlerConfig), + check_logger_config(App,HandlerConfig), DefaultAdded = lists:foldl( fun({handler, default = Id, Module, Config}, _) @@ -651,17 +661,22 @@ add_handlers(HandlerConfig) -> ({handler, Id, Module, Config}, Default) -> setup_handler(Id, Module, Config), Default orelse Id == default; - (_, Default) -> Default + (_,Default) -> Default end, false, HandlerConfig), %% If a default handler was added we try to remove the simple_logger %% If the simple logger exists it will replay its log events %% to the handler(s) added in the fold above. - _ = [case logger:remove_handler(simple) of - ok -> ok; - {error,{not_found,simple}} -> ok - end || DefaultAdded], + [case logger:remove_handler(simple) of + ok -> ok; + {error,{not_found,simple}} -> ok + end || DefaultAdded], ok - catch throw:Reason -> + catch throw:Reason0 -> + Reason = + case App of + undefined -> Reason0; + _ -> {App,Reason0} + end, ?LOG_ERROR("Invalid logger handler config: ~p", [Reason]), {error, {bad_config, {handler, Reason}}} end. @@ -672,26 +687,35 @@ setup_handler(Id, Module, Config) -> {error, Reason} -> throw(Reason) end. -check_logger_config(_) -> - ok. - --spec get_logger_type() -> {ok, standard_io | false | silent | - {file, file:name_all()} | - {file, file:name_all(), [file:mode()]}}. -get_logger_type() -> +check_logger_config(_,[]) -> + ok; +check_logger_config(App,[{handler,_,_,_}|Env]) -> + check_logger_config(App,Env); +check_logger_config(kernel,[{handler,default,undefined}|Env]) -> + check_logger_config(kernel,Env); +check_logger_config(kernel,[{filters,_,_}|Env]) -> + check_logger_config(kernel,Env); +check_logger_config(kernel,[{module_level,_,_}|Env]) -> + check_logger_config(kernel,Env); +check_logger_config(_,Bad) -> + throw(Bad). + +-spec get_logger_type(config_logger()) -> + {ok, standard_io | false | silent | + {file, file:name_all()} | + {file, file:name_all(), [file:mode()]}}. +get_logger_type(Env) -> case application:get_env(kernel, error_logger) of {ok, tty} -> {ok, standard_io}; {ok, {file, File}} when is_list(File) -> {ok, {file, File}}; - {ok, {file, File, Modes}} when is_list(File), is_list(Modes) -> - {ok, {file, File, Modes}}; {ok, false} -> {ok, false}; {ok, silent} -> {ok, silent}; undefined -> - case lists:member({handler,default,undefined}, get_logger_env()) of + case lists:member({handler,default,undefined}, Env) of true -> {ok, false}; false -> @@ -709,56 +733,55 @@ get_logger_level() -> throw({logger_level, Level}) end. -get_primary_filter_default() -> - case lists:keyfind(filters,1,get_logger_env()) of +get_primary_filter_default(Env) -> + case lists:keyfind(filters,1,Env) of {filters,Default,_} -> Default; false -> log end. -get_primary_filters() -> - lists:foldl( - fun({filters, _, Filters}, _Acc) -> - Filters; - (_, Acc) -> - Acc - end, [], get_logger_env()). +get_primary_filters(Env) -> + case [F || F={filters,_,_} <- Env] of + [{filters,_,Filters}] -> + case lists:all(fun({_,_}) -> true; (_) -> false end,Filters) of + true -> Filters; + false -> throw({invalid_filters,Filters}) + end; + [] -> []; + _ -> throw({multiple_filters,Env}) + end. %% This function looks at the kernel logger environment %% and updates it so that the correct logger is configured -init_default_config(Type) when Type==standard_io; - Type==standard_error; - element(1,Type)==file -> - Env = get_logger_env(), +init_default_config(Type,Env) when Type==standard_io; + Type==standard_error; + element(1,Type)==file -> DefaultFormatter = #{formatter=>{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}}, DefaultConfig = DefaultFormatter#{config=>#{type=>Type}}, NewLoggerEnv = case lists:keyfind(default, 2, Env) of - {handler, default, Module, Config} -> - lists:map( - fun({handler, default, logger_std_h, _}) -> - %% Only want to add the logger_std_h config - %% if not configured by user AND the default - %% handler is still the logger_std_h. - {handler, default, Module, maps:merge(DefaultConfig,Config)}; - ({handler, default, logger_disk_log_h, _}) -> - %% Add default formatter. The point of this - %% is to get the expected formatter config - %% for the default handler, since this - %% differs from the default values that - %% logger_formatter itself adds. - {handler, default, logger_disk_log_h, maps:merge(DefaultFormatter,Config)}; - (Other) -> - Other - end, Env); + {handler, default, logger_std_h, Config} -> + %% Only want to add the logger_std_h config + %% if not configured by user AND the default + %% handler is still the logger_std_h. + lists:keyreplace(default, 2, Env, + {handler, default, logger_std_h, + maps:merge(DefaultConfig,Config)}); + {handler, default, Module,Config} -> + %% Add default formatter. The point of this + %% is to get the expected formatter config + %% for the default handler, since this + %% differs from the default values that + %% logger_formatter itself adds. + lists:keyreplace(default, 2, Env, + {handler, default, Module, + maps:merge(DefaultFormatter,Config)}); _ -> %% Nothing has been configured, use default [{handler, default, logger_std_h, DefaultConfig} | Env] end, - application:set_env(kernel, logger, NewLoggerEnv, [{timeout,infinity}]); -init_default_config(Type) -> - throw({illegal_logger_type,Type}). + application:set_env(kernel, logger, NewLoggerEnv, [{timeout,infinity}]). get_default_handler_filters() -> case application:get_env(kernel, logger_sasl_compatible, false) of @@ -768,8 +791,8 @@ get_default_handler_filters() -> ?DEFAULT_HANDLER_FILTERS([otp,sasl]) end. -get_logger_env() -> - application:get_env(kernel, logger, []). +get_logger_env(App) -> + application:get_env(App, logger, []). %%%----------------------------------------------------------------- %%% Internal -- cgit v1.2.3 From 625616652595249ff0866d4de8a04f3c8fa0eec4 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 6 Sep 2018 14:30:36 +0200 Subject: [logger] Improve code coverage in test --- lib/kernel/src/logger_server.erl | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 01ac1b4b50..e3827c6475 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -372,7 +372,7 @@ sanity_check(Owner,Key,Value) -> sanity_check(HandlerId,Config) when is_map(Config) -> sanity_check_1(HandlerId,maps:to_list(Config)); sanity_check(_,Config) -> - {error,{invalid_handler_config,Config}}. + {error,{invalid_config,Config}}. sanity_check_1(Owner,Config) when is_list(Config) -> try @@ -417,8 +417,6 @@ check_mod(Mod) when is_atom(Mod) -> check_mod(Mod) -> throw({invalid_module,Mod}). -check_level({LevelInt,cached}) when LevelInt>=?EMERGENCY, LevelInt= - ok; check_level(Level) -> case lists:member(Level,?LEVELS) of true -> -- cgit v1.2.3 From a98ffe831d2a1cf44d0b7c53e2d72ade9d5a3dbb Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 7 Sep 2018 16:49:30 +0200 Subject: [logger] Fix spec for handler callbacks to always return ok --- lib/kernel/src/logger_disk_log_h.erl | 2 +- lib/kernel/src/logger_std_h.erl | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index 3c12c9e68b..26375373aa 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -225,7 +225,7 @@ removing_handler(#{id:=Name}) -> %%%----------------------------------------------------------------- %%% Log a string or report --spec log(LogEvent, Config) -> ok | dropped when +-spec log(LogEvent, Config) -> ok when LogEvent :: logger:log_event(), Config :: logger:handler_config(). diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index b60e7cf587..5dc4bc91ad 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -210,7 +210,7 @@ removing_handler(#{id:=Name}) -> %%%----------------------------------------------------------------- %%% Log a string or report --spec log(LogEvent, Config) -> ok | dropped when +-spec log(LogEvent, Config) -> ok when LogEvent :: logger:log_event(), Config :: logger:handler_config(). -- cgit v1.2.3 From 7140fe7679c1ea0862961d2fc34f9d8283c04ca3 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 11 Sep 2018 14:11:29 +0200 Subject: [logger] Check for deadlock when removing filters If a filter fails, it is removed by a call to logger:remove_filter/1,2. If the log event that caused the failure was issued on the logger process itself, this would earlier cause a deadlock due to a gen_server:call to self(). This is now prevented. --- lib/kernel/src/logger_server.erl | 1 + 1 file changed, 1 insertion(+) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index e3827c6475..a1d40f1123 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -319,6 +319,7 @@ call(Request) -> case get(?LOGGER_SERVER_TAG) of true when Action == add_handler; Action == remove_handler; + Action == add_filter; Action == remove_filter; Action == update_config; Action == set_config -> {error,{attempting_syncronous_call_to_self,Request}}; _ -> -- cgit v1.2.3 From a4ff9f378ae7008e268d1c2facd44d049be6e930 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 12 Sep 2018 14:37:02 +0200 Subject: [logger] Include single_line option to report_cb If the report callback function has two arguments, the second argument is a map with options to limit the size of the log event. To even allow a better formatting when the event shall be printed on a single line, the new option single_line is now included in this argument. --- lib/kernel/src/logger.erl | 3 ++- lib/kernel/src/logger_formatter.erl | 2 +- 2 files changed, 3 insertions(+), 2 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 0ada8b4924..752dd8d493 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -78,7 +78,8 @@ -type report_cb() :: fun((report()) -> {io:format(),[term()]}) | fun((report(),report_cb_config()) -> unicode:chardata()). -type report_cb_config() :: #{depth := pos_integer() | unlimited, - chars_limit := pos_integer() | unlimited}. + chars_limit := pos_integer() | unlimited, + single_line := boolean()}. -type msg_fun() :: fun((term()) -> {io:format(),[term()]} | report() | unicode:chardata()). diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 59aa6ec3af..ded89bac9f 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -165,7 +165,7 @@ format_msg({report,Report},#{report_cb:=Fun}=Meta,Config) when is_function(Fun,1 Meta,Config) end; format_msg({report,Report},#{report_cb:=Fun}=Meta,Config) when is_function(Fun,2) -> - try Fun(Report,maps:with([depth,chars_limit],Config)) of + try Fun(Report,maps:with([depth,chars_limit,single_line],Config)) of Chardata when ?IS_STRING(Chardata) -> try chardata_to_list(Chardata) % already size limited by report_cb catch _:_ -> -- cgit v1.2.3 From 48a1c458a46dcd1f031fd3b9689af80b32b4a6a2 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 11 Sep 2018 11:18:52 +0200 Subject: [error_logger] Handle report_cb with arity 2 --- lib/kernel/src/error_logger.erl | 29 +++++++++++++++++++++-------- 1 file changed, 21 insertions(+), 8 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index ad8c937882..e324be5290 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -147,14 +147,27 @@ do_log(Level,{report,Msg},#{?MODULE:=#{tag:=Tag}}=Meta) -> _ -> %% From logger call which added error_logger data to %% obtain backwards compatibility with error_logger:*_msg/1,2 - RCBFun=maps:get(report_cb,Meta,fun logger:format_report/1), - try RCBFun(Msg) of - {F,A} when is_list(F), is_list(A) -> - {F,A}; - Other -> - {"REPORT_CB ERROR: ~tp; Returned: ~tp",[Msg,Other]} - catch C:R -> - {"REPORT_CB CRASH: ~tp; Reason: ~tp",[Msg,{C,R}]} + case maps:get(report_cb,Meta,fun logger:format_report/1) of + RCBFun when is_function(RCBFun,1) -> + try RCBFun(Msg) of + {F,A} when is_list(F), is_list(A) -> + {F,A}; + Other -> + {"REPORT_CB ERROR: ~tp; Returned: ~tp",[Msg,Other]} + catch C:R -> + {"REPORT_CB CRASH: ~tp; Reason: ~tp",[Msg,{C,R}]} + end; + RCBFun when is_function(RCBFun,2) -> + try RCBFun(Msg,#{depth=>get_format_depth(), + chars_limit=>unlimited, + single_line=>false}) of + Chardata when ?IS_STRING(Chardata) -> + {"~ts",[Chardata]}; + Other -> + {"REPORT_CB ERROR: ~tp; Returned: ~tp",[Msg,Other]} + catch C:R -> + {"REPORT_CB CRASH: ~tp; Reason: ~tp",[Msg,{C,R}]} + end end end, notify(Level,Tag,Format,Args,Meta); -- cgit v1.2.3 From 6073d37a5a0691704d0fa1a5ff9289ba9e35c8ed Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 14 Sep 2018 14:12:13 +0200 Subject: [logger] Read config before terminating handler process When a handler process is terminated due to overload, it reads its configuration from the configuration database, so it can be restarted with the same configuration after a small delay. This was earlier done in a different process, which was spawned off from the terminate function. This caused a race condition, where in some cases, the configuration was already removed before it could be read. The reason for spawning off a process, is to avoid a deadlock due to the call to logger:remove_handler/1. This commit moves the call to logger:get_handler_config/1 back to the handler process - to ensure that the data is still there, but keeps the call to logger:remove_handler/1 in the spawned off process - to avoid deadlock. --- lib/kernel/src/logger_disk_log_h.erl | 3 ++- lib/kernel/src/logger_h_common.erl | 3 ++- lib/kernel/src/logger_std_h.erl | 3 ++- 3 files changed, 6 insertions(+), 3 deletions(-) (limited to 'lib/kernel/src') diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index 26375373aa..a8f141f135 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -426,8 +426,9 @@ terminate(Reason, State = #{id := Name}) -> _ = logger_h_common:cancel_timer(maps:get(rep_sync_tref, State, undefined)), _ = close_disk_log(Name, normal), + ok = logger_h_common:stop_or_restart(Name, Reason, State), unregister(?name_to_reg_name(?MODULE, Name)), - logger_h_common:stop_or_restart(Name, Reason, State). + ok. code_change(_OldVsn, State, _Extra) -> {ok, State}. diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index 2818a460f1..38ac7d8ffc 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -294,6 +294,7 @@ stop_or_restart(Name, {shutdown,Reason={overloaded,_Name,_QLen,_Mem}}, %% and set a restart timer. A separate process must perform this %% in order to avoid deadlock. HandlerPid = self(), + ConfigResult = logger:get_handler_config(Name), RemoveAndRestart = fun() -> MRef = erlang:monitor(process, HandlerPid), @@ -304,7 +305,7 @@ stop_or_restart(Name, {shutdown,Reason={overloaded,_Name,_QLen,_Mem}}, error_notify(Reason), exit(HandlerPid, kill) end, - case logger:get_handler_config(Name) of + case ConfigResult of {ok,#{module:=HMod}=HConfig} when is_integer(RestartAfter) -> _ = logger:remove_handler(Name), _ = timer:apply_after(RestartAfter, logger, add_handler, diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index 5dc4bc91ad..66fa6b6ab6 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -415,8 +415,9 @@ terminate(Reason, State = #{id:=Name, file_ctrl_pid:=FWPid, false -> ok end, + ok = logger_h_common:stop_or_restart(Name, Reason, State), unregister(?name_to_reg_name(?MODULE, Name)), - logger_h_common:stop_or_restart(Name, Reason, State). + ok. code_change(_OldVsn, State, _Extra) -> {ok, State}. -- cgit v1.2.3