From 0cd4f90dc8897f0820c9cdac0ed4db25a54aa1eb Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 18 Jun 2018 14:43:01 +0200 Subject: [logger] Update documentation --- lib/kernel/doc/src/logger_formatter.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml index e777afaf86..a482d02293 100644 --- a/lib/kernel/doc/src/logger_formatter.xml +++ b/lib/kernel/doc/src/logger_formatter.xml @@ -78,7 +78,7 @@ format controls ~p and ~w are replaced with ~P and ~W, respectively, and the value is used as the depth parameter. For details, see - io:format/2,3 + io:format/2,3 in STDLIB.

Defaults to unlimited.

-- cgit v1.2.3 From 308e7677170d56c4270d82af1a37375038da5d72 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 18 Jun 2018 15:26:23 +0200 Subject: [logger] Generate .png file from .dia --- lib/kernel/doc/src/.gitignore | 1 + lib/kernel/doc/src/Makefile | 14 +++++++++++++- lib/kernel/doc/src/logger_arch.dia | Bin 0 -> 2527 bytes lib/kernel/doc/src/logger_arch.png | Bin 32187 -> 117205 bytes lib/kernel/doc/src/logger_chapter.xml | 2 ++ 5 files changed, 16 insertions(+), 1 deletion(-) create mode 100644 lib/kernel/doc/src/.gitignore create mode 100644 lib/kernel/doc/src/logger_arch.dia (limited to 'lib') diff --git a/lib/kernel/doc/src/.gitignore b/lib/kernel/doc/src/.gitignore new file mode 100644 index 0000000000..c2813ac866 --- /dev/null +++ b/lib/kernel/doc/src/.gitignore @@ -0,0 +1 @@ +*.eps \ No newline at end of file diff --git a/lib/kernel/doc/src/Makefile b/lib/kernel/doc/src/Makefile index f34eee71ba..fceba14515 100644 --- a/lib/kernel/doc/src/Makefile +++ b/lib/kernel/doc/src/Makefile @@ -84,6 +84,7 @@ XML_CHAPTER_FILES = \ BOOK_FILES = book.xml +# The .png file is generated from a .dia file with target 'update_png' IMAGE_FILES = \ logger_arch.png @@ -111,6 +112,17 @@ SPECS_FILES = $(XML_REF3_FILES:%.xml=$(SPECDIR)/specs_%.xml) TOP_SPECS_FILE = specs.xml +# ---------------------------------------------------- +# FIGURES +# ---------------------------------------------------- +# In order to update the figures you have to have both dia +# and imagemagick installed. +# The generated .png file must be committed. + +update_png: + dia --export=logger_arch.eps logger_arch.dia + convert logger_arch.eps -resize 65% logger_arch.png + # ---------------------------------------------------- # FLAGS # ---------------------------------------------------- @@ -147,7 +159,7 @@ clean clean_docs: rm -f $(MAN6DIR)/* rm -f $(TOP_PDF_FILE) $(TOP_PDF_FILE:%.pdf=%.fo) rm -f $(SPECDIR)/* - rm -f errs core *~ + rm -f errs core *~ *.eps $(SPECDIR)/specs_erl_prim_loader_stub.xml: $(gen_verbose)escript $(SPECS_EXTRACTOR) $(SPECS_FLAGS) \ diff --git a/lib/kernel/doc/src/logger_arch.dia b/lib/kernel/doc/src/logger_arch.dia new file mode 100644 index 0000000000..97be31856e Binary files /dev/null and b/lib/kernel/doc/src/logger_arch.dia differ diff --git a/lib/kernel/doc/src/logger_arch.png b/lib/kernel/doc/src/logger_arch.png index a3a863c511..70933a5a41 100644 Binary files a/lib/kernel/doc/src/logger_arch.png and b/lib/kernel/doc/src/logger_arch.png differ diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index f4a752bde9..23a289f2ee 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -69,6 +69,8 @@ figure shows two log handlers, but any number of handlers can be installed.

+ Conceptual Overview -- cgit v1.2.3 From 8fed5e01980996cd34be6e27370eed74b5c0ed5d Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 18 Jun 2018 17:37:27 +0200 Subject: [logger] Improve spec for set_handler_config/3 and set_primary_config/2 Specify which keys and associated values are allowed. --- lib/kernel/doc/src/logger.xml | 115 +++++++++++++++++++++++++----------------- lib/kernel/src/logger.erl | 31 +++++++++--- 2 files changed, 95 insertions(+), 51 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index 33f1919de0..b1321a93dc 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -97,46 +97,6 @@ logger:error("error happened because: ~p", [Reason]). % Without macro - - - -

Primary configuration data for Logger. The following - default values apply:

- - level => info - filter_default => log - filters => [] - - - - - - -

Handler configuration data for Logger. The following - default values apply:

- - level => all - filter_default => log - filters => [] - formatter => {logger_formatter, DefaultFormatterConfig} - -

In addition to these, the following fields are - automatically inserted by Logger, values taken from the - two first parameters - to add_handler/3:

- - id => HandlerId - module => Module - -

Handler specific configuration data is inserted by the - handler callback itself, in a sub structure associated with - the field named config.

-

See the - logger_formatter(3) manual page for - information about the default configuration for this - formatter.

- - @@ -171,6 +131,39 @@ logger:error("error happened because: ~p", [Reason]). % Without macro for an example of a formatter implementation.

 + + + +

Handler configuration data for Logger. The following + default values apply:

+ + level => all + filter_default => log + filters => [] + formatter => {logger_formatter, DefaultFormatterConfig} + +

In addition to these, the following fields are + automatically inserted by Logger, values taken from the + two first parameters + to add_handler/3:

+ + id => HandlerId + module => Module + +

These are read-only and cannot be changed in runtime.

+

Handler specific configuration data is inserted by the + handler callback itself, in a sub structure associated with + the field named config. See + the logger_std_h(3) + and logger_disk_log_h + manual pages for information about the specifc configuration + for these handlers.

+

See the + logger_formatter(3) manual page for + information about the default configuration for this + formatter.

+ + @@ -248,6 +241,18 @@ logger:error("error happened because: ~p", [Reason]). % Without macro

+ + + +

Primary configuration data for Logger. The following + default values apply:

+ + level => info + filter_default => log + filters => [] + + + @@ -690,15 +695,30 @@ start(_, []) -> - + + + + + Add or update configuration data for the specified handler. + + + + + + +

Add or update configuration data for the specified handler. If the given Key already exists, its associated value will be changed - to Value. If it does not exist, it will + to the given value. If it does not exist, it will be added.

+

See the definition of + the + handler_config() type for more + information about the different parameters.

 @@ -721,13 +741,18 @@ start(_, []) -> - + + + Add or update primary configuration data for Logger. + + +

Add or update primary configuration data for Logger. If the given Key already exists, its associated - value will be changed to Value. If it - does not exist, it will be added.

