aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel/test/logger_disk_log_h_SUITE.erl
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel/test/logger_disk_log_h_SUITE.erl')
-rw-r--r--lib/kernel/test/logger_disk_log_h_SUITE.erl169
1 files changed, 72 insertions, 97 deletions
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index 87b8250781..9bbec42de8 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -24,6 +24,7 @@
-include_lib("common_test/include/ct.hrl").
-include_lib("kernel/include/logger.hrl").
-include_lib("kernel/src/logger_internal.hrl").
+-include_lib("kernel/src/logger_olp.hrl").
-include_lib("kernel/src/logger_h_common.hrl").
-include_lib("stdlib/include/ms_transform.hrl").
-include_lib("kernel/include/file.hrl").
@@ -97,7 +98,6 @@ all() ->
formatter_fail,
config_fail,
bad_input,
- info_and_reset,
reconfig,
sync,
disk_log_full,
@@ -306,9 +306,9 @@ logging(cleanup, _Config) ->
filter_config(_Config) ->
ok = logger:add_handler(?MODULE,logger_disk_log_h,#{}),
{ok,#{config:=HConfig}=Config} = logger:get_handler_config(?MODULE),
- HConfig = maps:without([handler_pid,mode_tab],HConfig),
+ HConfig = maps:without([olp],HConfig),
- FakeFullHConfig = HConfig#{handler_pid=>self(),mode_tab=>erlang:make_ref()},
+ FakeFullHConfig = HConfig#{olp=>{regname,self(),erlang:make_ref()}},
#{config:=HConfig} =
logger_disk_log_h:filter_config(Config#{config=>FakeFullHConfig}),
ok.
@@ -351,9 +351,7 @@ errors(Config) ->
%% Read-only fields may (accidentially) be included in the change,
%% but it won't take effect
{ok,C} = logger:get_handler_config(Name1),
- ok = logger:set_handler_config(Name1,config,
- #{handler_pid=>self(),
- mode_tab=>erlang:make_ref()}),
+ ok = logger:set_handler_config(Name1,config,#{olp=>dummyvalue}),
{ok,C} = logger:get_handler_config(Name1),
@@ -419,19 +417,16 @@ config_fail(_Config) ->
filter_default=>log,
formatter=>{?MODULE,self()}}),
- {error,{handler_not_added,{invalid_config,logger_disk_log_h,
- {invalid_levels,#{drop_mode_qlen:=1}}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=1}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{drop_mode_qlen=>1}}),
- {error,{handler_not_added,{invalid_config,logger_disk_log_h,
- {invalid_levels,#{sync_mode_qlen:=43,
- drop_mode_qlen:=42}}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{sync_mode_qlen:=43,
+ drop_mode_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{sync_mode_qlen=>43,
drop_mode_qlen=>42}}),
- {error,{handler_not_added,{invalid_config,logger_disk_log_h,
- {invalid_levels,#{drop_mode_qlen:=43,
- flush_qlen:=42}}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=43,
+ flush_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{drop_mode_qlen=>43,
flush_qlen=>42}}),
@@ -445,7 +440,7 @@ config_fail(_Config) ->
#{max_no_files=>2}),
%% incorrect values of OP params
{ok,#{config := HConfig}} = logger:get_handler_config(?MODULE),
- {error,{invalid_config,logger_disk_log_h,{invalid_levels,_}}} =
+ {error,{invalid_olp_levels,_}} =
logger:update_handler_config(?MODULE,config,
HConfig#{sync_mode_qlen=>100,
flush_qlen=>99}),
@@ -459,18 +454,7 @@ config_fail(cleanup,_Config) ->
bad_input(_Config) ->
{error,{badarg,{filesync,["BadType"]}}} =
- logger_disk_log_h:filesync("BadType"),
- {error,{badarg,{info,["BadType"]}}} = logger_disk_log_h:info("BadType"),
- {error,{badarg,{reset,["BadType"]}}} = logger_disk_log_h:reset("BadType").
-
-info_and_reset(_Config) ->
- ok = logger:add_handler(?MODULE,logger_disk_log_h,
- #{filter_default=>log,
- formatter=>{?MODULE,self()}}),
- #{id := ?MODULE} = logger_disk_log_h:info(?MODULE),
- ok = logger_disk_log_h:reset(?MODULE).
-info_and_reset(cleanup,_Config) ->
- logger:remove_handler(?MODULE).
+ logger_disk_log_h:filesync("BadType").
reconfig(Config) ->
Dir = ?config(priv_dir,Config),
@@ -479,7 +463,7 @@ reconfig(Config) ->
#{filter_default=>log,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- #{id := ?MODULE,
+ #{%id := ?MODULE,
sync_mode_qlen := ?SYNC_MODE_QLEN,
drop_mode_qlen := ?DROP_MODE_QLEN,
flush_qlen := ?FLUSH_QLEN,
@@ -490,13 +474,14 @@ reconfig(Config) ->
overload_kill_qlen := ?OVERLOAD_KILL_QLEN,
overload_kill_mem_size := ?OVERLOAD_KILL_MEM_SIZE,
overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER,
- filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL,
- handler_state :=
- #{log_opts := #{type := ?DISK_LOG_TYPE,
- max_no_files := ?DISK_LOG_MAX_NO_FILES,
- max_no_bytes := ?DISK_LOG_MAX_NO_BYTES,
- file := DiskLogFile}}} =
- logger_disk_log_h:info(?MODULE),
+ cb_state :=
+ #{handler_state :=
+ #{log_opts := #{type := ?DISK_LOG_TYPE,
+ max_no_files := ?DISK_LOG_MAX_NO_FILES,
+ max_no_bytes := ?DISK_LOG_MAX_NO_BYTES,
+ file := DiskLogFile}},
+ filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL}} =
+ logger_olp:info(h_proc_name()),
{ok,#{config :=
#{sync_mode_qlen := ?SYNC_MODE_QLEN,
drop_mode_qlen := ?DROP_MODE_QLEN,
@@ -527,7 +512,7 @@ reconfig(Config) ->
overload_kill_restart_after => infinity,
filesync_repeat_interval => no_repeat},
ok = logger:set_handler_config(?MODULE, config, HConfig1),
- #{id := ?MODULE,
+ #{%id := ?MODULE,
sync_mode_qlen := 1,
drop_mode_qlen := 2,
flush_qlen := 3,
@@ -538,8 +523,8 @@ reconfig(Config) ->
overload_kill_qlen := 100000,
overload_kill_mem_size := 10000000,
overload_kill_restart_after := infinity,
- filesync_repeat_interval := no_repeat} =
- logger_disk_log_h:info(?MODULE),
+ cb_state := #{filesync_repeat_interval := no_repeat}} =
+ logger_olp:info(h_proc_name()),
{ok,#{config:=HConfig1}} = logger:get_handler_config(?MODULE),
ok = logger:update_handler_config(?MODULE, config,
@@ -577,12 +562,13 @@ reconfig(Config) ->
max_no_files => 1,
max_no_bytes => 1024,
file => File}}),
- #{handler_state :=
- #{log_opts := #{type := halt,
- max_no_files := 1,
- max_no_bytes := 1024,
- file := File}}} =
- logger_disk_log_h:info(?MODULE),
+ #{cb_state :=
+ #{handler_state :=
+ #{log_opts := #{type := halt,
+ max_no_files := 1,
+ max_no_bytes := 1024,
+ file := File}}}} =
+ logger_olp:info(h_proc_name()),
{ok,#{config :=
#{type := halt,
max_no_files := 1,
@@ -650,13 +636,8 @@ sync(Config) ->
{ok,#{config := HConfig}} = logger:get_handler_config(?MODULE),
HConfig1 = HConfig#{filesync_repeat_interval => no_repeat},
ok = logger:update_handler_config(?MODULE, config, HConfig1),
-
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),
+ maps:get(cb_state,logger_olp:info(h_proc_name()))),
start_tracer([{logger_disk_log_h,disk_log_write,3},
{disk_log,sync,1}],
@@ -666,10 +647,10 @@ sync(Config) ->
{disk_log,sync}]),
logger:notice("second", ?domain),
- timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
+ timer:sleep(?IDLE_DETECT_TIME*2),
logger:notice("third", ?domain),
%% wait for automatic disk_log_sync
- check_tracer(?IDLE_DETECT_TIME_MSEC*2),
+ check_tracer(?IDLE_DETECT_TIME*2),
try_read_file(Log, {ok,<<"first\nsecond\nthird\n">>}, 1000),
@@ -678,14 +659,15 @@ sync(Config) ->
WaitT = 4500,
OneSync = {logger_h_common,handle_cast,repeated_filesync},
%% receive 1 repeated_filesync per sec
- start_tracer([{logger_h_common,handle_cast,2}],
+ start_tracer([{{logger_h_common,handle_cast,2},
+ [{[repeated_filesync,'_'],[],[{message,{caller}}]}]}],
[OneSync || _ <- lists:seq(1, trunc(WaitT/SyncInt))]),
HConfig2 = HConfig#{filesync_repeat_interval => SyncInt},
ok = logger:update_handler_config(?MODULE, config, HConfig2),
SyncInt = maps:get(filesync_repeat_interval,
- logger_disk_log_h:info(?MODULE)),
+ maps:get(cb_state,logger_olp:info(h_proc_name()))),
timer:sleep(WaitT),
HConfig3 = HConfig#{filesync_repeat_interval => no_repeat},
ok = logger:update_handler_config(?MODULE, config, HConfig3),
@@ -803,7 +785,7 @@ disk_log_full(cleanup, _Config) ->
dbg:stop_clear(),
logger:remove_handler(?MODULE).
-disk_log_events(Config) ->
+disk_log_events(_Config) ->
Node = node(),
Log = ?MODULE,
ok = logger:add_handler(?MODULE,
@@ -860,10 +842,12 @@ write_failure(Config) ->
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
rpc:call(Node, ?MODULE, set_result, [disk_log_write,ok]),
- HState = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- ct:pal("LogOpts = ~p", [LogOpts = maps:get(log_opts,
- maps:get(handler_state,HState))]),
-
+ HState = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ LogOpts = maps:get(log_opts,
+ maps:get(handler_state,
+ maps:get(cb_state,HState))),
+ ct:pal("LogOpts = ~p", [LogOpts]),
+
%% ?check and ?check_no_log in this test only check for internal log events
ok = log_on_remote_node(Node, "Logged1"),
rpc:call(Node, logger_disk_log_h, filesync, [?STANDARD_HANDLER]),
@@ -914,15 +898,16 @@ sync_failure(Config) ->
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
rpc:call(Node, ?MODULE, set_result, [disk_log_sync,ok]),
- HState = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- LogOpts = maps:get(log_opts, maps:get(handler_state,HState)),
+ HState = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ LogOpts = maps:get(log_opts, maps:get(handler_state,
+ maps:get(cb_state,HState))),
SyncInt = 500,
ok = rpc:call(Node, logger, update_handler_config,
[?STANDARD_HANDLER, config,
#{filesync_repeat_interval => SyncInt}]),
- Info = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- SyncInt = maps:get(filesync_repeat_interval, Info),
+ Info = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ SyncInt = maps:get(filesync_repeat_interval, maps:get(cb_state, Info)),
ok = log_on_remote_node(Node, "Logged1"),
?check_no_log,
@@ -1198,7 +1183,7 @@ qlen_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -1208,7 +1193,7 @@ qlen_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_disk_log_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1235,7 +1220,7 @@ mem_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -1245,7 +1230,7 @@ mem_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_disk_log_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1271,7 +1256,7 @@ restart_after(Config) ->
ok
after
5000 ->
- Info1 = logger_std_h:info(?MODULE),
+ Info1 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info1]),
ct:fail("Handler not dead! It should not have survived this!")
end,
@@ -1295,7 +1280,7 @@ restart_after(Config) ->
ok
after
5000 ->
- Info2 = logger_std_h:info(?MODULE),
+ Info2 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info2]),
ct:fail("Handler not dead! It should not have survived this!")
end,
@@ -1316,11 +1301,15 @@ handler_requests_under_load(Config) ->
flush_qlen => 2000,
burst_limit_enable => false}},
ok = logger:update_handler_config(?MODULE, NewHConfig),
- Pid = spawn_link(fun() -> send_requests(?MODULE, 1, [{filesync,[]},
- {info,[]},
- {reset,[]},
- {change_config,[]}])
- end),
+ Pid = spawn_link(
+ fun() -> send_requests(1,[{logger_disk_log_h,filesync,[?MODULE],[]},
+ {logger_olp,info,[h_proc_name()],[]},
+ {logger_olp,reset,[h_proc_name()],[]},
+ {logger,update_handler_config,
+ [?MODULE, config,
+ #{overload_kill_enable => false}],
+ []}])
+ end),
Procs = 100,
Sent = Procs * send_burst({n,5000}, {spawn,Procs,10}, {chars,79}, notice),
Pid ! {self(),finish},
@@ -1332,29 +1321,22 @@ handler_requests_under_load(Config) ->
[E || E <- Res,
is_tuple(E) andalso (element(1,E) == error)]
end,
- Errors = [{Req,FindError(Res)} || {Req,Res} <- ReqResult],
- NoOfReqs = lists:foldl(fun({_,Res}, N) -> N + length(Res) end, 0, ReqResult),
+ Errors = [{Func,FindError(Res)} || {_,Func,_,Res} <- ReqResult],
+ NoOfReqs = lists:foldl(fun({_,_,_,Res}, N) -> N + length(Res) end,
+ 0, ReqResult),
ct:pal("~w requests made. Errors: ~n~p", [NoOfReqs,Errors]),
ok = file_delete(Log).
handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
-send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) ->
+send_requests(TO, Reqs = [{Mod,Func,Args,Res}|Rs]) ->
receive
{From,finish} ->
From ! {self(),Reqs}
after
TO ->
- Result =
- case Req of
- change_config ->
- logger:update_handler_config(HName, logger_disk_log_h,
- #{overload_kill_enable =>
- false});
- Func ->
- logger_disk_log_h:Func(HName)
- end,
- send_requests(HName, TO, Rs ++ [{Req,[Result|Res]}])
+ Result = apply(Mod,Func,Args),
+ send_requests(TO, Rs ++ [{Mod,Func,Args,[Result|Res]}])
end.
%%%-----------------------------------------------------------------
@@ -1472,15 +1454,6 @@ format(Msg,Tag) ->
erlang:display(Error),
exit(Error).
-remove(Handler, LogName) ->
- logger_disk_log_h:remove(Handler, LogName),
- HState = #{log_names := Logs} = logger_disk_log_h:info(),
- false = maps:is_key(LogName, HState),
- false = lists:member(LogName, Logs),
- false = logger_config:exist(?LOGGER_TABLE, LogName),
- {error,no_such_log} = disk_log:info(LogName),
- ok.
-
start_and_add(Name, Config, LogOpts) ->
HConfig = maps:get(config, Config, #{}),
HConfig1 = maps:merge(HConfig, LogOpts),
@@ -1607,7 +1580,9 @@ start_tracer(Trace,Expected) ->
ok.
tpl([{M,F,A}|Trace]) ->
- {ok,Match} = dbg:tpl(M,F,A,c),
+ tpl([{{M,F,A},c}|Trace]);
+tpl([{{M,F,A},MS}|Trace]) ->
+ {ok,Match} = dbg:tpl(M,F,A,MS),
case lists:keyfind(matched,1,Match) of
{_,_,1} ->
ok;