%% %% %CopyrightBegin% %% %% Copyright Ericsson AB 2017-2018. All Rights Reserved. %% %% Licensed under the Apache License, Version 2.0 (the "License"); %% you may not use this file except in compliance with the License. %% You may obtain a copy of the License at %% %% http://www.apache.org/licenses/LICENSE-2.0 %% %% Unless required by applicable law or agreed to in writing, software %% distributed under the License is distributed on an "AS IS" BASIS, %% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. %% See the License for the specific language governing permissions and %% limitations under the License. %% %% %CopyrightEnd% %% -module(logger_formatter). -export([format/2]). -export([check_config/1]). -include("logger_internal.hrl"). %%%----------------------------------------------------------------- %%% Types -type config() :: #{chars_limit=>pos_integer()| unlimited, depth=>pos_integer() | unlimited, legacy_header=>boolean(), max_size=>pos_integer() | unlimited, report_cb=>fun((logger:report()) -> {io:format(),[term()]}), single_line=>boolean(), template=>template(), time_designator=>byte(), time_offset=>integer()|[byte()]}. -type template() :: [metakey()|{metakey(),template(),template()}|string()]. -type metakey() :: atom() | [atom()]. %%%----------------------------------------------------------------- %%% API -spec format(LogEvent,Config) -> unicode:chardata() when LogEvent :: logger:log_event(), Config :: config(). format(#{level:=Level,msg:=Msg0,meta:=Meta},Config0) when is_map(Config0) -> Config = add_default_config(Config0), Meta1 = maybe_add_legacy_header(Level,Meta,Config), Template = maps:get(template,Config), {BT,AT0} = lists:splitwith(fun(msg) -> false; (_) -> true end, Template), {DoMsg,AT} = case AT0 of [msg|Rest] -> {true,Rest}; _ ->{false,AT0} end, B = do_format(Level,Meta1,BT,Config), A = do_format(Level,Meta1,AT,Config), MsgStr = if DoMsg -> Config1 = case maps:get(chars_limit,Config) of unlimited -> Config; Size0 -> Size = case Size0 - string:length([B,A]) of S when S>=0 -> S; _ -> 0 end, Config#{chars_limit=>Size} end, MsgStr0 = format_msg(Msg0,Meta1,Config1), case maps:get(single_line,Config) of true -> %% Trim leading and trailing whitespaces, and replace %% newlines with ", " re:replace(string:trim(MsgStr0),",?\r?\n\s*",", ", [{return,list},global]); _false -> MsgStr0 end; true -> "" end, 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)]; do_format(Level,Data,[{Key,IfExist,Else}|Format],Config) -> String = case value(Key,Data) of {ok,Value} -> do_format(Level,Data#{Key=>Value},IfExist,Config); error -> do_format(Level,Data,Else,Config) end, [String|do_format(Level,Data,Format,Config)]; do_format(Level,Data,[Key|Format],Config) when is_atom(Key) orelse (is_list(Key) andalso is_atom(hd(Key))) -> String = case value(Key,Data) of {ok,Value} -> to_string(Key,Value,Config); error -> "" end, [String|do_format(Level,Data,Format,Config)]; do_format(Level,Data,[Str|Format],Config) -> [Str|do_format(Level,Data,Format,Config)]; do_format(_Level,_Data,[],_Config) -> []. value(Key,Meta) when is_map_key(Key,Meta) -> {ok,maps:get(Key,Meta)}; value([Key|Keys],Meta) when is_map_key(Key,Meta) -> value(Keys,maps:get(Key,Meta)); value([],Value) -> {ok,Value}; value(_,_) -> error. to_string(time,Time,Config) -> format_time(Time,Config); to_string(mfa,MFA,_Config) -> format_mfa(MFA); to_string(_,Value,_Config) -> to_string(Value). to_string(X) when is_atom(X) -> atom_to_list(X); to_string(X) when is_integer(X) -> integer_to_list(X); to_string(X) when is_pid(X) -> pid_to_list(X); to_string(X) when is_reference(X) -> ref_to_list(X); to_string(X) when is_list(X) -> case io_lib:printable_unicode_list(lists:flatten(X)) of true -> X; _ -> io_lib:format("~tp",[X]) end; to_string(X) -> io_lib:format("~tp",[X]). format_msg({string,Chardata},Meta,Config) -> format_msg({"~ts",[Chardata]},Meta,Config); format_msg({report,_}=Msg,Meta,#{report_cb:=Fun}=Config) when is_function(Fun,1) -> format_msg(Msg,Meta#{report_cb=>Fun},maps:remove(report_cb,Config)); format_msg({report,Report},#{report_cb:=Fun}=Meta,Config) when is_function(Fun,1) -> try Fun(Report) of {Format,Args} when is_list(Format), is_list(Args) -> format_msg({Format,Args},maps:remove(report_cb,Meta),Config); Other -> format_msg({"REPORT_CB ERROR: ~tp; Returned: ~tp", [Report,Other]},Meta,Config) catch C:R -> format_msg({"REPORT_CB CRASH: ~tp; Reason: ~tp", [Report,{C,R}]},Meta,Config) end; format_msg({report,Report},Meta,Config) -> format_msg({report,Report}, Meta#{report_cb=>fun logger:format_report/1}, Config); format_msg(Msg,_Meta,#{depth:=Depth,chars_limit:=CharsLimit}) -> limit_size(Msg, Depth, CharsLimit). limit_size(Msg,Depth,unlimited) -> limit_size(Msg,Depth,[]); limit_size(Msg,Depth,CharsLimit) when is_integer(CharsLimit) -> limit_size(Msg,Depth,[{chars_limit,CharsLimit}]); limit_size({Format,Args},unlimited,Opts) when is_list(Opts) -> try io_lib:format(Format,Args,Opts) catch _:_ -> io_lib:format("FORMAT ERROR: ~tp - ~tp",[Format,Args],Opts) end; limit_size({Format0,Args},Depth,Opts) when is_integer(Depth) -> try Format1 = io_lib:scan_format(Format0, Args), Format = limit_format(Format1, Depth), io_lib:build_text(Format,Opts) catch _:_ -> limit_size({"FORMAT ERROR: ~tp - ~tp",[Format0,Args]},Depth,Opts) end. limit_format([#{control_char:=C0}=M0|T], Depth) when C0 =:= $p; C0 =:= $w -> C = C0 - ($a - $A), %To uppercase. #{args:=Args} = M0, M = M0#{control_char:=C,args:=Args++[Depth]}, [M|limit_format(T, Depth)]; limit_format([H|T], Depth) -> [H|limit_format(T, Depth)]; limit_format([], _) -> []. truncate(String,unlimited) -> String; truncate(String,Size) -> Length = string:length(String), if Length>Size -> case lists:reverse(lists:flatten(String)) of [$\n|_] -> string:slice(String,0,Size-4)++"...\n"; _ -> string:slice(String,0,Size-3)++"..." end; true -> String end. %% SysTime is the system time in microseconds format_time(SysTime,#{time_offset:=Offset,time_designator:=Des}) when is_integer(SysTime) -> calendar:system_time_to_rfc3339(SysTime,[{unit,microsecond}, {offset,Offset}, {time_designator,Des}]). %% SysTime is the system time in microseconds timestamp_to_datetimemicro(SysTime,Config) when is_integer(SysTime) -> Micro = SysTime rem 1000000, Sec = SysTime div 1000000, UniversalTime = erlang:posixtime_to_universaltime(Sec), {{Date,Time},UtcStr} = case offset_to_utc(maps:get(time_offset,Config)) of true -> {UniversalTime,"UTC "}; _ -> {erlang:universaltime_to_localtime(UniversalTime),""} end, {Date,Time,Micro,UtcStr}. format_mfa({M,F,A}) when is_atom(M), is_atom(F), is_integer(A) -> atom_to_list(M)++":"++atom_to_list(F)++"/"++integer_to_list(A); format_mfa({M,F,A}) when is_atom(M), is_atom(F), is_list(A) -> format_mfa({M,F,length(A)}); format_mfa(MFA) -> to_string(MFA). 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,S},Micro,UtcStr} = timestamp_to_datetimemicro(Timestamp,Config), Header = 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. add_legacy_title(_Level,#{?MODULE:=#{title:=_}=MyMeta},_) -> MyMeta; add_legacy_title(Level,Meta,Config) -> case maps:get(?MODULE,Meta,#{}) of #{title:=_}=MyMeta -> MyMeta; MyMeta -> TitleLevel = case (Level=:=notice andalso maps:find(error_logger,Meta)) of {ok,_} -> maps:get(error_logger_notice_header,Config); _ -> Level end, Title = string:uppercase(atom_to_list(TitleLevel)) ++ " REPORT", MyMeta#{title=>Title} end. month(1) -> "Jan"; month(2) -> "Feb"; month(3) -> "Mar"; month(4) -> "Apr"; month(5) -> "May"; month(6) -> "Jun"; month(7) -> "Jul"; month(8) -> "Aug"; month(9) -> "Sep"; month(10) -> "Oct"; month(11) -> "Nov"; month(12) -> "Dec". %% Ensure that all valid configuration parameters exist in the final %% configuration map add_default_config(Config0) -> Default = #{legacy_header=>false, error_logger_notice_header=>info, single_line=>true, chars_limit=>unlimited, time_designator=>$T}, MaxSize = get_max_size(maps:get(max_size,Config0,undefined)), Depth = get_depth(maps:get(depth,Config0,undefined)), Offset = get_offset(maps:get(time_offset,Config0,undefined)), add_default_template(maps:merge(Default,Config0#{max_size=>MaxSize, depth=>Depth, time_offset=>Offset})). add_default_template(#{template:=_}=Config) -> Config; add_default_template(Config) -> Config#{template=>default_template(Config)}. default_template(#{legacy_header:=true}) -> ?DEFAULT_FORMAT_TEMPLATE_HEADER; default_template(#{single_line:=true}) -> ?DEFAULT_FORMAT_TEMPLATE_SINGLE; default_template(_) -> ?DEFAULT_FORMAT_TEMPLATE. get_max_size(undefined) -> unlimited; get_max_size(S) -> max(10,S). get_depth(undefined) -> error_logger:get_format_depth(); get_depth(S) -> max(5,S). get_offset(undefined) -> utc_to_offset(get_utc_config()); get_offset(Offset) -> Offset. utc_to_offset(true) -> "Z"; utc_to_offset(false) -> "". get_utc_config() -> %% SASL utc_log overrides stdlib config - in order to have uniform %% timestamps in log messages case application:get_env(sasl, utc_log) of {ok, Val} when is_boolean(Val) -> Val; _ -> case application:get_env(stdlib, utc_log) of {ok, Val} when is_boolean(Val) -> Val; _ -> false end end. offset_to_utc(Z) when Z=:=0; Z=:="z"; Z=:="Z" -> true; offset_to_utc([$+|Tz]) -> case io_lib:fread("~d:~d", Tz) of {ok, [0, 0], []} -> true; _ -> false end; offset_to_utc(_) -> false. -spec check_config(Config) -> ok | {error,term()} when Config :: config(). check_config(Config) when is_map(Config) -> do_check_config(maps:to_list(Config)); check_config(Config) -> {error,{invalid_formatter_config,?MODULE,Config}}. do_check_config([{Type,L}|Config]) when Type == chars_limit; Type == depth; Type == max_size -> case check_limit(L) of ok -> do_check_config(Config); error -> {error,{invalid_formatter_config,?MODULE,{Type,L}}} end; do_check_config([{single_line,SL}|Config]) when is_boolean(SL) -> do_check_config(Config); do_check_config([{legacy_header,LH}|Config]) when is_boolean(LH) -> do_check_config(Config); do_check_config([{error_logger_notice_header,ELNH}|Config]) when ELNH == info; ELNH == notice -> do_check_config(Config); do_check_config([{report_cb,RCB}|Config]) when is_function(RCB,1) -> do_check_config(Config); do_check_config([{template,T}|Config]) -> case check_template(T) of ok -> do_check_config(Config); error -> {error,{invalid_formatter_template,?MODULE,T}} end; do_check_config([{time_offset,Offset}|Config]) -> case check_offset(Offset) of ok -> do_check_config(Config); error -> {error,{invalid_formatter_config,?MODULE,{time_offset,Offset}}} end; do_check_config([{time_designator,Char}|Config]) when Char>=0, Char=<255 -> case io_lib:printable_latin1_list([Char]) of true -> do_check_config(Config); false -> {error,{invalid_formatter_config,?MODULE,{time_designator,Char}}} end; do_check_config([C|_]) -> {error,{invalid_formatter_config,?MODULE,C}}; do_check_config([]) -> ok. check_limit(L) when is_integer(L), L>0 -> ok; check_limit(unlimited) -> ok; check_limit(_) -> error. check_template([Key|T]) when is_atom(Key) -> check_template(T); check_template([Key|T]) when is_list(Key), is_atom(hd(Key)) -> case lists:all(fun(X) when is_atom(X) -> true; (_) -> false end, Key) of true -> check_template(T); false -> error end; check_template([{Key,IfExist,Else}|T]) when is_atom(Key) orelse (is_list(Key) andalso is_atom(hd(Key))) -> case check_template(IfExist) of ok -> case check_template(Else) of ok -> check_template(T); error -> error end; error -> error end; check_template([Str|T]) when is_list(Str) -> case io_lib:printable_unicode_list(Str) of true -> check_template(T); false -> error end; check_template([]) -> ok; check_template(_) -> error. check_offset(I) when is_integer(I) -> ok; check_offset(Tz) when Tz=:=""; Tz=:="Z"; Tz=:="z" -> ok; check_offset([Sign|Tz]) when Sign=:=$+; Sign=:=$- -> check_timezone(Tz); check_offset(_) -> error. check_timezone(Tz) -> try io_lib:fread("~d:~d", Tz) of {ok, [_, _], []} -> ok; _ -> error catch _:_ -> error end.