+ value will be changed to the given value. If it does not + exist, it will be added.

 diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 0a9b1672ec..c78f5372f0 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -352,9 +352,12 @@ add_handler(HandlerId,Module,Config) -> remove_handler(HandlerId) -> logger_server:remove_handler(HandlerId). --spec set_primary_config(Key,Value) -> ok | {error,term()} when - Key :: atom(), - Value :: term(). +-spec set_primary_config(level,Level) -> ok | {error,term()} when + Level :: level() | all | none; + (filter_default,FilterDefault) -> ok | {error,term()} when + FilterDefault :: log | stop; + (filters,Filters) -> ok | {error,term()} when + Filters :: [{filter_id(),filter()}]. set_primary_config(Key,Value) -> logger_server:set_config(primary,Key,Value). @@ -363,10 +366,26 @@ set_primary_config(Key,Value) -> set_primary_config(Config) -> logger_server:set_config(primary,Config). --spec set_handler_config(HandlerId,Key,Value) -> ok | {error,term()} when +-spec set_handler_config(HandlerId,level,Level) -> Return when HandlerId :: handler_id(), - Key :: atom(), - Value :: term(). + Level :: level() | all | none, + Return :: ok | {error,term()}; + (HandlerId,filter_default,FilterDefault) -> Return when + HandlerId :: handler_id(), + FilterDefault :: log | stop, + Return :: ok | {error,term()}; + (HandlerId,filters,Filters) -> Return when + HandlerId :: handler_id(), + Filters :: [{filter_id(),filter()}], + Return :: ok | {error,term()}; + (HandlerId,formatter,Formatter) -> Return when + HandlerId :: handler_id(), + Formatter :: {module(), formatter_config()}, + Return :: ok | {error,term()}; + (HandlerId,config,Config) -> Return when + HandlerId :: handler_id(), + Config :: term(), + Return :: ok | {error,term()}. set_handler_config(HandlerId,Key,Value) -> logger_server:set_config(HandlerId,Key,Value). -- cgit v1.2.3 From da166b76de977171243dd2ea7f86b98f451fabc5 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 18 Jun 2018 17:53:00 +0200 Subject: [logger] Add ?LOG macro which takes Level as argument --- lib/kernel/doc/src/logger.xml | 9 ++++++--- lib/kernel/include/logger.hrl | 4 ++++ lib/kernel/test/logger_SUITE.erl | 29 +++++++++++++++++++++++++++++ 3 files changed, 39 insertions(+), 3 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index b1321a93dc..8bf62a6b39 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -290,13 +290,16 @@ logger:error("error happened because: ~p", [Reason]). % Without macro ?LOG_INFO(FunOrFormat,Args[,Metadata]) ?LOG_DEBUG(StringOrReport[,Metadata]) ?LOG_DEBUG(FunOrFormat,Args[,Metadata]) + ?LOG(Level,StringOrReport[,Metadata]) + ?LOG(Level,FunOrFormat,Args[,Metadata])

All macros expand to a call to Logger, where Level is - taken from the macro name, and location data is added to the - metadata. See the description of + taken from the macro name, or from the first argument in the + case of the ?LOG macro. Location data is added to the + metadata as described under the metadata() - type for more information about the location data.

+ type definition.

