aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel/test/logger_std_h_SUITE.erl
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel/test/logger_std_h_SUITE.erl')
-rw-r--r--lib/kernel/test/logger_std_h_SUITE.erl342
1 files changed, 208 insertions, 134 deletions
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index 7c8d63cbbd..5764abd063 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -50,11 +50,12 @@
end).
suite() ->
- [{timetrap,{seconds,30}}].
+ [{timetrap,{seconds,30}},
+ {ct_hooks,[logger_test_lib]}].
init_per_suite(Config) ->
timer:start(), % to avoid progress report
- {ok,{?STANDARD_HANDLER,#{formatter:=OrigFormatter}}} =
+ {ok,{logger_std_h,#{formatter:=OrigFormatter}}} =
logger:get_handler_config(?STANDARD_HANDLER),
[{formatter,OrigFormatter}|Config].
@@ -241,36 +242,38 @@ formatter_fail(Config) ->
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE])}),
Pid = whereis(?MODULE),
true = is_pid(Pid),
- {ok,#{handlers:=H}} = logger:get_logger_config(),
+ #{handlers:=HC1} = logger:i(),
+ H = [Id || {Id,_,_} <- HC1],
true = lists:member(?MODULE,H),
%% Formatter is added automatically
{ok,{_,#{formatter:={logger_formatter,_}}}} =
logger:get_handler_config(?MODULE),
logger:info(M1=?msg,?domain),
- Got1 = try_match_file(Log,"=INFO REPORT====.*\n"++M1,5000),
+ Got1 = try_match_file(Log,"[0-9\\+\\-T:\\.]* info: "++M1,5000),
ok = logger:set_handler_config(?MODULE,formatter,{nonexistingmodule,#{}}),
logger:info(M2=?msg,?domain),
Got2 = try_match_file(Log,
- Got1++"=INFO REPORT====.*\nFORMATTER CRASH: .*"++M2,
+ escape(Got1)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M2,
5000),
ok = logger:set_handler_config(?MODULE,formatter,{?MODULE,crash}),
logger:info(M3=?msg,?domain),
Got3 = try_match_file(Log,
- Got2++"=INFO REPORT====.*\nFORMATTER CRASH: .*"++M3,
+ escape(Got2)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M3,
5000),
ok = logger:set_handler_config(?MODULE,formatter,{?MODULE,bad_return}),
logger:info(?msg,?domain),
try_match_file(Log,
- Got3++"FORMATTER ERROR: bad_return_value",
+ escape(Got3)++"FORMATTER ERROR: bad_return_value",
5000),
%% Check that handler is still alive and was never dead
Pid = whereis(?MODULE),
- {ok,#{handlers:=H}} = logger:get_logger_config(),
+ #{handlers:=HC2} = logger:i(),
+ H = [Id || {Id,_,_} <- HC2],
ok.
@@ -289,10 +292,17 @@ config_fail(_Config) ->
#{logger_std_h => #{restart_type => bad},
filter_default=>log,
formatter=>{?MODULE,self()}}),
- {error,{handler_not_added,{invalid_levels,{42,42,_}}}} =
+ {error,{handler_not_added,{invalid_levels,{_,1,_}}}} =
logger:add_handler(?MODULE,logger_std_h,
- #{logger_std_h => #{toggle_sync_qlen=>42,
+ #{logger_std_h => #{drop_new_reqs_qlen=>1}}),
+ {error,{handler_not_added,{invalid_levels,{43,42,_}}}} =
+ logger:add_handler(?MODULE,logger_std_h,
+ #{logger_std_h => #{toggle_sync_qlen=>43,
drop_new_reqs_qlen=>42}}),
+ {error,{handler_not_added,{invalid_levels,{_,43,42}}}} =
+ logger:add_handler(?MODULE,logger_std_h,
+ #{logger_std_h => #{drop_new_reqs_qlen=>43,
+ flush_reqs_qlen=>42}}),
ok = logger:add_handler(?MODULE,logger_std_h,
#{filter_default=>log,
@@ -315,29 +325,32 @@ config_fail(cleanup,_Config) ->
logger:remove_handler(?MODULE).
crash_std_h_to_file(Config) ->
- crash_std_h(Config,?FUNCTION_NAME,logger_dest,file).
+ Dir = ?config(priv_dir,Config),
+ Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])),
+ crash_std_h(Config,?FUNCTION_NAME,
+ [{handler,default,logger_std_h,
+ #{ logger_std_h => #{ type => {file, Log} }}}],
+ file, Log).
crash_std_h_to_file(cleanup,_Config) ->
crash_std_h(cleanup).
crash_std_h_to_disk_log(Config) ->
- crash_std_h(Config,?FUNCTION_NAME,logger_dest,disk_log).
+ Dir = ?config(priv_dir,Config),
+ Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])),
+ crash_std_h(Config,?FUNCTION_NAME,
+ [{handler,default,logger_disk_log_h,
+ #{ disk_log_opts => #{ file => Log }}}],
+ disk_log,Log).
crash_std_h_to_disk_log(cleanup,_Config) ->
crash_std_h(cleanup).
-crash_std_h(Config,Func,Var,Type) ->
+crash_std_h(Config,Func,Var,Type,Log) ->
Dir = ?config(priv_dir,Config),
- File = lists:concat([?MODULE,"_",Func,".log"]),
- Log = filename:join(Dir,File),
+ SysConfig = filename:join(Dir,lists:concat([?MODULE,"_",Func,".config"])),
+ ok = file:write_file(SysConfig, io_lib:format("[{kernel,[{logger,~p}]}].",[Var])),
Pa = filename:dirname(code:which(?MODULE)),
- TypeAndLog =
- case os:type() of
- {win32,_} ->
- lists:concat([" {",Type,",\\\"",Log,"\\\"}"]);
- _ ->
- lists:concat([" \'{",Type,",\"",Log,"\"}\'"])
- end,
- Args = lists:concat([" -kernel ",Var,TypeAndLog," -pa ",Pa]),
Name = lists:concat([?MODULE,"_",Func]),
+ Args = lists:concat([" -config ",filename:rootname(SysConfig)," -pa ",Pa]),
ct:pal("Starting ~p with ~tp", [Name,Args]),
%% Start a node which prints kernel logs to the destination specified by Type
{ok,Node} = test_server:start_node(Name, peer, [{args, Args}]),
@@ -578,7 +591,7 @@ write_failure(Config) ->
Dir = ?config(priv_dir, Config),
File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]),
Log = filename:join(Dir, File),
- Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log),
+ Node = start_std_h_on_new_node(Config, Log),
false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])),
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
@@ -615,7 +628,7 @@ sync_failure(Config) ->
Dir = ?config(priv_dir, Config),
File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]),
Log = filename:join(Dir, File),
- Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log),
+ Node = start_std_h_on_new_node(Config, Log),
false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])),
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
@@ -651,21 +664,12 @@ sync_failure(cleanup, _Config) ->
Nodes = nodes(),
[test_server:stop_node(Node) || Node <- Nodes].
-start_std_h_on_new_node(_Config, Func, Log) ->
- Pa = filename:dirname(code:which(?MODULE)),
- Dest =
- case os:type() of
- {win32,_} ->
- lists:concat([" {file,\\\"",Log,"\\\"}"]);
- _ ->
- lists:concat([" \'{file,\"",Log,"\"}\'"])
- end,
- Args = lists:concat([" -kernel ",logger_dest,Dest," -pa ",Pa]),
- Name = lists:concat([?MODULE,"_",Func]),
- ct:pal("Starting ~s with ~tp", [Name,Args]),
- {ok,Node} = test_server:start_node(Name, peer, [{args, Args}]),
- Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]),
- true = is_pid(Pid),
+start_std_h_on_new_node(Config, Log) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(
+ Config,
+ [{logger,[{handler,default,logger_std_h,
+ #{ logger_std_h => #{ type => {file,Log}}}}]}]),
ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter,
{?MODULE,nl}]),
Node.
@@ -691,16 +695,17 @@ internal_log(Type, Term) ->
op_switch_to_sync_file(Config) ->
{Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
+ NumOfReqs = 500,
NewHConfig =
- HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 3,
- drop_new_reqs_qlen => 501,
- flush_reqs_qlen => 2000,
+ HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 2,
+ drop_new_reqs_qlen => NumOfReqs+1,
+ flush_reqs_qlen => 2*NumOfReqs,
enable_burst_limit => false}},
ok = logger:set_handler_config(?MODULE, NewHConfig),
%% TRecvPid = start_op_trace(),
- NumOfReqs = 500,
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
- NumOfReqs = count_lines(Log),
+ Lines = count_lines(Log),
+ ok = file:delete(Log),
%% true = analyse_trace(TRecvPid,
%% fun(Events) -> find_mode(async,Events) end),
%% true = analyse_trace(TRecvPid,
@@ -711,68 +716,82 @@ op_switch_to_sync_file(Config) ->
%% fun(Events) -> find_mode(drop,Events) end),
%% false = analyse_trace(TRecvPid,
%% fun(Events) -> find_mode(flush,Events) end),
- ok = file:delete(Log),
%% stop_op_trace(TRecvPid),
+ NumOfReqs = Lines,
ok.
op_switch_to_sync_file(cleanup, _Config) ->
ok = stop_handler(?MODULE).
op_switch_to_sync_tty(Config) ->
{HConfig,StdHConfig} = start_handler(?MODULE, standard_io, Config),
+ NumOfReqs = 500,
NewHConfig =
HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 3,
- drop_new_reqs_qlen => 501,
- flush_reqs_qlen => 2000,
+ drop_new_reqs_qlen => NumOfReqs+1,
+ flush_reqs_qlen => 2*NumOfReqs,
enable_burst_limit => false}},
ok = logger:set_handler_config(?MODULE, NewHConfig),
- NumOfReqs = 500,
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
ok.
op_switch_to_sync_tty(cleanup, _Config) ->
ok = stop_handler(?MODULE).
+op_switch_to_drop_file() ->
+ [{timetrap,{seconds,180}}].
op_switch_to_drop_file(Config) ->
- {Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
-
- NewHConfig =
- HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 2,
- drop_new_reqs_qlen => 3,
- flush_reqs_qlen => 600,
+ Test =
+ fun() ->
+ {Log,HConfig,StdHConfig} =
+ start_handler(?MODULE, ?FUNCTION_NAME, Config),
+ NumOfReqs = 300,
+ Procs = 2,
+ Bursts = 10,
+ NewHConfig =
+ HConfig#{logger_std_h =>
+ StdHConfig#{toggle_sync_qlen => 1,
+ drop_new_reqs_qlen => 2,
+ flush_reqs_qlen =>
+ Procs*NumOfReqs*Bursts,
enable_burst_limit => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
- %% TRecvPid = start_op_trace(),
- NumOfReqs = 500,
- send_burst({n,NumOfReqs}, seq, {chars,79}, info),
- Logged = count_lines(Log),
- ct:pal("Number of messages dropped = ~w (~w)",
- [NumOfReqs-Logged,NumOfReqs]),
- true = (Logged < NumOfReqs),
- %% true = analyse_trace(TRecvPid,
- %% fun(Events) -> find_mode(async,Events) end),
- %% true = analyse_trace(TRecvPid,
- %% fun(Events) -> find_mode(drop,Events) end),
- %% false = analyse_trace(TRecvPid,
- %% fun(Events) -> find_mode(flush,Events) end),
- %% true = analyse_trace(TRecvPid,
- %% fun(Events) -> find_switch(async,drop,Events)
- %% orelse find_switch(sync,drop,Events)
- %% end),
- ok = file:delete(Log),
- %% stop_op_trace(TRecvPid),
- ok.
+ ok = logger:set_handler_config(?MODULE, NewHConfig),
+ %% It sometimes happens that the handler gets the
+ %% requests in a slow enough pace so that dropping
+ %% never occurs. Therefore, lets generate a number of
+ %% bursts to increase the chance of message buildup.
+ [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) ||
+ _ <- lists:seq(1, Bursts)],
+ Logged = count_lines(Log),
+ ok = stop_handler(?MODULE),
+ _ = file:delete(Log),
+ ct:pal("Number of messages dropped = ~w (~w)",
+ [Procs*NumOfReqs*Bursts-Logged,Procs*NumOfReqs*Bursts]),
+ true = (Logged < (Procs*NumOfReqs*Bursts)),
+ true = (Logged > 0),
+ ok
+ end,
+ %% As it's tricky to get the timing right in only one go, we perform the
+ %% test repeatedly, hoping that will generate a successful result.
+ case repeat_until_ok(Test, 10) of
+ {ok,{Failures,_Result}} ->
+ ct:log("Failed ~w times before success!", [Failures]);
+ {fails,Reason} ->
+ ct:fail(Reason)
+ end.
op_switch_to_drop_file(cleanup, _Config) ->
- ok = stop_handler(?MODULE).
+ _ = stop_handler(?MODULE).
op_switch_to_drop_tty(Config) ->
{HConfig,StdHConfig} = start_handler(?MODULE, standard_io, Config),
+ NumOfReqs = 300,
+ Procs = 2,
NewHConfig =
- HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 2,
- drop_new_reqs_qlen => 3,
- flush_reqs_qlen => 600,
+ HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 1,
+ drop_new_reqs_qlen => 2,
+ flush_reqs_qlen =>
+ Procs*NumOfReqs+1,
enable_burst_limit => false}},
ok = logger:set_handler_config(?MODULE, NewHConfig),
- NumOfReqs = 500,
- send_burst({n,NumOfReqs}, seq, {chars,79}, info),
+ send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info),
ok.
op_switch_to_drop_tty(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -780,32 +799,54 @@ op_switch_to_drop_tty(cleanup, _Config) ->
op_switch_to_flush_file() ->
[{timetrap,{minutes,3}}].
op_switch_to_flush_file(Config) ->
- {Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
-
- %% it's important that both async and sync requests have been queued
- %% when the flush happens (verify with coverage of flush_log_requests/2)
-
- NewHConfig =
- HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 2,
- drop_new_reqs_qlen => 99,
- flush_reqs_qlen => 100,
+ Test =
+ fun() ->
+ {Log,HConfig,StdHConfig} =
+ start_handler(?MODULE, ?FUNCTION_NAME, Config),
+
+ %% NOTE: it's important that both async and sync
+ %% requests have been queued when the flush happens
+ %% (verify with coverage of flush_log_requests/2)
+
+ NewHConfig =
+ HConfig#{logger_std_h =>
+ StdHConfig#{toggle_sync_qlen => 2,
+ %% disable drop mode
+ drop_new_reqs_qlen => 300,
+ flush_reqs_qlen => 300,
enable_burst_limit => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
- NumOfReqs = 10000,
- Procs = 100,
- send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info),
- Logged = count_lines(Log),
- ct:pal("Number of messages flushed/dropped = ~w (~w)",
- [(NumOfReqs*Procs)-Logged,NumOfReqs*Procs]),
- true = (Logged < (NumOfReqs*Procs)),
-
- %%! --- Thu Apr 12 13:46:00 2018 --- peppe was here!
- %%! TODO: Verify that handler has switched to flush mode
-
- ok = file:delete(Log),
- ok.
+ ok = logger:set_handler_config(?MODULE, NewHConfig),
+ NumOfReqs = 1500,
+ Procs = 10,
+ Bursts = 10,
+ %% It sometimes happens that the handler either gets
+ %% the requests in a slow enough pace so that flushing
+ %% never occurs, or it gets all messages at once,
+ %% causing all messages to get flushed (no dropping of
+ %% sync messages gets tested). Therefore, lets
+ %% generate a number of bursts to increase the chance
+ %% of message buildup in some random fashion.
+ [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) ||
+ _ <- lists:seq(1,Bursts)],
+ Logged = count_lines(Log),
+ ok = stop_handler(?MODULE),
+ _ = file:delete(Log),
+ ct:pal("Number of messages flushed/dropped = ~w (~w)",
+ [NumOfReqs*Procs*Bursts-Logged,NumOfReqs*Procs*Bursts]),
+ true = (Logged < (NumOfReqs*Procs*Bursts)),
+ true = (Logged > 0),
+ ok
+ end,
+ %% As it's tricky to get the timing right in only one go, we perform the
+ %% test repeatedly, hoping that will generate a successful result.
+ case repeat_until_ok(Test, 10) of
+ {ok,{Failures,_Result}} ->
+ ct:log("Failed ~w times before success!", [Failures]);
+ {fails,Reason} ->
+ ct:fail(Reason)
+ end.
op_switch_to_flush_file(cleanup, _Config) ->
- ok = stop_handler(?MODULE).
+ _ = stop_handler(?MODULE).
op_switch_to_flush_tty(Config) ->
{HConfig,StdHConfig} = start_handler(?MODULE, standard_io, Config),
@@ -815,12 +856,13 @@ op_switch_to_flush_tty(Config) ->
NewHConfig =
HConfig#{logger_std_h => StdHConfig#{toggle_sync_qlen => 2,
- drop_new_reqs_qlen => 99,
+ %% disable drop mode
+ drop_new_reqs_qlen => 100,
flush_reqs_qlen => 100,
enable_burst_limit => false}},
ok = logger:set_handler_config(?MODULE, NewHConfig),
- NumOfReqs = 10000,
- Procs = 10,
+ NumOfReqs = 1000,
+ Procs = 100,
send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info),
ok.
op_switch_to_flush_tty(cleanup, _Config) ->
@@ -904,10 +946,10 @@ kill_disabled(cleanup, _Config) ->
ok = stop_handler(?MODULE).
qlen_kill_new(Config) ->
- {Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
+ {_Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
Pid0 = whereis(?MODULE),
{_,Mem0} = process_info(Pid0, memory),
- RestartAfter = 2000,
+ RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
HConfig#{logger_std_h=>StdHConfig#{enable_kill_overloaded=>true,
handler_overloaded_qlen=>10,
@@ -927,7 +969,7 @@ qlen_kill_new(Config) ->
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
- timer:sleep(RestartAfter + 1000),
+ timer:sleep(RestartAfter + 2000),
true = is_pid(whereis(?MODULE)),
ok
after
@@ -941,7 +983,7 @@ qlen_kill_new(cleanup, _Config) ->
%% choke the standard handler on remote node to verify the termination
%% works as expected
-qlen_kill_std(Config) ->
+qlen_kill_std(_Config) ->
%%! HERE
%% Dir = ?config(priv_dir, Config),
%% File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]),
@@ -955,10 +997,10 @@ qlen_kill_std(Config) ->
{skip,"Not done yet"}.
mem_kill_new(Config) ->
- {Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
+ {_Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
Pid0 = whereis(?MODULE),
{_,Mem0} = process_info(Pid0, memory),
- RestartAfter = 2000,
+ RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
HConfig#{logger_std_h=>StdHConfig#{enable_kill_overloaded=>true,
handler_overloaded_qlen=>50000,
@@ -978,7 +1020,7 @@ mem_kill_new(Config) ->
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
- timer:sleep(RestartAfter * 2),
+ timer:sleep(RestartAfter * 3),
true = is_pid(whereis(?MODULE)),
ok
after
@@ -992,7 +1034,7 @@ mem_kill_new(cleanup, _Config) ->
%% choke the standard handler on remote node to verify the termination
%% works as expected
-mem_kill_std(Config) ->
+mem_kill_std(_Config) ->
{skip,"Not done yet"}.
restart_after(Config) ->
@@ -1016,7 +1058,7 @@ restart_after(Config) ->
end,
{Log,_,_} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
- RestartAfter = 2000,
+ RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig2 =
HConfig#{logger_std_h=>StdHConfig#{enable_kill_overloaded=>true,
handler_overloaded_qlen=>10,
@@ -1028,7 +1070,7 @@ restart_after(Config) ->
send_burst({n,100}, {spawn,2,0}, {chars,79}, info),
receive
{'DOWN', MRef2, _, _, _Info2} ->
- timer:sleep(RestartAfter + 1000),
+ timer:sleep(RestartAfter + 2000),
Pid1 = whereis(?MODULE),
true = is_pid(Pid1),
false = (Pid1 == Pid0),
@@ -1074,7 +1116,7 @@ handler_requests_under_load(Config) ->
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) ->
+handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) ->
@@ -1126,8 +1168,9 @@ start_handler(Name, FuncName, Config) ->
{Log,HConfig,StdHConfig}.
stop_handler(Name) ->
- ok = logger:remove_handler(Name),
- ct:pal("Handler ~p stopped!", [Name]).
+ R = logger:remove_handler(Name),
+ ct:pal("Handler ~p stopped! Result: ~p", [Name,R]),
+ R.
count_lines(File) ->
wait_until_written(File, -1),
@@ -1299,6 +1342,30 @@ try_match_file(_,Pattern,_,Incorrect) ->
[Pattern,Incorrect]),
erlang:error({error,not_matching_pattern,Pattern,Incorrect}).
+repeat_until_ok(Fun, N) ->
+ repeat_until_ok(Fun, 0, N, undefined).
+
+repeat_until_ok(_Fun, Stop, Stop, Reason) ->
+ {fails,Reason};
+
+repeat_until_ok(Fun, C, Stop, FirstReason) ->
+ if C > 0 -> timer:sleep(5000);
+ true -> ok
+ end,
+ try Fun() of
+ Result ->
+ {ok,{C,Result}}
+ catch
+ _:Reason:Stack ->
+ ct:pal("Test fails: ~p (~p)~n", [Reason,hd(Stack)]),
+ if FirstReason == undefined ->
+ repeat_until_ok(Fun, C+1, Stop, {Reason,Stack});
+ true ->
+ repeat_until_ok(Fun, C+1, Stop, FirstReason)
+ end
+ end.
+
+
%%%-----------------------------------------------------------------
%%%
start_op_trace() ->
@@ -1339,17 +1406,17 @@ find_mode(flush, Events) ->
find_mode(Mode, Events) ->
lists:keymember([{mode,Mode}], 3, Events).
-find_switch(From, To, Events) ->
- try lists:foldl(fun({trace_return,check_load,{To,_,_,_}},
- {trace_call,check_load,[#{mode := From}]}) ->
- throw(match);
- (Event, _) ->
- Event
- end, undefined, Events) of
- _ -> false
- catch
- throw:match -> true
- end.
+%% find_switch(_From, To, Events) ->
+%% try lists:foldl(fun({trace_return,check_load,{To,_,_,_}},
+%% {trace_call,check_load,[#{mode := From}]}) ->
+%% throw(match);
+%% (Event, _) ->
+%% Event
+%% end, undefined, Events) of
+%% _ -> false
+%% catch
+%% throw:match -> true
+%% end.
analyse_trace(TRecvPid, TestFun) ->
TRecvPid ! {test,self(),TestFun},
@@ -1411,7 +1478,7 @@ tpl([{M,F,A}|Trace]) ->
tpl([]) ->
ok.
-tracer({trace,_,call,{logger_std_h,handle_cast,[{Op,_}|_]}},
+tracer({trace,_,call,{logger_std_h,handle_cast,[Op|_]}},
{Pid,[{Mod,Func,Op}|Expected]}) ->
maybe_tracer_done(Pid,Expected,{Mod,Func,Op});
tracer({trace,_,call,{Mod=logger_std_h,Func=write_to_dev,[_,Data,_,_,_]}},
@@ -1451,3 +1518,10 @@ check_tracer(T,TimeoutFun) ->
dbg:stop_clear(),
TimeoutFun()
end.
+
+escape([$+|Rest]) ->
+ [$\\,$+|escape(Rest)];
+escape([H|T]) ->
+ [H|escape(T)];
+escape([]) ->
+ [].