aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel/test
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel/test')
-rw-r--r--lib/kernel/test/disk_log_SUITE.erl99
-rw-r--r--lib/kernel/test/global_SUITE.erl30
-rw-r--r--lib/kernel/test/logger_SUITE.erl233
-rw-r--r--lib/kernel/test/logger_disk_log_h_SUITE.erl66
-rw-r--r--lib/kernel/test/logger_formatter_SUITE.erl7
-rw-r--r--lib/kernel/test/logger_simple_h_SUITE.erl3
-rw-r--r--lib/kernel/test/logger_std_h_SUITE.erl2
7 files changed, 354 insertions, 86 deletions
diff --git a/lib/kernel/test/disk_log_SUITE.erl b/lib/kernel/test/disk_log_SUITE.erl
index 0709a6e766..9704c3b28c 100644
--- a/lib/kernel/test/disk_log_SUITE.erl
+++ b/lib/kernel/test/disk_log_SUITE.erl
@@ -1750,7 +1750,7 @@ block_queue(Conf) when is_list(Conf) ->
true = [{1,a},{2,b},{3,c},{4,d},{5,e},{6,f},{7,g},{8,h}] == Terms,
del(File, 2),
Q = qlen(),
- true = (P0 == pps()),
+ check_pps(P0),
ok.
%% OTP-4880. Blocked processes did not get disk_log_stopped message.
@@ -1782,7 +1782,7 @@ block_queue2(Conf) when is_list(Conf) ->
{ok,<<>>} = file:read_file(File ++ ".1"),
del(File, No),
Q = qlen(),
- true = (P0 == pps()),
+ check_pps(P0),
ok.
@@ -2119,7 +2119,7 @@ close_block(Conf) when is_list(Conf) ->
0 = sync_do(Pid2, users),
sync_do(Pid2, terminate),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Users terminate (no link...).
Pid3 = spawn_link(?MODULE, lserv, [n]),
@@ -2137,7 +2137,7 @@ close_block(Conf) when is_list(Conf) ->
disk_log:close(n),
disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking owner terminates.
Pid5 = spawn_link(?MODULE, lserv, [n]),
@@ -2154,7 +2154,7 @@ close_block(Conf) when is_list(Conf) ->
1 = users(n),
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking user terminates.
Pid6 = spawn_link(?MODULE, lserv, [n]),
@@ -2174,7 +2174,7 @@ close_block(Conf) when is_list(Conf) ->
1 = users(n),
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking owner terminates.
Pid7 = spawn_link(?MODULE, lserv, [n]),
@@ -2192,7 +2192,7 @@ close_block(Conf) when is_list(Conf) ->
1 = users(n),
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Two owners, the blocking one terminates.
Pid8 = spawn_link(?MODULE, lserv, [n]),
@@ -2207,7 +2207,7 @@ close_block(Conf) when is_list(Conf) ->
0 = sync_do(Pid9, users),
sync_do(Pid9, terminate),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking user closes.
Pid10 = spawn_link(?MODULE, lserv, [n]),
@@ -2225,7 +2225,7 @@ close_block(Conf) when is_list(Conf) ->
ok = disk_log:close(n),
sync_do(Pid10, terminate),
{error, no_such_log} = disk_log:info(n),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking user unblocks and closes.
Pid11 = spawn_link(?MODULE, lserv, [n]),
@@ -2244,7 +2244,7 @@ close_block(Conf) when is_list(Conf) ->
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
sync_do(Pid11, terminate),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking owner closes.
Pid12 = spawn_link(?MODULE, lserv, [n]),
@@ -2263,7 +2263,7 @@ close_block(Conf) when is_list(Conf) ->
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
sync_do(Pid12, terminate),
- true = (P0 == pps()),
+ check_pps(P0),
%% Blocking owner unblocks and closes.
Pid13 = spawn_link(?MODULE, lserv, [n]),
@@ -2283,7 +2283,7 @@ close_block(Conf) when is_list(Conf) ->
ok = disk_log:close(n),
{error, no_such_log} = disk_log:info(n),
sync_do(Pid13, terminate),
- true = (P0 == pps()),
+ check_pps(P0),
del(File, No), % cleanup
ok.
@@ -2487,7 +2487,7 @@ error_repair(Conf) when is_list(Conf) ->
P0 = pps(),
{error, {file_error, _, _}} =
disk_log:open([{name, n}, {file, File}, {type, wrap}, {size,{40,4}}]),
- true = (P0 == pps()),
+ check_pps(P0),
del(File, No),
ok = file:del_dir(Dir),
@@ -2506,7 +2506,7 @@ error_repair(Conf) when is_list(Conf) ->
disk_log:open([{name, n}, {file, File}, {type, wrap},
{format, internal}, {size, {40,No}}]),
ok = disk_log:close(n),
- true = (P1 == pps()),
+ check_pps(P1),
del(File, No),
receive {info_msg, _, "disk_log: repairing" ++ _, _} -> ok
after 1000 -> ct:fail(failed) end,
@@ -2524,7 +2524,7 @@ error_repair(Conf) when is_list(Conf) ->
disk_log:open([{name, n}, {file, File}, {type, wrap},
{format, internal}, {size, {4000,No}}]),
ok = disk_log:close(n),
- true = (P2 == pps()),
+ check_pps(P2),
del(File, No),
receive {info_msg, _, "disk_log: repairing" ++ _, _} -> ok
after 1000 -> ct:fail(failed) end,
@@ -2633,7 +2633,7 @@ error_log(Conf) when is_list(Conf) ->
{ok, n} = disk_log:open([{name, n}, {file, File}, {type, wrap},
{format, external},{size, {100, No}}]),
{error, {file_error, _, _}} = disk_log:truncate(n),
- true = (P0 == pps()),
+ check_pps(P0),
del(File, No),
%% OTP-4880.
@@ -2641,7 +2641,7 @@ error_log(Conf) when is_list(Conf) ->
{ok, n} = disk_log:open([{name, n}, {file, File}, {type, halt},
{format, external},{size, 100000}]),
{error, {file_error, _, eisdir}} = disk_log:reopen(n, LDir),
- true = (P0 == pps()),
+ check_pps(P0),
file:delete(File),
B = mk_bytes(60),
@@ -3003,7 +3003,7 @@ error_index(Conf) when is_list(Conf) ->
{error, {invalid_index_file, _}} = disk_log:open(Args),
del(File, No),
- true = (P0 == pps()),
+ check_pps(P0),
true = (Q == qlen()),
ok.
@@ -4436,7 +4436,7 @@ dist_open2(Conf) when is_list(Conf) ->
timer:sleep(500),
file:delete(File),
- true = (P0 == pps()),
+ check_pps(P0),
%% This time the first process has a naughty head_func. This test
%% does not add very much. Perhaps it should be removed. However,
@@ -4482,7 +4482,7 @@ dist_open2(Conf) when is_list(Conf) ->
timer:sleep(100),
{error, no_such_log} = disk_log:close(Log),
file:delete(File),
- true = (P0 == pps()),
+ check_pps(P0),
No = 2,
Log2 = n2,
@@ -4511,7 +4511,7 @@ dist_open2(Conf) when is_list(Conf) ->
file:delete(File2),
del(File, No),
- true = (P0 == pps()),
+ check_pps(P0),
R.
@@ -4556,7 +4556,7 @@ dist_open2_1(Conf, Delay) ->
{error, no_such_log} = disk_log:info(Log),
file:delete(File),
- true = (P0 == pps()),
+ check_pps(P0),
ok.
@@ -4613,7 +4613,7 @@ dist_open2_2(Conf, Delay) ->
{[{Node1,{repaired,_,_,_}}],[]}} -> ok
end,
- true = (P0 == pps()),
+ check_pps(P0),
stop_node(Node1),
file:delete(File),
ok.
@@ -4791,10 +4791,59 @@ log(Name, N) ->
format_error(E) ->
lists:flatten(disk_log:format_error(E)).
+check_pps({Ports0,Procs0} = P0) ->
+ case pps() of
+ P0 ->
+ ok;
+ _ ->
+ timer:sleep(500),
+ case pps() of
+ P0 ->
+ ok;
+ {Ports1,Procs1} = P1 ->
+ case {Ports1 -- Ports0, Procs1 -- Procs0} of
+ {[], []} -> ok;
+ {PortsDiff,ProcsDiff} ->
+ io:format("failure, got ~p~n, expected ~p\n", [P1, P0]),
+ show("Old port", Ports0 -- Ports1),
+ show("New port", PortsDiff),
+ show("Old proc", Procs0 -- Procs1),
+ show("New proc", ProcsDiff),
+ ct:fail(failed)
+ end
+ end
+ end.
+
+show(_S, []) ->
+ ok;
+show(S, [{Pid, Name, InitCall}|Pids]) when is_pid(Pid) ->
+ io:format("~s: ~w (~w), ~w: ~p~n",
+ [S, Pid, proc_reg_name(Name), InitCall,
+ erlang:process_info(Pid)]),
+ show(S, Pids);
+show(S, [{Port, _}|Ports]) when is_port(Port)->
+ io:format("~s: ~w: ~p~n", [S, Port, erlang:port_info(Port)]),
+ show(S, Ports).
+
pps() ->
timer:sleep(100),
- {erlang:ports(), lists:filter(fun(P) -> erlang:is_process_alive(P) end,
- processes())}.
+ {port_list(), process_list()}.
+
+port_list() ->
+ [{P,safe_second_element(erlang:port_info(P, name))} ||
+ P <- erlang:ports()].
+
+process_list() ->
+ [{P,process_info(P, registered_name),
+ safe_second_element(process_info(P, initial_call))} ||
+ P <- processes(), erlang:is_process_alive(P)].
+
+proc_reg_name({registered_name, Name}) -> Name;
+proc_reg_name([]) -> no_reg_name.
+
+safe_second_element({_,Info}) -> Info;
+safe_second_element(Other) -> Other.
+
qlen() ->
{_, {_, N}} = lists:keysearch(message_queue_len, 1, process_info(self())),
diff --git a/lib/kernel/test/global_SUITE.erl b/lib/kernel/test/global_SUITE.erl
index 0e7b7adc47..8eab36e308 100644
--- a/lib/kernel/test/global_SUITE.erl
+++ b/lib/kernel/test/global_SUITE.erl
@@ -1383,7 +1383,7 @@ ring(Config) when is_list(Config) ->
rpc_cast(Cp8, ?MODULE, single_node, [Time, Cp7, Config]),
%% sleep to make the partitioned net ready
- ct:sleep(Time - msec()),
+ sleep(Time - msec()),
pong = net_adm:ping(Cp0),
pong = net_adm:ping(Cp1),
@@ -1466,7 +1466,7 @@ simple_ring(Config) when is_list(Config) ->
rpc_cast(Cp5, ?MODULE, single_node, [Time, Cp4, Config]),
%% sleep to make the partitioned net ready
- ct:sleep(Time - msec()),
+ sleep(Time - msec()),
pong = net_adm:ping(Cp0),
pong = net_adm:ping(Cp1),
@@ -1542,7 +1542,7 @@ line(Config) when is_list(Config) ->
rpc_cast(Cp8, ?MODULE, single_node, [Time, Cp7, Config]),
%% Sleep to make the partitioned net ready
- ct:sleep(Time - msec()),
+ sleep(Time - msec()),
pong = net_adm:ping(Cp0),
pong = net_adm:ping(Cp1),
@@ -1626,7 +1626,7 @@ simple_line(Config) when is_list(Config) ->
rpc_cast(Cp5, ?MODULE, single_node, [Time, Cp4, Config]),
%% sleep to make the partitioned net ready
- ct:sleep(Time - msec()),
+ sleep(Time - msec()),
pong = net_adm:ping(Cp0),
pong = net_adm:ping(Cp1),
@@ -3555,7 +3555,7 @@ single_node(Time, Node, Config) ->
lists:foreach(fun(N) -> _ = erlang:disconnect_node(N) end, nodes()),
?UNTIL(get_known(node()) =:= [node()]),
spawn(?MODULE, init_2, []),
- ct:sleep(Time - msec()),
+ sleep(Time - msec()),
net_adm:ping(Node).
init_2() ->
@@ -4009,13 +4009,6 @@ collect_nodes(N, Max) ->
[Node | collect_nodes(N+1, Max)]
end.
-only_element(_E, []) ->
- true;
-only_element(E, [E|R]) ->
- only_element(E, R);
-only_element(_E, _) ->
- false.
-
exit_p(Pid) ->
Ref = erlang:monitor(process, Pid),
Pid ! die,
@@ -4038,6 +4031,11 @@ wait_for_exit_fast(Pid) ->
ok
end.
+sleep(Time) when Time > 0 ->
+ ct:sleep(Time);
+sleep(_Time) ->
+ ok.
+
check_everywhere(Nodes, Name, Config) ->
?UNTIL(begin
case rpc:multicall(Nodes, global, whereis_name, [Name]) of
@@ -4162,10 +4160,10 @@ rpc_cast(Node, Module, Function, Args, File) ->
%% The emulator now ensures that the node has been removed from
%% nodes().
-rpc_disconnect_node(Node, DisconnectedNode, _Config) ->
- True = rpc:call(Node, erlang, disconnect_node, [DisconnectedNode]),
- False = lists:member(DisconnectedNode, rpc:call(Node, erlang, nodes, [])),
- {true, false} = {True, False}.
+rpc_disconnect_node(Node, DisconnectedNode, Config) ->
+ true = rpc:call(Node, erlang, disconnect_node, [DisconnectedNode]),
+ ?UNTIL
+ (not lists:member(DisconnectedNode, rpc:call(Node, erlang, nodes, []))).
%%%
%%% Utility
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
index 6bd9b20c35..36c093d7f4 100644
--- a/lib/kernel/test/logger_SUITE.erl
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -37,7 +37,8 @@
suite() ->
- [{timetrap,{seconds,30}}].
+ [{timetrap,{seconds,30}},
+ {ct_hooks,[logger_test_lib]}].
init_per_suite(Config) ->
case logger:get_handler_config(?STANDARD_HANDLER) of
@@ -98,7 +99,9 @@ all() ->
via_logger_process,
other_node,
compare_levels,
- process_metadata].
+ process_metadata,
+ app_config,
+ kernel_config].
start_stop(_Config) ->
S = whereis(logger),
@@ -211,6 +214,7 @@ add_remove_filter(cleanup,_Config) ->
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),
@@ -259,7 +263,7 @@ change_config(_Config) ->
logger:get_primary_config(),
3 = maps:size(PC1),
%% Check that internal 'handlers' field has not been changed
- MS = [{{{?HANDLER_KEY,'$1'},'_','_','_'},[],['$1']}],
+ 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,
@@ -389,6 +393,8 @@ set_module_level(_Config) ->
{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),
@@ -405,6 +411,7 @@ set_module_level(_Config) ->
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),
@@ -547,7 +554,7 @@ 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_handler_config,bad}} = logger:add_handler(h1,?MODULE,bad),
+ {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}} =
@@ -622,7 +629,8 @@ handler_failed(cleanup,_Config) ->
ok.
config_sanity_check(_Config) ->
- %% Logger 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),
@@ -895,12 +903,227 @@ process_metadata(_Config) ->
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) ->
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index a4b15c841b..a815db14e9 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -367,7 +367,7 @@ formatter_fail(Config) ->
ok = logger:set_handler_config(Name,formatter,{?MODULE,bad_return}),
logger:notice(?msg,?domain),
try_match_file(?log_no(LogFile,1),
- escape(Got3)++"FORMATTER ERROR: bad_return_value",
+ escape(Got3)++"FORMATTER ERROR: bad return value",
5000),
%% Check that handler is still alive and was never dead
@@ -524,27 +524,14 @@ sync(Config) ->
formatter=>{?MODULE,nl}}),
start_tracer([{disk_log,blog,2},
- {disk_log,sync,1}],
+ {logger_disk_log_h,disk_log_sync,2}],
[{disk_log,blog,<<"first\n">>},
- {disk_log,sync}]),
+ {logger_disk_log_h,disk_log_sync}]),
logger:notice("first", ?domain),
%% wait for automatic disk_log_sync
check_tracer(?FILESYNC_REPEAT_INTERVAL*2),
- start_tracer([{disk_log,blog,2},
- {disk_log,sync,1}],
- [{disk_log,blog,<<"second\n">>},
- {disk_log,blog,<<"third\n">>},
- {disk_log,sync}]),
- %% two log requests in fast succession will make the handler skip
- %% an automatic disk log sync
- logger:notice("second", ?domain),
- logger:notice("third", ?domain),
- %% do explicit sync
- logger_disk_log_h:filesync(?MODULE),
- check_tracer(100),
-
%% check that if there's no repeated disk_log_sync active,
%% a disk_log_sync is still performed when handler goes idle
{ok,#{config := HConfig}} = logger:get_handler_config(?MODULE),
@@ -553,20 +540,25 @@ sync(Config) ->
no_repeat = maps:get(filesync_repeat_interval,
logger_disk_log_h:info(?MODULE)),
+ %% The following timer is to make sure the time from last log
+ %% ("first") to next ("second") is long enough, so the a flush is
+ %% triggered by the idle timeout between "fourth" and "fifth".
+ timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
start_tracer([{disk_log,blog,2},
- {disk_log,sync,1}],
- [{disk_log,blog,<<"fourth\n">>},
- {disk_log,blog,<<"fifth\n">>},
- {disk_log,sync}]),
+ {logger_disk_log_h,disk_log_sync,2}],
+ [{disk_log,blog,<<"second\n">>},
+ {logger_disk_log_h,disk_log_sync},
+ {disk_log,blog,<<"third\n">>},
+ {logger_disk_log_h,disk_log_sync}]),
- logger:notice("fourth", ?domain),
+ logger:notice("second", ?domain),
timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
- logger:notice("fifth", ?domain),
+ logger:notice("third", ?domain),
%% wait for automatic disk_log_sync
check_tracer(?IDLE_DETECT_TIME_MSEC*2),
- try_read_file(Log, {ok,<<"first\nsecond\nthird\nfourth\nfifth\n">>}, 1000),
+ try_read_file(Log, {ok,<<"first\nsecond\nthird\n">>}, 1000),
%% switch repeated disk_log_sync on and verify that the looping works
SyncInt = 1000,
@@ -1194,7 +1186,7 @@ restart_after(cleanup, _Config) ->
%% during high load to verify that sync, dropping and flushing is
%% handled correctly.
handler_requests_under_load() ->
- [{timetrap,{minutes,3}}].
+ [{timetrap,{minutes,5}}].
handler_requests_under_load(Config) ->
{Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
NewHConfig =
@@ -1494,7 +1486,7 @@ start_tracer(Trace,Expected) ->
ok.
tpl([{M,F,A}|Trace]) ->
- {ok,Match} = dbg:tpl(M,F,A,[]),
+ {ok,Match} = dbg:tpl(M,F,A,c),
case lists:keyfind(matched,1,Match) of
{_,_,1} ->
ok;
@@ -1507,23 +1499,23 @@ tpl([{M,F,A}|Trace]) ->
tpl([]) ->
ok.
-tracer({trace,_,call,{logger_disk_log_h,handle_cast,[Op|_]}},
+tracer({trace,_,call,{logger_disk_log_h,handle_cast,[Op|_]},Caller},
{Pid,[{Mod,Func,Op}|Expected]}) ->
- maybe_tracer_done(Pid,Expected,{Mod,Func,Op});
-tracer({trace,_,call,{Mod=disk_log,Func=blog,[_,Data]}}, {Pid,[{Mod,Func,Data}|Expected]}) ->
- maybe_tracer_done(Pid,Expected,{Mod,Func,Data});
-tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) ->
- maybe_tracer_done(Pid,Expected,{Mod,Func});
-tracer({trace,_,call,Call}, {Pid,Expected}) ->
- ct:log("Tracer got unexpected: ~p~nExpected: ~p~n",[Call,Expected]),
+ maybe_tracer_done(Pid,Expected,{Mod,Func,Op},Caller);
+tracer({trace,_,call,{Mod=disk_log,Func=blog,[_,Data]},Caller}, {Pid,[{Mod,Func,Data}|Expected]}) ->
+ maybe_tracer_done(Pid,Expected,{Mod,Func,Data},Caller);
+tracer({trace,_,call,{Mod,Func,_},Caller}, {Pid,[{Mod,Func}|Expected]}) ->
+ maybe_tracer_done(Pid,Expected,{Mod,Func},Caller);
+tracer({trace,_,call,Call,Caller}, {Pid,Expected}) ->
+ ct:log("Tracer got unexpected: ~p~nCaller: ~p~nExpected: ~p~n",[Call,Caller,Expected]),
Pid ! {tracer_got_unexpected,Call,Expected},
{Pid,Expected}.
-maybe_tracer_done(Pid,[],Got) ->
- ct:log("Tracer got: ~p~n",[Got]),
+maybe_tracer_done(Pid,[],Got,Caller) ->
+ ct:log("Tracer got: ~p~nCaller: ~p~n",[Got,Caller]),
Pid ! tracer_done;
-maybe_tracer_done(Pid,Expected,Got) ->
- ct:log("Tracer got: ~p~n",[Got]),
+maybe_tracer_done(Pid,Expected,Got,Caller) ->
+ ct:log("Tracer got: ~p~nCaller: ~p~n",[Got,Caller]),
{Pid,Expected}.
check_tracer(T) ->
diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl
index 2ec4b243cf..8c13f0f908 100644
--- a/lib/kernel/test/logger_formatter_SUITE.erl
+++ b/lib/kernel/test/logger_formatter_SUITE.erl
@@ -765,6 +765,8 @@ check_config(_Config) ->
%% Test that formatter config can be changed, and that the default
%% template is updated accordingly
update_config(_Config) ->
+ {error,{not_found,?MODULE}} = logger:update_formatter_config(?MODULE,#{}),
+
logger:add_handler_filter(default,silence,{fun(_,_) -> stop end,ok}),
ok = logger:add_handler(?MODULE,?MODULE,#{}),
D = lists:seq(1,1000),
@@ -817,6 +819,11 @@ update_config(_Config) ->
ct:log("~p",[C6]),
["=NOTICE REPORT==== "++_,_D6] = Lines6,
+ {error,{invalid_formatter_config,bad}} =
+ logger:update_formatter_config(?MODULE,bad),
+ {error,{invalid_formatter_config,logger_formatter,{depth,bad}}} =
+ logger:update_formatter_config(?MODULE,depth,bad),
+
ok.
update_config(cleanup,_Config) ->
diff --git a/lib/kernel/test/logger_simple_h_SUITE.erl b/lib/kernel/test/logger_simple_h_SUITE.erl
index 79e5c057ad..e0ad792bdb 100644
--- a/lib/kernel/test/logger_simple_h_SUITE.erl
+++ b/lib/kernel/test/logger_simple_h_SUITE.erl
@@ -117,8 +117,7 @@ replace_default(Config) ->
log(Node, critical, [?str,[?keyval_rep]]),
log(Node, notice, [["fake",string,"line:",?LINE]]),
- Env = rpc:call(Node, application, get_env, [kernel, logger, []]),
- ok = rpc:call(Node, logger, add_handlers, [Env]),
+ ok = rpc:call(Node, logger, add_handlers, [kernel]),
ok.
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index 0930cd4211..3426567bbf 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -280,7 +280,7 @@ formatter_fail(Config) ->
ok = logger:set_handler_config(?MODULE,formatter,{?MODULE,bad_return}),
logger:notice(?msg,?domain),
try_match_file(Log,
- escape(Got3)++"FORMATTER ERROR: bad_return_value",
+ escape(Got3)++"FORMATTER ERROR: bad return value",
5000),
%% Check that handler is still alive and was never dead
generated by cgit v1.2.3 (git 2.25.1) at 2024-06-27 10:03:37 +0000