The call is wrapped in a case statement and will be evaluated only if Level is equal to or below the configured log diff --git a/lib/kernel/include/logger.hrl b/lib/kernel/include/logger.hrl index 2143ccd297..b09977e0f2 100644 --- a/lib/kernel/include/logger.hrl +++ b/lib/kernel/include/logger.hrl @@ -32,6 +32,10 @@ -define(LOG_DEBUG(A,B),?DO_LOG(debug,[A,B])). -define(LOG_DEBUG(A,B,C),?DO_LOG(debug,[A,B,C])). +-define(LOG(L,A),?DO_LOG(L,[A])). +-define(LOG(L,A,B),?DO_LOG(L,[A,B])). +-define(LOG(L,A,B,C),?DO_LOG(L,[A,B,C])). + -define(LOCATION,#{mfa=>{?MODULE,?FUNCTION_NAME,?FUNCTION_ARITY}, line=>?LINE, file=>?FILE}). diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index b367b4dd54..bb9a6acdcc 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -355,6 +355,7 @@ log_all_levels_api(cleanup,_Config) -> macros(_Config) -> ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}), test_macros(emergency), + test_log_macro(alert), ok. macros(cleanup,_Config) -> @@ -1009,6 +1010,34 @@ test_macros(emergency=Level) -> [{F2,x},{error,fun_that_crashes}],#{}), ok. +test_log_macro(Level) -> + ?LOG(Level,#{Level=>rep}), + ok = check_logged(Level,#{Level=>rep},?MY_LOC(1)), + ?LOG(Level,#{Level=>rep},#{my=>meta}), + ok = check_logged(Level,#{Level=>rep},(?MY_LOC(1))#{my=>meta}), + ?LOG(Level,"~w: ~w",[Level,fa]), + ok = check_logged(Level,"~w: ~w",[Level,fa],?MY_LOC(1)), + ?LOG(Level,"~w: ~w ~w",[Level,fa,meta],#{my=>meta}), + ok = check_logged(Level,"~w: ~w ~w",[Level,fa,meta],(?MY_LOC(1))#{my=>meta}), + ?LOG(Level,fun(x) -> {"~w: ~w ~w",[Level,fun_to_fa,meta]} end, + x, #{my=>meta}), + ok = check_logged(Level,"~w: ~w ~w",[Level,fun_to_fa,meta], + (?MY_LOC(3))#{my=>meta}), + ?LOG(Level,fun(x) -> #{Level=>fun_to_r,meta=>true} end, x, #{my=>meta}), + ok = check_logged(Level,#{Level=>fun_to_r,meta=>true}, + (?MY_LOC(2))#{my=>meta}), + ?LOG(Level,fun(x) -> <<"fun_to_s">> end,x,#{}), + ok = check_logged(Level,<<"fun_to_s">>,?MY_LOC(1)), + F1=fun(x) -> {fun_to_bad} end, + ?LOG(Level,F1,x,#{}), + ok = check_logged(Level,"LAZY_FUN ERROR: ~tp; Returned: ~tp", + [{F1,x},{fun_to_bad}],#{}), + F2=fun(x) -> erlang:error(fun_that_crashes) end, + ?LOG(Level,F2,x,#{}), + ok = check_logged(Level,"LAZY_FUN CRASH: ~tp; Reason: ~tp", + [{F2,x},{error,fun_that_crashes}],#{}), + ok. + %%%----------------------------------------------------------------- %%% Called by macro ?TRY(X) my_try(Fun) -> -- cgit v1.2.3 From ce8832d3113a78ed60fcbe186d9c177bcebff2ab Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Mon, 18 Jun 2018 13:46:47 +0200 Subject: [logger] Fix problem with test cases waiting for handler restart --- lib/kernel/test/logger_disk_log_h_SUITE.erl | 29 ++++++++++++++++----------- lib/kernel/test/logger_std_h_SUITE.erl | 31 ++++++++++++++++++----------- 2 files changed, 36 insertions(+), 24 deletions(-) (limited to 'lib') diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 7e5b574869..a4b15c841b 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -1551,25 +1551,30 @@ h_proc_name() -> h_proc_name(Name) -> list_to_atom(lists:concat([logger_disk_log_h,"_",Name])). -file_delete(Log) -> - file:delete(Log). - wait_for_process_up(T) -> - wait_for_process_up(h_proc_name(),T). + wait_for_process_up(?MODULE, h_proc_name(), T). -wait_for_process_up(Name,T) -> +wait_for_process_up(Name, RegName, T) -> N = (T div 500) + 1, - wait_for_process_up1(Name,N). + wait_for_process_up1(Name, RegName, N). -wait_for_process_up1(Name,0) -> +wait_for_process_up1(_Name, _RegName, 0) -> error; -wait_for_process_up1(Name,N) -> +wait_for_process_up1(Name, RegName, N) -> timer:sleep(500), - case whereis(Name) of + case whereis(RegName) of Pid when is_pid(Pid) -> - %% ct:pal("Process ~p up (~p tries left)",[Name,N]), - {ok,Pid}; + case logger:get_handler_config(Name) of + {ok,_} -> + %% ct:pal("Process ~p up (~p tries left)",[Name,N]), + {ok,Pid}; + _ -> + wait_for_process_up1(Name, RegName, N-1) + end; undefined -> %% ct:pal("Waiting for process ~p (~p tries left)",[Name,N]), - wait_for_process_up1(Name,N-1) + wait_for_process_up1(Name, RegName, N-1) end. + +file_delete(Log) -> + file:delete(Log). diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index ca54458ac1..0930cd4211 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -1570,27 +1570,29 @@ h_proc_name() -> h_proc_name(Name) -> ?name_to_reg_name(logger_std_h,Name). -file_delete(Log) -> - file:delete(Log). - wait_for_process_up(T) -> - wait_for_process_up(h_proc_name(),T). + wait_for_process_up(?MODULE, h_proc_name(), T). -wait_for_process_up(Name,T) -> +wait_for_process_up(Name, RegName, T) -> N = (T div 500) + 1, - wait_for_process_up1(Name,N). + wait_for_process_up1(Name, RegName, N). -wait_for_process_up1(_Name,0) -> +wait_for_process_up1(_Name, _RegName, 0) -> error; -wait_for_process_up1(Name,N) -> +wait_for_process_up1(Name, RegName, N) -> timer:sleep(500), - case whereis(Name) of + case whereis(RegName) of Pid when is_pid(Pid) -> - %% ct:pal("Process ~p up (~p tries left)",[Name,N]), - {ok,Pid}; + case logger:get_handler_config(Name) of + {ok,_} -> + %% ct:pal("Process ~p up (~p tries left)",[Name,N]), + {ok,Pid}; + _ -> + wait_for_process_up1(Name, RegName, N-1) + end; undefined -> %% ct:pal("Waiting for process ~p (~p tries left)",[Name,N]), - wait_for_process_up1(Name,N-1) + wait_for_process_up1(Name, RegName, N-1) end. filesync_rep_int() -> @@ -1598,3 +1600,8 @@ filesync_rep_int() -> true -> 5500; false -> ?FILESYNC_REPEAT_INTERVAL + 500 end. + + +file_delete(Log) -> + file:delete(Log). + -- cgit v1.2.3 From b98f8afa52a479a6730ba4da175dbd1789029722 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 26 Jun 2018 10:27:52 +0200 Subject: [logger] Remove compiler warnings in test --- lib/kernel/test/logger_SUITE.erl | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) (limited to 'lib') diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index bb9a6acdcc..8f74ebdc47 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -470,7 +470,11 @@ filter_failed(_Config) -> %% Logger filters {error,{invalid_filter,_}} = logger:add_primary_filter(lf,{fun(_) -> ok end,args}), - ok = logger:add_primary_filter(lf,{fun(_,_) -> a=b end,args}), + ok = logger:add_primary_filter(lf, + {fun(_,_) -> + erlang:error({badmatch,b}) + end, + args}), #{filters:=[_]} = logger:get_primary_config(), ok = logger:notice(M1=?map_rep), ok = check_logged(notice,M1,#{}), @@ -488,7 +492,11 @@ filter_failed(_Config) -> {error,{not_found,h0}} = logger:remove_handler_filter(h0,hf), {error,{invalid_filter,_}} = logger:add_handler_filter(h1,hf,{fun(_) -> ok end,args}), - ok = logger:add_handler_filter(h1,hf,{fun(_,_) -> a=b end,args}), + ok = logger:add_handler_filter(h1,hf, + {fun(_,_) -> + erlang:error({badmatch,b}) + end, + args}), {ok,#{filters:=[_]}} = logger:get_handler_config(h1), ok = logger:notice(M3=?map_rep), ok = check_logged(notice,M3,#{}), @@ -524,7 +532,11 @@ handler_failed(_Config) -> false = lists:search(fun(#{id:=h1}) -> true; (_) -> false end,H1), {error,{not_found,h1}} = logger:remove_handler(h1), - ok = logger:add_handler(h2,?MODULE,#{filter_default=>log,log_call=>fun() -> a = b end}), + ok = logger:add_handler(h2,?MODULE, + #{filter_default => log, + log_call => fun() -> + erlang:error({badmatch,b}) + end}), {error,{already_exist,h2}} = logger:add_handler(h2,othermodule,#{}), [add] = test_server:messages_get(), @@ -535,7 +547,7 @@ handler_failed(_Config) -> {error,{not_found,h2}} = logger:remove_handler(h2), CallAddHandler = fun() -> logger:add_handler(h2,?MODULE,#{}) end, - CrashHandler = fun() -> a = b end, + CrashHandler = fun() -> erlang:error({badmatch,b}) end, KillHandler = fun() -> exit(self(), die) end, {error,{handler_not_added,{attempting_syncronous_call_to_self,_}}} = -- cgit v1.2.3 From d4789fa6f6795252f9eecec8c4b7e0ec4c7f86ec Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 26 Jun 2018 16:31:58 +0200 Subject: Add legacy test of sasl_report_file_h and size limiting --- lib/sasl/test/sasl_report_SUITE.erl | 81 ++++++++++++++++++++++++++++++++----- 1 file changed, 70 insertions(+), 11 deletions(-) (limited to 'lib') diff --git a/lib/sasl/test/sasl_report_SUITE.erl b/lib/sasl/test/sasl_report_SUITE.erl index 863b765645..a03932133e 100644 --- a/lib/sasl/test/sasl_report_SUITE.erl +++ b/lib/sasl/test/sasl_report_SUITE.erl @@ -21,6 +21,7 @@ -export([all/0, suite/0,groups/0,init_per_suite/1, end_per_suite/1, init_per_group/2,end_per_group/2]). -export([gen_server_crash/1, gen_server_crash_unicode/1]). +-export([legacy_gen_server_crash/1, legacy_gen_server_crash_unicode/1]). -export([crash_me/0,start_link/0,init/1,handle_cast/2,terminate/2]). @@ -29,7 +30,10 @@ suite() -> [{ct_hooks,[ts_install_cth]}]. all() -> - [gen_server_crash, gen_server_crash_unicode]. + [gen_server_crash, + gen_server_crash_unicode, + legacy_gen_server_crash, + legacy_gen_server_crash_unicode]. groups() -> []. @@ -52,17 +56,77 @@ gen_server_crash(Config) -> gen_server_crash_unicode(Config) -> gen_server_crash(Config, unicode). +legacy_gen_server_crash(Config) -> + legacy_gen_server_crash(Config,latin1). + +legacy_gen_server_crash_unicode(Config) -> + legacy_gen_server_crash(Config,unicode). + gen_server_crash(Config, Encoding) -> + TC = list_to_atom(lists:concat([?FUNCTION_NAME,"_",Encoding])), + PrivDir = filename:join(?config(priv_dir,Config),?MODULE), + ConfigFileName = filename:join(PrivDir,TC), + KernelLog = filename:join(PrivDir,lists:concat([TC,"_kernel.log"])), + SaslLog = filename:join(PrivDir,lists:concat([TC,"_sasl.log"])), + KernelConfig = [{logger,[{handler,default,logger_std_h, + #{config=>#{type=>{file,KernelLog}}}}]}, + {logger_sasl_compatible,true}], + Modes = [write, {encoding, Encoding}], + SaslConfig = [{sasl_error_logger,{file,SaslLog,Modes}}], + ok = filelib:ensure_dir(SaslLog), + + ok = file:write_file(ConfigFileName ++ ".config", + io_lib:format("[{kernel, ~p},~n{sasl, ~p}].", + [KernelConfig,SaslConfig])), + {ok,Node} = + test_server:start_node( + TC, peer, + [{args, ["-pa ",filename:dirname(code:which(?MODULE)), + " -boot start_sasl -kernel start_timer true " + "-config ",ConfigFileName]}]), + + %% Set depth + ok = rpc:call(Node,logger,update_formatter_config,[default,depth,30]), + ok = rpc:call(Node,logger,update_formatter_config,[sasl,depth,30]), + + %% Make sure remote node logs it's own logs, and current node does + %% not log them. + ok = rpc:call(Node,logger,remove_handler_filter,[default,remote_gl]), + ok = rpc:call(Node,logger,remove_handler_filter,[sasl,remote_gl]), + ok = logger:add_primary_filter(no_remote,{fun(#{meta:=#{pid:=Pid}},_) + when node(Pid)=/=node() -> stop; + (_,_) -> ignore + end,[]}), + ct:log("Local node Logger config:~n~p", + [rpc:call(Node,logger,get_config,[])]), + ct:log("Remote node Logger config:~n~p", + [rpc:call(Node,logger,get_config,[])]), + ct:log("Remote node error_logger handlers: ~p", + [rpc:call(Node,error_logger,which_report_handlers,[])]), + + ok = rpc:call(Node,?MODULE,crash_me,[]), + + test_server:stop_node(Node), + ok = logger:remove_primary_filter(no_remote), + + check_file(KernelLog, utf8, 70000, 150000), + check_file(SaslLog, Encoding, 70000, 150000), + + ok = file:delete(KernelLog), + ok = file:delete(SaslLog), + + ok. + +legacy_gen_server_crash(Config, Encoding) -> StopFilter = {fun(_,_) -> stop end, ok}, logger:add_handler_filter(default,stop_all,StopFilter), + logger:add_handler_filter(sasl,stop_all,StopFilter), logger:add_handler_filter(cth_log_redirect,stop_all,StopFilter), try do_gen_server_crash(Config, Encoding) after - ok = application:unset_env(kernel, logger_sasl_compatible), - ok = application:unset_env(sasl, sasl_error_logger), - ok = application:unset_env(kernel, error_logger_format_depth), logger:remove_handler_filter(default,stop_all), + logger:remove_handler_filter(sasl,stop_all), logger:remove_handler_filter(cth_log_redirect,stop_all) end, ok. @@ -74,22 +138,17 @@ do_gen_server_crash(Config, Encoding) -> SaslLog = filename:join(LogDir, "sasl.log"), ok = filelib:ensure_dir(SaslLog), - application:stop(sasl), Modes = [write, {encoding, Encoding}], - ok = application:set_env(kernel, logger_sasl_compatible, true), - ok = application:set_env(sasl, sasl_error_logger, {file,SaslLog,Modes}, - [{persistent,true}]), application:set_env(kernel, error_logger_format_depth, 30), error_logger:logfile({open,KernelLog}), - application:start(sasl), + error_logger:add_report_handler(sasl_report_file_h,{SaslLog,Modes,all}), ct:log("Logger config:~n~p",[logger:get_config()]), ct:log("error_logger handlers: ~p",[error_logger:which_report_handlers()]), crash_me(), - error_logger:logfile(close), - application:stop(sasl), + error_logger:delete_report_handler(sasl_report_file_h), check_file(KernelLog, utf8, 70000, 150000), check_file(SaslLog, Encoding, 70000, 150000), -- cgit v1.2.3 From c606b5659908618a4e54a1ac7af90f8f4e78c2c8 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 28 Jun 2018 14:47:56 +0200 Subject: Don't call report_cb from cth_log_redirect - formatter does that --- lib/common_test/src/cth_log_redirect.erl | 13 ++----------- 1 file changed, 2 insertions(+), 11 deletions(-) (limited to 'lib') diff --git a/lib/common_test/src/cth_log_redirect.erl b/lib/common_test/src/cth_log_redirect.erl index 99c484de48..4980d1ee4b 100644 --- a/lib/common_test/src/cth_log_redirect.erl +++ b/lib/common_test/src/cth_log_redirect.erl @@ -184,21 +184,12 @@ handle_call({log,#{meta:=#{gl:=GL}},_}, _From, {reply, ok, State}; handle_call({log, - #{msg:=Msg0, - meta:=#{?MODULE:=#{category:=Category}}=Meta}=Log, + #{meta:=#{?MODULE:=#{category:=Category}}}=Log, #{formatter:={Formatter,FConfig}}}, _From, #eh_state{log_func=LogFunc}=State) -> Header = format_header(State), - Msg = - case Msg0 of - {report,R} -> - Fun=maps:get(report_cb,Meta,fun logger:format_report/1), - Fun(R); - _ -> - Msg0 - end, - String = Formatter:format(Log#{msg=>Msg},FConfig), + String = Formatter:format(Log,FConfig), case LogFunc of tc_log -> ct_logs:tc_log(Category, ?STD_IMPORTANCE, -- cgit v1.2.3 From 270d909696a753af022df72a404c73f2895b4a02 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 28 Jun 2018 14:52:11 +0200 Subject: [logger] Allow report callback with two arguments returning a string If the report callback is a fun of arity 2, then the second argument is a map with the keys 'encoding', 'depth' and 'chars_limit', and the fun must return a string which is size limited according to the given depth and chars_limit. If the report callback is a fun of arity 1, then it must return a tuple containing a format string and a list of arguments. The formatter will produce the string, and limit it's size. --- lib/kernel/doc/src/logger.xml | 21 +++- lib/kernel/doc/src/logger_chapter.xml | 18 +++- lib/kernel/doc/src/logger_formatter.xml | 13 ++- lib/kernel/src/logger.erl | 27 +++++- lib/kernel/src/logger_formatter.erl | 151 +++++++++++++++++++---------- lib/kernel/test/logger_formatter_SUITE.erl | 44 ++++++--- 6 files changed, 200 insertions(+), 74 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index 8bf62a6b39..f1830a8224 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -227,7 +227,10 @@ logger:error("error happened because: ~p", [Reason]). % Without macro a report(), the report_cb key can be associated with a fun (report callback) that converts the report to a format - string and arguments. See + string and arguments, or directly to a string. See the + type definition + of report_cb(), + and section Log Message in the User's Guide for more information about report callbacks.

@@ -259,6 +262,22 @@ logger:error("error happened because: ~p", [Reason]). % Without macro

+ + + +

A fun which converts a report() + to a format string and arguments, or directly to a string. + See section Log + Message in the User's Guide for more + information.

+ + + + + +

+ + diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index 23a289f2ee..dc68d5c761 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -194,10 +194,26 @@ the log event's metadata. The report callback is a convenience function that the formatter can use - to convert the report to a format string and arguments. The + to convert the report to a format string and arguments, or + directly to a string. The formatter can also use its own conversion function, if no callback is provided, or if a customized formatting is desired.

+

The report callback must be a fun with one or two + arguments. If it takes one argument, this is the report + itself, and the fun returns a format string and arguments:

+ 
fun((logger:report()) -> {io:format(),[term()]})
+

If it takes two arguments, the first is the report, and the + second is a map containing extra data that allows direct + coversion to a string:

+ 
fun((logger:report(),logger:report_cb_config()) -> unicode:chardata())
+
+

The fun must obey the encoding, depth + and chars_limit parameters provided in the second + argument, as the formatter can not do anything useful of these + parameters with the returned string. This variant is used when + the formatting of the report depends on the size and encoding + parameters.

Example, format string and arguments:

logger:error("The file does not exist: ~ts",[Filename])

Example, string:

diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml index a482d02293..9226d19834 100644 --- a/lib/kernel/doc/src/logger_formatter.xml +++ b/lib/kernel/doc/src/logger_formatter.xml @@ -82,6 +82,13 @@ in STDLIB.

Defaults to unlimited.

+ encoding = + unicode:encoding() + +

This parameter must reflect the encoding of the device + that the handler prints to.

+

Defaults to utf8

+ legacy_header = boolean()

If set to true a header field is added to @@ -105,7 +112,8 @@ by chars_limit or depth, it is truncated.

Defaults to unlimited.

 - report_cb = fun((logger:report()) -> {io:format(), [term()]}) + report_cb = + logger:report_cb()

A report callback is used by the formatter to transform log messages on report form to a format string and @@ -119,9 +127,6 @@ both the default report callback, and any report callback found in metadata. That is, all reports are converted by this configured function.

-

The value must be a function with arity 1, - returning {Format,Args}, and it will be called - with a report as only argument.

 single_line = boolean() diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index c78f5372f0..4924c6cb4f 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -74,6 +74,11 @@ -type level() :: emergency | alert | critical | error | warning | notice | info | debug. -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, + chars_limit := pos_integer() | unlimited}. -type msg_fun() :: fun((term()) -> {io:format(),[term()]} | report() | unicode:chardata()). @@ -84,7 +89,7 @@ file => file:filename(), line => non_neg_integer(), domain => [atom()], - report_cb => fun((report()) -> {io:format(),[term()]}), + report_cb => report_cb(), atom() => term()}. -type location() :: #{mfa := {module(),atom(),non_neg_integer()}, file := file:filename(), @@ -110,10 +115,22 @@ -type config_handler() :: {handler, handler_id(), module(), handler_config()}. --export_type([log_event/0,level/0,report/0,msg_fun/0,metadata/0, - primary_config/0,handler_config/0,handler_id/0, - filter_id/0,filter/0,filter_arg/0,filter_return/0, - config_handler/0,formatter_config/0]). +-export_type([log_event/0, + level/0, + report/0, + report_cb/0, + report_cb_config/0, + msg_fun/0, + metadata/0, + primary_config/0, + handler_config/0, + handler_id/0, + filter_id/0, + filter/0, + filter_arg/0, + filter_return/0, + config_handler/0, + formatter_config/0]). %%%----------------------------------------------------------------- %%% API diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 456b0c9e8d..937e7f859b 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -26,16 +26,17 @@ %%%----------------------------------------------------------------- %%% 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 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(), + single_line => boolean(), + template => template(), + time_designator => byte(), + time_offset => integer() | [byte()]}. +-type template() :: [metakey() | {metakey(),template(),template()} | string()]. -type metakey() :: atom() | [atom()]. %%%----------------------------------------------------------------- @@ -119,65 +120,96 @@ value(_,_) -> 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(mfa,MFA,Config) -> + format_mfa(MFA,Config); +to_string(_,Value,Config) -> + to_string(Value,Config). -to_string(X) when is_atom(X) -> +to_string(X,_) when is_atom(X) -> atom_to_list(X); -to_string(X) when is_integer(X) -> +to_string(X,_) when is_integer(X) -> integer_to_list(X); -to_string(X) when is_pid(X) -> +to_string(X,_) when is_pid(X) -> pid_to_list(X); -to_string(X) when is_reference(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 +to_string(X,Config) when is_list(X) -> + case printable_list(lists:flatten(X)) of true -> X; - _ -> io_lib:format("~tp",[X]) + _ -> io_lib:format(p(Config),[X]) end; -to_string(X) -> - io_lib:format("~tp",[X]). +to_string(X,Config) -> + io_lib:format(p(Config),[X]). + +printable_list([]) -> + false; +printable_list(X) -> + io_lib:printable_list(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({s(Config),[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)); 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", + P = p(Config), + format_msg({"REPORT_CB/1 ERROR: "++P++"; Returned: "++P, + [Report,Other]},Meta,Config) + catch C:R:S -> + P = p(Config), + format_msg({"REPORT_CB/1 CRASH: "++P++"; Reason: "++P, + [Report,{C,R,logger:filter_stacktrace(?MODULE,S)}]}, + 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) + catch _:_ -> + P = p(Config), + format_msg({"REPORT_CB/2 ERROR: "++P++"; Returned: "++P, + [Report,String]},Meta,Config) + end; + Other -> + P = p(Config), + format_msg({"REPORT_CB/2 ERROR: "++P++"; Returned: "++P, [Report,Other]},Meta,Config) - catch C:R -> - format_msg({"REPORT_CB CRASH: ~tp; Reason: ~tp", - [Report,{C,R}]},Meta,Config) + catch C:R:S -> + P = p(Config), + format_msg({"REPORT_CB/2 CRASH: "++P++"; Reason: "++P, + [Report,{C,R,logger:filter_stacktrace(?MODULE,S)}]}, + 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) -> +format_msg(Msg,_Meta,#{depth:=Depth,chars_limit:=CharsLimit,encoding:=Enc}) -> + limit_size(Msg, Depth, CharsLimit, Enc). + +limit_size(Msg,Depth,unlimited,Enc) -> + limit_size(Msg,Depth,[],Enc); +limit_size(Msg,Depth,CharsLimit,Enc) when is_integer(CharsLimit) -> + limit_size(Msg,Depth,[{chars_limit,CharsLimit}],Enc); +limit_size({Format,Args},unlimited,Opts,Enc) when is_list(Opts) -> try io_lib:format(Format,Args,Opts) catch _:_ -> - io_lib:format("FORMAT ERROR: ~tp - ~tp",[Format,Args],Opts) + P = p(Enc), + io_lib:format("FORMAT ERROR: "++P++" - "++P,[Format,Args],Opts) end; -limit_size({Format0,Args},Depth,Opts) when is_integer(Depth) -> +limit_size({Format0,Args},Depth,Opts,Enc) 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) + P = p(Enc), + limit_size({"FORMAT ERROR: "++P++" - "++P,[Format0,Args]}, + Depth,Opts,Enc) end. limit_format([#{control_char:=C0}=M0|T], Depth) when C0 =:= $p; @@ -225,22 +257,23 @@ timestamp_to_datetimemicro(SysTime,Config) when is_integer(SysTime) -> end, {Date,Time,Micro,UtcStr}. -format_mfa({M,F,A}) when is_atom(M), is_atom(F), is_integer(A) -> +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). +format_mfa({M,F,A},Config) when is_atom(M), is_atom(F), is_list(A) -> + format_mfa({M,F,length(A)},Config); +format_mfa(MFA,Config) -> + to_string(MFA,Config). 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} = + {{Y,Mo,D},{H,Mi,Sec},Micro,UtcStr} = timestamp_to_datetimemicro(Timestamp,Config), + S = s(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]), + 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]), Meta#{?MODULE=>MyMeta#{header=>Header}}; maybe_add_legacy_header(_,Meta,_) -> Meta. @@ -280,10 +313,11 @@ month(12) -> "Dec". %% configuration map add_default_config(Config0) -> Default = - #{legacy_header=>false, + #{chars_limit=>unlimited, + encoding=>utf8, error_logger_notice_header=>info, + legacy_header=>false, 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)), @@ -369,7 +403,8 @@ do_check_config([{legacy_header,LH}|Config]) when is_boolean(LH) -> 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([{report_cb,RCB}|Config]) when is_function(RCB,1); + is_function(RCB,2) -> do_check_config(Config); do_check_config([{template,T}|Config]) -> case check_template(T) of @@ -456,3 +491,17 @@ check_timezone(Tz) -> catch _:_ -> error end. + +p(#{encoding:=Enc}) -> + p(Enc); +p(latin1) -> + "~p"; +p(_) -> + "~tp". + +s(#{encoding:=Enc}) -> + s(Enc); +s(latin1) -> + "~s"; +s(_) -> + "~ts". diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index 8fe8d5199b..aa8dc42691 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -312,30 +312,48 @@ format_msg(_Config) -> #{report_cb=>fun(_)-> faulty_return end}, #{template=>Template}), ct:log(String5), - "REPORT_CB ERROR: term; Returned: faulty_return" = String5, + "REPORT_CB/1 ERROR: term; Returned: faulty_return" = String5, String6 = format(info,{report,term}, #{report_cb=>fun(_)-> erlang:error(fun_crashed) end}, #{template=>Template}), ct:log(String6), - "REPORT_CB CRASH: term; Reason: {error,fun_crashed}" = String6, + "REPORT_CB/1 CRASH: term; Reason: {error,fun_crashed,"++_ = String6, + + String7 = format(info,{report,term}, + #{report_cb=>fun(_,_)-> ['not',a,string] end}, + #{template=>Template}), + ct:log(String7), + "REPORT_CB/2 ERROR: term; Returned: ['not',a,string]" = String7, + + String8 = format(info,{report,term}, + #{report_cb=>fun(_,_)-> faulty_return end}, + #{template=>Template}), + ct:log(String8), + "REPORT_CB/2 ERROR: term; Returned: faulty_return" = String8, + + String9 = format(info,{report,term}, + #{report_cb=>fun(_,_)-> erlang:error(fun_crashed) end}, + #{template=>Template}), + ct:log(String9), + "REPORT_CB/2 CRASH: term; Reason: {error,fun_crashed,"++_ = String9, %% strings are not formatted - String7 = format(info,{string,"string"}, + String10 = format(info,{string,"string"}, #{report_cb=>fun(_)-> {"formatted",[]} end}, #{template=>Template}), - ct:log(String7), - "string" = String7, + ct:log(String10), + "string" = String10, - String8 = format(info,{string,['not',printable,list]}, + String11 = format(info,{string,['not',printable,list]}, #{report_cb=>fun(_)-> {"formatted",[]} end}, #{template=>Template}), - ct:log("~ts",[String8]), % avoiding ct_log crash - "FORMAT ERROR: \"~ts\" - [['not',printable,list]]" = String8, + ct:log("~ts",[String11]), % avoiding ct_log crash + "FORMAT ERROR: \"~ts\" - [['not',printable,list]]" = String11, - String9 = format(info,{string,"string"},#{},#{template=>Template}), - ct:log(String9), - "string" = String9, + String12 = format(info,{string,"string"},#{},#{template=>Template}), + ct:log(String12), + "string" = String12, ok. @@ -639,8 +657,10 @@ check_config(_Config) -> ?cfgerr({max_size,bad}) = logger_formatter:check_config(#{max_size => bad}), + ok = + logger_formatter:check_config(#{report_cb => fun(_,_) -> "" end}), ?cfgerr({report_cb,F}) = - logger_formatter:check_config(#{report_cb => F=fun(_,_) -> {"",[]} end}), + logger_formatter:check_config(#{report_cb => F=fun(_,_,_) -> {"",[]} end}), ?cfgerr({report_cb,bad}) = logger_formatter:check_config(#{report_cb => bad}), -- cgit v1.2.3 From 9fbe5cc9c770b9cd31e18447dfecc1c73e6f4c5f Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 2 Jul 2018 11:25:32 +0200 Subject: Update proc_lib:report_cb to obey logger formatter's size limiting params --- lib/stdlib/src/proc_lib.erl | 128 ++++++++++++++++++++++---------------------- 1 file changed, 65 insertions(+), 63 deletions(-) (limited to 'lib') diff --git a/lib/stdlib/src/proc_lib.erl b/lib/stdlib/src/proc_lib.erl index 89a840be2d..d07c62500b 100644 --- a/lib/stdlib/src/proc_lib.erl +++ b/lib/stdlib/src/proc_lib.erl @@ -30,7 +30,7 @@ start/3, start/4, start/5, start_link/3, start_link/4, start_link/5, hibernate/3, init_ack/1, init_ack/2, - init_p/3,init_p/5,format/1,format/2,format/3,report_cb/1, + init_p/3,init_p/5,format/1,format/2,format/3,report_cb/2, initial_call/1, translate_initial_call/1, stop/1, stop/3]). @@ -509,7 +509,7 @@ crash_report(Class, Reason, StartF, Stacktrace) -> report=>[my_info(Class, Reason, StartF, Stacktrace), linked_info(self())]}, #{domain=>[otp,sasl], - report_cb=>fun proc_lib:report_cb/1, + report_cb=>fun proc_lib:report_cb/2, logger_formatter=>#{title=>"CRASH REPORT"}, error_logger=>#{tag=>error_report,type=>crash_report}}). @@ -750,14 +750,15 @@ check(Res) -> Res. %%% Format a generated crash info structure. %%% ----------------------------------------------------------- --spec report_cb(CrashReport) -> {Format,Args} when - CrashReport :: #{label=>{proc_lib,crash},report=>[term()]}, - Format :: io:format(), - Args :: [term()]. -report_cb(#{label:={proc_lib,crash}, - report:=CrashReport}) -> - Depth = error_logger:get_format_depth(), - get_format_and_args(CrashReport, utf8, Depth). +-spec report_cb(CrashReport,FormatOpts) -> unicode:chardata() when + CrashReport :: #{label => {proc_lib,crash}, + report => [term()]}, + FormatOpts :: logger:report_cb_config(). +report_cb(#{label:={proc_lib,crash}, report:=CrashReport}, Extra) -> + Default = #{chars_limit => unlimited, + depth => unlimited, + encoding => latin1}, + do_format(CrashReport, maps:merge(Default,Extra)). -spec format(CrashReport) -> string() when CrashReport :: [term()]. @@ -777,66 +778,47 @@ format(CrashReport, Encoding) -> Depth :: unlimited | pos_integer(). format(CrashReport, Encoding, Depth) -> - {F,A} = get_format_and_args(CrashReport, Encoding, Depth), - lists:flatten(io_lib:format(F,A)). + do_format(CrashReport, #{chars_limit => unlimited, + depth => Depth, + encoding => Encoding}). -get_format_and_args([OwnReport,LinkReport], Encoding, Depth) -> - Extra = {Encoding,Depth}, +do_format([OwnReport,LinkReport], Extra) -> MyIndent = " ", - {OwnFormat,OwnArgs} = format_report(OwnReport, MyIndent, Extra, [], []), - {LinkFormat,LinkArgs} = format_link_report(LinkReport, MyIndent, Extra, [], []), - {" crasher:~n"++OwnFormat++" neighbours:~n"++LinkFormat,OwnArgs++LinkArgs}. + OwnFormat = format_report(OwnReport, MyIndent, Extra), + LinkFormat = format_link_report(LinkReport, MyIndent, Extra), + Str = io_lib:format(" crasher:~n~ts neighbours:~n~ts", + [OwnFormat, LinkFormat]), + lists:flatten(Str). -format_link_report([], _Indent, _Extra, Format, Args) -> - {lists:flatten(lists:reverse(Format)),lists:append(lists:reverse(Args))}; -format_link_report([Link|Reps], Indent, Extra, Format, Args) -> +format_link_report([Link|Reps], Indent, Extra) -> Rep = case Link of {neighbour,Rep0} -> Rep0; _ -> Link end, LinkIndent = [" ",Indent], - {LinkFormat,LinkArgs} = format_report(Rep, LinkIndent, Extra, [], []), - F = "~sneighbour:\n"++LinkFormat, - A = [Indent|LinkArgs], - format_link_report(Reps, Indent, Extra, [F|Format], [A|Args]); -format_link_report(Rep, Indent, Extra, Format, Args) -> - {F,A} = format_report(Rep, Indent, Extra, [], []), - format_link_report([], Indent, Extra, [F|Format],[A|Args]). - -format_report([], _Indent, _Extra, Format, Args) -> - {lists:flatten(lists:reverse(Format)),lists:append(lists:reverse(Args))}; -format_report([Rep|Reps], Indent, Extra, Format, Args) -> - {F,A} = format_rep(Rep, Indent, Extra), - format_report(Reps, Indent, Extra, [F|Format], [A|Args]); -format_report(Rep, Indent, {Enc,unlimited}=Extra, Format, Args) -> - {F,A} = {"~s~"++modifier(Enc)++"p~n", [Indent, Rep]}, - format_report([], Indent, Extra, [F|Format], [A|Args]); -format_report(Rep, Indent, {Enc,Depth}=Extra, Format, Args) -> - {F,A} = {"~s~"++modifier(Enc)++"P~n", [Indent, Rep, Depth]}, - format_report([], Indent, Extra, [F|Format], [A|Args]). - -format_rep({initial_call,InitialCall}, Indent, Extra) -> - format_mfa(Indent, InitialCall, Extra); -format_rep({error_info,{Class,Reason,StackTrace}}, _Indent, Extra) -> - {lists:flatten(format_exception(Class, Reason, StackTrace, Extra)),[]}; -format_rep({Tag,Data}, Indent, Extra) -> - format_tag(Indent, Tag, Data, Extra). - -format_mfa(Indent, {M,F,Args}=StartF, {Enc,_}=Extra) -> - try - A = length(Args), - {lists:flatten([Indent,"initial call: ",atom_to_list(M), - $:,to_string(F, Enc),$/,integer_to_list(A),"\n"]),[]} - catch - error:_ -> - format_tag(Indent, initial_call, StartF, Extra) - end. - -format_tag(Indent, Tag, Data, {Enc,Depth}) -> - {P,Tl} = p(Enc, Depth), - {"~s~p: ~80.18" ++ P ++ "\n", [Indent, Tag, Data|Tl]}. + [Indent,"neighbour:\n",format_report(Rep, LinkIndent, Extra)| + format_link_report(Reps, Indent, Extra)]; +format_link_report(Rep, Indent, Extra) -> + format_report(Rep, Indent, Extra). + +format_report(Rep, Indent, Extra) when is_list(Rep) -> + format_rep(Rep, Indent, Extra); +format_report(Rep, Indent, #{encoding:=Enc,depth:=unlimited}) -> + io_lib:format("~s~"++modifier(Enc)++"p~n", [Indent, Rep]); +format_report(Rep, Indent, #{encoding:=Enc,depth:=Depth}) -> + io_lib:format("~s~"++modifier(Enc)++"P~n", [Indent, Rep, Depth]). + +format_rep([{initial_call,InitialCall}|Rep], Indent, Extra) -> + [format_mfa(Indent, InitialCall, Extra)|format_rep(Rep, Indent, Extra)]; +format_rep([{error_info,{Class,Reason,StackTrace}}|Rep], Indent, Extra) -> + [format_exception(Class, Reason, StackTrace, Extra)| + format_rep(Rep, Indent, Extra)]; +format_rep([{Tag,Data}|Rep], Indent, Extra) -> + [format_tag(Indent, Tag, Data, Extra)|format_rep(Rep, Indent, Extra)]; +format_rep(_, _, _Extra) -> + []. -format_exception(Class, Reason, StackTrace, {Enc,_}=Extra) -> +format_exception(Class, Reason, StackTrace, #{encoding:=Enc}=Extra) -> PF = pp_fun(Extra), StackFun = fun(M, _F, _A) -> (M =:= erl_eval) or (M =:= ?MODULE) end, %% EI = " exception: ", @@ -844,17 +826,37 @@ format_exception(Class, Reason, StackTrace, {Enc,_}=Extra) -> [EI, erl_error:format_exception(1+length(EI), Class, Reason, StackTrace, StackFun, PF, Enc), "\n"]. +format_mfa(Indent, {M,F,Args}=StartF, #{encoding:=Enc}=Extra) -> + try + A = length(Args), + [Indent,"initial call: ",atom_to_list(M),$:,to_string(F, Enc),$/, + integer_to_list(A),"\n"] + catch + error:_ -> + format_tag(Indent, initial_call, StartF, Extra) + end. + to_string(A, latin1) -> io_lib:write_atom_as_latin1(A); to_string(A, _) -> io_lib:write_atom(A). -pp_fun({Enc,Depth}) -> +pp_fun(#{encoding:=Enc,depth:=Depth,chars_limit:=Limit}) -> {P,Tl} = p(Enc, Depth), + Opts = if is_integer(Limit) -> [{chars_limit,Limit}]; + true -> [] + end, fun(Term, I) -> - io_lib:format("~." ++ integer_to_list(I) ++ P, [Term|Tl]) + io_lib:format("~." ++ integer_to_list(I) ++ P, [Term|Tl], Opts) end. +format_tag(Indent, Tag, Data, #{encoding:=Enc,depth:=Depth,chars_limit:=Limit}) -> + {P,Tl} = p(Enc, Depth), + Opts = if is_integer(Limit) -> [{chars_limit,Limit}]; + true -> [] + end, + io_lib:format("~s~p: ~80.18" ++ P ++ "\n", [Indent, Tag, Data|Tl], Opts). + p(Encoding, Depth) -> {Letter, Tl} = case Depth of unlimited -> {"p", []}; -- cgit v1.2.3 From 4ae5136ccb68bed0e72e1f45d34d1a8b44594590 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 2 Jul 2018 11:48:09 +0200 Subject: [logger] Fix regexp replacement for unicode strings --- lib/kernel/src/logger_formatter.erl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'lib') diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 937e7f859b..a5c6984bc6 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -77,7 +77,7 @@ format(#{level:=Level,msg:=Msg0,meta:=Meta},Config0) %% Trim leading and trailing whitespaces, and replace %% newlines with ", " re:replace(string:trim(MsgStr0),",?\r?\n\s*",", ", - [{return,list},global]); + [{return,list},global,unicode]); _false -> MsgStr0 end; -- cgit v1.2.3 From 0a4834e59f2aac7b76331410bcee641d375d8ec0 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 6 Jul 2018 15:27:42 +0200 Subject: [kernel] Reduce risk of dead lock when terminating logger_sup --- lib/kernel/src/Makefile | 3 +- lib/kernel/src/error_logger.erl | 15 ++-- lib/kernel/src/kernel.app.src | 2 + lib/kernel/src/logger_disk_log_h.erl | 8 ++- lib/kernel/src/logger_h_common.erl | 13 ---- lib/kernel/src/logger_handler_watcher.erl | 113 ++++++++++++++++++++++++++++++ lib/kernel/src/logger_std_h.erl | 8 ++- lib/kernel/src/logger_sup.erl | 6 +- 8 files changed, 144 insertions(+), 24 deletions(-) create mode 100644 lib/kernel/src/logger_handler_watcher.erl (limited to 'lib') diff --git a/lib/kernel/src/Makefile b/lib/kernel/src/Makefile index c595c25341..57f17defc8 100644 --- a/lib/kernel/src/Makefile +++ b/lib/kernel/src/Makefile @@ -112,7 +112,8 @@ MODULES = \ logger \ logger_backend \ logger_config \ - logger_std_h \ + logger_handler_watcher \ + logger_std_h \ logger_disk_log_h \ logger_h_common \ logger_filters \ diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index a7e7f19167..ad8c937882 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -74,8 +74,8 @@ start() -> type => worker, modules => dynamic}, case supervisor:start_child(logger_sup, ErrorLogger) of - {ok,_} -> - ok; + {ok,Pid} -> + ok = logger_handler_watcher:register_handler(?MODULE,Pid); Error -> Error end; @@ -95,9 +95,14 @@ start_link() -> %%% Stop the event manager -spec stop() -> ok. stop() -> - _ = supervisor:terminate_child(logger_sup,?MODULE), - _ = supervisor:delete_child(logger_sup,?MODULE), - ok. + case whereis(?MODULE) of + undefined -> + ok; + _Pid -> + _ = gen_event:stop(?MODULE,{shutdown,stopped},infinity), + _ = supervisor:delete_child(logger_sup,?MODULE), + ok + end. %%%----------------------------------------------------------------- %%% Callbacks for logger diff --git a/lib/kernel/src/kernel.app.src b/lib/kernel/src/kernel.app.src index 47dd7c03d5..4933eae76f 100644 --- a/lib/kernel/src/kernel.app.src +++ b/lib/kernel/src/kernel.app.src @@ -67,6 +67,7 @@ logger_filters, logger_formatter, logger_h_common, + logger_handler_watcher, logger_server, logger_simple_h, logger_std_h, @@ -129,6 +130,7 @@ kernel_refc, kernel_sup, logger, + logger_handler_watcher, logger_sup, net_kernel, net_sup, diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index 0a72654e11..e56531c3cb 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -488,7 +488,8 @@ start(Name, Config, HandlerState) -> type => worker, modules => [?MODULE]}, case supervisor:start_child(logger_sup, LoggerDLH) of - {ok,_Pid,Config1} -> + {ok,Pid,Config1} -> + ok = logger_handler_watcher:register_handler(Name,Pid), {ok,Config1}; Error -> Error @@ -506,8 +507,11 @@ stop(Name) -> %% system termination in order to avoid circular attempts %% at removing the handler (implying deadlocks and %% timeouts). + %% And we don't need to do supervisor:delete_child, since + %% the restart type is temporary, which means that the + %% child specification is automatically removed from the + %% supervisor when the process dies. _ = gen_server:call(Pid, stop), - _ = supervisor:delete_child(logger_sup, Name), ok end. diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index a40345dddc..854e5479b9 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -309,19 +309,6 @@ stop_or_restart(Name, {shutdown,Reason={overloaded,_Name,_QLen,_Mem}}, end, spawn(RemoveAndRestart), ok; - -stop_or_restart(Name, shutdown, _State) -> - %% Probably terminated by supervisor. Remove the handler to avoid - %% error printouts due to failing handler. - _ = case logger:get_handler_config(Name) of - {ok,_} -> - %% Spawning to avoid deadlock - spawn(logger,remove_handler,[Name]); - _ -> - ok - end, - ok; - stop_or_restart(_Name, _Reason, _State) -> ok. diff --git a/lib/kernel/src/logger_handler_watcher.erl b/lib/kernel/src/logger_handler_watcher.erl new file mode 100644 index 0000000000..b75c74c643 --- /dev/null +++ b/lib/kernel/src/logger_handler_watcher.erl @@ -0,0 +1,113 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 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_handler_watcher). + +-behaviour(gen_server). + +%% API +-export([start_link/0]). +-export([register_handler/2]). + +%% gen_server callbacks +-export([init/1, handle_call/3, handle_cast/2, handle_info/2, terminate/2]). + +-define(SERVER, ?MODULE). + +-record(state, {handlers}). + +%%%=================================================================== +%%% API +%%%=================================================================== + +-spec start_link() -> {ok, Pid :: pid()} | + {error, Error :: {already_started, pid()}} | + {error, Error :: term()} | + ignore. +start_link() -> + gen_server:start_link({local, ?SERVER}, ?MODULE, [], []). + +-spec register_handler(Id::logger:handler_id(),Pid::pid()) -> ok. +register_handler(Id,Pid) -> + gen_server:call(?SERVER,{register,Id,Pid}). + +%%%=================================================================== +%%% gen_server callbacks +%%%=================================================================== + +-spec init(Args :: term()) -> {ok, State :: term()} | + {ok, State :: term(), Timeout :: timeout()} | + {ok, State :: term(), hibernate} | + {stop, Reason :: term()} | + ignore. +init([]) -> + process_flag(trap_exit, true), + {ok, #state{handlers=[]}}. + +-spec handle_call(Request :: term(), From :: {pid(), term()}, State :: term()) -> + {reply, Reply :: term(), NewState :: term()} | + {reply, Reply :: term(), NewState :: term(), Timeout :: timeout()} | + {reply, Reply :: term(), NewState :: term(), hibernate} | + {noreply, NewState :: term()} | + {noreply, NewState :: term(), Timeout :: timeout()} | + {noreply, NewState :: term(), hibernate} | + {stop, Reason :: term(), Reply :: term(), NewState :: term()} | + {stop, Reason :: term(), NewState :: term()}. +handle_call({register,Id,Pid}, _From, #state{handlers=Hs}=State) -> + Ref = erlang:monitor(process,Pid), + Hs1 = lists:keystore(Id,1,Hs,{Id,Ref}), + {reply, ok, State#state{handlers=Hs1}}. + +-spec handle_cast(Request :: term(), State :: term()) -> + {noreply, NewState :: term()} | + {noreply, NewState :: term(), Timeout :: timeout()} | + {noreply, NewState :: term(), hibernate} | + {stop, Reason :: term(), NewState :: term()}. +handle_cast(_Request, State) -> + {noreply, State}. + +-spec handle_info(Info :: timeout() | term(), State :: term()) -> + {noreply, NewState :: term()} | + {noreply, NewState :: term(), Timeout :: timeout()} | + {noreply, NewState :: term(), hibernate} | + {stop, Reason :: normal | term(), NewState :: term()}. +handle_info({'DOWN',Ref,process,_,shutdown}, #state{handlers=Hs}=State) -> + case lists:keytake(Ref,2,Hs) of + {value,{Id,Ref},Hs1} -> + %% Probably terminated by supervisor. Remove the handler to avoid + %% error printouts due to failing handler. + _ = case logger:get_handler_config(Id) of + {ok,_} -> + logger:remove_handler(Id); + _ -> + ok + end, + {noreply,State#state{handlers=Hs1}}; + false -> + {noreply, State} + end; +handle_info({'DOWN',Ref,process,_,_OtherReason}, #state{handlers=Hs}=State) -> + {noreply,State#state{handlers=lists:keydelete(Ref,2,Hs)}}; +handle_info(_Other,State) -> + {noreply,State}. + +-spec terminate(Reason :: normal | shutdown | {shutdown, term()} | term(), + State :: term()) -> any(). +terminate(_Reason, _State) -> + ok. diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index 480fafd6d8..9a2a1443b3 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -467,7 +467,8 @@ start(Name, Config, HandlerState) -> type => worker, modules => [?MODULE]}, case supervisor:start_child(logger_sup, LoggerStdH) of - {ok,_Pid,Config1} -> + {ok,Pid,Config1} -> + ok = logger_handler_watcher:register_handler(Name,Pid), {ok,Config1}; Error -> Error @@ -485,8 +486,11 @@ stop(Name) -> %% system termination in order to avoid circular attempts %% at removing the handler (implying deadlocks and %% timeouts). + %% And we don't need to do supervisor:delete_child, since + %% the restart type is temporary, which means that the + %% child specification is automatically removed from the + %% supervisor when the process dies. _ = gen_server:call(Pid, stop), - _ = supervisor:delete_child(logger_sup, Name), ok end. diff --git a/lib/kernel/src/logger_sup.erl b/lib/kernel/src/logger_sup.erl index dcdcdad0bd..3d6f482e20 100644 --- a/lib/kernel/src/logger_sup.erl +++ b/lib/kernel/src/logger_sup.erl @@ -46,7 +46,11 @@ init([]) -> intensity => 1, period => 5}, - {ok, {SupFlags, []}}. + Watcher = #{id => logger_handler_watcher, + start => {logger_handler_watcher, start_link, []}, + shutdown => brutal_kill}, + + {ok, {SupFlags, [Watcher]}}. %%%=================================================================== %%% Internal functions -- cgit v1.2.3 From 48824be3d833b13a35b92652df372c6ce3c190a0 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 11 Jul 2018 16:13:13 +0200 Subject: [logger] Allow setting kernel parameter 'logger_level' to 'all' --- lib/kernel/src/logger.erl | 2 +- lib/kernel/test/logger_env_var_SUITE.erl | 19 +++++++++++++++++++ 2 files changed, 20 insertions(+), 1 deletion(-) (limited to 'lib') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 4924c6cb4f..ffc90f4fc5 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -687,7 +687,7 @@ get_logger_type() -> get_logger_level() -> case application:get_env(kernel,logger_level,info) of - Level when ?IS_LEVEL(Level) -> + Level when ?IS_LEVEL(Level); Level=:=all; Level=:=none -> Level; Level -> throw({logger_level, Level}) diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl index 04a4364947..e8d1a313dc 100644 --- a/lib/kernel/test/logger_env_var_SUITE.erl +++ b/lib/kernel/test/logger_env_var_SUITE.erl @@ -71,6 +71,7 @@ all() -> sasl_compatible_false, sasl_compatible_false_no_progress, sasl_compatible, + all_logger_level, {group,bad}, {group,error_logger}, {group,logger} @@ -572,6 +573,24 @@ sasl_compatible(Config) -> 0),% progress in std logger ok. +all_logger_level(Config) -> + [all_logger_level(Config,Level) || Level <- [none, + emergency, + alert, + critical, + error, + warning, + notice, + info, + debug, + all]], + ok. + +all_logger_level(Config,Level) -> + {ok,#{primary:=#{level:=Level}},Node} = setup(Config,[{logger_level,Level}]), + true = test_server:stop_node(Node), + ok. + bad_error_logger(Config) -> error = setup(Config,[{error_logger,baddest}]). -- cgit v1.2.3