aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel/test/logger_SUITE.erl
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel/test/logger_SUITE.erl')
-rw-r--r--lib/kernel/test/logger_SUITE.erl1330
1 files changed, 1330 insertions, 0 deletions
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
new file mode 100644
index 0000000000..d831d0d108
--- /dev/null
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -0,0 +1,1330 @@
+%%
+%% %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_SUITE).
+
+-compile(export_all).
+
+-include_lib("common_test/include/ct.hrl").
+-include_lib("kernel/include/logger.hrl").
+-include_lib("kernel/src/logger_internal.hrl").
+
+-define(str,"Log from "++atom_to_list(?FUNCTION_NAME)++
+ ":"++integer_to_list(?LINE)).
+-define(map_rep,#{function=>?FUNCTION_NAME, line=>?LINE}).
+-define(keyval_rep,[{function,?FUNCTION_NAME}, {line,?LINE}]).
+
+-define(MY_LOC(N),#{mfa=>{?MODULE,?FUNCTION_NAME,?FUNCTION_ARITY},
+ file=>?FILE, line=>?LINE-N}).
+
+-define(TRY(X), my_try(fun() -> X end)).
+
+
+suite() ->
+ [{timetrap,{seconds,30}},
+ {ct_hooks,[logger_test_lib]}].
+
+init_per_suite(Config) ->
+ case logger:get_handler_config(?STANDARD_HANDLER) of
+ {ok,StdH} ->
+ ok = logger:remove_handler(?STANDARD_HANDLER),
+ [{default_handler,StdH}|Config];
+ _ ->
+ Config
+ end.
+
+end_per_suite(Config) ->
+ case ?config(default_handler,Config) of
+ #{module:=HMod} = HConfig ->
+ ok = logger:add_handler(?STANDARD_HANDLER,HMod,HConfig);
+ _ ->
+ ok
+ end.
+
+init_per_group(_Group, Config) ->
+ Config.
+
+end_per_group(_Group, _Config) ->
+ ok.
+
+init_per_testcase(_TestCase, Config) ->
+ PC = logger:get_primary_config(),
+ [{logger_config,PC}|Config].
+
+end_per_testcase(Case, Config) ->
+ try apply(?MODULE,Case,[cleanup,Config])
+ catch error:undef -> ok
+ end,
+ ok.
+
+groups() ->
+ [].
+
+all() ->
+ [start_stop,
+ add_remove_handler,
+ multiple_handlers,
+ add_remove_filter,
+ change_config,
+ set_formatter,
+ log_no_levels,
+ log_all_levels_api,
+ macros,
+ set_level,
+ set_module_level,
+ set_application_level,
+ cache_module_level,
+ format_report,
+ filter_failed,
+ handler_failed,
+ config_sanity_check,
+ log_failed,
+ emulator,
+ via_logger_process,
+ other_node,
+ compare_levels,
+ process_metadata,
+ app_config,
+ kernel_config].
+
+start_stop(_Config) ->
+ S = whereis(logger),
+ true = is_pid(S),
+ ok.
+
+add_remove_handler(_Config) ->
+ register(callback_receiver,self()),
+ Hs0 = logger:get_handler_config(),
+ {error,{not_found,h1}} = logger:get_handler_config(h1),
+ ok = logger:add_handler(h1,?MODULE,#{}),
+ [add] = test_server:messages_get(),
+ Hs = logger:get_handler_config(),
+ Hs0 = lists:filter(fun(#{id:=h1}) -> false; (_) -> true end, Hs),
+ {ok,#{module:=?MODULE,level:=all,filters:=[],filter_default:=log}} = %defaults
+ logger:get_handler_config(h1),
+ ok = logger:set_handler_config(h1,filter_default,stop),
+ [changing_config] = test_server:messages_get(),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_no_log(),
+ ok = logger:set_handler_config(h1,filter_default,log),
+ [changing_config] = test_server:messages_get(),
+ {ok,#{filter_default:=log}} = logger:get_handler_config(h1),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(notice,"hello",[],?MY_LOC(1)),
+ ok = logger:remove_handler(h1),
+ [remove] = test_server:messages_get(),
+ Hs0 = logger:get_handler_config(),
+ {error,{not_found,h1}} = logger:get_handler_config(h1),
+ {error,{not_found,h1}} = logger:remove_handler(h1),
+ logger:notice("hello",[]),
+ ok = check_no_log(),
+ ok.
+
+add_remove_handler(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+multiple_handlers(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ ok = logger:add_handler(h2,?MODULE,#{level=>error,filter_default=>log}),
+ ?LOG_ERROR("hello",[]),
+ ok = check_logged(error,"hello",[],?MY_LOC(1)),
+ ok = check_logged(error,"hello",[],?MY_LOC(2)),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(notice,"hello",[],?MY_LOC(1)),
+ ok = check_no_log(),
+ ok.
+
+multiple_handlers(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:remove_handler(h2),
+ ok.
+
+add_remove_filter(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ LF = {fun(Log,_) -> Log#{level=>error} end, []},
+ ok = logger:add_primary_filter(lf,LF),
+ {error,{already_exist,lf}} = logger:add_primary_filter(lf,LF),
+ {error,{already_exist,lf}} = logger:add_primary_filter(lf,{fun(Log,_) ->
+ Log
+ end, []}),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(error,"hello",[],?MY_LOC(1)),
+ ok = check_no_log(),
+
+ ok = logger:add_handler(h2,?MODULE,#{level=>notice,filter_default=>log}),
+ HF = {fun(#{level:=error}=Log,_) ->
+ Log#{level=>mylevel};
+ (_,_) ->
+ ignore
+ end,
+ []},
+ ok = logger:add_handler_filter(h1,hf,HF),
+ {error,{already_exist,hf}} = logger:add_handler_filter(h1,hf,HF),
+ {error,{already_exist,hf}} = logger:add_handler_filter(h1,hf,{fun(Log,_) ->
+ Log
+ end, []}),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(mylevel,"hello",[],?MY_LOC(1)),
+ ok = check_logged(error,"hello",[],?MY_LOC(2)),
+
+ ok = logger:remove_primary_filter(lf),
+ {error,{not_found,lf}} = logger:remove_primary_filter(lf),
+
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(notice,"hello",[],?MY_LOC(1)),
+ ok = check_logged(notice,"hello",[],?MY_LOC(2)),
+
+ ?LOG_ERROR("hello",[]),
+ ok = check_logged(mylevel,"hello",[],?MY_LOC(1)),
+ ok = check_logged(error,"hello",[],?MY_LOC(2)),
+
+ ok = logger:remove_handler_filter(h1,hf),
+ {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf),
+ ?LOG_NOTICE("hello",[]),
+ ok = check_logged(notice,"hello",[],?MY_LOC(1)),
+ ok = check_logged(notice,"hello",[],?MY_LOC(2)),
+
+ ?LOG_ERROR("hello",[]),
+ ok = check_logged(error,"hello",[],?MY_LOC(1)),
+ ok = check_logged(error,"hello",[],?MY_LOC(2)),
+ ok.
+
+add_remove_filter(cleanup,_Config) ->
+ logger:remove_primary_filter(lf),
+ logger:remove_handler(h1),
+ logger:remove_handler(h2),
+ ok.
+
+change_config(_Config) ->
+ %% Overwrite handler config - check that defaults are added
+ {error,{not_found,h1}} = logger:set_handler_config(h1,#{}),
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,custom=>custom}),
+ {ok,#{module:=?MODULE,level:=notice,filter_default:=log,custom:=custom}} =
+ logger:get_handler_config(h1),
+ register(callback_receiver,self()),
+ ok = logger:set_handler_config(h1,#{filter_default=>stop}),
+ [changing_config] = test_server:messages_get(),
+ {ok,#{module:=?MODULE,level:=all,filter_default:=stop}=C2} =
+ logger:get_handler_config(h1),
+ false = maps:is_key(custom,C2),
+ {error,fail} = logger:set_handler_config(h1,#{conf_call=>fun() -> {error,fail} end}),
+ {error,{attempting_syncronous_call_to_self,_}} =
+ logger:set_handler_config(
+ h1,#{conf_call=>fun() -> logger:set_handler_config(?MODULE,#{}) end}),
+ ok =
+ logger:set_handler_config(
+ h1,#{conf_call=>fun() -> logger:set_module_level(?MODULE,debug) end}),
+ {ok,C2} = logger:get_handler_config(h1),
+
+ %% Change handler config: Single key
+ {error,fail} = logger:set_handler_config(h1,conf_call,fun() -> {error,fail} end),
+ ok = logger:set_handler_config(h1,custom,custom),
+ [changing_config] = test_server:messages_get(),
+ {ok,#{custom:=custom}=C3} = logger:get_handler_config(h1),
+ C2 = maps:remove(custom,C3),
+
+ %% Change handler config: Map
+ ok = logger:update_handler_config(h1,#{custom=>new_custom}),
+ [changing_config] = test_server:messages_get(),
+ {ok,C4} = logger:get_handler_config(h1),
+ C4 = C3#{custom:=new_custom},
+
+ %% Change handler config: Id and module can not be changed
+ {error,{illegal_config_change,Old,New}} =
+ logger:set_handler_config(h1,id,newid),
+ %% Check that only the faulty field is included in return
+ [{id,h1}] = maps:to_list(Old),
+ [{id,newid}] = maps:to_list(New),
+ %% Check that both fields are included when both are changed
+ {error,{illegal_config_change,
+ #{id:=h1,module:=?MODULE},
+ #{id:=newid,module:=newmodule}}} =
+ logger:set_handler_config(h1,#{id=>newid,module=>newmodule}),
+
+ %% Change primary config: Single key
+ PConfig0 = logger:get_primary_config(),
+ ok = logger:set_primary_config(level,warning),
+ PConfig1 = logger:get_primary_config(),
+ PConfig1 = PConfig0#{level:=warning},
+
+ %% Change primary config: Map
+ ok = logger:update_primary_config(#{level=>error}),
+ PConfig2 = logger:get_primary_config(),
+ PConfig2 = PConfig1#{level:=error},
+
+ %% Overwrite primary config - check that defaults are added
+ ok = logger:set_primary_config(#{filter_default=>stop}),
+ #{level:=notice,filters:=[],filter_default:=stop}=PC1 =
+ logger:get_primary_config(),
+ 3 = maps:size(PC1),
+ %% Check that internal 'handlers' field has not been changed
+ MS = [{{{?HANDLER_KEY,'$1'},'_','_'},[],['$1']}],
+ HIds1 = lists:sort(ets:select(?LOGGER_TABLE,MS)), % dirty, internal data
+ HIds2 = lists:sort(logger:get_handler_ids()),
+ HIds1 = HIds2,
+
+ %% Cleanup
+ ok = logger:set_primary_config(PConfig0),
+ [] = test_server:messages_get(),
+
+ ok.
+
+change_config(cleanup,Config) ->
+ logger:remove_handler(h1),
+ PC = ?config(logger_config,Config),
+ logger:set_primary_config(PC),
+ ok.
+
+set_formatter(_Config) ->
+ {error,{not_found,h1}}=logger:set_handler_config(h1,formatter,{?MODULE,[]}),
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ ok = logger:set_handler_config(h1,formatter,{?MODULE,[]}),
+ logger:notice("hello",[]),
+ receive
+ {_Log,#{formatter:={?MODULE,[]}}} ->
+ ok
+ after 500 ->
+ ct:fail({timeout,no_log,process_info(self(),messages)})
+ end,
+ ok.
+
+set_formatter(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+log_no_levels(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}),
+ logger:notice(M1=?map_rep),
+ ok = check_logged(notice,M1,#{}),
+
+ Levels = [emergency,alert,critical,error,warning,notice,info,debug],
+ ok = logger:set_primary_config(level,none),
+ [logger:Level(#{Level=>rep}) || Level <- Levels],
+ ok = check_no_log(),
+
+ ok = logger:set_primary_config(level,all),
+ M2 = ?map_rep,
+ ?LOG_NOTICE(M2),
+ ok = check_logged(notice,M2,#{}),
+
+ ok = logger:set_module_level(?MODULE,none),
+ ?LOG_EMERGENCY(?map_rep),
+ ?LOG_ALERT(?map_rep),
+ ?LOG_CRITICAL(?map_rep),
+ ?LOG_ERROR(?map_rep),
+ ?LOG_WARNING(?map_rep),
+ ?LOG_NOTICE(?map_rep),
+ ?LOG_INFO(?map_rep),
+ ?LOG_DEBUG(?map_rep),
+ ok = check_no_log(),
+
+ ok = logger:unset_module_level(?MODULE),
+ logger:notice(M3=?map_rep),
+ ok = check_logged(notice,M3,#{}),
+
+ ok = logger:set_handler_config(h1,level,none),
+ [logger:Level(#{Level=>rep}) || Level <- Levels],
+ ok = check_no_log(),
+
+ ok.
+log_no_levels(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:set_primary_config(level,notice),
+ logger:unset_module_level(?MODULE),
+ ok.
+
+log_all_levels_api(_Config) ->
+ ok = logger:set_primary_config(level,all),
+ ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}),
+ test_api(emergency),
+ test_api(alert),
+ test_api(critical),
+ test_api(error),
+ test_api(warning),
+ test_api(notice),
+ test_api(info),
+ test_api(debug),
+ test_log_function(emergency),
+ ok.
+
+log_all_levels_api(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:set_primary_config(level,notice),
+ ok.
+
+macros(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}),
+ test_macros(emergency),
+ test_log_macro(alert),
+ ok.
+
+macros(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:unset_module_level(?MODULE),
+ ok.
+
+set_level(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}),
+ logger:debug(?map_rep),
+ ok = check_no_log(),
+ logger:notice(M1=?map_rep),
+ ok = check_logged(notice,M1,#{}),
+ ok = logger:set_primary_config(level,debug),
+ logger:debug(M2=?map_rep),
+ ok = check_logged(debug,M2,#{}),
+ ok.
+
+set_level(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:set_primary_config(level,notice),
+ ok.
+
+set_module_level(_Config) ->
+ [] = logger:get_module_level([?MODULE,other]),
+ [] = logger:get_module_level(?MODULE),
+ [] = logger:get_module_level(),
+
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ {error,{invalid_level,bad}} = logger:set_module_level(?MODULE,bad),
+ {error,{not_a_list_of_modules,{bad}}} =
+ logger:set_module_level({bad},warning),
+ {error,{not_a_list_of_modules,[{bad}]}} =
+ logger:set_module_level([{bad}],warning),
+ ok = logger:set_module_level(?MODULE,warning),
+ [{?MODULE,warning}] = logger:get_module_level([?MODULE,other]),
+ [{?MODULE,warning}] = logger:get_module_level(?MODULE),
+ [{?MODULE,warning}] = logger:get_module_level(),
+ logger:notice(?map_rep,?MY_LOC(0)),
+ ok = check_no_log(),
+ logger:warning(M1=?map_rep,?MY_LOC(0)),
+ ok = check_logged(warning,M1,?MY_LOC(1)),
+ ok = logger:set_module_level(?MODULE,notice),
+ [{?MODULE,notice}] = logger:get_module_level([?MODULE,other]),
+ [{?MODULE,notice}] = logger:get_module_level(?MODULE),
+ [{?MODULE,notice}] = logger:get_module_level(),
+ logger:notice(M2=?map_rep,?MY_LOC(0)),
+ ok = check_logged(notice,M2,?MY_LOC(1)),
+
+ {error,{not_a_list_of_modules,{bad}}} = logger:unset_module_level({bad}),
+ {error,{not_a_list_of_modules,[{bad}]}} = logger:unset_module_level([{bad}]),
+ ok = logger:unset_module_level(?MODULE),
+ [] = logger:get_module_level([?MODULE,other]),
+ [] = logger:get_module_level(?MODULE),
+ [] = logger:get_module_level(),
+
+ ok = logger:set_module_level([m1,m2,m3],notice),
+ [{m1,notice},{m2,notice},{m3,notice}] = logger:get_module_level(),
+ ok = logger:unset_module_level(m2),
+ [{m1,notice},{m3,notice}] = logger:get_module_level(),
+ ok = logger:unset_module_level(),
+ [] = logger:get_module_level(),
+
+ ok.
+
+set_module_level(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:unset_module_level(?MODULE),
+ ok.
+
+set_application_level(_Config) ->
+
+ {error,{not_loaded,mnesia}} = logger:set_application_level(mnesia, warning),
+ {error,{not_loaded,mnesia}} = logger:unset_application_level(mnesia),
+
+ case application:load(mnesia) of
+ ok ->
+ {ok, Modules} = application:get_key(mnesia, modules),
+ [] = logger:get_module_level(Modules),
+
+ {error,{invalid_level,warn}} =
+ logger:set_application_level(mnesia, warn),
+
+ ok = logger:set_application_level(mnesia, debug),
+ DebugModules = lists:sort([{M,debug} || M <- Modules]),
+ DebugModules = lists:sort(logger:get_module_level(Modules)),
+
+ ok = logger:set_application_level(mnesia, warning),
+
+ WarnModules = lists:sort([{M,warning} || M <- Modules]),
+ WarnModules = lists:sort(logger:get_module_level(Modules)),
+
+ ok = logger:unset_application_level(mnesia),
+ [] = logger:get_module_level(Modules);
+ {error,{"no such file or directory","mnesia.app"}} ->
+ {skip, "Cannot load mnesia, does not exist"}
+ end.
+
+set_application_level(cleanup,_Config) ->
+ _ = logger:unset_application_level(mnesia),
+ _ = application:unload(mnesia),
+ ok.
+
+cache_module_level(_Config) ->
+ ok = logger:unset_module_level(?MODULE),
+ [] = ets:lookup(?LOGGER_TABLE,?MODULE), %dirty - add API in logger_config?
+ ?LOG_NOTICE(?map_rep),
+ %% Caching is done asynchronously, so wait a bit for the update
+ timer:sleep(100),
+ [_] = ets:lookup(?LOGGER_TABLE,?MODULE), %dirty - add API in logger_config?
+ ok = logger:unset_module_level(?MODULE),
+ [] = ets:lookup(?LOGGER_TABLE,?MODULE), %dirty - add API in logger_config?
+ ok.
+
+cache_module_level(cleanup,_Config) ->
+ logger:unset_module_level(?MODULE),
+ ok.
+
+format_report(_Config) ->
+ {"~ts",["string"]} = logger:format_report("string"),
+ {"~tp",[term]} = logger:format_report(term),
+ {"~tp",[[]]} = logger:format_report([]),
+ {" ~tp: ~tp",[key,value]} = logger:format_report([{key,value}]),
+ KeyVals = [{key1,value1},{key2,"value2"},{key3,[]}],
+ KeyValRes =
+ {" ~tp: ~tp\n ~tp: ~ts\n ~tp: ~tp",
+ [key1,value1,key2,"value2",key3,[]]} =
+ logger:format_report(KeyVals),
+ KeyValRes = logger:format_report(maps:from_list(KeyVals)),
+ KeyValRes = logger:format_otp_report(#{label=>{?MODULE,test},report=>KeyVals}),
+ {" ~tp: ~tp\n ~tp: ~tp",
+ [label,{?MODULE,test},report,KeyVals]} =
+ logger:format_report(#{label=>{?MODULE,test},report=>KeyVals}),
+
+ {" ~tp: ~tp\n ~tp",[key1,value1,term]} =
+ logger:format_report([{key1,value1},term]),
+
+ {" ~tp: ~tp\n ~tp",[key1,value1,[]]} =
+ logger:format_report([{key1,value1},[]]),
+
+ {"~tp",[[]]} = logger:format_report([[],[],[]]),
+
+ ok.
+
+filter_failed(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+
+ %% Logger filters
+ {error,{invalid_filter,_}} =
+ logger:add_primary_filter(lf,{fun(_) -> ok 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,#{}),
+ {error,{not_found,lf}} = logger:remove_primary_filter(lf),
+
+ ok = logger:add_primary_filter(lf,{fun(_,_) -> faulty_return end,args}),
+ #{filters:=[_]} = logger:get_primary_config(),
+ ok = logger:notice(M2=?map_rep),
+ ok = check_logged(notice,M2,#{}),
+ {error,{not_found,lf}} = logger:remove_primary_filter(lf),
+
+ %% Handler filters
+ {error,{not_found,h0}} =
+ logger:add_handler_filter(h0,hf,{fun(_,_) -> ignore end,args}),
+ {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(_,_) ->
+ erlang:error({badmatch,b})
+ end,
+ args}),
+ {ok,#{filters:=[_]}} = logger:get_handler_config(h1),
+ ok = logger:notice(M3=?map_rep),
+ ok = check_logged(notice,M3,#{}),
+ {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf),
+
+ ok = logger:add_handler_filter(h1,hf,{fun(_,_) -> faulty_return end,args}),
+ {ok,#{filters:=[_]}} = logger:get_handler_config(h1),
+ ok = logger:notice(M4=?map_rep),
+ ok = check_logged(notice,M4,#{}),
+ {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf),
+
+ ok.
+
+filter_failed(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+handler_failed(_Config) ->
+ register(callback_receiver,self()),
+ {error,{invalid_id,1}} = logger:add_handler(1,?MODULE,#{}),
+ {error,{invalid_module,"nomodule"}} = logger:add_handler(h1,"nomodule",#{}),
+ {error,{invalid_config,bad}} = logger:add_handler(h1,?MODULE,bad),
+ {error,{invalid_filters,false}} =
+ logger:add_handler(h1,?MODULE,#{filters=>false}),
+ {error,{invalid_filter_default,true}} =
+ logger:add_handler(h1,?MODULE,#{filter_default=>true}),
+ {error,{invalid_formatter,[]}} =
+ logger:add_handler(h1,?MODULE,#{formatter=>[]}),
+ {error,{invalid_handler,_}} = logger:add_handler(h1,nomodule,#{filter_default=>log}),
+ logger:notice(?map_rep),
+ check_no_log(),
+ H1 = logger:get_handler_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() ->
+ erlang:error({badmatch,b})
+ end}),
+ {error,{already_exist,h2}} = logger:add_handler(h2,othermodule,#{}),
+ [add] = test_server:messages_get(),
+
+ logger:notice(?map_rep),
+ [remove] = test_server:messages_get(),
+ H2 = logger:get_handler_config(),
+ false = lists:search(fun(#{id:=h2}) -> true; (_) -> false end,H2),
+ {error,{not_found,h2}} = logger:remove_handler(h2),
+
+ CallAddHandler = fun() -> logger:add_handler(h2,?MODULE,#{}) end,
+ CrashHandler = fun() -> erlang:error({badmatch,b}) end,
+ KillHandler = fun() -> exit(self(), die) end,
+
+ {error,{handler_not_added,{attempting_syncronous_call_to_self,_}}} =
+ logger:add_handler(h1,?MODULE,#{add_call=>CallAddHandler}),
+ {error,{handler_not_added,{callback_crashed,_}}} =
+ logger:add_handler(h1,?MODULE,#{add_call=>CrashHandler}),
+ {error,{handler_not_added,{logger_process_exited,_,die}}} =
+ logger:add_handler(h1,?MODULE,#{add_call=>KillHandler}),
+
+ check_no_log(),
+ ok = logger:add_handler(h1,?MODULE,#{}),
+ {error,{attempting_syncronous_call_to_self,_}} =
+ logger:set_handler_config(h1,#{conf_call=>CallAddHandler}),
+ {error,{callback_crashed,_}} =
+ logger:set_handler_config(h1,#{conf_call=>CrashHandler}),
+ {error,{logger_process_exited,_,die}} =
+ logger:set_handler_config(h1,#{conf_call=>KillHandler}),
+
+ {error,{attempting_syncronous_call_to_self,_}} =
+ logger:set_handler_config(h1,conf_call,CallAddHandler),
+ {error,{callback_crashed,_}} =
+ logger:set_handler_config(h1,conf_call,CrashHandler),
+ {error,{logger_process_exited,_,die}} =
+ logger:set_handler_config(h1,conf_call,KillHandler),
+
+ ok = logger:remove_handler(h1),
+ [add,remove] = test_server:messages_get(),
+
+ check_no_log(),
+ ok = logger:add_handler(h1,?MODULE,#{rem_call=>CallAddHandler}),
+ ok = logger:remove_handler(h1),
+ ok = logger:add_handler(h1,?MODULE,#{rem_call=>CrashHandler}),
+ ok = logger:remove_handler(h1),
+ ok = logger:add_handler(h1,?MODULE,#{rem_call=>KillHandler}),
+ ok = logger:remove_handler(h1),
+ [add,add,add] = test_server:messages_get(),
+
+ ok.
+
+handler_failed(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ logger:remove_handler(h2),
+ ok.
+
+config_sanity_check(_Config) ->
+ %% Primary config
+ {error,{invalid_config,bad}} = logger:set_primary_config(bad),
+ {error,{invalid_filter_default,bad}} =
+ logger:set_primary_config(filter_default,bad),
+ {error,{invalid_level,bad}} = logger:set_primary_config(level,bad),
+ {error,{invalid_filters,bad}} = logger:set_primary_config(filters,bad),
+ {error,{invalid_filter,bad}} = logger:set_primary_config(filters,[bad]),
+ {error,{invalid_filter,{_,_}}} =
+ logger:set_primary_config(filters,[{id,bad}]),
+ {error,{invalid_filter,{_,{_,_}}}} =
+ logger:set_primary_config(filters,[{id,{bad,args}}]),
+ {error,{invalid_filter,{_,{_,_}}}} =
+ logger:set_primary_config(filters,[{id,{fun() -> ok end,args}}]),
+ {error,{invalid_primary_config,{bad,bad}}} =
+ logger:set_primary_config(bad,bad),
+
+ %% Handler config
+ {error,{not_found,h1}} = logger:set_handler_config(h1,a,b),
+ ok = logger:add_handler(h1,?MODULE,#{}),
+ {error,{invalid_filter_default,bad}} =
+ logger:set_handler_config(h1,filter_default,bad),
+ {error,{invalid_level,bad}} = logger:set_handler_config(h1,level,bad),
+ {error,{invalid_filters,bad}} = logger:set_handler_config(h1,filters,bad),
+ {error,{invalid_filter,bad}} = logger:set_handler_config(h1,filters,[bad]),
+ {error,{invalid_filter,{_,_}}} =
+ logger:set_handler_config(h1,filters,[{id,bad}]),
+ {error,{invalid_filter,{_,{_,_}}}} =
+ logger:set_handler_config(h1,filters,[{id,{bad,args}}]),
+ {error,{invalid_filter,{_,{_,_}}}} =
+ logger:set_handler_config(h1,filters,[{id,{fun() -> ok end,args}}]),
+ {error,{invalid_formatter,bad}} =
+ logger:set_handler_config(h1,formatter,bad),
+ {error,{invalid_module,{bad}}} =
+ logger:set_handler_config(h1,formatter,{{bad},cfg}),
+ {error,{invalid_formatter_config,logger_formatter,bad}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,bad}),
+ {error,{invalid_formatter_config,logger_formatter,{bad,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,#{bad=>bad}}),
+ {error,{invalid_formatter_template,logger_formatter,bad}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{template=>bad}}),
+ {error,{invalid_formatter_template,logger_formatter,[1]}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{template=>[1]}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{template=>[]}}),
+ {error,{invalid_formatter_config,logger_formatter,{single_line,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{single_line=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{single_line=>true}}),
+ {error,{invalid_formatter_config,logger_formatter,{legacy_header,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{legacy_header=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{legacy_header=>true}}),
+ {error,{invalid_formatter_config,logger_formatter,{report_cb,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{report_cb=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{report_cb=>fun(R) ->
+ {"~p",[R]}
+ end}}),
+ {error,{invalid_formatter_config,logger_formatter,{chars_limit,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{chars_limit=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{chars_limit=>unlimited}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{chars_limit=>4}}),
+ {error,{invalid_formatter_config,logger_formatter,{depth,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{depth=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{depth=>unlimited}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{depth=>4}}),
+ {error,{invalid_formatter_config,logger_formatter,{max_size,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{max_size=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{max_size=>unlimited}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{max_size=>4}}),
+ ok = logger:set_handler_config(h1,formatter,{module,config}),
+ {error,{callback_crashed,{error,{badmatch,3},[{?MODULE,check_config,1,_}]}}} =
+ logger:set_handler_config(h1,formatter,{?MODULE,crash}),
+ ok = logger:set_handler_config(h1,custom,custom),
+
+ %% Old utc parameter is no longer allowed (replaced by time_offset)
+ {error,{invalid_formatter_config,logger_formatter,{utc,true}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{utc=>true}}),
+ {error,{invalid_formatter_config,logger_formatter,{time_offset,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>bad}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>0}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>""}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>"Z"}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>"z"}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>"-0:0"}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>"+10:13"}}),
+
+ {error,{invalid_formatter_config,logger_formatter,{time_offset,"+0"}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_offset=>"+0"}}),
+
+ {error,{invalid_formatter_config,logger_formatter,{time_designator,bad}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_designator=>bad}}),
+ {error,{invalid_formatter_config,logger_formatter,{time_designator,"s"}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_designator=>"s"}}),
+ {error,{invalid_formatter_config,logger_formatter,{time_designator,0}}} =
+ logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_designator=>0}}),
+ ok = logger:set_handler_config(h1,formatter,{logger_formatter,
+ #{time_designator=>$\s}}),
+ ok.
+
+config_sanity_check(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+log_failed(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ {error,function_clause} = ?TRY(logger:log(bad,?map_rep)),
+ {error,function_clause} = ?TRY(logger:log(notice,?map_rep,bad)),
+ {error,function_clause} = ?TRY(logger:log(notice,fun() -> ?map_rep end,bad)),
+ {error,function_clause} = ?TRY(logger:log(notice,fun() -> ?map_rep end,bad,#{})),
+ {error,function_clause} = ?TRY(logger:log(notice,bad,bad,bad)),
+ {error,function_clause} = ?TRY(logger:log(notice,bad,bad,#{})),
+ check_no_log(),
+ ok = logger:log(notice,M1=?str,#{}),
+ check_logged(notice,M1,#{}),
+ ok = logger:log(notice,M2=?map_rep,#{}),
+ check_logged(notice,M2,#{}),
+ ok = logger:log(notice,M3=?keyval_rep,#{}),
+ check_logged(notice,M3,#{}),
+
+ %% Should we check report input more thoroughly?
+ ok = logger:log(notice,M4=?keyval_rep++[other,stuff,in,list],#{}),
+ check_logged(notice,M4,#{}),
+
+ %% This might break a handler since it is assumed to be a format
+ %% string and args, so it depends how the handler protects itself
+ %% against something like io_lib:format("ok","ok")
+ ok = logger:log(notice,"ok","ok",#{}),
+ check_logged(notice,"ok","ok",#{}),
+
+ ok.
+
+log_failed(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+emulator(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log,
+ tc_proc=>self()}),
+ Msg = "Error in process ~p on node ~p with exit value:~n~p~n",
+ Error = {badmatch,4},
+ Stack = [{module, function, 2, []}],
+ Pid = spawn(?MODULE, generate_error, [Error, Stack]),
+ check_logged(error, Msg, [Pid, node(), {Error, Stack}],
+ #{gl=>group_leader(),
+ error_logger=>#{tag=>error,emulator=>true}}),
+ ok.
+
+emulator(cleanup, _Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+generate_error(Error, Stack) ->
+ erlang:raise(error, Error, Stack).
+
+via_logger_process(Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log,
+ tc_proc=>self()}),
+
+ %% Explicitly send a message to the logger process
+ %% This is used by code_server, erl_prim_loader, init, prim_file, ...
+ Msg = ?str,
+ logger ! {log,error,Msg,[],#{}},
+ check_logged(error, Msg, [], #{}),
+
+ case os:type() of
+ {win32,_} ->
+ %% Skip this part on windows - cant change file mode"
+ ok;
+ _ ->
+ %% This should trigger the same thing from erl_prim_loader
+ Dir = filename:join(?config(priv_dir,Config),"dummydir"),
+ ok = file:make_dir(Dir),
+ ok = file:change_mode(Dir,8#0222),
+ error = erl_prim_loader:list_dir(Dir),
+ check_logged(error,
+ #{report=>"File operation error: eacces. Target: " ++
+ Dir ++". Function: list_dir. "},
+ #{pid=>self(),
+ gl=>group_leader(),
+ error_logger=>#{tag=>error_report,
+ type=>std_error}}),
+ ok
+ end.
+
+via_logger_process(cleanup, Config) ->
+ Dir = filename:join(?config(priv_dir,Config),"dummydir"),
+ _ = file:change_mode(Dir,8#0664),
+ _ = file:del_dir(Dir),
+ logger:remove_handler(h1),
+ ok.
+
+other_node(_Config) ->
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log,
+ tc_proc=>self()}),
+ {ok,Node} = test_server:start_node(?FUNCTION_NAME,slave,[]),
+ rpc:call(Node,logger,error,[Msg=?str,#{}]),
+ check_logged(error,Msg,#{}),
+ ok.
+
+other_node(cleanup,_Config) ->
+ Nodes = nodes(),
+ [test_server:stop_node(Node) || Node <- Nodes],
+ logger:remove_handler(h1),
+ ok.
+
+compare_levels(_Config) ->
+ Levels = [emergency,alert,critical,error,warning,notice,info,debug],
+ ok = compare(Levels),
+ {error,badarg} = ?TRY(logger:compare_levels(bad,bad)),
+ {error,badarg} = ?TRY(logger:compare_levels({bad},notice)),
+ {error,badarg} = ?TRY(logger:compare_levels(notice,"bad")),
+ ok.
+
+compare([L|Rest]) ->
+ eq = logger:compare_levels(L,L),
+ [gt = logger:compare_levels(L,L1) || L1 <- Rest],
+ [lt = logger:compare_levels(L1,L) || L1 <- Rest],
+ compare(Rest);
+compare([]) ->
+ ok.
+
+process_metadata(_Config) ->
+ undefined = logger:get_process_metadata(),
+ {error,badarg} = ?TRY(logger:set_process_metadata(bad)),
+ ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+ Time = erlang:system_time(microsecond),
+ ProcMeta = #{time=>Time,line=>0,custom=>proc},
+ ok = logger:set_process_metadata(ProcMeta),
+ S1 = ?str,
+ ?LOG_NOTICE(S1,#{custom=>macro}),
+ check_logged(notice,S1,#{time=>Time,line=>0,custom=>macro}),
+
+ Time2 = erlang:system_time(microsecond),
+ S2 = ?str,
+ ?LOG_NOTICE(S2,#{time=>Time2,line=>1,custom=>macro}),
+ check_logged(notice,S2,#{time=>Time2,line=>1,custom=>macro}),
+
+ logger:notice(S3=?str,#{custom=>func}),
+ check_logged(notice,S3,#{time=>Time,line=>0,custom=>func}),
+
+ ProcMeta = logger:get_process_metadata(),
+ ok = logger:update_process_metadata(#{custom=>changed,custom2=>added}),
+ Expected = ProcMeta#{custom:=changed,custom2=>added},
+ Expected = logger:get_process_metadata(),
+ ok = logger:unset_process_metadata(),
+ undefined = logger:get_process_metadata(),
+
+ ok = logger:update_process_metadata(#{custom=>added_again}),
+ {error,badarg} = ?TRY(logger:update_process_metadata(bad)),
+ #{custom:=added_again} = logger:get_process_metadata(),
+
+ ok.
+
+process_metadata(cleanup,_Config) ->
+ logger:remove_handler(h1),
+ ok.
+
+app_config(Config) ->
+ %% Start a node with default configuration
+ {ok,_,Node} = logger_test_lib:setup(Config,[]),
+
+ App1Name = app1,
+ App1 = {application, App1Name,
+ [{description, "Test of app with logger config"},
+ {applications, [kernel]}]},
+ ok = rpc:call(Node,application,load,[App1]),
+ ok = rpc:call(Node,application,set_env,
+ [App1Name,logger,[{handler,default,logger_std_h,#{}}]]),
+
+ %% Try to add an own default handler
+ {error,{bad_config,{handler,{app1,{already_exist,default}}}}} =
+ rpc:call(Node,logger,add_handlers,[App1Name]),
+
+ %% Add a different handler
+ ok = rpc:call(Node,application,set_env,[App1Name,logger,
+ [{handler,myh,logger_std_h,#{}}]]),
+ ok = rpc:call(Node,logger,add_handlers,[App1Name]),
+
+ {ok,#{filters:=DF}} = rpc:call(Node,logger,get_handler_config,[default]),
+ {ok,#{filters:=[]}} = rpc:call(Node,logger,get_handler_config,[myh]),
+
+ true = test_server:stop_node(Node),
+
+ %% Start a node with no default handler, then add an own default handler
+ {ok,#{handlers:=[#{id:=simple}]},Node} =
+ logger_test_lib:setup(Config,[{logger,[{handler,default,undefined}]}]),
+
+ ok = rpc:call(Node,application,load,[App1]),
+ ok = rpc:call(Node,application,set_env,
+ [App1Name,logger,[{handler,default,logger_std_h,#{}}]]),
+ ok = rpc:call(Node,logger,add_handlers,[App1Name]),
+
+ #{handlers:=[#{id:=default,filters:=DF}]} =
+ rpc:call(Node,logger,get_config,[]),
+
+ true = test_server:stop_node(Node),
+
+ %% Start a silent node, then add an own default handler
+ {ok,#{handlers:=[]},Node} =
+ logger_test_lib:setup(Config,[{error_logger,silent}]),
+
+ {error,{bad_config,{handler,[{some,bad,config}]}}} =
+ rpc:call(Node,logger,add_handlers,[[{some,bad,config}]]),
+ ok = rpc:call(Node,logger,add_handlers,
+ [[{handler,default,logger_std_h,#{}}]]),
+
+ #{handlers:=[#{id:=default,filters:=DF}]} =
+ rpc:call(Node,logger,get_config,[]),
+
+ ok.
+
+%% This test case is maintly to see code coverage. Note that
+%% logger_env_var_SUITE tests a lot of the same, and checks the
+%% functionality more thoroughly, but since it all happens at node
+%% start, it is not possible to see code coverage in that test.
+kernel_config(Config) ->
+ %% Start a node with simple handler only, then simulate kernel
+ %% start by calling internally exported
+ %% internal_init_logger(). This is to test all variants of kernel
+ %% config, including bad config, and see the code coverage.
+ {ok,#{handlers:=[#{id:=simple,filters:=DF}]}=LC,Node} =
+ logger_test_lib:setup(Config,[{error_logger,false}]),
+
+ %% Same once more, to get coverage
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ LC = rpc:call(Node,logger,get_config,[]),
+
+ %% This shall mean the same as above, but using 'logger' parameter
+ %% instead of 'error_logger'
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{handler,default,undefined}]]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ LC = rpc:call(Node,logger,get_config,[]),
+
+ %% Silent
+ ok = rpc:call(Node,application,unset_env,[kernel,logger]),
+ ok = rpc:call(Node,application,set_env,[kernel,error_logger,silent]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Default
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ ok = rpc:call(Node,application,unset_env,[kernel,logger]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{type:=standard_io}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% error_logger=tty (same as default)
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ ok = rpc:call(Node,application,set_env,[kernel,error_logger,tty]),
+ ok = rpc:call(Node,application,unset_env,[kernel,logger]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{type:=standard_io}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% error_logger={file,File}
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ F = filename:join(?config(priv_dir,Config),
+ atom_to_list(?FUNCTION_NAME)++".log"),
+ ok = rpc:call(Node,application,set_env,[kernel,error_logger,{file,F}]),
+ ok = rpc:call(Node,application,unset_env,[kernel,logger]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F}}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Same, but using 'logger' parameter instead of 'error_logger'
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ ok = rpc:call(Node,application,set_env,[kernel,logger,
+ [{handler,default,logger_std_h,
+ #{config=>#{type=>{file,F}}}}]]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F}}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Same, but with type={file,File,Modes}
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ M = [raw,write,delayed_write],
+ ok = rpc:call(Node,application,set_env,[kernel,logger,
+ [{handler,default,logger_std_h,
+ #{config=>#{type=>{file,F,M}}}}]]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,M}}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Same, but with disk_log handler
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ M = [raw,write,delayed_write],
+ ok = rpc:call(Node,application,set_env,[kernel,logger,
+ [{handler,default,logger_disk_log_h,
+ #{config=>#{file=>F}}}]]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=log,filters:=[]},
+ handlers:=[#{id:=default,filters:=DF,config:=#{file:=F}}],
+ module_levels:=[]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Set primary filters and module level. No default handler.
+ ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{handler,default,undefined},
+ {filters,stop,[{f1,{fun(_,_) -> log end,ok}}]},
+ {module_level,debug,[?MODULE]}]]),
+ ok = rpc:call(Node,logger,internal_init_logger,[]),
+ ok = rpc:call(Node,logger,add_handlers,[kernel]),
+ #{primary:=#{filter_default:=stop,filters:=[_]},
+ handlers:=[],
+ module_levels:=[{?MODULE,debug}]} = rpc:call(Node,logger,get_config,[]),
+
+ %% Bad config
+ ok = rpc:call(Node,application,unset_env,[kernel,logger]),
+
+ ok = rpc:call(Node,application,set_env,[kernel,error_logger,bad]),
+ {error,{bad_config,{kernel,{error_logger,bad}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,unset_env,[kernel,error_logger]),
+ ok = rpc:call(Node,application,set_env,[kernel,logger_level,bad]),
+ {error,{bad_config,{kernel,{logger_level,bad}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,unset_env,[kernel,logger_level]),
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{filters,stop,[bad]}]]),
+ {error,{bad_config,{kernel,{invalid_filters,[bad]}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{filters,stop,[bad]}]]),
+ {error,{bad_config,{kernel,{invalid_filters,[bad]}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{filters,stop,[{f1,bad}]}]]),
+ {error,{bad_config,{kernel,{invalid_filter,{f1,bad}}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,MF=[{filters,stop,[]},{filters,log,[]}]]),
+ {error,{bad_config,{kernel,{multiple_filters,MF}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok = rpc:call(Node,application,set_env,
+ [kernel,logger,[{module_level,bad,[?MODULE]}]]),
+ {error,{bad_config,{kernel,{invalid_level,bad}}}} =
+ rpc:call(Node,logger,internal_init_logger,[]),
+
+ ok.
+
+%%%-----------------------------------------------------------------
+%%% Internal
+check_logged(Level,Format,Args,Meta) ->
+ do_check_logged(Level,{Format,Args},Meta).
+
+check_logged(Level,Msg,Meta) when ?IS_REPORT(Msg) ->
+ do_check_logged(Level,{report,Msg},Meta);
+check_logged(Level,Msg,Meta) when ?IS_STRING(Msg) ->
+ do_check_logged(Level,{string,Msg},Meta).
+
+do_check_logged(Level,Msg0,Meta0) ->
+ receive
+ {#{level:=Level,msg:=Msg,meta:=Meta},_} ->
+ check_msg(Msg0,Msg),
+ check_maps(Meta0,Meta,meta)
+ after 500 ->
+ ct:fail({timeout,no_log,process_info(self(),messages)})
+ end.
+
+check_no_log() ->
+ receive
+ X -> ct:fail({got_unexpected_log,X})
+ after 500 ->
+ ok
+ end.
+
+check_msg(Msg,Msg) ->
+ ok;
+check_msg({report,Expected},{report,Got}) when is_map(Expected), is_map(Got) ->
+ check_maps(Expected,Got,msg);
+check_msg(Expected,Got) ->
+ ct:fail({unexpected,msg,Expected,Got}).
+
+check_maps(Expected,Got,What) ->
+ case maps:merge(Got,Expected) of
+ Got ->
+ ok;
+ _ ->
+ ct:fail({unexpected,What,Expected,Got})
+ end.
+
+%% Handler
+adding_handler(#{add_call:=Fun}) ->
+ Fun();
+adding_handler(Config) ->
+ maybe_send(add),
+ {ok,Config}.
+
+removing_handler(#{rem_call:=Fun}) ->
+ Fun();
+removing_handler(_Config) ->
+ maybe_send(remove),
+ ok.
+changing_config(_Old,#{conf_call:=Fun}) ->
+ Fun();
+changing_config(_Old,Config) ->
+ maybe_send(changing_config),
+ {ok,Config}.
+
+maybe_send(Msg) ->
+ case whereis(callback_receiver) of
+ undefined -> ok;
+ Pid -> Pid ! Msg
+ end.
+
+log(_Log,#{log_call:=Fun}) ->
+ Fun();
+log(Log,Config) ->
+ TcProc = maps:get(tc_proc,Config,self()),
+ TcProc ! {Log,Config},
+ ok.
+
+test_api(Level) ->
+ logger:Level(#{Level=>rep}),
+ ok = check_logged(Level,#{Level=>rep},#{}),
+ logger:Level(#{Level=>rep},#{my=>meta}),
+ ok = check_logged(Level,#{Level=>rep},#{my=>meta}),
+ logger:Level("~w: ~w",[Level,fa]),
+ ok = check_logged(Level,"~w: ~w",[Level,fa],#{}),
+ logger:Level("~w: ~w ~w",[Level,fa,meta],#{my=>meta}),
+ ok = check_logged(Level,"~w: ~w ~w",[Level,fa,meta],#{my=>meta}),
+ logger: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=>meta}),
+ logger:Level(fun(x) -> #{Level=>fun_to_r,meta=>true} end,x,
+ #{my=>meta}),
+ ok = check_logged(Level,#{Level=>fun_to_r,meta=>true},#{my=>meta}),
+ logger:Level(fun(x) -> <<"fun_to_s">> end,x,#{}),
+ ok = check_logged(Level,<<"fun_to_s">>,#{}),
+ logger:Level(F1=fun(x) -> {fun_to_bad} end,x,#{}),
+ ok = check_logged(Level,"LAZY_FUN ERROR: ~tp; Returned: ~tp",
+ [{F1,x},{fun_to_bad}],#{}),
+ logger:Level(F2=fun(x) -> erlang:error(fun_that_crashes) end,x,#{}),
+ ok = check_logged(Level,"LAZY_FUN CRASH: ~tp; Reason: ~tp",
+ [{F2,x},{error,fun_that_crashes}],#{}),
+ ok.
+
+test_log_function(Level) ->
+ logger:log(Level,#{Level=>rep}),
+ ok = check_logged(Level,#{Level=>rep},#{}),
+ logger:log(Level,#{Level=>rep},#{my=>meta}),
+ ok = check_logged(Level,#{Level=>rep},#{my=>meta}),
+ logger:log(Level,"~w: ~w",[Level,fa]),
+ ok = check_logged(Level,"~w: ~w",[Level,fa],#{}),
+ logger:log(Level,"~w: ~w ~w",[Level,fa,meta],#{my=>meta}),
+ ok = check_logged(Level,"~w: ~w ~w",[Level,fa,meta],#{my=>meta}),
+ logger: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=>meta}),
+ logger: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=>meta}),
+ logger:log(Level,fun(x) -> <<"fun_to_s">> end,x,#{}),
+ ok = check_logged(Level,<<"fun_to_s">>,#{}),
+ logger:log(Level,F1=fun(x) -> {fun_to_bad} end,x,#{}),
+ ok = check_logged(Level,"LAZY_FUN ERROR: ~tp; Returned: ~tp",
+ [{F1,x},{fun_to_bad}],#{}),
+ logger:log(Level,F2=fun(x) -> erlang:error(fun_that_crashes) end,x,#{}),
+ ok = check_logged(Level,"LAZY_FUN CRASH: ~tp; Reason: ~tp",
+ [{F2,x},{error,fun_that_crashes}],#{}),
+ ok.
+
+test_macros(emergency=Level) ->
+ ?LOG_EMERGENCY(#{Level=>rep}),
+ ok = check_logged(Level,#{Level=>rep},?MY_LOC(1)),
+ ?LOG_EMERGENCY(#{Level=>rep},#{my=>meta}),
+ ok = check_logged(Level,#{Level=>rep},(?MY_LOC(1))#{my=>meta}),
+ ?LOG_EMERGENCY("~w: ~w",[Level,fa]),
+ ok = check_logged(Level,"~w: ~w",[Level,fa],?MY_LOC(1)),
+ ?LOG_EMERGENCY("~w: ~w ~w",[Level,fa,meta],#{my=>meta}),
+ ok = check_logged(Level,"~w: ~w ~w",[Level,fa,meta],(?MY_LOC(1))#{my=>meta}),
+ ?LOG_EMERGENCY(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_EMERGENCY(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_EMERGENCY(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_EMERGENCY(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_EMERGENCY(F2,x,#{}),
+ ok = check_logged(Level,"LAZY_FUN CRASH: ~tp; Reason: ~tp",
+ [{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) ->
+ try Fun() catch C:R -> {C,R} end.
+
+check_config(crash) ->
+ erlang:error({badmatch,3});
+check_config(_) ->
+ ok.