diff options
author | Lukas Larsson <[email protected]> | 2018-05-08 16:13:50 +0200 |
---|---|---|
committer | Lukas Larsson <[email protected]> | 2018-05-21 17:43:52 +0200 |
commit | 395dbad6bcc38c3384840674f40657273b05b14a (patch) | |
tree | 931ec833578d1f46dc5b642dadd17e613d1d3785 /lib/kernel/test | |
parent | 5ec78bc5314f5b32ba28bae4d95f12ffa28469ca (diff) | |
download | otp-395dbad6bcc38c3384840674f40657273b05b14a.tar.gz otp-395dbad6bcc38c3384840674f40657273b05b14a.tar.bz2 otp-395dbad6bcc38c3384840674f40657273b05b14a.zip |
logger: Rework configuration of logger
Most logger configuration that was possible through
kernel application variables have been moved into a
common 'logger' application environment in kernel.
Now all the configuration possible through the logger
API can be done as sys config.
The handler started by kernel has been renamed to 'default'
instead of logger_std_h.
There is a new logger:setup_handlers/1 function that given an
application name can be used to setup handlers in other applications.
Diffstat (limited to 'lib/kernel/test')
-rw-r--r-- | lib/kernel/test/Makefile | 1 | ||||
-rw-r--r-- | lib/kernel/test/logger_SUITE.erl | 12 | ||||
-rw-r--r-- | lib/kernel/test/logger_disk_log_h_SUITE.erl | 28 | ||||
-rw-r--r-- | lib/kernel/test/logger_env_var_SUITE.erl | 790 | ||||
-rw-r--r-- | lib/kernel/test/logger_formatter_SUITE.erl | 4 | ||||
-rw-r--r-- | lib/kernel/test/logger_simple_SUITE.erl | 203 | ||||
-rw-r--r-- | lib/kernel/test/logger_std_h_SUITE.erl | 59 | ||||
-rw-r--r-- | lib/kernel/test/logger_test_lib.erl | 82 |
8 files changed, 695 insertions, 484 deletions
diff --git a/lib/kernel/test/Makefile b/lib/kernel/test/Makefile index 8599a3d814..2f637ca9de 100644 --- a/lib/kernel/test/Makefile +++ b/lib/kernel/test/Makefile @@ -79,6 +79,7 @@ MODULES= \ logger_legacy_SUITE \ logger_simple_SUITE \ logger_std_h_SUITE \ + logger_test_lib \ os_SUITE \ pg2_SUITE \ seq_trace_SUITE \ diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index f311a9c7ed..8a757f0078 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -40,18 +40,18 @@ suite() -> [{timetrap,{seconds,30}}]. init_per_suite(Config) -> - case logger:get_handler_config(logger_std_h) of + case logger:get_handler_config(?STANDARD_HANDLER) of {ok,StdH} -> - ok = logger:remove_handler(logger_std_h), - [{logger_std_h,StdH}|Config]; + ok = logger:remove_handler(?STANDARD_HANDLER), + [{default_handler,StdH}|Config]; _ -> Config end. end_per_suite(Config) -> - case ?config(logger_std_h,Config) of + case ?config(default_handler,Config) of {HMod,HConfig} -> - ok = logger:add_handler(logger_std_h,HMod,HConfig); + ok = logger:add_handler(?STANDARD_HANDLER,HMod,HConfig); _ -> ok end. @@ -434,7 +434,7 @@ handler_failed(_Config) -> logger:add_handler(h1,?MODULE,#{filter_default=>true}), {error,{invalid_formatter,[]}} = logger:add_handler(h1,?MODULE,#{formatter=>[]}), - ok = logger:add_handler(h1,nomodule,#{filter_default=>log}), + {error,{invalid_handler,_}} = logger:add_handler(h1,nomodule,#{filter_default=>log}), logger:info(?map_rep), check_no_log(), #{logger:=#{handlers:=Ids1}, diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 7c33c9130c..cdd1e68947 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -31,7 +31,8 @@ end). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> timer:start(), % to avoid progress report @@ -725,7 +726,7 @@ write_failure(Config) -> Log = lists:concat([File,".1"]), ct:pal("Log = ~p", [Log]), - Node = start_h_on_new_node(Config, ?FUNCTION_NAME, File), + Node = start_h_on_new_node(Config, File), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -769,7 +770,7 @@ sync_failure(Config) -> File = filename:join(Dir, FileName), - Node = start_h_on_new_node(Config, ?FUNCTION_NAME, File), + Node = start_h_on_new_node(Config, File), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -809,21 +810,12 @@ sync_failure(cleanup, _Config) -> Nodes = nodes(), [test_server:stop_node(Node) || Node <- Nodes]. -start_h_on_new_node(_Config, Func, File) -> - Pa = filename:dirname(code:which(?MODULE)), - Dest = - case os:type() of - {win32,_} -> - lists:concat([" {disk_log,\\\"",File,"\\\"}"]); - _ -> - lists:concat([" \'{disk_log,\"",File,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",logger_dest,Dest," -pa ",Pa]), - NodeName = lists:concat([?MODULE,"_",Func]), - ct:pal("Starting ~s with ~tp", [NodeName,Args]), - {ok,Node} = test_server:start_node(NodeName, peer, [{args, Args}]), - Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]), - true = is_pid(Pid), +start_h_on_new_node(Config, File) -> + {ok,_,Node} = + logger_test_lib:setup( + Config, + [{logger,[{handler,default,logger_disk_log_h, + #{ disk_log_opts => #{ file => File }}}]}]), ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter, {?MODULE,nl}]), Node. diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl index c2d3364701..e976a10b21 100644 --- a/lib/kernel/test/logger_env_var_SUITE.erl +++ b/lib/kernel/test/logger_env_var_SUITE.erl @@ -1,4 +1,4 @@ -% +%% %% %CopyrightBegin% %% %% Copyright Ericsson AB 2018. All Rights Reserved. @@ -21,83 +21,64 @@ -compile(export_all). --include_lib("common_test/include/ct.hrl"). -include_lib("kernel/include/logger.hrl"). -include_lib("kernel/src/logger_internal.hrl"). --define(all_vars,[{kernel,logger_dest}, - {kernel,logger_level}, - {kernel,logger_log_progress}, - {kernel,logger_sasl_compatible}, - {kernel,error_logger}]). +-import(logger_test_lib,[setup/2,log/3,sync_and_read/3]). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,60}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> - Env = [{App,Key,application:get_env(App,Key)} || {App,Key} <- ?all_vars], - Removed = cleanup(), - [{env,Env},{logger,Removed}|Config]. - -end_per_suite(Config) -> - [application:set_env(App,Key,Val) || - {App,Key,Val} <- ?config(env,Config), - Val =/= undefined], - Hs = ?config(logger,Config), - [ok = logger:add_handler(Id,Mod,C) || {Id,Mod,C} <- Hs], - ok. - -init_per_group(_Group, Config) -> - Config. - -end_per_group(_Group, _Config) -> - ok. - -init_per_testcase(_TestCase, Config) -> Config. -end_per_testcase(Case, Config) -> - try apply(?MODULE,Case,[cleanup,Config]) - catch error:undef -> ok - end, - cleanup(), +end_per_suite(_Config) -> ok. groups() -> - []. - -all() -> + [{error_logger,[],[error_logger_tty, + error_logger_tty_sasl_compatible, + error_logger_false, + error_logger_false_progress, + error_logger_false_sasl_compatible, + error_logger_silent, + error_logger_silent_sasl_compatible, + error_logger_file]}, + {logger,[],[logger_file, + logger_file_sasl_compatible, + logger_file_log_progress, + logger_file_no_filter, + logger_file_no_filter_level, + logger_file_formatter, + logger_filters, + logger_filters_stop, + logger_module_level, + logger_disk_log, + logger_disk_log_formatter, + logger_undefined, + logger_many_handlers_default_first, + logger_many_handlers_default_last + ]}, + {bad,[],[bad_error_logger, + bad_level, + bad_sasl_compatibility, + bad_progress]}]. + +all() -> [default, default_sasl_compatible, - dest_tty, - dest_tty_sasl_compatible, - dest_false, - dest_false_progress, - dest_false_sasl_compatible, - dest_silent, - dest_silent_sasl_compatible, - dest_file_old, - dest_file, - dest_disk_log, - %% disk_log_vars, % or test this in logger_disk_log_SUITE? sasl_compatible_false, sasl_compatible_false_no_progress, sasl_compatible, - bad_dest%% , - %% bad_level, - %% bad_sasl_compatibility, - %% bad_progress + {group,bad}, + {group,error_logger}, + {group,logger} ]. default(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - undefined, - undefined, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), + {ok,#{handlers:=Hs},_Node} = setup(Config,[]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = @@ -105,18 +86,12 @@ default(Config) -> true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), - false = is_pid(whereis(sasl_h)), ok. default_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - undefined, - undefined, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{logger_sasl_compatible,true}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = @@ -124,18 +99,11 @@ default_sasl_compatible(Config) -> false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_tty(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - tty, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), +error_logger_tty(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config,[{error_logger,tty}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = @@ -143,18 +111,13 @@ dest_tty(Config) -> true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), - false = is_pid(whereis(sasl_h)), ok. -dest_tty_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - tty, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), +error_logger_tty_sasl_compatible(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,tty}, + {logger_sasl_compatible,true}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = @@ -162,19 +125,17 @@ dest_tty_sasl_compatible(Config) -> false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_false(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), @@ -182,16 +143,16 @@ dest_false(Config) -> false = lists:keymember(sasl_h,1,Hs), ok. -dest_false_progress(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - undefined, % sasl comp (default=false) - true), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false_progress(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}, + {logger_log_progress,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), @@ -199,253 +160,472 @@ dest_false_progress(Config) -> false = lists:keymember(sasl_h,1,Hs), ok. -dest_false_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false_sasl_compatible(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}, + {logger_sasl_compatible,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = lists:keyfind(domain,1,SimpleFilters), false = lists:keymember(stop_progress,1,SimpleFilters), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_silent(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - silent, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_silent(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,silent}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. + +error_logger_silent_sasl_compatible(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,silent}, + {logger_sasl_compatible,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + false = lists:keymember(logger_simple,1,Hs), + true = lists:keymember(sasl_h,1,Hs), + ok. + + +error_logger_file(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + ok. + + +logger_file(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), + ok. -dest_silent_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - silent, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +logger_file_sasl_compatible(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger_sasl_compatible,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), + + ok. + +logger_file_log_progress(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. +logger_file_no_filter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filter_default=>log,filters=>[], + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), -dest_file_old(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - error_logger, - file, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - file, % dest - 0), % progress in std logger ok. - - -dest_file(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - file, % dest - 0), % progress in std logger + +logger_file_no_filter_level(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[],level=>error, + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0,% progress in std logger + error),% level + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + error = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. - - -dest_disk_log(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - disk_log, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - disk_log, % dest - 0), % progress in std logger + +logger_file_formatter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_single_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_filters(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,logger:=Logger},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}, + {filters,log,[{stop_progress,{fun logger_filters:progress/2,stop}}]} + ]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + LoggerFilters = maps:get(filters,Logger), + true = lists:keymember(stop_progress,1,LoggerFilters), + + ok. + +logger_filters_stop(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,logger:=Logger},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[], + logger_std_h=>#{type=>{file,Log}}}}, + {filters,stop,[{log_error,{fun logger_filters:level/2,{log,gt,info}}}]} + ]}]), + check_default_log(Node,Log, + file,% dest + 0, + notice),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + LoggerFilters = maps:get(filters,Logger), + true = lists:keymember(log_error,1,LoggerFilters), + + ok. + +logger_module_level(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,module_levels:=ModuleLevels},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}, + {module_level,error,[supervisor]} + ]}]), + check_default_log(Node,Log, + file,% dest + 3),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + [{supervisor,error}] = ModuleLevels, + ok. + +logger_disk_log(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_disk_log_h, + #{disk_log_opts=>#{file=>Log}}}]}]), + check_default_log(Node,Log, + disk_log,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_disk_log_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + true = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_disk_log_formatter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_disk_log_h, + #{filters=>[], + formatter=>{logger_formatter,#{}}, + disk_log_opts=>#{file=>Log}}}]}]), + check_single_log(Node,Log, + disk_log,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_disk_log_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_undefined(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config,[{logger,[{handler,?STANDARD_HANDLER,undefined}]}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), + info = maps:get(level,SimpleC), + info = maps:get(level,L), + SimpleFilters = maps:get(filters,SimpleC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,SimpleFilters), + true = lists:keymember(stop_progress,1,SimpleFilters), + false = lists:keymember(sasl_h,1,Hs), + ok. + +logger_many_handlers_default_first(Config) -> + LogErr = file(Config,logger_many_handlers_default_first_error), + LogInfo = file(Config,logger_many_handlers_default_first_info), + + logger_many_handlers( + Config,[{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{level=>error, + filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,LogErr}}} + }, + {handler,info,logger_std_h, + #{level=>info, + filters=>[{level,{fun logger_filters:level/2,{stop,gteq,error}}}], + logger_std_h=>#{type=>{file,LogInfo}}} + } + ]}], LogErr, LogInfo, 6). + +%% Test that we can add multiple handlers with the default last +logger_many_handlers_default_last(Config) -> + LogErr = file(Config,logger_many_handlers_default_last_error), + LogInfo = file(Config,logger_many_handlers_default_last_info), + logger_many_handlers( + Config,[{logger, + [{handler,info,logger_std_h, + #{level=>info, + filters=>[{level,{fun logger_filters:level/2,{stop,gteq,error}}}], + logger_std_h=>#{type=>{file,LogInfo}}} + }, + {handler,?STANDARD_HANDLER,logger_std_h, + #{level=>error, + filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,LogErr}}} + } + ]}], LogErr, LogInfo, 7). + +logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) -> + {ok,#{handlers:=Hs},Node} = setup(Config,Env), + check_single_log(Node,LogErr, + file,% dest + 0,% progress in std logger + error), % level + ok = rpc:call(Node,logger_std_h,filesync,[info]), + {ok, Bin} = file:read_file(LogInfo), + ct:log("Log content:~n~s",[Bin]), + match(Bin,<<"PROGRESS REPORT">>,NumProgress,info,info), + match(Bin,<<"ALERT REPORT">>,0,alert,info), + ok. - sasl_compatible_false(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - false, % sasl comp - true), % progress - check_log(Log, - file, % dest - 4), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {logger_sasl_compatible,false}, + {logger_log_progress,true}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger ok. sasl_compatible_false_no_progress(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - false, % sasl comp - false), % progress - check_log(Log, - file, % dest - 0), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {logger_sasl_compatible,false}, + {logger_log_progress,false}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger ok. sasl_compatible(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - true, % sasl comp - undefined), % progress - check_log(Log, - file, % dest - 0), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {sasl_compatible,true}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger ok. -bad_dest(Config) -> - {error,{bad_config,{kernel,{logger_dest,baddest}}}} = - setup(Config,?FUNCTION_NAME, - logger_dest, - baddest, - undefined, - undefined, - undefined). +bad_error_logger(Config) -> + error = setup(Config,[{error_logger,baddest}]). bad_level(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - badlevel, - undefined, - undefined). + error = setup(Config,[{logger_level,badlevel}]). bad_sasl_compatibility(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - info, - badcomp, - undefined). + error = setup(Config,[{logger_sasl_compatible,badcomp}]). bad_progress(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - info, - undefined, - badprogress). + error = setup(Config,[{logger_log_progress,badprogress}]). %%%----------------------------------------------------------------- %%% Internal -setup(Config,Func,DestVar,Dest,Level,SaslComp,Progress) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - Dir = ?config(priv_dir,Config), - File = lists:concat([?MODULE,"_",Func,".log"]), - Log = filename:join(Dir,File), - case Dest of - undefined -> - ok; - F when F==file; F==disk_log -> - application:set_env(kernel,DestVar,{Dest,Log}); - _ -> - application:set_env(kernel,DestVar,Dest) - end, - case Level of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_level,Level) - end, - case SaslComp of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_sasl_compatible,SaslComp) - end, - case Progress of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_log_progress,Progress) - end, - case logger:setup_standard_handler() of - ok -> - application:start(sasl), - StdH = case Dest of - NoH when NoH==false; NoH==silent -> false; - _ -> true - end, - StdH = is_pid(whereis(?STANDARD_HANDLER)), - SaslH = if SaslComp -> true; - true -> false - end, - SaslH = is_pid(whereis(sasl_h)), - {ok,{Log,maps:get(handlers,logger:i())}}; - Error -> - Error - end. +file(Config,Func) -> + filename:join(proplists:get_value(priv_dir,Config), + lists:concat([Func,".log"])). -check_log(Log,Dest,NumProgress) -> - ok = logger:alert("dummy1"), - ok = logger:debug("dummy1"), +check_default_log(Node,Log,Dest,NumProgress) -> + check_default_log(Node,Log,Dest,NumProgress,info). +check_default_log(Node,Log,Dest,NumProgress,Level) -> + + {ok,Bin1,Bin2} = check_log(Node,Log,Dest), + + match(Bin1,<<"PROGRESS REPORT">>,NumProgress,info,Level), + match(Bin1,<<"ALERT REPORT">>,1,alert,Level), + match(Bin1,<<"INFO REPORT">>,0,info,Level), + match(Bin1,<<"DEBUG REPORT">>,0,debug,Level), + + match(Bin2,<<"INFO REPORT">>,1,info,Level), + match(Bin2,<<"DEBUG REPORT">>,0,debug,Level), + ok. + +check_single_log(Node,Log,Dest,NumProgress) -> + check_single_log(Node,Log,Dest,NumProgress,info). +check_single_log(Node,Log,Dest,NumProgress,Level) -> + + {ok,Bin1,Bin2} = check_log(Node,Log,Dest), + + match(Bin1,<<"info:">>,NumProgress,info,Level), + match(Bin1,<<"alert:">>,1,alert,Level), + match(Bin1,<<"debug:">>,0,debug,Level), + + match(Bin2,<<"info:">>,NumProgress+1,info,Level), + match(Bin2,<<"debug:">>,0,debug,Level), + + ok. + +check_log(Node,Log,Dest) -> + + ok = log(Node,alert,["dummy1"]), + ok = log(Node,debug,["dummy1"]), %% Check that there are progress reports (supervisor and %% application_controller) and an error report (the call above) in %% the log. There should not be any info reports yet. - {ok,Bin1} = sync_and_read(Dest,Log), + {ok,Bin1} = sync_and_read(Node,Dest,Log), ct:log("Log content:~n~s",[Bin1]), - match(Bin1,<<"PROGRESS REPORT">>,NumProgress), - match(Bin1,<<"ALERT REPORT">>,1), - match(Bin1,<<"INFO REPORT">>,0), - match(Bin1,<<"DEBUG REPORT">>,0), %% Then stop sasl and see that the info report from %% application_controller is there - ok = application:stop(sasl), - {ok,Bin2} = sync_and_read(Dest,Log), + ok = rpc:call(Node,application,stop,[sasl]), + {ok,Bin2} = sync_and_read(Node,Dest,Log), ct:log("Log content:~n~s",[Bin2]), - match(Bin2,<<"INFO REPORT">>,1), - match(Bin1,<<"DEBUG REPORT">>,0), - ok. + {ok,Bin1,Bin2}. -match(Bin,Pattern,0) -> +match(Bin,Pattern,0,_,_) -> nomatch = re:run(Bin,Pattern,[{capture,none}]); -match(Bin,Pattern,N) -> - {match,M} = re:run(Bin,Pattern,[{capture,all},global]), - N = length(M). - -sync_and_read(disk_log,Log) -> - logger_disk_log_h:disk_log_sync(?STANDARD_HANDLER), - file:read_file(Log ++ ".1"); -sync_and_read(file,Log) -> - logger_std_h:filesync(?STANDARD_HANDLER), - file:read_file(Log). - -cleanup() -> - application:stop(sasl), - [application:unset_env(App,Key) || {App,Key} <- ?all_vars], - #{handlers:=Hs0} = logger:i(), - Hs = lists:keydelete(cth_log_redirect,1,Hs0), - [ok = logger:remove_handler(Id) || {Id,_,_} <- Hs], - Hs. +match(Bin,Pattern,N,LogLevel,ConfLevel) -> + case logger:compare_levels(LogLevel,ConfLevel) of + lt -> match(Bin,Pattern,0,LogLevel,ConfLevel); + _ -> + {match,M} = re:run(Bin,Pattern,[{capture,all},global]), + N = length(M) + end. diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index 7d1f33746d..c80e5694cf 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -341,7 +341,7 @@ depth(_Config) -> {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, #{}, #{template=>Template}), - application:set_env(kernel,logger_format_depth,12), + application:set_env(kernel,error_logger_format_depth,12), "[1,2,3,4,5,6,7,8,9,0,1|...]" = format(info, {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, @@ -361,7 +361,7 @@ depth(_Config) -> depth=>unlimited}), ok. depth(cleanup,_Config) -> - application:unset_env(kernel,logger_format_depth), + application:unset_env(kernel,error_logger_format_depth), ok. chars_limit(_Config) -> diff --git a/lib/kernel/test/logger_simple_SUITE.erl b/lib/kernel/test/logger_simple_SUITE.erl index 5d8d32492d..0d505b14f5 100644 --- a/lib/kernel/test/logger_simple_SUITE.erl +++ b/lib/kernel/test/logger_simple_SUITE.erl @@ -25,6 +25,8 @@ -include_lib("kernel/include/logger.hrl"). -include_lib("kernel/src/logger_internal.hrl"). +-import(logger_test_lib, [setup/2, log/3, sync_and_read/3]). + -define(check_no_log,[] = test_server:messages_get()). -define(check(Expected), receive {log,Expected} -> @@ -42,15 +44,15 @@ -define(keyval_rep,[{function,?FUNCTION_NAME}, {line,?LINE}]). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks, [logger_test_lib]}]. init_per_suite(Config) -> #{handlers:=Hs0} = logger:i(), Hs = lists:keydelete(cth_log_redirect,1,Hs0), [ok = logger:remove_handler(Id) || {Id,_,_} <- Hs], Env = [{App,Key,application:get_env(App,Key)} || - {App,Key} <- [{kernel,logger_dest}, - {kernel,logger_level}]], + {App,Key} <- [{kernel,logger_level}]], [{env,Env},{logger,Hs}|Config]. end_per_suite(Config) -> @@ -79,7 +81,7 @@ groups() -> all() -> [start_stop, - get_buffer, + replace_default, replace_file, replace_disk_log ]. @@ -100,99 +102,46 @@ start_stop(_Config) -> start_stop(cleanup,_Config) -> logger:remove_handler(logger_simple). -get_buffer(_Config) -> - %% Start simple without buffer - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log}), - logger:emergency(?str), - logger:alert(?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - {ok,[]} = logger_simple:get_buffer(), % no buffer - ok = logger:remove_handler(logger_simple), +%% This testcase just tests that it does not crash, the default handler prints +%% to stdout which we cannot read from in a detached slave. +replace_default(Config) -> - %% Start with buffer - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(M3=?map_rep), - logger:info(M4=?keyval_rep), - logger:info(M41=?keyval_rep++[not_key_val]), - error_logger:error_report(some_type,M5=?map_rep), - error_logger:warning_report("some_type",M6=?map_rep), - logger:critical(M7=?str,[A7=?keyval_rep]), - logger:notice(M8=["fake",string,"line:",?LINE]), - {ok,Buffered1} = logger_simple:get_buffer(), - [#{level:=emergency,msg:={string,M1}}, - #{level:=alert,msg:={M2,[]}}, - #{level:=error,msg:={report,M3}}, - #{level:=info,msg:={report,M4}}, - #{level:=info,msg:={report,M41}}, - #{level:=error,msg:={report,#{label:={error_logger,error_report}, - report:=M5}}}, - #{level:=warning,msg:={report,#{label:={error_logger,warning_report}, - report:=M6}}}, - #{level:=critical,msg:={M7,[A7]}}, - #{level:=notice,msg:={string,M8}}] = Buffered1, - - %% Keep logging - should not buffer any more - logger:emergency(?str), - logger:alert(?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - {ok,[]} = logger_simple:get_buffer(), - ok = logger:remove_handler(logger_simple), + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + rpc:call(Node, error_logger, error_report, [some_type,M5=?map_rep]), + rpc:call(Node, error_logger, warning_report, ["some_type",M6=?map_rep]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + Env = rpc:call(Node, application, get_env, [kernel, logger, []]), + ok = rpc:call(Node, logger, add_handlers, [Env]), - %% Fill buffer and drop - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M9=?str), - M10=?str, - [logger:info(M10) || _ <- lists:seq(1,8)], - logger:error(M11=?str), - logger:error(?str), - logger:error(?str), - {ok,Buffered3} = logger_simple:get_buffer(), - 11 = length(Buffered3), - [#{level:=emergency,msg:={string,M9}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=error,msg:={string,M11}}, - #{level:=info,msg:={"Simple handler buffer full, dropped ~w messages",[2]}}] - = Buffered3, ok. -get_buffer(cleanup,_Config) -> - logger:remove_handler(logger_simple). replace_file(Config) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - undefined = whereis(?STANDARD_HANDLER), - PrivDir = ?config(priv_dir,Config), - File = filename:join(PrivDir,atom_to_list(?FUNCTION_NAME)++".log"), - - application:set_env(kernel,logger_dest,{file,File}), - application:set_env(kernel,logger_level,info), - - ok = logger:setup_standard_handler(), - true = is_pid(whereis(?STANDARD_HANDLER)), - ok = logger_std_h:filesync(?STANDARD_HANDLER), - {ok,Bin} = file:read_file(File), - Lines = [unicode:characters_to_list(L) || + + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + File = filename:join(proplists:get_value(priv_dir,Config), + atom_to_list(?FUNCTION_NAME)++".log"), + + ok = rpc:call(Node, logger, add_handlers, + [[{handler, default, logger_std_h, + #{ logger_std_h => #{ type => {file, File} }}}]]), + + {ok,Bin} = sync_and_read(Node, file, File), + Lines = [unicode:characters_to_list(L) || L <- binary:split(Bin,<<"\n">>,[global,trim])], ["=EMERGENCY REPORT===="++_, M1, @@ -203,32 +152,38 @@ replace_file(Config) -> _, "=INFO REPORT===="++_, _, - _] = Lines, + _, + "=INFO REPORT===="++_, + _, + _, + _, + "=CRITICAL REPORT===="++_, + _, + _, + "=NOTICE REPORT===="++_, + _ + ] = Lines, ok. -replace_file(cleanup,_Config) -> - logger:remove_handler(?STANDARD_HANDLER), - logger:remove_handler(logger_simple). - + replace_disk_log(Config) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - undefined = whereis(?STANDARD_HANDLER), - PrivDir = ?config(priv_dir,Config), - File = filename:join(PrivDir,atom_to_list(?FUNCTION_NAME)), - - application:set_env(kernel,logger_dest,{disk_log,File}), - application:set_env(kernel,logger_level,info), - - ok = logger:setup_standard_handler(), - true = is_pid(whereis(?STANDARD_HANDLER)), - ok = logger_disk_log_h:disk_log_sync(?STANDARD_HANDLER), - {ok,Bin} = file:read_file(File++".1"), - Lines = [unicode:characters_to_list(L) || + + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + File = filename:join(proplists:get_value(priv_dir,Config), + atom_to_list(?FUNCTION_NAME)++".log"), + + ok = rpc:call(Node, logger, add_handlers, + [[{handler, default, logger_disk_log_h, + #{ disk_log_opts => #{ file => File }}}]]), + {ok,Bin} = sync_and_read(Node, disk_log, File), + Lines = [unicode:characters_to_list(L) || L <- binary:split(Bin,<<"\n">>,[global,trim])], ["=EMERGENCY REPORT===="++_, M1, @@ -239,9 +194,15 @@ replace_disk_log(Config) -> _, "=INFO REPORT===="++_, _, - _|_] = Lines, % the tail might be an info report about opening the disk log + _, + "=INFO REPORT===="++_, + _, + _, + _, + "=CRITICAL REPORT===="++_, + _, + _, + "=NOTICE REPORT===="++_, + _ + ] = Lines, ok. -replace_disk_log(cleanup,_Config) -> - logger:remove_handler(?STANDARD_HANDLER), - logger:remove_handler(logger_simple). - diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 34c3167960..83bc96620f 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -50,11 +50,12 @@ end). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> timer:start(), % to avoid progress report - {ok,{?STANDARD_HANDLER,#{formatter:=OrigFormatter}}} = + {ok,{logger_std_h,#{formatter:=OrigFormatter}}} = logger:get_handler_config(?STANDARD_HANDLER), [{formatter,OrigFormatter}|Config]. @@ -322,29 +323,32 @@ config_fail(cleanup,_Config) -> logger:remove_handler(?MODULE). crash_std_h_to_file(Config) -> - crash_std_h(Config,?FUNCTION_NAME,logger_dest,file). + Dir = ?config(priv_dir,Config), + Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])), + crash_std_h(Config,?FUNCTION_NAME, + [{handler,default,logger_std_h, + #{ logger_std_h => #{ type => {file, Log} }}}], + file, Log). crash_std_h_to_file(cleanup,_Config) -> crash_std_h(cleanup). crash_std_h_to_disk_log(Config) -> - crash_std_h(Config,?FUNCTION_NAME,logger_dest,disk_log). + Dir = ?config(priv_dir,Config), + Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])), + crash_std_h(Config,?FUNCTION_NAME, + [{handler,default,logger_disk_log_h, + #{ disk_log_opts => #{ file => Log }}}], + disk_log,Log). crash_std_h_to_disk_log(cleanup,_Config) -> crash_std_h(cleanup). -crash_std_h(Config,Func,Var,Type) -> +crash_std_h(Config,Func,Var,Type,Log) -> Dir = ?config(priv_dir,Config), - File = lists:concat([?MODULE,"_",Func,".log"]), - Log = filename:join(Dir,File), + SysConfig = filename:join(Dir,lists:concat([?MODULE,"_",Func,".config"])), + ok = file:write_file(SysConfig, io_lib:format("[{kernel,[{logger,~p}]}].",[Var])), Pa = filename:dirname(code:which(?MODULE)), - TypeAndLog = - case os:type() of - {win32,_} -> - lists:concat([" {",Type,",\\\"",Log,"\\\"}"]); - _ -> - lists:concat([" \'{",Type,",\"",Log,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",Var,TypeAndLog," -pa ",Pa]), Name = lists:concat([?MODULE,"_",Func]), + Args = lists:concat([" -config ",filename:rootname(SysConfig)," -pa ",Pa]), ct:pal("Starting ~p with ~tp", [Name,Args]), %% Start a node which prints kernel logs to the destination specified by Type {ok,Node} = test_server:start_node(Name, peer, [{args, Args}]), @@ -585,7 +589,7 @@ write_failure(Config) -> Dir = ?config(priv_dir, Config), File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]), Log = filename:join(Dir, File), - Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log), + Node = start_std_h_on_new_node(Config, Log), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -622,7 +626,7 @@ sync_failure(Config) -> Dir = ?config(priv_dir, Config), File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]), Log = filename:join(Dir, File), - Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log), + Node = start_std_h_on_new_node(Config, Log), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -658,21 +662,12 @@ sync_failure(cleanup, _Config) -> Nodes = nodes(), [test_server:stop_node(Node) || Node <- Nodes]. -start_std_h_on_new_node(_Config, Func, Log) -> - Pa = filename:dirname(code:which(?MODULE)), - Dest = - case os:type() of - {win32,_} -> - lists:concat([" {file,\\\"",Log,"\\\"}"]); - _ -> - lists:concat([" \'{file,\"",Log,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",logger_dest,Dest," -pa ",Pa]), - Name = lists:concat([?MODULE,"_",Func]), - ct:pal("Starting ~s with ~tp", [Name,Args]), - {ok,Node} = test_server:start_node(Name, peer, [{args, Args}]), - Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]), - true = is_pid(Pid), +start_std_h_on_new_node(Config, Log) -> + {ok,_,Node} = + logger_test_lib:setup( + Config, + [{logger,[{handler,default,logger_std_h, + #{ logger_std_h => #{ type => {file,Log}}}}]}]), ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter, {?MODULE,nl}]), Node. diff --git a/lib/kernel/test/logger_test_lib.erl b/lib/kernel/test/logger_test_lib.erl new file mode 100644 index 0000000000..4ac05e6480 --- /dev/null +++ b/lib/kernel/test/logger_test_lib.erl @@ -0,0 +1,82 @@ +% +%% %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_test_lib). + +-include_lib("kernel/src/logger_internal.hrl"). + +-export([setup/2, log/3, sync_and_read/3]). + +-export([init/2, + pre_init_per_suite/3, pre_init_per_testcase/4, + post_end_per_testcase/5, post_end_per_suite/3]). + +setup(Config,Vars) -> + FuncStr = lists:concat([proplists:get_value(suite, Config), "_", + proplists:get_value(tc, Config)]), + ConfigFileName = filename:join(proplists:get_value(priv_dir, Config), FuncStr), + file:write_file(ConfigFileName ++ ".config", io_lib:format("[{kernel, ~p}].",[Vars])), + case test_server:start_node(proplists:get_value(tc, Config), slave, + [{args, ["-pa ",filename:dirname(code:which(?MODULE)), + " -boot start_sasl -kernel start_timer true " + "-config ",ConfigFileName]}]) of + {ok, Node} -> + L = rpc:call(Node, logger, i, []), + ct:log("~p",[L]), + {ok, L, Node}; + {error, Reason} -> + ct:log("Failed to start node: ~p",[Reason]), + error + end. + +log(Node, F, A) -> + log(Node, logger, F, A). +log(Node, M, F, A) -> + MD = #{ gl => rpc:call(Node, erlang, whereis, [logger]) }, + rpc:call(Node, M, F, A ++ [MD]). + +sync_and_read(Node,disk_log,Log) -> + rpc:call(Node,logger_disk_log_h,disk_log_sync,[?STANDARD_HANDLER]), + file:read_file(Log ++ ".1"); +sync_and_read(Node, file,Log) -> + ok = rpc:call(Node,logger_std_h,filesync,[?STANDARD_HANDLER]), + file:read_file(Log). + + +init(_, _) -> + {ok, []}. + +pre_init_per_suite(_Suite, Config, State) -> + {[{nodes, nodes()} | Config], State}. + +pre_init_per_testcase(Suite, TC, Config, State) -> + cleanup(Config), + {[{suite, Suite}, {tc, TC} | Config], State}. + +post_end_per_testcase(_, _TC, Config, Res, State) -> + cleanup(Config), + {Res, State}. + +post_end_per_suite(_, Config, State) -> + cleanup(Config), + {Config, State}. + +cleanup(Config) -> + [test_server:stop_node(N) || N <- nodes(), + not lists:member(N, proplists:get_value(nodes, Config))]. |